Arduino LMIC-based devices Downlink only works directly after join

joachimt · May 8, 2023, 11:11am

Hello,

I have setup an TTGO Lora32-Oled-V1 according to Devices - ChirpStack open-source LoRaWAN<sup>®</sup> Network Server.

Uplink messages arrive. Everything is working fine.
Then within the GUI I queue a downlink message. This message is not transferred (or at least I do not see anything) to my device.

Only when I reboot my device joins I see the downlink data coming correctly to my device, but surprisingly the queued message stays in the queue and has not been flushed.

output of my arduino sketch:
rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5856
entry 0x400806a8
Starting
Packet queued
1965: EV_JOINING
273419: EV_TXSTART
594462: EV_JOINED
netid: 0
devaddr: 5B6FC5
AppSKey: EB-F0-EB-B5-18-97-4A-70-B6-4C-03-F0-D2-62-A2-4C
NwkSKey: FD-FC-8F-F1-63-BC-B8-72-6D-C5-E6-BA-D8-AC-C2-72
594667: EV_TXSTART
672915: EV_TXCOMPLETE (includes waiting for RX windows)

Received 92 bytes of payload

979631: EV_TXSTART
1121843: EV_TXCOMPLETE (includes waiting for RX windows)
4871864: EV_TXSTART
Packet queued
5015042: EV_TXCOMPLETE (includes waiting for RX windows)

I have put a big message of 92 bytes as I myself am only able to trace the message in the size of transferred data in the logs of chirpstack docker-compose and the logs of my gateway.
And I only see the data is transferred after a join. I don’t see anything when the device has already joined and queue the message afterwards.

Does anybody has an idea? Can anybody help?

Best regards

Joachim

bakok · May 8, 2023, 12:05pm

hello dear @joachimt!

Can you post server log here?
How do you connect your server?
ABP or OTAA?

joachimt · May 8, 2023, 12:41pm

Hello,

Thank you for your reply.

I use OTAA.
In the configuration I have set up verbose logging for chirpstack-gateway-bridge and mqtt.


mosquitto_1                        | 1683445754: Received PINGREQ from 76e8d7f81266057c
mosquitto_1                        | 1683445754: Sending PINGRESP to 76e8d7f81266057c
mosquitto_1                        | 1683445755: Received PUBLISH from auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (111 bytes))
mosquitto_1                        | 1683445755: Sending PUBLISH to 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (111 bytes))
mosquitto_1                        | 1683445755: Received PUBLISH from 9b8c0b323372a5ce (d0, q0, r0, m0, 'application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/up', ... (961 bytes))
mosquitto_1                        | 1683445755: Received PUBLISH from 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (340 bytes))
mosquitto_1                        | 1683445755: Sending PUBLISH to auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (340 bytes))
mosquitto_1                        | 1683445781: Received PINGREQ from 9b8c0b323372a5ce
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160516885Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160730297Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=eu868/gateway/b827ebfffe34b37f/event/up uplink_id=1083
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160772516Z" level=debug msg="[client]   enter Publish" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160795983Z" level=debug msg="[client]   sending publish message, topic: eu868/gateway/b827ebfffe34b37f/event/up" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:42.161700Z  INFO chirpstack::gateway::backend::mqtt: Message received from gateway region_config_id="eu868" topic="eu868/gateway/b827ebfffe34b37f/event/up" qos=0 json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160753614Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.160834348Z" level=debug msg="[net]      obound msg to write 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.161123695Z" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.161158321Z" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:42.364223Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}: chirpstack::uplink: Uplink received m_type="JoinRequest"
chirpstack_1                       | 2023-05-07T07:49:42.373256Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::storage::device_keys: Device-nonce validated and stored dev_eui=675b165d484517d4 dev_nonce=18230
chirpstack_1                       | 2023-05-07T07:49:42.376212Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::storage::device_keys: Device-keys updated dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:42.377307Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:42.380013Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::storage::device: Enabled class updated dev_eui=675b165d484517d4 enabled_class=A
chirpstack_1                       | 2023-05-07T07:49:42.380141Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::gateway::backend::mqtt: Sending downlink frame gateway_id=b827ebfffe34b37f topic=eu868/gateway/b827ebfffe34b37f/command/down json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.380914914Z" level=debug msg="[net]      startIncoming Received Message" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.38097767Z" level=debug msg="[net]      startIncomingComms: got msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.381017402Z" level=debug msg="[net]      startIncomingComms: received publish, msgId: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.381063085Z" level=debug msg="[net]      logic waiting for msg on ibound" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:42.381321Z  INFO up{deduplication_id=67c52a02-db8c-4cae-9db7-5d67060d4062}:join_request: chirpstack::storage::downlink_frame: Downlink-frame saved downlink_id=289052062
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.381184573Z" level=info msg="integration/mqtt: downlink frame received" downlink_id=289052062 gateway_id=b827ebfffe34b37f
chirpstack_1                       | 2023-05-07T07:49:42.382171Z  INFO chirpstack::integration::mqtt: Publishing event topic=application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/join
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.381314291Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullResp
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.660243343Z" level=debug msg="[pinger]   ping check 0.49906711" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.697938654Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.698196141Z" level=info msg="integration/mqtt: publishing event" event=stats qos=0 topic=eu868/gateway/b827ebfffe34b37f/event/stats
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.698235303Z" level=debug msg="[client]   enter Publish" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.69825879Z" level=debug msg="[client]   sending publish message, topic: eu868/gateway/b827ebfffe34b37f/event/stats" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.69829595Z" level=debug msg="[net]      obound msg to write 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.698198856Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushACK
chirpstack_1                       | 2023-05-07T07:49:42.698957Z  INFO chirpstack::gateway::backend::mqtt: Message received from gateway region_config_id="eu868" topic="eu868/gateway/b827ebfffe34b37f/event/stats" qos=0 json=false
mosquitto_1                        | 1683445781: Sending PINGRESP to 9b8c0b323372a5ce
mosquitto_1                        | 1683445781: Received PINGREQ from 230af1e06bdc0790
mosquitto_1                        | 1683445781: Sending PINGRESP to 230af1e06bdc0790
mosquitto_1                        | 1683445782: Received PUBLISH from auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (110 bytes))
mosquitto_1                        | 1683445782: Sending PUBLISH to 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (110 bytes))
mosquitto_1                        | 1683445782: Received PUBLISH from 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (278 bytes))
mosquitto_1                        | 1683445782: Sending PUBLISH to auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (278 bytes))
mosquitto_1                        | 1683445782: Received PUBLISH from 9b8c0b323372a5ce (d0, q0, r0, m0, 'application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/join', ... (444 bytes))
mosquitto_1                        | 1683445782: Received PUBLISH from auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/stats', ... (100 bytes))
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.698426932Z" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:42.698453334Z" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:42.701675Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::gateway: Gateway state and location updated gateway_id=b827ebfffe34b37f
chirpstack_1                       | 2023-05-07T07:49:42.702132Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=HOUR
chirpstack_1                       | 2023-05-07T07:49:42.702465Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=DAY
chirpstack_1                       | 2023-05-07T07:49:42.702794Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=MONTH
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298061466Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.29840673Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298453464Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=eu868/gateway/b827ebfffe34b37f/event/up uplink_id=37942
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298498953Z" level=debug msg="[client]   enter Publish" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298537771Z" level=debug msg="[client]   sending publish message, topic: eu868/gateway/b827ebfffe34b37f/event/up" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298615915Z" level=debug msg="[net]      obound msg to write 0" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:47.299409Z  INFO chirpstack::gateway::backend::mqtt: Message received from gateway region_config_id="eu868" topic="eu868/gateway/b827ebfffe34b37f/event/up" qos=0 json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298775786Z" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.298804543Z" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:47.502246Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}: chirpstack::uplink: Uplink received m_type="UnconfirmedDataUp"
chirpstack_1                       | 2023-05-07T07:49:47.506360Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:47.508732Z  INFO chirpstack::storage::device: Setting device lock dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:47.513361Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device: Data-rate updated dev_eui=675b165d484517d4 dr=5
chirpstack_1                       | 2023-05-07T07:49:47.514230Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device_gateway: Gateway rx-info saved dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:47.514969Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:47.515138Z  INFO chirpstack::integration::mqtt: Publishing event topic=application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/up
chirpstack_1                       | 2023-05-07T07:49:47.515561Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=HOUR
chirpstack_1                       | 2023-05-07T07:49:47.516082Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=DAY
chirpstack_1                       | 2023-05-07T07:49:47.516585Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=MONTH
chirpstack_1                       | 2023-05-07T07:49:47.619013Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::mac_command: Pending mac-command block set dev_eui=675b165d484517d4 cid=LinkADRReq
chirpstack_1                       | 2023-05-07T07:49:47.622710Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device_queue: Device queue-item updated id=25d6d458-6963-499b-b3ce-60574ec4f08f dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:47.623374Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::downlink_frame: Downlink-frame saved downlink_id=2608589117
chirpstack_1                       | 2023-05-07T07:49:47.624132Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:47.624222Z  INFO up{deduplication_id=c874b81f-57cb-448a-ac17-e0a3a578d8b0}:data_up: chirpstack::gateway::backend::mqtt: Sending downlink frame gateway_id=b827ebfffe34b37f topic=eu868/gateway/b827ebfffe34b37f/command/down json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.624975499Z" level=debug msg="[net]      startIncoming Received Message" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.625048122Z" level=debug msg="[net]      startIncomingComms: got msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.625072168Z" level=debug msg="[net]      startIncomingComms: received publish, msgId: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.625096429Z" level=debug msg="[net]      logic waiting for msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.625207513Z" level=info msg="integration/mqtt: downlink frame received" downlink_id=2608589117 gateway_id=b827ebfffe34b37f
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.625394452Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullResp
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:47.65986827Z" level=debug msg="[pinger]   ping check 0.361031614" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:49.090208114Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:49.090323315Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:49.090393138Z" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:49.090479752Z" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:52.660422943Z" level=debug msg="[pinger]   ping check 5.36159861" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440454702Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440734766Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440736292Z" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=eu868/gateway/b827ebfffe34b37f/event/up uplink_id=61666
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440877851Z" level=debug msg="[client]   enter Publish" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440919333Z" level=debug msg="[client]   sending publish message, topic: eu868/gateway/b827ebfffe34b37f/event/up" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.440994061Z" level=debug msg="[net]      obound msg to write 0" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:53.441821Z  INFO chirpstack::gateway::backend::mqtt: Message received from gateway region_config_id="eu868" topic="eu868/gateway/b827ebfffe34b37f/event/up" qos=0 json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.441200806Z" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.441241736Z" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt
chirpstack_1                       | 2023-05-07T07:49:53.643603Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}: chirpstack::uplink: Uplink received m_type="UnconfirmedDataUp"
chirpstack_1                       | 2023-05-07T07:49:53.647078Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:53.649705Z  INFO chirpstack::storage::device: Setting device lock dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:53.653768Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device: Data-rate updated dev_eui=675b165d484517d4 dr=5
chirpstack_1                       | 2023-05-07T07:49:53.655150Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::mac_command: Pending mac-command block deleted dev_eui=675b165d484517d4 cid=LinkADRAns
chirpstack_1                       | 2023-05-07T07:49:53.655194Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::maccommand::link_adr: LinkADRReq acknowledged dev_eui=675b165d484517d4 tx_power_index=2 dr=5 nb_trans=1 enabled_channels=[0, 1, 2, 3, 4, 5, 6, 7]
chirpstack_1                       | 2023-05-07T07:49:53.655631Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device_gateway: Gateway rx-info saved dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:53.656386Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:53.656428Z  INFO chirpstack::integration::mqtt: Publishing event topic=application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/up
mosquitto_1                        | 1683445782: Sending PUBLISH to 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/stats', ... (100 bytes))
mosquitto_1                        | 1683445787: Received PUBLISH from auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (113 bytes))
mosquitto_1                        | 1683445787: Sending PUBLISH to 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (113 bytes))
mosquitto_1                        | 1683445787: Received PUBLISH from 9b8c0b323372a5ce (d0, q0, r0, m0, 'application/e62c8299-58ce-4189-8cdb-b77e189c5a7c/device/675b165d484517d4/event/up', ... (961 bytes))
mosquitto_1                        | 1683445787: Received PUBLISH from 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (340 bytes))
mosquitto_1                        | 1683445787: Sending PUBLISH to auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/command/down', ... (340 bytes))
mosquitto_1                        | 1683445793: Received PUBLISH from auto-A2C57EC8-F38A-874F-3438-E528EA39B2C6 (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (103 bytes))
mosquitto_1                        | 1683445793: Sending PUBLISH to 76e8d7f81266057c (d0, q0, r0, m0, 'eu868/gateway/b827ebfffe34b37f/event/up', ... (103 bytes))
chirpstack_1                       | 2023-05-07T07:49:53.657100Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=HOUR
chirpstack_1                       | 2023-05-07T07:49:53.657695Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=DAY
chirpstack_1                       | 2023-05-07T07:49:53.658340Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::metrics: Metrics saved name=device:675b165d484517d4 aggregation=MONTH
chirpstack_1                       | 2023-05-07T07:49:53.761440Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::mac_command: Pending mac-command block set dev_eui=675b165d484517d4 cid=LinkADRReq
chirpstack_1                       | 2023-05-07T07:49:53.764619Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device_queue: Device queue-item updated id=25d6d458-6963-499b-b3ce-60574ec4f08f dev_eui=675b165d484517d4
chirpstack_1                       | 2023-05-07T07:49:53.765169Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::downlink_frame: Downlink-frame saved downlink_id=4260431410
chirpstack_1                       | 2023-05-07T07:49:53.765900Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::storage::device_session: Device-session saved dev_eui=675b165d484517d4 dev_addr=005b6fc5
chirpstack_1                       | 2023-05-07T07:49:53.766026Z  INFO up{deduplication_id=8b024398-6dfa-4d96-8592-526f89b04bd1}:data_up: chirpstack::gateway::backend::mqtt: Sending downlink frame gateway_id=b827ebfffe34b37f topic=eu868/gateway/b827ebfffe34b37f/command/down json=false
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.766782178Z" level=debug msg="[net]      startIncoming Received Message" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.766851606Z" level=debug msg="[net]      startIncomingComms: got msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.766890597Z" level=debug msg="[net]      startIncomingComms: received publish, msgId: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.766929435Z" level=debug msg="[net]      logic waiting for msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.767105203Z" level=info msg="integration/mqtt: downlink frame received" downlink_id=4260431410 gateway_id=b827ebfffe34b37f
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:53.767248099Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullResp
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:57.660242251Z" level=debug msg="[pinger]   ping check 4.218978009" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:59.230040523Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:59.230160903Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:59.230181165Z" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:49:59.230294729Z" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:02.660469993Z" level=debug msg="[pinger]   ping check 9.219206768" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:07.660198415Z" level=debug msg="[pinger]   ping check 14.218936583" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:09.309872676Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:09.310008219Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:09.310040482Z" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:09.310105539Z" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.659846122Z" level=debug msg="[pinger]   ping check 19.218582323" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708406919Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708621395Z" level=info msg="integration/mqtt: publishing event" event=stats qos=0 topic=eu868/gateway/b827ebfffe34b37f/event/stats
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708658971Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="192.168.1.116:33278" protocol_version=1 type=PushACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708661213Z" level=debug msg="[client]   enter Publish" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708848881Z" level=debug msg="[client]   sending publish message, topic: eu868/gateway/b827ebfffe34b37f/event/stats" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.708897017Z" level=debug msg="[net]      obound msg to write 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.709022787Z" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:12.709045365Z" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt
chirpstack_1                       | 2023-05-07T07:50:12.709647Z  INFO chirpstack::gateway::backend::mqtt: Message received from gateway region_config_id="eu868" topic="eu868/gateway/b827ebfffe34b37f/event/stats" qos=0 json=false
chirpstack_1                       | 2023-05-07T07:50:12.714978Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::gateway: Gateway state and location updated gateway_id=b827ebfffe34b37f
chirpstack_1                       | 2023-05-07T07:50:12.715764Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=HOUR
chirpstack_1                       | 2023-05-07T07:50:12.716410Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=DAY
chirpstack_1                       | 2023-05-07T07:50:12.716894Z  INFO stats{gateway_id=b827ebfffe34b37f}: chirpstack::storage::metrics: Metrics saved name=gw:b827ebfffe34b37f aggregation=MONTH
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:17.660531393Z" level=debug msg="[pinger]   ping check 4.951464888" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:19.390673478Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:19.39078016Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:19.390822659Z" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:19.390919576Z" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:22.660365135Z" level=debug msg="[pinger]   ping check 9.951296725" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.660763488Z" level=debug msg="[pinger]   ping check 14.951696211" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.660810673Z" level=debug msg="[pinger]   keepalive sending ping" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.661144928Z" level=debug msg="[net]      startIncoming Received Message" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.661211622Z" level=debug msg="[net]      startIncomingComms: got msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.661242253Z" level=debug msg="[net]      startIncomingComms: received pingresp" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:27.661258067Z" level=debug msg="[net]      logic waiting for msg on ibound" module=mqtt
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:29.469829215Z" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullData
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:29.469983756Z" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="172.18.0.1:44257" protocol_version=1 type=PullACK
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:29.470053915Z" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:29.4701256Z" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=b827ebfffe34b37f subscribe=true
chirpstack-gateway-bridge-eu868_1  | time="2023-05-07T07:50:32.640447251Z" level=debug msg="backend/semtechudp: cleanup gateway registry"

Joachim

bakok · May 8, 2023, 12:57pm

You running GW, NS and AS server?
The gateway is appear in chirpstack webgui?

joachimt · May 8, 2023, 1:55pm

Hi,

I am running the gw and the docker-compose git Setup.
yes of course. I can see the gw in the webgui as uplink events work fine.

Joachim