Commit solving #1284 introduces a failure in EU868
VolkerChristian opened this issue · 13 comments
I'm very sorry, but the commit solving #1284 introduces a failure at least in EU868. After a view uplinks (the number of uplinks working is not always the same - ranges from four to seven or eight) node.sendReceive(...) returns with error -12.
[LoRaWAN] Constructing uplink
[LoRaWAN] Sending: 48.264775,14.441480,263.100000,2.890000
Error in sendReceive(-12)
Going back one commit and everything is fine!
Currently, I didn't have enough resources to debug this issue myself, thus I stay at 33ab117.
Originally posted by @VolkerChristian in #1284 (comment)
Please let me know what additional debug infos you will need to solve this issue. Where should I start?
It would be helpful if you could enable the BASIC and PROTOCOL debug flags and paste the output (including millisecond-timestamps) here! If it's just a few uplinks before the error, the whole cycle from join until then is nice, otherwise leave only like the last four or something (or since last downlink with MAC command).
It's a bit of a weird error here, -12, so I'm not sure if we can find out from the available output, but who knows.
OK, give me two or three days to produce the log.
FWIW I was not able to reproduce this issue with SX1262 in EU868, I'm at 60+ uplinks without problems. Since -12 is RADIOLIB_ERR_INVALID_FREQUENCY the primary question I have is which module are you using - but it should be visible in the logs, so I'll wait for those ;)
I use the SX1276. I will dive deeper into this problem today and will post the logs as soon as possible.
-12 is likely due to a 0.0MHz channel incorrectly being used, as a hint.
Here is the log containing the last working and the first failing uplink. @StevenCellist you are right it reports RLB_PRO: PHY: Frequency = 0.000 MHz, TX = 12 dBm
Setup
Wake from sleep
Boot count: 8
Initalise the radio
RLB_DBG:
RadioLib Info
Version: "7.0.2.0"
Platform: "ESP32"
Compiled: "Oct 27 2024" "10:12:58"
RLB_DBG: M SX127x
Recalling LoRaWAN nonces & session
RLB_PRO: LoRaWAN session: v1.1
RLB_PRO: Setting up dynamic channels
RLB_PRO: UL: 0 1 868.100 (0 - 5) | DL: 0 1 868.100 (0 - 5)
RLB_PRO: UL: 1 1 868.300 (0 - 5) | DL: 1 1 868.300 (0 - 5)
RLB_PRO: UL: 2 1 868.500 (0 - 5) | DL: 2 1 868.500 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 03 18 4f 84 50 ..O.P
RLB_PRO: UL: 3 1 867.100 (0 - 5) | DL: 3 1 867.100 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 04 e8 56 84 50 ..V.P
RLB_PRO: UL: 4 1 867.300 (0 - 5) | DL: 4 1 867.300 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 05 b8 5e 84 50 ..^.P
RLB_PRO: UL: 5 1 867.500 (0 - 5) | DL: 5 1 867.500 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 06 88 66 84 50 ..f.P
RLB_PRO: UL: 6 1 867.700 (0 - 5) | DL: 6 1 867.700 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 07 58 6e 84 50 .Xn.P
RLB_PRO: UL: 7 1 867.900 (0 - 5) | DL: 7 1 867.900 (0 - 5)
RLB_PRO: [MAC] 0x03
RLB_PRO: 00000000: 52 ff 00 00 00 00 00 00 00 00 00 00 00 01 R.............
RLB_PRO: LinkAdrReq: dataRate = 5, txSteps = 2, nbTrans = 1
RLB_PRO: UL: 0 1 868.100 (0 - 5) | DL: 0 1 868.100 (0 - 5)
RLB_PRO: UL: 1 1 868.300 (0 - 5) | DL: 1 1 868.300 (0 - 5)
RLB_PRO: UL: 2 1 868.500 (0 - 5) | DL: 2 1 868.500 (0 - 5)
RLB_PRO: UL: 3 1 867.100 (0 - 5) | DL: 3 1 867.100 (0 - 5)
RLB_PRO: UL: 4 1 867.300 (0 - 5) | DL: 4 1 867.300 (0 - 5)
RLB_PRO: UL: 5 1 867.500 (0 - 5) | DL: 5 1 867.500 (0 - 5)
RLB_PRO: UL: 6 1 867.700 (0 - 5) | DL: 6 1 867.700 (0 - 5)
RLB_PRO: UL: 7 1 867.900 (0 - 5) | DL: 7 1 867.900 (0 - 5)
RLB_PRO: LinkAdrAns: 07
RLB_PRO: [MAC] 0x04
RLB_PRO: 00000000: 07 .
RLB_PRO: DutyCycleReq: max duty cycle = 1/2^7
RLB_PRO: [MAC] 0x05
RLB_PRO: 00000000: 03 d2 ad 84 ....
RLB_PRO: RXParamSetupReq: Rx1DrOffset = 0, rx2DataRate = 3, freq = 869.525
RLB_PRO: [MAC] 0x08
RLB_PRO: 00000000: 05 .
RLB_PRO: RXTimingSetupReq: delay = 5 sec
RLB_PRO: [MAC] 0x09
RLB_PRO: 00000000: 00 .
RLB_PRO: [MAC] 0x0c
RLB_PRO: 00000000: 65 e
RLB_PRO: ADRParamSetupReq: limitExp = 6, delayExp = 5
RLB_PRO: [MAC] 0x0f
RLB_PRO: 00000000: fa .
RLB_PRO: RejoinParamSetupReq: maxTime = 15, maxCount = 10
Succesfully restored session - now activating
Aquire data
Checksum 1 = FB
Checksum 2 = 11
fullPacket is: B5, 62, 6, 1, 3, 0, F0, 1, 0, FB, 11,
Reading ACK response: Searching for UBX ACK response:
Target data packet: B5, 62, 5, 1, 2, 0, 6, 1, F, 38,
Candidate packet: B5, 62, 5, 1, 2, 0, 6, 1, F, 38, (Response received from GPS unit:)
ACK-ACK!
$GPRMC,093924.00,A,4815.88336,N,01426.48524,E,0.190,,271024,,,A*7F
$GPVTG,,T,,M,0.190,N,0.352,K,A*2F
$GPGGA,093924.00,4815.88336,N,01426.48524,E,1,06,1.34,245.9,M,43.8,M,,*5C
[GPS] ############### GPS ###############
[GPS] LAT = 48.264723
[GPS] LONG = 14.441421
[GPS] Date in UTC = 2024/10/27
[GPS] Time in UTC = 9:39:24
[GPS] Satellites = 6
[GPS] ALT (min) = 245.90
[GPS] SPEED (km/h) = 0.35
[GPS] COURSE = 0.00
[GPS] HDOP = 1.34
[GPS] -----------------------------------
[LoRaWAN] Constructing uplink
[LoRaWAN] Sending: 48.264723,14.441421,245.900000,1.340000
RLB_PRO: Uplink (FCntUp = 7) decoded:
RLB_PRO: 00000000: 6a 93 ef b2 0e 4c ae ed ea 61 49 83 c3 97 93 52 j....L...aI....R
RLB_PRO: 00000010: 40 05 68 0b 26 80 07 00 01 27 30 fa e2 c5 1c a4 @.h.&....'0.....
RLB_PRO: 00000020: 0f 33 1d 8f 0a 5b 57 1c f2 58 ad 18 98 02 10 09 .3...[W..X......
RLB_PRO: 00000030: fc f9 04 59 9a 92 8a 33 10 80 a0 24 ad 97 43 4b ...Y...3...$..CK
RLB_PRO: 00000040: 00 06 91 5c ...\
RLB_PRO:
RLB_PRO: PHY: Frequency = 868.100 MHz, TX = 12 dBm
RLB_PRO: LoRa: SF = 7, BW = 125.0 kHz, CR = 4/5, IQ: U
RLB_DBG: Timeout in 154 ms
RLB_PRO: Uplink sent <-- Rx Delay start
RLB_PRO:
RLB_PRO: PHY: Frequency = 868.100 MHz, TX = 12 dBm
RLB_PRO: LoRa: SF = 7, BW = 125.0 kHz, CR = 4/5, IQ: D
RLB_PRO: Opening Rx1 window (51 ms timeout)... <-- Rx Delay end
RLB_PRO: Closing Rx1 window
RLB_PRO:
RLB_PRO: PHY: Frequency = 869.525 MHz, TX = 12 dBm
RLB_PRO: LoRa: SF = 9, BW = 125.0 kHz, CR = 4/5, IQ: D
RLB_PRO: Opening Rx2 window (129 ms timeout)... <-- Rx Delay end
RLB_PRO: Closing Rx2 window
[LoRaWAN] No downlink received
[LoRaWAN] Set sleep: SUCCESS
Sleeping
Setup
Wake from sleep
Boot count: 9
Initalise the radio
RLB_DBG:
RadioLib Info
Version: "7.0.2.0"
Platform: "ESP32"
Compiled: "Oct 27 2024" "10:12:58"
RLB_DBG: M SX127x
Recalling LoRaWAN nonces & session
RLB_PRO: LoRaWAN session: v1.1
RLB_PRO: Setting up dynamic channels
RLB_PRO: UL: 0 1 868.100 (0 - 5) | DL: 0 1 868.100 (0 - 5)
RLB_PRO: UL: 1 1 868.300 (0 - 5) | DL: 1 1 868.300 (0 - 5)
RLB_PRO: UL: 2 1 868.500 (0 - 5) | DL: 2 1 868.500 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 03 18 4f 84 50 ..O.P
RLB_PRO: UL: 3 1 867.100 (0 - 5) | DL: 3 1 867.100 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 04 e8 56 84 50 ..V.P
RLB_PRO: UL: 4 1 867.300 (0 - 5) | DL: 4 1 867.300 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 05 b8 5e 84 50 ..^.P
RLB_PRO: UL: 5 1 867.500 (0 - 5) | DL: 5 1 867.500 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 06 88 66 84 50 ..f.P
RLB_PRO: UL: 6 1 867.700 (0 - 5) | DL: 6 1 867.700 (0 - 5)
RLB_PRO: [MAC] 0x07
RLB_PRO: 00000000: 07 58 6e 84 50 .Xn.P
RLB_PRO: UL: 7 1 867.900 (0 - 5) | DL: 7 1 867.900 (0 - 5)
RLB_PRO: [MAC] 0x03
RLB_PRO: 00000000: 52 00 00 00 00 00 00 00 00 00 00 00 00 01 R.............
RLB_PRO: LinkAdrReq: dataRate = 5, txSteps = 2, nbTrans = 1
RLB_PRO: ADR: no channels available for datarate 5
RLB_PRO: LinkAdrAns: 05
RLB_PRO: [MAC] 0x04
RLB_PRO: 00000000: 07 .
RLB_PRO: DutyCycleReq: max duty cycle = 1/2^7
RLB_PRO: [MAC] 0x05
RLB_PRO: 00000000: 03 d2 ad 84 ....
RLB_PRO: RXParamSetupReq: Rx1DrOffset = 0, rx2DataRate = 3, freq = 869.525
RLB_PRO: [MAC] 0x08
RLB_PRO: 00000000: 05 .
RLB_PRO: RXTimingSetupReq: delay = 5 sec
RLB_PRO: [MAC] 0x09
RLB_PRO: 00000000: 00 .
RLB_PRO: [MAC] 0x0c
RLB_PRO: 00000000: 65 e
RLB_PRO: ADRParamSetupReq: limitExp = 6, delayExp = 5
RLB_PRO: [MAC] 0x0f
RLB_PRO: 00000000: fa .
RLB_PRO: RejoinParamSetupReq: maxTime = 15, maxCount = 10
Succesfully restored session - now activating
Aquire data
Checksum 1 = FB
Checksum 2 = 11
fullPacket is: B5, 62, 6, 1, 3, 0, F0, 1, 0, FB, 11,
Reading ACK response: Searching for UBX ACK response:
Target data packet: B5, 62, 5, 1, 2, 0, 6, 1, F, 38,
Candidate packet: B5, 62, 5, 1, 2, 0, 6, 1, F, 38, (Response received from GPS unit:)
ACK-ACK!
$GPRMC,094033.00,A,4815.88290,N,01426.48342,E,0.297,,271024,,,A*78
$GPVTG,,T,,M,0.297,N,0.550,K,A*2F
$GPGGA,094033.00,4815.88290,N,01426.48342,E,1,06,1.35,273.9,M,43.8,M,,*5B
[GPS] ############### GPS ###############
[GPS] LAT = 48.264715
[GPS] LONG = 14.441390
[GPS] Date in UTC = 2024/10/27
[GPS] Time in UTC = 9:40:33
[GPS] Satellites = 6
[GPS] ALT (min) = 273.90
[GPS] SPEED (km/h) = 0.54
[GPS] COURSE = 0.00
[GPS] HDOP = 1.35
[GPS] -----------------------------------
[LoRaWAN] Constructing uplink
[LoRaWAN] Sending: 48.264715,14.441390,273.900000,1.350000
RLB_PRO: Uplink (FCntUp = 8) decoded:
RLB_PRO: 00000000: 6a 93 ef 92 0e 4c af ec ea e3 49 83 c3 87 92 52 j....L....I....R
RLB_PRO: 00000010: 40 05 68 0b 26 80 08 00 01 5e 38 32 36 79 d9 2c @.h.&....^826y.,
RLB_PRO: 00000020: 0c 8d 62 c6 6b 94 dc d9 3a 7e 93 f4 45 58 dd 6a ..b.k...:~..EX.j
RLB_PRO: 00000030: 00 b4 b8 40 e1 21 53 84 c6 c8 ae f1 0b ba dd 17 ...@.!S.........
RLB_PRO: 00000040: 20 06 93 5c ..\
RLB_PRO:
RLB_PRO: PHY: Frequency = 0.000 MHz, TX = 12 dBm
Error in sendReceive(-12)
[LoRaWAN] No downlink received
[LoRaWAN] Set sleep: SUCCESS
Sleeping
Something happened here:
(first uplink)
RLB_PRO: [MAC] 0x03
RLB_PRO: 00000000: 52 ff 00 00 00 00 00 00 00 00 00 00 00 01
(second uplink):
RLB_PRO: [MAC] 0x03
RLB_PRO: 00000000: 52 00 00 00 00 00 00 00 00 00 00 00 00 01
Which is pretty weird to occur randomly. I'll see if I can trace the origin for this bug. Can you meanwhile share your full code?
https://github.com/PCo-IoT-2024/platform.io/tree/main/LoRaWAN-HelloWorld-radiolib
It is in "draft" state so it is a little bit messy ...
In case you are curious what we want to do with LoRaWAN ...
I have been able to reproduce this now.
This problem only occurred when using persistence, which took some time to figure out (and is the reason @jgromes didn't encounter it). The bug has been fixed and tested on both EU868 and US915.
Just for the sake of completeness: I can confirm that this issue is fixed!
Thank you!