Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Commit solving #1284 introduces a failure in EU868 #1293

Closed
VolkerChristian opened this issue Oct 25, 2024 · 13 comments
Closed

Commit solving #1284 introduces a failure in EU868 #1293

VolkerChristian opened this issue Oct 25, 2024 · 13 comments
Assignees
@StevenCellist
Labels
bug Something isn't working resolved Issue was resolved (e.g. bug fixed, or feature implemented)

Comments

@VolkerChristian
Copy link
Contributor

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)
@StevenCellist StevenCellist self-assigned this Oct 25, 2024
@StevenCellist StevenCellist added the more information needed Further investigation is needed, not necessarily by the author label Oct 25, 2024
@VolkerChristian
Copy link
Contributor Author

Please let me know what additional debug infos you will need to solve this issue. Where should I start?

@StevenCellist
Copy link
Collaborator

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.

@VolkerChristian
Copy link
Contributor Author

OK, give me two or three days to produce the log.

@jgromes
Copy link
Owner

jgromes commented Oct 27, 2024 •
edited
Loading

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 ;)

@VolkerChristian
Copy link
Contributor Author

I use the SX1276. I will dive deeper into this problem today and will post the logs as soon as possible.

@StevenCellist
Copy link
Collaborator

-12 is likely due to a 0.0MHz channel incorrectly being used, as a hint.

@VolkerChristian
Copy link
Contributor Author

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

@StevenCellist
Copy link
Collaborator

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?

@VolkerChristian
Copy link
Contributor Author

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 ...

@VolkerChristian
Copy link
Contributor Author

In case you are curious what we want to do with LoRaWAN ...

Globale Acting in IT

@StevenCellist
Copy link
Collaborator

I have been able to reproduce this now.

@StevenCellist StevenCellist added bug Something isn't working and removed more information needed Further investigation is needed, not necessarily by the author labels Oct 28, 2024
@StevenCellist
Copy link
Collaborator

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.

@VolkerChristian
Copy link
Contributor Author

Just for the sake of completeness: I can confirm that this issue is fixed!

Thank you!

@jgromes jgromes added the resolved Issue was resolved (e.g. bug fixed, or feature implemented) label Oct 28, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@StevenCellist StevenCellist

Labels
bug Something isn't working resolved Issue was resolved (e.g. bug fixed, or feature implemented)
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jgromes @VolkerChristian @StevenCellist