Lora Server 2.0.19, stops publishing on broker after downlink

[Daniel Nilsson]

Hi, I have an application with 40 sensors. Certain frames from these require downlink responses. Sometimes the lora-network-server suddenly stops publishing new events on the MQTT broker when a downlink has been posted. I checked with having a mosquitto_sub client running on it subscribing to all topics, it goes silent but the lora-server log activity is continuing when it happens.

Below is an example with the server log output in level 100. At 11:43:48 CET (9:43:48 in lora log (utc)) no more MQTT messages are posted, when lora server is restarted it works again.

Would be awesome if someone could shed some light why this is happening 🙂

From sensorservice
——————
[2018-06-13 11:43:48 (SensorService)] INFO: Downlink send 00-80-00-01-A5-00-00-AB => 12060D030B2B0000

From lora-network-server log (loglevel 100 used) when this happens:
——————————————————————-
9:43:48:787|TRACE| AUTH KEY: e4.e3.78.02.3a.7a.44.78.af.4f.f1.02.5d.33.f9.c7
9:43:48:787|TRACE| PMIC: e26fde69 CMIC: 73895b56
9:43:48:787|WARNING| ED:00-80-00-01-a5-00-00-ab|CHECK-PKT|MIC Check Failed 0x00010000
9:43:48:788|TRACE| 110797 ms since last packet
9:43:48:788|TRACE| AUTH KEY: e4.e3.78.02.3a.7a.44.78.af.4f.f1.02.5d.33.f9.c7
9:43:48:788|TRACE| PMIC: e26fde69 CMIC: e26fde69
9:43:48:789|INFO| ED:00-80-00-01-a5-00-00-ab|CHECK-PKT|FCNT: 00000000 LAST-FCNT: 0000000c Duplicate: no
9:43:48:789|INFO| ED:00-80-00-01-a5-00-00-ab|CHECK-MIC|ADDR: 02-aa-72-88 passed
9:43:48:789|INFO| ED:00-80-00-01-a5-00-00-ab|PER|0.000000%
9:43:48:790|DEBUG| ED:00-80-00-01-a5-00-00-ab|PACKET-RX|GW:00-80-00-00-a0-00-1c-13 Time_us:395907948
9:43:48:790|DEBUG| ED:00-80-00-01-a5-00-00-ab|PACKET-RX|Downlink Packets Queued: 1
9:43:48:790|INFO| ED:00-80-00-01-a5-00-00-ab|FCTRL|ADR:1 ADRACK:0 ACK:0 CLASS:A OPTS:0
9:43:48:791|DEBUG| getTimeOnAirMs SF: 9 BW: 125 PL: 8 SZ: 21 TOA: 185
9:43:48:791|TRACE| Schedule DC band: 1 available: 841 duration: 235 freq: 868500000
9:43:48:792|INFO| ED:00-80-00-01-a5-00-00-ab|SCHED-TX|Use RX1 TOA:235 ms
9:43:48:811|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|JSON: {“tmst”:395907948,”chan”:2,”rfch”:0,”freq”:868.5,”stat”:1,”modu”:”LORA”,”datr”:”SF9BW125″,”codr”:”4/5″,”lsnr”:-4.2,”rssi”:-111,”size”:24,”data”:”gIhyqgKAAAABb0vPy5nAF071DEfib95p”}
9:43:48:956|DEBUG| ED:00-80-00-01-a5-00-00-ab|DOWNLINK|Queue {“data”: “EgYNAwsrAAA=”, “deveui”: “00-80-00-01-A5-00-00-AB”}
9:43:48:962|WARNING| ED:00-80-00-01-a5-00-00-ab|QUEUE|Created downlink record ID:958
9:43:48:963|INFO| ED:00-80-00-01-a5-00-00-ab|QUEUE-TX|DATA SIZE: 8
9:43:49:210|TRACE| TX-ACK|127.0.0.1:38330 4 bytes 02a6f201
9:43:49:215|TRACE| GW:00-80-00-00-a0-00-1c-13|SEEN|PUSH-DATA|127.0.0.1:38330
9:43:49:215|INFO| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|Parsing 1 packets
9:43:49:216|WARNING| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|CRC-ERROR
9:43:49:560|DEBUG| Device response requested 0 ACK 1
9:43:49:561|INFO| GW:00-80-00-00-a0-00-1c-13|FRAME-TX|IP: 127.0.0.1:35427 CH: LC3 DEV: 02-aa-72-88 FCNT: 000002d3 REPEAT: 0
9:43:49:564|INFO| ED:00-80-00-01-a5-00-00-ab|SCHED-TX|Q-SIZE: 2 PKT-ROOM: 115
9:43:49:565|DEBUG| getTimeOnAirMs SF: 9 BW: 125 PL: 8 SZ: 17 TOA: 164
9:43:49:565|DEBUG| ED:00-80-00-01-a5-00-00-ab|PACKET-TX|ADDR: 02aa7288 PORT: 1 ACK: 0 FCNT: 000002d3
9:43:49:565|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-TX|DATA: 608872aa0230d302012f13c136101e2f385390e5ac
9:43:49:566|DEBUG| GW:00-80-00-00-a0-00-1c-13|PACKET-TX|RX1 OFFSET: 1000000
9:43:49:577|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-TX|JSON: {“txpk”:{“appeui”:”00-80-00-01-a5-00-00-aa”,”codr”:”4/5″,”data”:”YIhyqgIw0wIBLxPBNhAeLzhTkOWs”,”datr”:”SF9BW125″,”deveui”:”00-80-00-01-a5-00-00-ab”,”freq”:868.5,”gweui”:”00-80-00-00-a0-00-1c-13″,”ipol”:true,”modu”:”LORA”,”ncrc”:true,”powe”:11,”rfch”:0,”size”:21,”tmst”:396907948,”twnd”:1}}
9:43:49:578|DEBUG| GW:00-80-00-00-a0-00-1c-13|DUTY-CYCLE|BAND: 1 DUTY: 851
9:43:49:578|DEBUG| getTimeOnAirMs SF: 9 BW: 0 PL: 8 SZ: 21 TOA: 185
9:43:49:578|INFO| Update DC Band: 1 Duration: 185 time-on-air available: 666 ms
9:43:49:579|INFO| GW:00-80-00-00-a0-00-1c-13|UDP-TX|JSON-SIZE:290
9:43:49:579|TRACE| TX-MSG|127.0.0.1:35427 294 bytes
9:43:49:581|INFO| GW:00-80-00-00-a0-00-1c-13|TX-ACK|OK
9:43:49:583|DEBUG| DeviceTransmitController::TransmitFrame ID: 951
9:43:49:777|TRACE| TX-ACK|127.0.0.1:35427 4 bytes 02b4a804
9:43:49:778|TRACE| GW:00-80-00-00-a0-00-1c-13|SEEN|PULL-DATA|127.0.0.1:35427
9:43:53:397|TRACE| TX-ACK|127.0.0.1:38330 4 bytes 02ca9901
9:43:53:398|TRACE| GW:00-80-00-00-a0-00-1c-13|SEEN|PUSH-DATA|127.0.0.1:38330
9:43:53:399|INFO| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|Parsing 1 packets
9:43:53:400|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|DATA: 808872aa02800000016f4bcfcb99c0174ef50c47e26fde69
9:43:53:400|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|FREQ: 868.300000 MHz DR2 RSSI: -110 dB SNR: 0 cB
9:43:53:401|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|TYPE: Confirmed Up
9:43:53:401|DEBUG| GW:00-80-00-00-a0-00-1c-13|PACKET-RX|ADDR: 02:aa:72:88 FCnt:0000
9:43:53:402|TRACE| Test authentication of duplicate frame
9:43:53:402|TRACE| AUTH KEY: e4.e3.78.02.3a.7a.44.78.af.4f.f1.02.5d.33.f9.c7
9:43:53:402|TRACE| PMIC: e26fde69 CMIC: e26fde69
9:43:53:403|INFO| ED:00-80-00-01-a5-00-00-ab|CHECK-PKT|FCNT: 00000000 LAST-FCNT: 00000000 Duplicate: yes
9:43:53:403|INFO| ED:00-80-00-01-a5-00-00-ab|CHECK-MIC|ADDR: 02-aa-72-88 passed
9:43:53:403|INFO| ED:00-80-00-01-a5-00-00-ab|PER|0.000000%
9:43:53:403|DEBUG| ED:00-80-00-01-a5-00-00-ab|PACKET-RX|GW:00-80-00-00-a0-00-1c-13 Time_us:400513404
9:43:53:404|DEBUG| ED:00-80-00-01-a5-00-00-ab|PACKET-RX|Downlink Packets Queued: 1
9:43:53:404|INFO| ED:00-80-00-01-a5-00-00-ab|FCTRL|ADR:1 ADRACK:0 ACK:0 CLASS:A OPTS:0
9:43:53:405|DEBUG| getTimeOnAirMs SF: 10 BW: 125 PL: 8 SZ: 21 TOA: 370
9:43:53:405|TRACE| Schedule DC band: 1 available: 706 duration: 420 freq: 868300000
9:43:53:405|INFO| ED:00-80-00-01-a5-00-00-ab|SCHED-TX|Use RX1 TOA:420 ms
9:43:53:406|DEBUG| GW:00-80-00-00-a0-00-1c-13|FRAME-RX|JSON: {“tmst”:400513404,”chan”:1,”rfch”:0,”freq”:868.3,”stat”:1,”modu”:”LORA”,”datr”:”SF10BW125″,”codr”:”4/5″,”lsnr”:0.0,”rssi”:-110,”size”:24,”data”:”gIhyqgKAAAABb0vPy5nAF071DEfib95p”}
9:43:54:236|DEBUG| Device response requested 0 ACK 1
9:43:54:247|INFO| GW:00-80-00-00-a0-00-1c-13|FRAME-TX|IP: 127.0.0.1:35427 CH: LC2 DEV: 02-aa-72-88 FCNT: 000002d4 REPEAT: 0
9:43:54:251|INFO| ED:00-80-00-01-a5-00-00-ab|SCHED-TX|Q-SIZE: 1 PKT-ROOM: 51
9:43:54:251|DEBUG| getTimeOnAirMs SF: 10 BW: 125 PL: 8 SZ: 17 TOA: 329

[Jason Reiss]

Please open a ticket at support.multitech.com to share config and log files.

[Daniel Nilsson]

Thanks, it’s now done 🙂

[Author]

Posts