(Kerlink iStation) Heartbeat messages are sent to the gateway but most uplink messages are lost?

ldorigo · September 23, 2022, 10:34am

Hi,

I’ve been trying to setup a Kerlink iStation with Chirpstack v4, with the gateway bridge on the station itself. It seems that the majority of uplink messages are not acknowledged by the gateway bridge:

2022-09-23T10:23:01.343665+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  02 0D F3 00 70 76 FF 00 56 07 0A 51 7B 22 73 74 61 74 22 3A 7B 22 61 63 6B 72 22 3A 31 30 30 2E  |....pv..V..Q{"stat":{"ackr":100.|
2022-09-23T10:23:01.343960+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  30 2C 22 62 6F 6F 74 22 3A 22 32 30 32 32 2D 30 39 2D 32 33 20 30 38 3A 34 35 3A 35 39 20 47 4D  |0,"boot":"2022-09-23 08:45:59 GM|
2022-09-23T10:23:01.344179+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  54 22 2C 22 64 77 6E 62 22 3A 30 2C 22 66 70 67 61 22 3A 33 31 2C 22 68 61 6C 22 3A 22 35 2E 30  |T","dwnb":0,"fpga":31,"hal":"5.0|
2022-09-23T10:23:01.344391+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  2E 31 22 2C 22 6C 70 70 73 22 3A 33 30 2C 22 70 69 6E 67 22 3A 32 2C 22 72 78 66 77 22 3A 37 2C  |.1","lpps":30,"ping":2,"rxfw":7,|
2022-09-23T10:23:01.344598+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  22 72 78 6E 62 22 3A 30 2C 22 72 78 6F 6B 22 3A 30 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 30  |"rxnb":0,"rxok":0,"time":"2022-0|
2022-09-23T10:23:01.344792+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  39 2D 32 33 20 31 30 3A 32 33 3A 30 31 20 47 4D 54 22 2C 22 74 78 6E 62 22 3A 30 7D 7D           |9-23 10:23:01 GMT","txnb":0}}|
2022-09-23T10:23:01.345035+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Uplink message (0DF3) sent
2022-09-23T10:23:01.347731+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.recv:  02 0D F3 01                                                                                      |....|
2022-09-23T10:23:01.347885+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Uplink message (0DF3) acknowledged in 2.80446 ms
2022-09-23T10:23:01.415330+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  02 0D F4 00 70 76 FF 00 56 07 0A 51 7B 22 72 78 70 6B 22 3A 5B 7B 22 61 65 73 6B 22 3A 30 2C 22  |....pv..V..Q{"rxpk":[{"aesk":0,"|
2022-09-23T10:23:01.416117+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  62 72 64 22 3A 33 2C 22 63 6F 64 72 22 3A 22 34 2F 35 22 2C 22 64 61 74 61 22 3A 22 22 2C 22 64  |brd":3,"codr":"4/5","data":"","d|
2022-09-23T10:23:01.416685+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  61 74 72 22 3A 22 53 46 37 42 57 31 32 35 22 2C 22 64 65 6C 61 79 65 64 22 3A 74 72 75 65 2C 22  |atr":"SF7BW125","delayed":true,"|
2022-09-23T10:23:01.417213+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  66 72 65 71 22 3A 38 36 37 2E 37 2C 22 6A 76 65 72 22 3A 32 2C 22 6D 6F 64 75 22 3A 22 4C 4F 52  |freq":867.7,"jver":2,"modu":"LOR|
2022-09-23T10:23:01.417977+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  41 22 2C 22 72 73 69 67 22 3A 5B 7B 22 61 6E 74 22 3A 30 2C 22 63 68 61 6E 22 3A 33 2C 22 6C 73  |A","rsig":[{"ant":0,"chan":3,"ls|
2022-09-23T10:23:01.418887+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  6E 72 22 3A 2D 31 31 2E 35 2C 22 72 73 73 69 63 22 3A 2D 31 31 32 7D 5D 2C 22 73 69 7A 65 22 3A  |nr":-11.5,"rssic":-112}],"size":|
2022-09-23T10:23:01.419505+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  30 2C 22 73 74 61 74 22 3A 2D 31 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 30 39 2D 32 33 54 30  |0,"stat":-1,"time":"2022-09-23T0|
2022-09-23T10:23:01.420169+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  38 3A 34 38 3A 30 36 2E 33 31 31 38 38 31 5A 22 2C 22 74 6D 73 74 22 3A 31 32 30 31 37 37 36 39  |8:48:06.311881Z","tmst":12017769|
2022-09-23T10:23:01.420592+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  36 33 7D 5D 7D                                                                                   |63}]}|
2022-09-23T10:23:01.422649+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.recv:  02 0D F4 01                                                                                      |....|
2022-09-23T10:23:01.422766+00:00 klk-wiis-070A51 lorafwd[1530]: <4> Uplink message (0DF2) timed out
2022-09-23T10:23:01.424378+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Uplink message (0DF4) sent
2022-09-23T10:23:03.906594+00:00 klk-wiis-070A51 lorad[982]: <7> Demodulator synchronized with MONOTONIC: drift=9us sum=-1321us
2022-09-23T10:23:03.907508+00:00 klk-wiis-070A51 lorad[982]: <7> Demodulator synchronized with UTC: drift=377us sum=-648us
2022-09-23T10:23:04.426684+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  02 0D F5 00 70 76 FF 00 56 07 0A 51 7B 22 72 78 70 6B 22 3A 5B 7B 22 61 65 73 6B 22 3A 30 2C 22  |....pv..V..Q{"rxpk":[{"aesk":0,"|
2022-09-23T10:23:04.427452+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  62 72 64 22 3A 32 36 31 2C 22 63 6F 64 72 22 3A 22 34 2F 35 22 2C 22 64 61 74 61 22 3A 22 22 2C  |brd":261,"codr":"4/5","data":"",|
2022-09-23T10:23:04.428033+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  22 64 61 74 72 22 3A 22 53 46 37 42 57 31 32 35 22 2C 22 64 65 6C 61 79 65 64 22 3A 74 72 75 65  |"datr":"SF7BW125","delayed":true|
2022-09-23T10:23:04.428566+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  2C 22 66 72 65 71 22 3A 38 36 38 2E 31 2C 22 6A 76 65 72 22 3A 32 2C 22 6D 6F 64 75 22 3A 22 4C  |,"freq":868.1,"jver":2,"modu":"L|
2022-09-23T10:23:04.429084+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  4F 52 41 22 2C 22 72 73 69 67 22 3A 5B 7B 22 61 6E 74 22 3A 30 2C 22 63 68 61 6E 22 3A 35 2C 22  |ORA","rsig":[{"ant":0,"chan":5,"|
2022-09-23T10:23:04.429593+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  6C 73 6E 72 22 3A 2D 31 31 2E 35 2C 22 72 73 73 69 63 22 3A 2D 31 31 32 7D 5D 2C 22 73 69 7A 65  |lsnr":-11.5,"rssic":-112}],"size|
2022-09-23T10:23:04.430320+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  22 3A 30 2C 22 73 74 61 74 22 3A 2D 31 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 30 39 2D 32 33  |":0,"stat":-1,"time":"2022-09-23|
2022-09-23T10:23:04.430911+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  54 30 38 3A 34 38 3A 30 30 2E 30 31 37 33 32 35 5A 22 2C 22 74 6D 73 74 22 3A 31 31 39 35 34 38  |T08:48:00.017325Z","tmst":119548|
2022-09-23T10:23:04.431903+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  32 34 38 34 7D 5D 7D                                                                             |2484}]}|
2022-09-23T10:23:04.433879+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.recv:  02 0D F5 01                                                                                      |....|
2022-09-23T10:23:04.433996+00:00 klk-wiis-070A51 lorafwd[1530]: <4> Uplink message (0DF4) timed out
2022-09-23T10:23:04.435542+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Uplink message (0DF5) sent
2022-09-23T10:23:08.150409+00:00 klk-wiis-070A51 lorafwd[1530]: <4> Uplink message (0DF5) timed out
2022-09-23T10:23:09.595623+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  02 0B 7D 02 70 76 FF 00 56 07 0A 51                                                              |..}.pv..V..Q|
2022-09-23T10:23:09.595910+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Heartbeat (0B7D) sent
2022-09-23T10:23:09.598110+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.recv:  02 0B 7D 04                                                                                      |..}.|
2022-09-23T10:23:09.598247+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Heartbeat (0B7D) acknowledged in 2.3361 ms
2022-09-23T10:23:10.438955+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  02 0D F6 00 70 76 FF 00 56 07 0A 51 7B 22 72 78 70 6B 22 3A 5B 7B 22 61 65 73 6B 22 3A 30 2C 22  |....pv..V..Q{"rxpk":[{"aesk":0,"|
2022-09-23T10:23:10.439812+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  62 72 64 22 3A 32 36 31 2C 22 63 6F 64 72 22 3A 22 34 2F 35 22 2C 22 64 61 74 61 22 3A 22 22 2C  |brd":261,"codr":"4/5","data":"",|
2022-09-23T10:23:10.440410+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  22 64 61 74 72 22 3A 22 53 46 37 42 57 31 32 35 22 2C 22 64 65 6C 61 79 65 64 22 3A 74 72 75 65  |"datr":"SF7BW125","delayed":true|
2022-09-23T10:23:10.440953+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  2C 22 66 72 65 71 22 3A 38 36 38 2E 31 2C 22 6A 76 65 72 22 3A 32 2C 22 6D 6F 64 75 22 3A 22 4C  |,"freq":868.1,"jver":2,"modu":"L|
2022-09-23T10:23:10.441596+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  4F 52 41 22 2C 22 72 73 69 67 22 3A 5B 7B 22 61 6E 74 22 3A 30 2C 22 63 68 61 6E 22 3A 35 2C 22  |ORA","rsig":[{"ant":0,"chan":5,"|
2022-09-23T10:23:10.442140+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  6C 73 6E 72 22 3A 2D 31 31 2E 35 2C 22 72 73 73 69 63 22 3A 2D 31 31 32 7D 5D 2C 22 73 69 7A 65  |lsnr":-11.5,"rssic":-112}],"size|
2022-09-23T10:23:10.442742+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  22 3A 30 2C 22 73 74 61 74 22 3A 2D 31 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 30 39 2D 32 33  |":0,"stat":-1,"time":"2022-09-23|
2022-09-23T10:23:10.443274+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  54 30 38 3A 34 38 3A 30 30 2E 30 31 37 33 32 35 5A 22 2C 22 74 6D 73 74 22 3A 31 31 39 35 34 38  |T08:48:00.017325Z","tmst":119548|
2022-09-23T10:23:10.443674+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.send:  32 34 38 34 7D 5D 7D                                                                             |2484}]}|
2022-09-23T10:23:10.446140+00:00 klk-wiis-070A51 lorafwd[1530]: <7>  gwmp.recv:  02 0D F6 01                                                                                      |....|
2022-09-23T10:23:10.447858+00:00 klk-wiis-070A51 lorafwd[1530]: <6> Uplink message (0DF6) sent

Is this normal? Additionally, is it normal that no lorawan frames are shown in the Chirpstack web app?

Appreciate any help.

datnus · September 23, 2022, 11:00am

Is there any web proxy?

ldorigo · September 23, 2022, 2:36pm

The chirpstack-gateway-bridge is running on the gateway itself so I doubt it could be caused by network issues.

And I’m not sure what you mean by web proxy? The main chirpstack server is on a VM hosted on azure.

brocaar · September 28, 2022, 9:18am

Please note that there is an uplink and downlink port configuration in the Kerlink packet-forwarder configuration. Have you checked both ports are configured correctly? Also, have you checked the ChirpStack Gateway Bridge logs on the gateway?

ldorigo · October 5, 2022, 7:33am

Thanks for your answer and sorry for the slow response.

Both uplink and downlink ports are configured to 1700: gist:556ad5718765129eeb7a811b362cb5b8 · GitHub

And chirpstack-gateway-bridge is configured accordingly: gist:0ee5e5edaaeb26fdf15b6372928605be · GitHub

The gateway-bridge logs don’t show anything suspect (at least to me). The forwarder (backend?) logs on the other hand show those “timeout” messages. If you have time, here are the log files:

Gateway Bridge: gist:90c15e8cc3dd35daf170277d658027b8 · GitHub
Forwarder: gist:35465afaa09f66434c3d2231a70033ef · GitHub

Do you see anything weird?

Thanks a lot!

ldorigo · October 5, 2022, 10:09am

I’m quite sure something is wrong in the Gateway-Bridge. See these logs:

2022-10-05T11:26:53.969143+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:53.968844464+02:00" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushData                   
2022-10-05T11:26:53.975921+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:53.975689768+02:00" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushACK                       
2022-10-05T11:26:55.817461+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:55.817273733+02:00" level=debug msg="[pinger]   ping check 4.246189219" module=mqtt                                                                                  
2022-10-05T11:26:56.989257+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.988963004+02:00" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushData                   
2022-10-05T11:26:56.991936+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.991619789+02:00" level=info msg="integration/mqtt: publishing event" event=up qos=0 topic=eu868/gateway/7076ff0056070a51/event/up uplink_id=14509                 
2022-10-05T11:26:56.992987+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.992670502+02:00" level=debug msg="[client]   enter Publish" module=mqtt                                                                                           
2022-10-05T11:26:56.994727+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.993680547+02:00" level=debug msg="[client]   sending publish message, topic: eu868/gateway/7076ff0056070a51/event/up" module=mqtt                                 
2022-10-05T11:26:56.997848+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.997521717+02:00" level=debug msg="[net]      obound msg to write 0" module=mqtt                                                                                   
2022-10-05T11:26:56.998758+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:56.995323286+02:00" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushACK                       
2022-10-05T11:26:57.004184+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:57.004024005+02:00" level=debug msg="[net]      obound wrote msg, id: 0" module=mqtt                                                                                 
2022-10-05T11:26:57.004455+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:26:57.004333019+02:00" level=debug msg="[net]      outgoing waiting for an outbound message" module=mqtt                                                                
2022-10-05T11:27:00.004971+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.00453268+02:00" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushData                    
2022-10-05T11:27:00.005747+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.005544391+02:00" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushACK                       
2022-10-05T11:27:00.817333+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.817109034+02:00" level=debug msg="[pinger]   ping check 3.812699679" module=mqtt                                                                                  
2022-10-05T11:27:00.817607+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.817484051+02:00" level=debug msg="[pinger]   keepalive sending ping" module=mqtt                                                                                  
2022-10-05T11:27:00.849633+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.849382798+02:00" level=debug msg="[net]      startIncoming Received Message" module=mqtt                                                                          
2022-10-05T11:27:00.849965+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.849830151+02:00" level=debug msg="[net]      startIncomingComms: got msg on ibound" module=mqtt                                                                   
2022-10-05T11:27:00.850251+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.850125831+02:00" level=debug msg="[net]      startIncomingComms: received pingresp" module=mqtt                                                                   
2022-10-05T11:27:00.853485+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:00.853103963+02:00" level=debug msg="[net]      logic waiting for msg on ibound" module=mqtt                                                                         
2022-10-05T11:27:01.557169+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:01.55685516+02:00" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="127.0.0.1:35872" protocol_version=2 type=PullData                    
2022-10-05T11:27:01.557680+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:01.557488188+02:00" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="127.0.0.1:35872" protocol_version=2 type=PullACK                       
2022-10-05T11:27:01.559447+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:01.559149262+02:00" level=debug msg="integration/mqtt: set gateway subscription" gateway_id=7076ff0056070a51 subscribe=true                                          
2022-10-05T11:27:01.559752+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:01.559608616+02:00" level=debug msg="integration/mqtt: gateway subscription set" gateway_id=7076ff0056070a51 subscribe=true                                          
2022-10-05T11:27:03.017350+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:03.01703189+02:00" level=debug msg="backend/semtechudp: received udp packet from gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushData                    
2022-10-05T11:27:03.018125+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:03.01792493+02:00" level=debug msg="backend/semtechudp: sending udp packet to gateway" addr="127.0.0.1:37642" protocol_version=2 type=PushACK                        
2022-10-05T11:27:05.816688+02:00 klk-wiis-070A51 chirpstack-gateway-bridge[1184]: time="2022-10-05T11:27:05.816453991+02:00" level=debug msg="[pinger]   ping check 4.998534588" module=mqtt

And the corresponding two messages seen from the forwarder logs:

:26:53.964734+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  02 AD 37 00 70 76 FF 00 56 07 0A 51 7B 22 72 78 70 6B 22 3A 5B 7B 22 61 65 73 6B 22 3A 30 2C 22  |..7.pv..V..Q{"rxpk":[{"aesk":0,"|                                                                                                                      
:26:53.965841+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  62 72 64 22 3A 33 2C 22 63 6F 64 72 22 3A 22 34 2F 35 22 2C 22 64 61 74 61 22 3A 22 22 2C 22 64  |brd":3,"codr":"4/5","data":"","d|                                                                                                                      
:26:53.966435+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  61 74 72 22 3A 22 53 46 37 42 57 31 32 35 22 2C 22 64 65 6C 61 79 65 64 22 3A 74 72 75 65 2C 22  |atr":"SF7BW125","delayed":true,"|                                                                                                                      
:26:53.966902+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  66 72 65 71 22 3A 38 36 37 2E 37 2C 22 6A 76 65 72 22 3A 32 2C 22 6D 6F 64 75 22 3A 22 4C 4F 52  |freq":867.7,"jver":2,"modu":"LOR|                                                                                                                      
:26:53.967252+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  41 22 2C 22 72 73 69 67 22 3A 5B 7B 22 61 6E 74 22 3A 30 2C 22 63 68 61 6E 22 3A 33 2C 22 6C 73  |A","rsig":[{"ant":0,"chan":3,"ls|                                                                                                                      
:26:53.967578+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  6E 72 22 3A 2D 31 31 2E 38 2C 22 72 73 73 69 63 22 3A 2D 31 31 32 7D 5D 2C 22 73 69 7A 65 22 3A  |nr":-11.8,"rssic":-112}],"size":|                                                                                                                      
:26:53.967890+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  30 2C 22 73 74 61 74 22 3A 2D 31 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 31 30 2D 30 35 54 30  |0,"stat":-1,"time":"2022-10-05T0|                                                                                                                      
:26:53.968202+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  39 3A 32 36 3A 32 39 2E 33 37 39 37 39 5A 22 2C 22 74 6D 73 74 22 3A 33 37 34 33 39 30 33 35 7D  |9:26:29.37979Z","tmst":37439035}|                                                                                                                      
:26:53.968381+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  5D 7D                                                                                            |]}|                                                                                                                                                    
:26:53.977465+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.recv:  02 AD 37 01                                                                                      |..7.|                                                                                                                                                  
:26:53.979182+02:00 klk-wiis-070A51 lorafwd[1216]: <6> Uplink message (AD37) sent                                                                                                                                                                                                                                            
:26:56.243383+02:00 klk-wiis-070A51 lorad[1169]: <7>   api.send:  0a 7f 08 82 80 80 87 03 12 47 0a 37 40 c9 a8 04 e0 80 05 00 02 97 c7 df 25 56 23 54 03 ff bb 14  |.........G.7@...........%V#T....|                                                                                                                        
:26:56.243879+02:00 klk-wiis-070A51 lorad[1169]: <7>   api.send:  4e 8d c6 58 77 17 78 2b 6d cb 73 ff 79 81 ba cf 3b d2 ea 1c e7 51 10 c5 b5 9e 5b 56 44 62 db b7  |N..Xw.x+m.s.y...;....Q....[VDb..|                                                                                                                        
:26:56.244264+02:00 klk-wiis-070A51 lorad[1169]: <7>   api.send:  5c ae af 10 a0 cf f8 9d 03 18 00 20 00 28 04 30 00 1a 2e 08 85 02 12 29 08 b4 d2 d3 1e 12 0c 08  |\.......... .(.0.......)........|                                                                                                                        
:26:56.244614+02:00 klk-wiis-070A51 lorad[1169]: <7>   api.send:  00 10 e0 9b f5 99 06 18 d8 e3 0d 1d 00 00 8f c2 22 0f 0d 00 00 28 41 15 00 00 8a 41 1d 00 00 80  |................"....(A....A....|                                                                                                                        
:26:56.244936+02:00 klk-wiis-070A51 lorad[1169]: <7>   api.send:  40                                                                                               |@|                                                                                                                                                       
:26:56.245917+02:00 klk-wiis-070A51 lorafwd[1216]: <7>   api.recv:  0A 7F 08 82 80 80 87 03 12 47 0A 37 40 C9 A8 04 E0 80 05 00 02 97 C7 DF 25 56 23 54 03 FF BB 14  |.........G.7@...........%V#T....|                                                                                                                      
:26:56.246163+02:00 klk-wiis-070A51 lorafwd[1216]: <7>   api.recv:  4E 8D C6 58 77 17 78 2B 6D CB 73 FF 79 81 BA CF 3B D2 EA 1C E7 51 10 C5 B5 9E 5B 56 44 62 DB B7  |N..Xw.x+m.s.y...;....Q....[VDb..|                                                                                                                      
:26:56.246382+02:00 klk-wiis-070A51 lorafwd[1216]: <7>   api.recv:  5C AE AF 10 A0 CF F8 9D 03 18 00 20 00 28 04 30 00 1A 2E 08 85 02 12 29 08 B4 D2 D3 1E 12 0C 08  |\.......... .(.0.......)........|                                                                                                                      
:26:56.246591+02:00 klk-wiis-070A51 lorafwd[1216]: <7>   api.recv:  00 10 E0 9B F5 99 06 18 D8 E3 0D 1D 00 00 8F C2 22 0F 0D 00 00 28 41 15 00 00 8A 41 1D 00 00 80  |................"....(A....A....|                                                                                                                      
:26:56.246660+02:00 klk-wiis-070A51 lorafwd[1216]: <7>   api.recv:  40                                                                                               |@|                                                                                                                                                     
:26:56.246810+02:00 klk-wiis-070A51 lorafwd[1216]: <6> Received uplink message:                                                                                                                                                                                                                                              
:26:56.246920+02:00 klk-wiis-070A51 lorafwd[1216]: <6> | lora uplink (30E00002), payload 55 B, channel 868.1 MHz, crc ok, bw 125 kHz, sf 11, cr 4/5                                                                                                                                                                          
:26:56.246990+02:00 klk-wiis-070A51 lorafwd[1216]: <6> | Unconfirmed Data Up, DevAddr E004A8C9, FCtrl [ADR], FCnt 5, FPort 2                                                                                                                                                                                                 
:26:56.247047+02:00 klk-wiis-070A51 lorafwd[1216]: <6> |  - radio (00000105)                                                                                                                                                                                                                                                 
:26:56.247155+02:00 klk-wiis-070A51 lorafwd[1216]: <6> |   - demodulator counter 64284980, UTC time 2022-10-05T09:26:56.225752Z, rssi -71.5 dB, snr 4< 10.5 <17.25 dB                                                                                                                                                        
:26:56.251939+02:00 klk-wiis-070A51 lorad[1169]: <6> Sent 1 uplink message                                                                                                                                                                                                                                                   
:26:56.981899+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  02 AD 38 00 70 76 FF 00 56 07 0A 51 7B 22 72 78 70 6B 22 3A 5B 7B 22 61 65 73 6B 22 3A 30 2C 22  |..8.pv..V..Q{"rxpk":[{"aesk":0,"|                                                                                                                      
:26:56.982588+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  62 72 64 22 3A 32 36 31 2C 22 63 6F 64 72 22 3A 22 34 2F 35 22 2C 22 64 61 74 61 22 3A 22 51 4D  |brd":261,"codr":"4/5","data":"QM|                                                                                                                      
:26:56.983334+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  6D 6F 42 4F 43 41 42 51 41 43 6C 38 66 66 4A 56 59 6A 56 41 50 2F 75 78 52 4F 6A 63 5A 59 64 78  |moBOCABQACl8ffJVYjVAP/uxROjcZYdx|                                                                                                                      
:26:56.983922+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  64 34 4B 32 33 4C 63 2F 39 35 67 62 72 50 4F 39 4C 71 48 4F 64 52 45 4D 57 31 6E 6C 74 57 52 47  |d4K23Lc/95gbrPO9LqHOdREMW1nltWRG|                                                                                                                      
:26:56.984564+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  4C 62 74 31 79 75 72 77 3D 3D 22 2C 22 64 61 74 72 22 3A 22 53 46 31 31 42 57 31 32 35 22 2C 22  |Lbt1yurw==","datr":"SF11BW125","|                                                                                                                      
:26:56.985109+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  66 72 65 71 22 3A 38 36 38 2E 31 2C 22 6A 76 65 72 22 3A 32 2C 22 6D 6F 64 75 22 3A 22 4C 4F 52  |freq":868.1,"jver":2,"modu":"LOR|                                                                                                                      
:26:56.985639+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  41 22 2C 22 72 73 69 67 22 3A 5B 7B 22 61 6E 74 22 3A 30 2C 22 63 68 61 6E 22 3A 35 2C 22 6C 73  |A","rsig":[{"ant":0,"chan":5,"ls|                                                                                                                      
:26:56.986799+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  6E 72 22 3A 31 30 2E 35 2C 22 72 73 73 69 63 22 3A 2D 37 31 7D 5D 2C 22 73 69 7A 65 22 3A 35 35  |nr":10.5,"rssic":-71}],"size":55|                                                                                                                      
:26:56.987395+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  2C 22 73 74 61 74 22 3A 31 2C 22 74 69 6D 65 22 3A 22 32 30 32 32 2D 31 30 2D 30 35 54 30 39 3A  |,"stat":1,"time":"2022-10-05T09:|                                                                                                                      
:26:56.987937+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  32 36 3A 35 36 2E 32 32 35 37 35 32 5A 22 2C 22 74 6D 73 74 22 3A 36 34 32 38 34 39 38 30 7D 5D  |26:56.225752Z","tmst":64284980}]|                                                                                                                      
:26:56.988317+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.send:  7D                                                                                               |}|                                                                                                                                                     
:26:56.994165+02:00 klk-wiis-070A51 lorafwd[1216]: <6> Uplink message (AD38) sent                                                                                                                                                                                                                                            
:26:56.996005+02:00 klk-wiis-070A51 lorafwd[1216]: <4> Uplink message (AD37) timed out                                                                                                                                                                                                                                       
:26:57.000089+02:00 klk-wiis-070A51 lorafwd[1216]: <7>  gwmp.recv:  02 AD 38 01                                                                                      |..8.|                                                                                                                                                  
:26:57.028256+02:00 klk-wiis-070A51 lorafwd[1216]: <6> Uplink message (AD38) acknowledged in 6.30061 ms

You can see that the first message (sent/received at 11:56:23) is received by the gateway-bridge, and the gateway-bridge logs indicate that an ACK was sent, but the forwarder logs show a “timeout” for that message (3rd-last line). This message does not appear on the chirpstack web ui (and indeed it’s not published to mqtt in the bridge logs? not sure why). On the other hand, the one sent at 11:56:26 is acknowledged properly and indeed appears on the webui.

Another thing to note is that when we reboot the antenna, a bunch of old messages are successfully sent to mqtt, but then it stops working a few messages later.

I’m out of ideas on how to troubleshoot…