Device keeps sending join accepts

End Devices (Nodes)
1

Summary

My end device keeps sending a join request and the join accept being accepted. Everything looks normal (to me), but something must be wrong somewhere, and I’m struggling to figure out, what it could be. And help or ideas are very much appreciated. Please see the logs below.

Logs
I’ve posted the logs from the live data tab of the end device in The Things Network below. Also the log from the gateway:

Logs from TTN (uploaded since too big for the post):
woody3536_live_data_1719484290368.json (210.3 KB)

Screenshot of Live Data tab in TTN:

Screenshot 2024-06-27 at 12.38.15
Screenshot 2024-06-27 at 12.38.151639×720 75.9 KB

Logs from gateway (logread command):

root@eui-ac1f09fffe061440:~# logread
Thu Jun 27 10:30:21 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=3, timeonair=349, tm=1719484221
Thu Jun 27 10:30:21 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=3, tm=1719484221
Thu Jun 27 10:30:21 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=1, timeonair=349, tm=1719484221
Thu Jun 27 10:30:21 2024 user.debug basicstation[2450]: [SYN:VERB] Time sync rejected: quality=240 threshold=200
Thu Jun 27 10:30:22 2024 user.debug basicstation[2450]: [S2E:DEBU] ::1 diid=55332 [ant#0] - next TX start ahead by 4s147ms (10:30:26.513457)
Thu Jun 27 10:30:23 2024 user.debug basicstation[2450]: [SYN:VERB] Time sync rejected: quality=208 threshold=200
Thu Jun 27 10:30:26 2024 user.debug basicstation[2450]: [S2E:VERB] ::1 diid=55332 [ant#0] - starting TX in 49ms924us: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=6027070227A1000006940A059A (13 bytes)
Thu Jun 27 10:30:26 2024 user.info basicstation[2450]: [RAL:INFO] RAL_LGW: lgw_send done: count_us=1286923219.
Thu Jun 27 10:30:26 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-421 downlinkTqByAirtime: dr=3, timeonair=144, tm=1719484226
Thu Jun 27 10:30:26 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-423 downlinkTqByPkt: dr=3, tm=1719484226
Thu Jun 27 10:30:26 2024 user.info basicstation[2450]: [S2E:INFO] TX ::1 diid=55332 [ant#0] - dntxed: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=6027070227A1000006940A059A (13 bytes)
Thu Jun 27 10:30:26 2024 user.debug basicstation[2450]: [S2E:DEBU] Tx done diid=55332
Thu Jun 27 10:30:27 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=867300000 bw=0 sz=47 dr=7 40AC070227832D0706003B01E2DE516E8947FC673BE41E1F1C61E77F8C25CAD5FDD3EAC8630C0CDA55D3771ABCAAC1
Thu Jun 27 10:30:27 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=92, tm=1719484227
Thu Jun 27 10:30:27 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484227
Thu Jun 27 10:30:27 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=4, timeonair=92, tm=1719484227
Thu Jun 27 10:30:38 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868300000 bw=0 sz=23 dr=9 00521403D07ED5B37050648DF53B91D8C769EA7724E87C
Thu Jun 27 10:30:38 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=3, timeonair=185, tm=1719484238
Thu Jun 27 10:30:38 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=3, tm=1719484238
Thu Jun 27 10:30:38 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=1, timeonair=185, tm=1719484238
Thu Jun 27 10:30:40 2024 user.info basicstation[2450]: [SYN:INFO] MCU/SX130X drift stats: min: +0.0ppm  q50: -2.9ppm  q80: -6.2ppm  max: -10.0ppm - threshold q90: -6.7ppm
Thu Jun 27 10:30:40 2024 user.info basicstation[2450]: [SYN:INFO] Mean MCU drift vs SX130X#0: -2.7ppm
Thu Jun 27 10:30:42 2024 user.debug basicstation[2450]: [SYN:VERB] Time sync rejected: quality=233 threshold=200
Thu Jun 27 10:30:46 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=867900000 bw=0 sz=21 dr=7 40BDA030E080B11205EC9C3E6E55D8152C39CBAB93
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=51, tm=1719484246
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484246
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=7, timeonair=51, tm=1719484246
Thu Jun 27 10:30:46 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868300000 bw=2 sz=23 dr=9 00521403D07ED5B370811C51E36F2AC1FB7C1103B96404
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=3, timeonair=185, tm=1719484246
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=3, tm=1719484246
Thu Jun 27 10:30:46 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=1, timeonair=185, tm=1719484246
Thu Jun 27 10:30:48 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=867900000 bw=0 sz=21 dr=7 4056BE30E0805B4905F7C7AC29EF11143BFF727BFA
Thu Jun 27 10:30:48 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=51, tm=1719484248
Thu Jun 27 10:30:48 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484248
Thu Jun 27 10:30:48 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=7, timeonair=51, tm=1719484248
Thu Jun 27 10:30:48 2024 user.debug basicstation[2450]: [S2E:DEBU] ::1 diid=55749 [ant#0] - next TX start ahead by 2s968ms (10:30:51.746277)
Thu Jun 27 10:30:49 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=867900000 bw=0 sz=43 dr=9 40F87C00270071B1012DBBD443806CA80DB2438EA49A11A37E246E5FCD23BD9B85E3D76709E4C7C1FB5220
Thu Jun 27 10:30:49 2024 user.debug basicstation[2450]: [RAL:DEBU] [CRC FAIL] 867.900MHz -15.25/-130.1 SF9/BW125 (mod=16/dr=9/bw=4) xtick=4e12e640 (1309861440) 43 bytes: 40F87C00270071B1012DBBD443806CA80DB2438EA49A11A37E246E5FCD23BD9B85E3D76709E4C7C1FB5220
Thu Jun 27 10:30:51 2024 user.debug basicstation[2450]: [S2E:VERB] ::1 diid=55749 [ant#0] - starting TX in 49ms769us: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=2083C9F3312DECEC05F93101..A4C40049 (33 bytes)
Thu Jun 27 10:30:51 2024 user.info basicstation[2450]: [RAL:INFO] RAL_LGW: lgw_send done: count_us=1312155985.
Thu Jun 27 10:30:51 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-421 downlinkTqByAirtime: dr=3, timeonair=247, tm=1719484251
Thu Jun 27 10:30:51 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-423 downlinkTqByPkt: dr=3, tm=1719484251
Thu Jun 27 10:30:51 2024 user.info basicstation[2450]: [S2E:INFO] TX ::1 diid=55749 [ant#0] - dntxed: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=2083C9F3312DECEC05F93101..A4C40049 (33 bytes)
Thu Jun 27 10:30:52 2024 user.debug basicstation[2450]: [S2E:DEBU] Tx done diid=55749
Thu Jun 27 10:30:55 2024 user.debug basicstation[2450]: [SYN:VERB] Time sync rejected: quality=219 threshold=200
Thu Jun 27 10:31:00 2024 cron.info crond[29308]: USER root pid 23628 cmd /mnt/mmcblk0p1/scripts/ws_job_every_minute.sh
Thu Jun 27 10:31:08 2024 user.info basicstation[2450]: [SYN:INFO] Time sync qualities: min=139 q90=219 max=240 (previous q90=200)
Thu Jun 27 10:31:12 2024 user.debug basicstation[2450]: [LOG:DEBU] logger read datas: aws-iot-stats
Thu Jun 27 10:31:12 2024 user.debug basicstation[2450]: [LOG:DEBU] logger write datas size: 592
Thu Jun 27 10:31:12 2024 user.debug basicstation[2450]: [LOG:DEBU] close logger connection [7].
Thu Jun 27 10:31:12 2024 user.info wisdm[2466]: [truncated] Update Statistic: {"state":{"reported":{"report":"stats","company":"woodsense","radio":[{"ifch":0,"freq":868100000,"dutycycle":0.231666667,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":1,"freq":868300000,"dutycycle":1.11166667,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":2,"freq":868500000,"dutycycle":0.636666667,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":3,"freq":867100000,"dutycycle":0,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":4,"freq":867300000,"dutycycle":0.015,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":5,"freq":867500000,"dutycycle":0,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":6,"freq":867700000,"dutycycle":0,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":7,"freq":867900000,"dutycycle":0.268333333,"uplink":0,"downlink":0,"mod":"LoRa MultiSF"},{"ifch":8,"freq":868300000,"dutycycle":0,"uplink":0,"downlink":0,"mod":"LoRa STD"},{"ifch":9,"freq":868800000,"dutycycle":0,"uplink":0,"downlink":0,"m
Thu Jun 27 10:31:12 2024 user.info wisdm[2466]: Update Statistic Accepted !!
Thu Jun 27 10:31:14 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868300000 bw=0 sz=60 dr=9 80C407022780000001AFF99D1B6AEFC3E1DB64E356DBFC139F5EFCC385A8DEA1D137B552E328A3281B3FA706AC1EE9C302AB5870740BB97755435B68
Thu Jun 27 10:31:14 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=3, timeonair=349, tm=1719484274
Thu Jun 27 10:31:14 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=3, tm=1719484274
Thu Jun 27 10:31:14 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=1, timeonair=349, tm=1719484274
Thu Jun 27 10:31:14 2024 user.debug basicstation[2450]: [S2E:DEBU] ::1 diid=56149 [ant#0] - next TX start ahead by 4s435ms (10:31:18.962536)
Thu Jun 27 10:31:18 2024 user.debug basicstation[2450]: [S2E:VERB] ::1 diid=56149 [ant#0] - starting TX in 49ms928us: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=60C4070227A1000006964D466A (13 bytes)
Thu Jun 27 10:31:18 2024 user.info basicstation[2450]: [RAL:INFO] RAL_LGW: lgw_send done: count_us=1339372315.
Thu Jun 27 10:31:18 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-421 downlinkTqByAirtime: dr=3, timeonair=144, tm=1719484278
Thu Jun 27 10:31:18 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-423 downlinkTqByPkt: dr=3, tm=1719484278
Thu Jun 27 10:31:18 2024 user.info basicstation[2450]: [S2E:INFO] TX ::1 diid=56149 [ant#0] - dntxed: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=60C4070227A1000006964D466A (13 bytes)
Thu Jun 27 10:31:19 2024 user.debug basicstation[2450]: [S2E:DEBU] Tx done diid=56149
Thu Jun 27 10:31:23 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868500000 bw=0 sz=21 dr=7 40586430E0C0727E05561FDD86DF19D183986AA979
Thu Jun 27 10:31:23 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=51, tm=1719484283
Thu Jun 27 10:31:23 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484283
Thu Jun 27 10:31:23 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=2, timeonair=51, tm=1719484283
Thu Jun 27 10:31:23 2024 user.debug basicstation[2450]: [SYN:VERB] Time sync rejected: quality=267 threshold=219
Thu Jun 27 10:31:28 2024 user.info basicstation[2450]: [SYN:INFO] MCU/SX130X drift stats: min: +0.5ppm  q50: -3.3ppm  q80: -6.2ppm  max: -10.0ppm - threshold q90: -6.7ppm
Thu Jun 27 10:31:28 2024 user.info basicstation[2450]: [SYN:INFO] Mean MCU drift vs SX130X#0: -3.1ppm
Thu Jun 27 10:31:31 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868100000 bw=0 sz=21 dr=7 406C9631E080837E0549612378A2D13B4DCD74ED56
Thu Jun 27 10:31:31 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=51, tm=1719484291
Thu Jun 27 10:31:31 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484291
Thu Jun 27 10:31:31 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=0, timeonair=51, tm=1719484291
Thu Jun 27 10:31:39 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868300000 bw=0 sz=23 dr=9 00521403D07ED5B370811C51E36F2AC1FBA5CFF4E86C4B
Thu Jun 27 10:31:39 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=3, timeonair=185, tm=1719484299
Thu Jun 27 10:31:39 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=3, tm=1719484299
Thu Jun 27 10:31:39 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=1, timeonair=185, tm=1719484299
Thu Jun 27 10:31:40 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868100000 bw=0 sz=21 dr=7 4070CC31E080695505DC68A05B7845891F00395E45
Thu Jun 27 10:31:40 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=5, timeonair=51, tm=1719484300
Thu Jun 27 10:31:40 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=5, tm=1719484300
Thu Jun 27 10:31:40 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=0, timeonair=51, tm=1719484300
Thu Jun 27 10:31:41 2024 user.debug basicstation[2450]: [S2E:DEBU] ::1 diid=56550 [ant#0] - next TX start ahead by 2s785ms (10:31:44.195655)
Thu Jun 27 10:31:44 2024 user.debug basicstation[2450]: [S2E:VERB] ::1 diid=56550 [ant#0] - starting TX in 49ms928us: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=20C8D132A2CB40E3EDA79323..D738D135 (33 bytes)
Thu Jun 27 10:31:44 2024 user.info basicstation[2450]: [RAL:INFO] RAL_LGW: lgw_send done: count_us=1364605366.
Thu Jun 27 10:31:44 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-421 downlinkTqByAirtime: dr=3, timeonair=247, tm=1719484304
Thu Jun 27 10:31:44 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_down-423 downlinkTqByPkt: dr=3, tm=1719484304
Thu Jun 27 10:31:44 2024 user.info basicstation[2450]: [S2E:INFO] TX ::1 diid=56550 [ant#0] - dntxed: 868.3MHz 16.0dBm ant#0(0) DR3 SF9/BW125 frame=20C8D132A2CB40E3EDA79323..D738D135 (33 bytes)
Thu Jun 27 10:31:44 2024 user.debug basicstation[2450]: [S2E:DEBU] Tx done diid=56550
Thu Jun 27 10:31:55 2024 user.notice data-broker: data-broker timeout, restart it
Thu Jun 27 10:31:57 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=868300000 bw=0 sz=60 dr=9 8088070227800000015122FA464DE5F86FDD44BE8B08EF50A5A36913FF9199014E65050FDBF2FCA9530DC77DF36AD6182DF815EC72C4990329689E4D
Thu Jun 27 10:31:57 2024 user.debug basicstation[2450]: [RAL:DEBU] [CRC FAIL] 868.300MHz -13.25/-128.1 SF9/BW125 (mod=16/dr=9/bw=4) xtick=52203bf7 (1377844215) 60 bytes: 8088070227800000015122FA464DE5F86FDD44BE8B08EF50A5A36913FF9199014E65050FDBF2FCA9530DC77DF36AD6182DF815EC72C4990329689E4D
Thu Jun 27 10:32:00 2024 cron.info crond[29308]: USER root pid 27699 cmd /mnt/mmcblk0p1/scripts/ws_job_every_minute.sh
Thu Jun 27 10:32:04 2024 user.info basicstation[2450]: [RAL:INFO] RX mod=LORA f=867300000 bw=0 sz=44 dr=10 40CA070227809F0301B4D794B0F17A6429500AE7C13A804F5BCFB4BF6A5783E74CD7835ED1A3F4D6E04EA5DC
Thu Jun 27 10:32:04 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-357 uplinkTqByAirtime: dr=2, timeonair=534, tm=1719484324
Thu Jun 27 10:32:04 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-359 uplinkTqByPkt: dr=2, tm=1719484324
Thu Jun 27 10:32:04 2024 user.debug basicstation[2450]: [LOG:DEBU] rrd_statistic_up-361 ChanBusyByAirtime: chan=4, timeonair=534, tm=1719484324
Thu Jun 27 10:32:04 2024 user.info basicstation[2450]: [SYN:INFO] Time sync qualities: min=136 q90=202 max=267 (previous q90=219)
Thu Jun 27 10:32:04 2024 user.info basicstation[2450]: [SYN:INFO] MCU/SX130X drift stats: min: +0.5ppm  q50: -3.3ppm  q80: -9.0ppm  max: -13.8ppm - threshold q90: -11.4ppm
Thu Jun 27 10:32:04 2024 user.info basicstation[2450]: [SYN:INFO] Mean MCU drift vs SX130X#0: -4.7ppm
Thu Jun 27 10:32:10 2024 authpriv.info dropbear[28342]: Child connection from 10.8.0.56:56502
Thu Jun 27 10:32:14 2024 authpriv.notice dropbear[28342]: Password auth succeeded for 'root' from 10.8.0.56:56502
root@eui-ac1f09fffe061440:~#

Hardware

The end device is our own custom device. It’s working fine for many different projects, so we don’t suspect the firmware or hardware to be the issue. The gateway is a WisGate Edge Lite 2 RAK7268.

2

You seem to have documented everything other than the device which is clearly offending because the device is the one with the problem, there’s no backoff on the rejoin and your payload is massive so perhaps there’s a buffer overflow or even a brown-out?

Without knowing what radio and firmware you are using, no one can realistically help.

3

Thank you for your response @descartes, and sorry about the missing device information.

The device is a Class A device we developed ourselves using:

  • Europe 863-870 MHz (SF9 for RX2 - recommended)
  • LoRaWAN Specification 1.0.2
  • RP001 Regional Parameters 1.0.2 revision B

and the firmware is obviously also custom, and you are right we are indeed missing some backoff in the firmware. This is the first time experiencing an issue like this, hence we hadn’t thought of it.

The payload is probably quite big since in our first uplink we also send a few strings containing firmware details, hence the first uplink is quite bigger than the rest. However this has never been an issue even on very pool signals using spreading factor 12, so I was suspecting the problem being somewhere else (gateway/network server).

4

Did you write your own LoRaWAN stack? If you look at other similar questions we almost always want to know what stack you are using.

5

No we are using The Things Network.

6

What is the LoRaWAN stack ON THE DEVICE?

Strings???

Perhaps break it up in to smaller chunks?

Nope and nope. SF12 takes forever to send a longish payload and is therefore prone to interference. And the LW Alliance ask operators to restrict the use of SF11 & 12. Nothing wrong with the gateway & network server, it’s YOUR device and your confusion about what LW stack the firmware is using is indicative of where the issue may lie.

7

Is this the SNR/RSSI?

Can you see the error message?

8

The comms appear to be OK, it’s the device rejoining - possibly restarting - that is the issue at hand.

9

The stack was implemented by an external company for an SAMR34 MCU, and they have been using a lorawan stack from asf as far as I know. I’m sorry that I can’t give a better explanation than this.

We are always sending the first payload using SF9, and then using ADR to adjust the SF to optimal setting based on the signal strength to the gateway, so the string will only be sent with SF9.

10

Hi @johan , thank you for chipping in. The logs are generated by basicstation developed by SemTech, so I’m not 100% sure, but it could indeed look like the SNR and RSSI, yes.

11

I know this is not easy to debug given the information that’s available, but I just wanted to hear, if you have seen anything like this happen before, and what possible causes could be? Assuming that it’s not the device that’s the problem.

12

Fine, now we know, the current Microchip LoRaWAN Stack (MLS) is v1.0.4, not v1.0.2 so that could do with being adjusted.

The second paragraph is inexplicably random - why send the first payload at SF9, with v1.0.4 you’ll be updated with an appropriate DR almost immediately - but none the less, what if the device needs SF10?

There is no world where “the string will only be sent with SF9” is good engineering or forms a justifiable response. There’s no need to send strings, it’s very inefficient, store the data in the firmware as a number as well as a printable string for the debug serial output and sending it at a particular DR doesn’t make it any better.

Now that we know what the stack is, can you tell us what version of MLS you are using and what is the debug output from the device when it does this join / fall-over loop?

This should not be hard to debug with serial debug and if necessary, the addition of more debug printf’s.

13

According to the MLS guide it should be used with the LoRaWAN 1.0.2 specification. Or am I reading this wrong?
MLS_Migration_Guide.pdf (321.8 KB)

You are completely right. We are also gonna update the firmware to save the version numbers as integers.

We are using MLS stack version MLS_SDK_1_0_P_4.

14

Serial debug output is the most essential info …

15

Unfortunately I don’t have physical access to the device, and I can’t recreate the issue with another device, which is also why I assumed this was related to the gateway/network server, and wanted to hear if anything experienced anything similar with other LoRaWAN devices.

16

Hard to tell, I’ve only used 1_0_P_5 which is v1.0.4 and the current 1_0_P_6, both of which have been run through the certification tool. Prior to that the releases were incremental to add in the missing bits from the initial v1.0.2 level release, so it may have passed through v1.0.3 but it’s not documented or clear.

I’m sure there are lots of people who’ve had a vicious rejoin loop, me included, but without any serial debug it’s just going to be random guesses, particularly if it’s just one device.

Given the thousands of devices that use the TTN Network Server, I think it would be a safe bet that it’s not that. And if other devices are using the gateway OK then that rather discounts that.

Sometimes it’s simpler to chuck a badly behaved one-off device away. And using a stack that’s had multiple revisions over the years is always a good idea - you may have triggered an issue that has since been resolved.

Without serial debug I can’t think of anything else.

17

Thank you very much for your input @descartes, it is much appreciated!

Your reasoning make good sense. I will continue trying to replicate the issue and get some serial logs.

18

This topic was automatically closed 24 hours after the last reply. New replies are no longer allowed.