search

cyberman54 / ESP32-Paxcounter

Wifi & BLE driven passenger flow metering with cheap ESP32 boards
https://cyberman54.github.io/ESP32-Paxcounter/
Other
1.69k stars 397 forks source link

LoPy4 Fails to join LoRa network (TTN & North) unless for SF7 #981

Closed markwaters306 closed 1 year ago

markwaters306 commented 1 year ago

I have a LoPy4 that fails to join the LoRa network unless the device is within 10m of the gateway.

I have tried two different services TTN and North and experience the same issue.

I have also tried two different LoPy4 boards and antennas and the issue remains.

I've also uncommented '#define CLOCK_ERROR_PROCENTAGE 5' to try help but still no luck.

I'm wondering if there is an issue with the lmic stack. I've left the device on for 24 hours and still nothing came through on the gateway. Here is output log with '#define LMIC_DEBUG_LEVEL 2'.

The only time I can get it to join is by taking the device extreamly close to the gateway. Over 10m and it struggles.

09:13:21.339 > -41293353: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:13:21.579 > rxtimeout: entry: -41278983 rxtime: -41293360 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:13:21.580 > -41278829: processRx2Jacc txrxFlags 0x2 --> 00 09:13:21.580 > -41278608: engineUpdate, opmode=0x4 09:14:03.296 > W (68101538) src/lorawan.cpp: LORA sendqueue is full 09:15:03.292 > W (68161538) src/lorawan.cpp: LORA sendqueue is full 09:15:23.502 > -33658233: engineUpdate, opmode=0x4 09:15:23.502 > -33658176: TXMODE, freq=868500000, len=23, SF=9, BW=125, CR=4/5, IH=0 09:15:28.708 > -33333483: setupRx1 txrxFlags 00 --> 01 09:15:28.709 > start single rx: now-rxtime: 3 09:15:28.709 > -33332916: RXMODE_SINGLE, freq=868500000, SF=9, BW=125, CR=4/5, IH=0 09:15:28.737 > rxtimeout: entry: -33331046 rxtime: -33332923 entry-rxtime: 1877 now-entry: 128 rxtime-txend: 312375 09:15:29.683 > -33270983: setupRx2 txrxFlags 0x1 --> 02 09:15:29.707 > start single rx: now-rxtime: 3 09:15:29.707 > -33270416: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:15:29.949 > rxtimeout: entry: -33256046 rxtime: -33270423 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:15:29.949 > -33255892: processRx2Jacc txrxFlags 0x2 --> 00 09:15:29.949 > -33255671: engineUpdate, opmode=0x4 09:16:03.294 > W (68221538) src/lorawan.cpp: LORA sendqueue is full 09:17:03.288 > W (68281538) src/lorawan.cpp: LORA sendqueue is full 09:18:03.286 > W (68341538) src/lorawan.cpp: LORA sendqueue is full 09:19:03.298 > W (68401538) src/lorawan.cpp: LORA sendqueue is full 09:19:18.616 > -18963796: engineUpdate, opmode=0x4 09:19:18.616 > -18963738: TXMODE, freq=868100000, len=23, SF=9, BW=125, CR=4/5, IH=0 09:19:23.823 > -18639046: setupRx1 txrxFlags 00 --> 01 09:19:23.823 > start single rx: now-rxtime: 3 09:19:23.823 > -18638478: RXMODE_SINGLE, freq=868100000, SF=9, BW=125, CR=4/5, IH=0 09:19:23.853 > rxtimeout: entry: -18636608 rxtime: -18638485 entry-rxtime: 1877 now-entry: 128 rxtime-txend: 312375 09:19:24.798 > -18576546: setupRx2 txrxFlags 0x1 --> 02 09:19:24.820 > start single rx: now-rxtime: 2 09:19:24.820 > -18575978: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:19:25.064 > rxtimeout: entry: -18561608 rxtime: -18575985 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:19:25.064 > -18561454: processRx2Jacc txrxFlags 0x2 --> 00 09:19:25.064 > -18561233: engineUpdate, opmode=0x4 09:20:03.291 > W (68461538) src/lorawan.cpp: LORA sendqueue is full 09:21:03.302 > W (68521538) src/lorawan.cpp: LORA sendqueue is full 09:22:03.298 > W (68581538) src/lorawan.cpp: LORA sendqueue is full 09:22:52.328 > -5605733: engineUpdate, opmode=0x4 09:22:52.351 > -5605677: TXMODE, freq=868300000, len=23, SF=9, BW=125, CR=4/5, IH=0 09:22:57.555 > -5280983: setupRx1 txrxFlags 00 --> 01 09:22:57.556 > start single rx: now-rxtime: 3 09:22:57.556 > -5280416: RXMODE_SINGLE, freq=868300000, SF=9, BW=125, CR=4/5, IH=0 09:22:57.587 > rxtimeout: entry: -5278546 rxtime: -5280423 entry-rxtime: 1877 now-entry: 128 rxtime-txend: 312375 09:22:58.531 > -5218483: setupRx2 txrxFlags 0x1 --> 02 09:22:58.554 > start single rx: now-rxtime: 3 09:22:58.554 > -5217916: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:22:58.791 > rxtimeout: entry: -5203546 rxtime: -5217923 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:22:58.792 > -5203392: processRx2Jacc txrxFlags 0x2 --> 00 09:22:58.792 > -5203171: engineUpdate, opmode=0x4 09:23:03.289 > W (68641538) src/lorawan.cpp: LORA sendqueue is full 09:24:03.300 > W (68701538) src/lorawan.cpp: LORA sendqueue is full 09:25:03.297 > W (68761538) src/lorawan.cpp: LORA sendqueue is full 09:26:03.293 > W (68821538) src/lorawan.cpp: LORA sendqueue is full 09:27:03.304 > W (68881538) src/lorawan.cpp: LORA sendqueue is full 09:27:04.180 > 10133392: engineUpdate, opmode=0x4 09:27:04.180 > 10133449: TXMODE, freq=868500000, len=23, SF=10, BW=125, CR=4/5, IH=0 09:27:09.526 > 10468517: setupRx1 txrxFlags 00 --> 01 09:27:09.550 > start single rx: now-rxtime: 3 09:27:09.551 > 10469084: RXMODE_SINGLE, freq=868500000, SF=10, BW=125, CR=4/5, IH=0 09:27:09.610 > rxtimeout: entry: 10472704 rxtime: 10469077 entry-rxtime: 3627 now-entry: 128 rxtime-txend: 312375 09:27:10.522 > 10531017: setupRx2 txrxFlags 0x1 --> 02 09:27:10.550 > start single rx: now-rxtime: 3 09:27:10.550 > 10531584: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:27:10.787 > rxtimeout: entry: 10545954 rxtime: 10531577 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:27:10.787 > 10546107: processRx2Jacc txrxFlags 0x2 --> 00 09:27:10.787 > 10546329: engineUpdate, opmode=0x4 09:28:03.308 > W (68941538) src/lorawan.cpp: LORA sendqueue is full 09:29:03.305 > W (69001538) src/lorawan.cpp: LORA sendqueue is full 09:30:03.301 > W (69061538) src/lorawan.cpp: LORA sendqueue is full 09:31:03.296 > W (69121538) src/lorawan.cpp: LORA sendqueue is full 09:32:03.308 > W (69181538) src/lorawan.cpp: LORA sendqueue is full 09:33:03.304 > W (69241538) src/lorawan.cpp: LORA sendqueue is full 09:33:20.141 > 33630642: engineUpdate, opmode=0x4 09:33:20.141 > 33630698: TXMODE, freq=868100000, len=23, SF=10, BW=125, CR=4/5, IH=0 09:33:25.488 > 33965767: setupRx1 txrxFlags 00 --> 01 09:33:25.513 > start single rx: now-rxtime: 3 09:33:25.513 > 33966334: RXMODE_SINGLE, freq=868100000, SF=10, BW=125, CR=4/5, IH=0 09:33:25.572 > rxtimeout: entry: 33969954 rxtime: 33966327 entry-rxtime: 3627 now-entry: 128 rxtime-txend: 312375 09:33:26.484 > 34028267: setupRx2 txrxFlags 0x1 --> 02 09:33:26.511 > start single rx: now-rxtime: 3 09:33:26.511 > 34028834: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:33:26.750 > rxtimeout: entry: 34043204 rxtime: 34028827 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:33:26.750 > 34043357: processRx2Jacc txrxFlags 0x2 --> 00 09:33:26.750 > 34043579: engineUpdate, opmode=0x4 09:34:03.311 > W (69301538) src/lorawan.cpp: LORA sendqueue is full 09:35:03.308 > W (69361538) src/lorawan.cpp: LORA sendqueue is full 09:36:03.303 > W (69421538) src/lorawan.cpp: LORA sendqueue is full 09:37:03.315 > W (69481538) src/lorawan.cpp: LORA sendqueue is full 09:38:03.312 > W (69541538) src/lorawan.cpp: LORA sendqueue is full 09:39:03.307 > W (69601538) src/lorawan.cpp: LORA sendqueue is full 09:40:02.401 > 58771517: engineUpdate, opmode=0x4 09:40:02.402 > 58771573: TXMODE, freq=868300000, len=23, SF=10, BW=125, CR=4/5, IH=0 09:40:03.314 > W (69661538) src/lorawan.cpp: LORA sendqueue is full 09:40:07.748 > 59106642: setupRx1 txrxFlags 00 --> 01 09:40:07.773 > start single rx: now-rxtime: 3 09:40:07.773 > 59107210: RXMODE_SINGLE, freq=868300000, SF=10, BW=125, CR=4/5, IH=0 09:40:07.834 > rxtimeout: entry: 59110829 rxtime: 59107202 entry-rxtime: 3627 now-entry: 128 rxtime-txend: 312375 09:40:08.745 > 59169142: setupRx2 txrxFlags 0x1 --> 02 09:40:08.772 > start single rx: now-rxtime: 3 09:40:08.772 > 59169709: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:40:09.011 > rxtimeout: entry: 59184079 rxtime: 59169702 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:40:09.011 > 59184233: processRx2Jacc txrxFlags 0x2 --> 00 09:40:09.011 > 59184454: engineUpdate, opmode=0x4 09:41:03.308 > W (69721538) src/lorawan.cpp: LORA sendqueue is full 09:42:03.320 > W (69781538) src/lorawan.cpp: LORA sendqueue is full 09:43:03.316 > W (69841538) src/lorawan.cpp: LORA sendqueue is full 09:44:03.312 > W (69901538) src/lorawan.cpp: LORA sendqueue is full 09:45:03.324 > W (69961538) src/lorawan.cpp: LORA sendqueue is full 09:46:03.320 > W (70021538) src/lorawan.cpp: LORA sendqueue is full 09:47:03.316 > W (70081538) src/lorawan.cpp: LORA sendqueue is full 09:47:22.973 > 86307767: engineUpdate, opmode=0x4 09:47:22.974 > 86307822: TXMODE, freq=868100000, len=23, SF=11, BW=125, CR=4/5, IH=0 09:47:28.783 > 86671142: setupRx1 txrxFlags 00 --> 01 09:47:28.816 > start single rx: now-rxtime: 3 09:47:28.816 > 86671709: RXMODE_SINGLE, freq=868100000, SF=11, BW=125, CR=4/5, IH=0 09:47:28.911 > rxtimeout: entry: 86678954 rxtime: 86671702 entry-rxtime: 7252 now-entry: 128 rxtime-txend: 312375 09:47:29.814 > 86733642: setupRx2 txrxFlags 0x1 --> 02 09:47:29.815 > start single rx: now-rxtime: 2 09:47:29.815 > 86734209: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 09:47:30.049 > rxtimeout: entry: 86748579 rxtime: 86734202 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 09:47:30.049 > 86748732: processRx2Jacc txrxFlags 0x2 --> 00 09:47:30.049 > 86748954: engineUpdate, opmode=0x4 09:48:03.329 > W (70141538) src/lorawan.cpp: LORA sendqueue is full 09:49:03.326 > W (70201538) src/lorawan.cpp: LORA sendqueue is full 09:50:03.321 > W (70261538) src/lorawan.cpp: LORA sendqueue is full 09:51:03.317 > W (70321538) src/lorawan.cpp: LORA sendqueue is full 09:52:03.330 > W (70381538) src/lorawan.cpp: LORA sendqueue is full 09:53:03.326 > W (70441538) src/lorawan.cpp: LORA sendqueue is full 09:54:03.322 > W (70501538) src/lorawan.cpp: LORA sendqueue is full 09:55:03.334 > W (70561538) src/lorawan.cpp: LORA sendqueue is full 09:56:03.330 > W (70621538) src/lorawan.cpp: LORA sendqueue is full 09:57:03.326 > W (70681538) src/lorawan.cpp: LORA sendqueue is full 09:58:03.339 > W (70741538) src/lorawan.cpp: LORA sendqueue is full 09:59:03.334 > W (70801538) src/lorawan.cpp: LORA sendqueue is full 10:00:03.331 > W (70861538) src/lorawan.cpp: LORA sendqueue is full 10:01:03.327 > W (70921538) src/lorawan.cpp: LORA sendqueue is full 10:02:03.339 > W (70981538) src/lorawan.cpp: LORA sendqueue is full 10:02:06.364 > 141519017: engineUpdate, opmode=0x4 10:02:06.385 > 141519073: TXMODE, freq=868500000, len=23, SF=11, BW=125, CR=4/5, IH=0 10:02:12.180 > 141882392: setupRx1 txrxFlags 00 --> 01 10:02:12.206 > start single rx: now-rxtime: 3 10:02:12.206 > 141882959: RXMODE_SINGLE, freq=868500000, SF=11, BW=125, CR=4/5, IH=0 10:02:12.326 > rxtimeout: entry: 141890204 rxtime: 141882952 entry-rxtime: 7252 now-entry: 128 rxtime-txend: 312375 10:02:13.208 > 141944892: setupRx2 txrxFlags 0x1 --> 02 10:02:13.209 > start single rx: now-rxtime: 2 10:02:13.209 > 141945459: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 10:02:13.449 > rxtimeout: entry: 141959829 rxtime: 141945452 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 10:02:13.450 > 141959983: processRx2Jacc txrxFlags 0x2 --> 00 10:02:13.450 > 141960204: engineUpdate, opmode=0x4 10:03:03.330 > W (71041538) src/lorawan.cpp: LORA sendqueue is full 10:04:03.343 > W (71101538) src/lorawan.cpp: LORA sendqueue is full 10:05:03.337 > W (71161538) src/lorawan.cpp: LORA sendqueue is full 10:06:03.334 > W (71221538) src/lorawan.cpp: LORA sendqueue is full 10:07:03.346 > W (71281538) src/lorawan.cpp: LORA sendqueue is full 10:08:03.343 > W (71341538) src/lorawan.cpp: LORA sendqueue is full 10:09:03.338 > W (71401538) src/lorawan.cpp: LORA sendqueue is full 10:10:03.351 > W (71461538) src/lorawan.cpp: LORA sendqueue is full 10:11:03.346 > W (71521538) src/lorawan.cpp: LORA sendqueue is full 10:12:03.342 > W (71581538) src/lorawan.cpp: LORA sendqueue is full 10:13:03.339 > W (71641538) src/lorawan.cpp: LORA sendqueue is full 10:14:03.350 > W (71701538) src/lorawan.cpp: LORA sendqueue is full 10:15:03.347 > W (71761538) src/lorawan.cpp: LORA sendqueue is full 10:15:59.193 > 193568704: engineUpdate, opmode=0x4 10:15:59.193 > 193568761: TXMODE, freq=868300000, len=23, SF=11, BW=125, CR=4/5, IH=0 10:16:03.355 > W (71821538) src/lorawan.cpp: LORA sendqueue is full 10:16:04.988 > 193932079: setupRx1 txrxFlags 00 --> 01 10:16:05.014 > start single rx: now-rxtime: 2 10:16:05.014 > 193932647: RXMODE_SINGLE, freq=868300000, SF=11, BW=125, CR=4/5, IH=0 10:16:05.134 > rxtimeout: entry: 193939892 rxtime: 193932640 entry-rxtime: 7252 now-entry: 128 rxtime-txend: 312375 10:16:06.018 > 193994579: setupRx2 txrxFlags 0x1 --> 02 10:16:06.018 > start single rx: now-rxtime: 3 10:16:06.018 > 193995148: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0 10:16:06.258 > rxtimeout: entry: 194009517 rxtime: 193995140 entry-rxtime: 14377 now-entry: 128 rxtime-txend: 374875 10:16:06.259 > 194009670: processRx2Jacc txrxFlags 0x2 --> 00 10:16:06.259 > 194009892: engineUpdate, opmode=0x4

cyberman54 commented 1 year ago

The log just shows that LMiC is increasing the SF level during join process. This works as designed. Please post log which shows the begin of the join proces, and a successful join.

Which network server or network provider are you using for join? Which country settings? Which type of gateway? Do you have access to gateway and/or network server and can you provide logs from this side? Did you double check that your network credentials are valid?

I don't expect an lmic issue here, since the used mcci lmic lib has reached a pretty stable and well tested state.

markwaters306 commented 1 year ago

Thanks for your response.

Which network server or network provider are you using for join?

messages.csv

Have you had a LoPy4 working at distance before?

cyberman54 commented 1 year ago

The gateway log show that the server accepted the join. So it's not a crendential problem. I looks like you may have an RX problem, what means the downlink with the accept does not lmic. This is a common reason why OTA joining fails.

Your log shows rssi < -100. This is very low, far too low for a device which is close to the gateway. You should see values -60 ... -80 here.

Make sure

image

markwaters306 commented 1 year ago

Had the antenna connected to wrong port... stupid avoidable mistake! RTFM

Thanks for the support and sorry for the non-code issue!