Bump to RadioLib 7.0 #106

StevenCellist · 2024-09-17T13:37:41Z

Hi @matthias-bs, just opening this so you are aware of the update to RadioLib 7.0 with some breaking changes. Most notably, uplink() and downlink() are now replaced by a single sendReceive() which may return a positive value when downlink is received or 0 when no downlink is received. Also, some of the return code names have been updated. There are a few more changes - I suggest taking another look at the examples provided in RadioLib (as well as the README in examples/LoRaWAN - v1.0.4 is now also officially supported).
Feel free to close this at any moment, just a heads-up.

The text was updated successfully, but these errors were encountered:

matthias-bs · 2024-09-17T16:46:02Z

Hi @StevenCellist, thanks a lot for your notification and the helpful hints - and of course for putting so much effort and knowledge into the LoRaWAN part of RadioLib!

matthias-bs · 2024-09-23T17:37:38Z

Didn't manage to update to RadioLib v7.0.0 yet. Currently, I get strange errors like [config.h:403] debug(): Error in sendReceive - See TypeDef.h (-25).
Eagerly awaiting the update of radiolib-org/radiolib-persistence...

StevenCellist · 2024-09-23T17:47:30Z

Do you have more information on this problem? (E.g. using debug protocol flag.) There has been no change to the persistence side, except for some rearranging of the internal buffer size & structure.

matthias-bs · 2024-09-24T05:53:11Z

@StevenCellist Thanks for offering help and the information that no changes have been made regarding persistence handling.

I enabled protocol output, erased the Flash (again) to clear the Preferences, flashed the sketch, flashed my secrets.json (LoRaWAN credentials) - and it worked! (17 uplink frames without any errors)

I have no idea what was wrong before, but I suspect that the Preferences had not been cleared properly.

matthias-bs · 2024-09-24T06:04:10Z

@StevenCellist No, unfortunately the problem has not been solved.

Logfile:
devttyUSB0_2024_09_24.07.53.34.280.txt

Source code:
matthias-bs/BresserWeatherSensorLW/tree/20240922-bump-radiolib7.0

StevenCellist · 2024-09-24T06:15:46Z

From the log:

RLB_PRO: ADR: no channels available for datarate 2

Is your radio asleep maybe? The channels are definitely available, so that is quite weird.

StevenCellist · 2024-09-24T06:17:14Z

Hmmm I have a suspicion. I hope to have a look soon.

StevenCellist · 2024-09-24T06:20:18Z

As I don't have the time to scan your full project: do you have ADR enabled? I expect it is disabled, right?

matthias-bs · 2024-09-24T16:15:58Z

I don't call node.setADR() in the sketch, so ADR should be enabled (according to the example), right?

matthias-bs · 2024-09-24T16:23:47Z

From the log:

RLB_PRO: ADR: no channels available for datarate 2

Is your radio asleep maybe? The channels are definitely available, so that is quite weird.

I don't think so - I don't put it into sleep mode between radio.begin() and putting the ESP32 into sleep mode.

StevenCellist · 2024-09-24T16:33:48Z

The problem at hand is that the channel mask is either not stored correctly before going into deepsleep, or not being restored corrected after coming back from deepsleep. As you can see, the command is full of 00:

RLB_PRO: 00000000: 20 00 00 00 00 00 00 00 00 00 00 00 00 00

It should be either
RLB_PRO: 00000000: 20
or
RLB_PRO: 00000000: 20 ff 00 00 00 00 00 00 00 00 00 00 00 01

With the conference tomorrow I don't have time to investigate now; I have verified that session restore works just before the release so this is a bit weird. But may be a bug after all.

matthias-bs · 2024-09-24T16:48:55Z

Would it be helpful if I put some debug printing of the channel mask into getBufferSession() / setBufferSession()?

StevenCellist · 2024-09-24T16:52:56Z

Yes, as well as the memcpy into the bufferSession in execMacCommand for MAC_LINK_ADR.

matthias-bs · 2024-09-24T18:25:46Z

Could this (the template type in ntoh() / hton()) be a problem?

In setBufferSession():

uint16_t chMask = LoRaWANNode::ntoh<uint32_t>(&this->bufferSession[RADIOLIB_LORAWAN_SESSION_AVAILABLE_CHANNELS]);

In getBufferSession():

uint16_t chMask = 0x0000;
(void)this->getAvailableChannels(&chMask);
  LoRaWANNode::hton<uint16_t>(&this->bufferSession[RADIOLIB_LORAWAN_SESSION_AVAILABLE_CHANNELS], chMask);

StevenCellist · 2024-09-24T18:37:20Z

That's an interesting typo, but this chMask is not the thing we're looking for here - we're looking for a 12-byte (uint64 + uint32) complete channel mask. I see the naming scheme is quite confusing.
(This channel mask tells which channels have recently been used so it doesn't reuse the same over and over randomly.)

matthias-bs · 2024-09-24T19:15:05Z

I don't understand this entirely, but I'd say that this data is not stored in getBufferSession().
In setBufferSession(), there seems to be the code starting at https://github.com/jgromes/RadioLib/blob/ec6de3795b1269eb051f60ae2174031048366b89/src/protocols/LoRaWAN/LoRaWAN.cpp#L517 for restoring.

StevenCellist · 2024-09-24T19:45:26Z

MAC commands are stored in-progress in execMacCommands, line 1964 for ADR.

matthias-bs · 2024-09-25T06:41:19Z

MAC commands are stored in-progress in execMacCommands, line 1964 for ADR.

I hope this is correct:

      [...]
      // only apply channel mask if present (internal Dr/Tx commands do not set channel mask)
      if(lenIn > 1) {
        uint64_t macChMaskGrp0123 = LoRaWANNode::ntoh<uint64_t>(&optIn[1]);
        uint32_t macChMaskGrp45 = LoRaWANNode::ntoh<uint32_t>(&optIn[9]);
        RADIOLIB_DEBUG_PROTOCOL_PRINTLN("execMacCommand(): chMask0123=0x%08X%08X", macChMaskGrp0123 >> 32, macChMaskGrp0123 & 0xFFFFFFFF);
        RADIOLIB_DEBUG_PROTOCOL_PRINTLN("execMacCommand(): chMask45=0x%04X", macChMaskGrp45);
        // apply requested channel mask and enable all of them for testing datarate
        chMaskAck = this->applyChannelMask(macChMaskGrp0123, macChMaskGrp45);
      } else {
        chMaskAck = true;
      }
      [...]

      [...]
      RADIOLIB_DEBUG_PROTOCOL_PRINTLN("chMask0123, chMask45:");
      RADIOLIB_DEBUG_PROTOCOL_HEXDUMP(&optIn[1], 12);
      memcpy(&this->bufferSession[RADIOLIB_LORAWAN_SESSION_LINK_ADR], optIn, lenIn);
      [...][...]

matthias-bs · 2024-09-25T06:42:00Z

Here is a new logfile:
devttyUSB0_2024_09_25.07.48.32.193.txt

matthias-bs · 2024-09-25T09:57:43Z

See also: radiolib-org/radiolib-persistence#6

StevenCellist · 2024-09-25T17:42:02Z

In your latest logfile, all uplinks succeed and there is no error at all. So that is interesting...?

matthias-bs · 2024-09-25T19:30:07Z

08:36:01:010 -> RLB_PRO: PHY: Frequency UL = 0.000 MHz seemed suspicious to me.
I'll try to provide a better sample.

StevenCellist · 2024-09-25T19:39:01Z

I agree that that is weird, but that is not a problem at that point in the code (yeah I know, not clear to a user).

matthias-bs · 2024-09-25T19:47:47Z

Here we go:

21:26:03:579 -> [ 31235][W][config.h:403] debug(): Restoring session buffer failed - RADIOLIB_ERR_NETWORK_NOT_JOINED (-1101)
21:26:03:587 -> [ 31244][D][BresserWeatherSensorLW.ino:434] lwActivate(): Join ('login') to the LoRaWAN Network
21:26:03:596 -> RLB_PRO: Setting up dynamic channels
21:26:03:598 -> RLB_PRO: UL:   0 1 868.100 (0 - 5) | DL:   0 1 868.100 (0 - 5)
21:26:03:604 -> RLB_PRO: UL:   1 1 868.300 (0 - 5) | DL:   1 1 868.300 (0 - 5)
21:26:03:609 -> RLB_PRO: UL:   2 1 868.500 (0 - 5) | DL:   2 1 868.500 (0 - 5)
21:26:03:615 -> RLB_PRO: [MAC] 0x03
21:26:03:618 -> RLB_PRO: 00000000: 20                                                                 
21:26:03:623 -> RLB_PRO: LinkAdrReq: dataRate = 2, txSteps = 0, nbTrans = 0
21:26:03:629 -> RLB_PRO: LinkAdrAns: 07
21:26:03:631 -> RLB_PRO: chMask0123, chMask45:
21:26:03:634 -> RLB_PRO: 00000000: a3 07 40 3f 20 00 00 00 e4 3a fc 3f              ..@? ....:.?      
21:26:03:642 -> RLB_PRO: [MAC] 0x04
21:26:03:642 -> RLB_PRO: 00000000: 07                                               .                 
21:26:03:651 -> RLB_PRO: DutyCycleReq: max duty cycle = 1/2^7
21:26:03:653 -> RLB_PRO: [MAC] 0x05
21:26:03:656 -> RLB_PRO: 00000000: 00 d2 ad 84                                      ....              
21:26:03:664 -> RLB_PRO: RXParamSetupReq: Rx1DrOffset = 0, rx2DataRate = 0, freq = 869.525
21:26:03:670 -> RLB_PRO: [MAC] 0x08
21:26:03:673 -> RLB_PRO: 00000000: 01                                               .                 
21:26:03:681 -> RLB_PRO: RXTimingSetupReq: delay = 1 sec
21:26:03:684 -> RLB_PRO: [MAC] 0x09
21:26:03:684 -> RLB_PRO: 00000000: 05                                               .                 
21:26:03:692 -> RLB_PRO: [MAC] 0x0c
21:26:03:696 -> RLB_PRO: 00000000: 65                                               e                 
21:26:03:701 -> RLB_PRO: ADRParamSetupReq: limitExp = 6, delayExp = 5
21:26:03:706 -> RLB_PRO: [MAC] 0x0f
21:26:03:709 -> RLB_PRO: 00000000: fa                                               .                 
21:26:03:718 -> RLB_PRO: RejoinParamSetupReq: maxTime = 15, maxCount = 10
21:26:03:760 -> RLB_PRO: 
21:26:03:760 -> RLB_PRO: PHY:  Frequency UL = 868.300 MHz
21:26:03:763 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:26:04:141 -> RLB_PRO: JoinRequest sent (DevNonce = 20) <-- Rx Delay start
21:26:04:143 -> RLB_PRO: 00000000: 00 00 00 00 00 00 00 00 00 41 c9 11 00 00 b6 76  .........A.....v
21:26:04:152 -> RLB_PRO: 00000010: 98 14 00 19 22 3d f9                             ...."=.           
21:26:04:160 -> RLB_PRO: 
21:26:04:160 -> RLB_PRO: PHY:  Frequency DL = 868.300 MHz
21:26:04:170 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:26:09:132 -> RLB_PRO: Opening Rx1 window (232 ms timeout)... <-- Rx Delay end 
21:26:09:366 -> RLB_PRO: Closing Rx1 window
21:26:09:600 -> RLB_PRO: JoinAccept (JoinNonce = 10306, previously 10305):
21:26:09:603 -> RLB_PRO: 00000000: 20 42 28 00 13 00 00 44 ae 0b 26 83 05 18 4f 84   B(....D..&...O.
21:26:09:611 -> RLB_PRO: 00000010: e8 56 84 b8 5e 84 88 66 84 58 6e 84 00 2a 46 48  .V..^..f.Xn..*FH
21:26:09:620 -> RLB_PRO: 00000020: 82                                               .                 
21:26:09:625 -> RLB_PRO: LoRaWAN revision: 1.1
21:26:09:628 -> RLB_PRO: Setting up dynamic channels
21:26:09:633 -> RLB_PRO: UL:   0 1 868.100 (0 - 5) | DL:   0 1 868.100 (0 - 5)
21:26:09:636 -> RLB_PRO: UL:   1 1 868.300 (0 - 5) | DL:   1 1 868.300 (0 - 5)
21:26:09:642 -> RLB_PRO: UL:   2 1 868.500 (0 - 5) | DL:   2 1 868.500 (0 - 5)
21:26:09:647 -> RLB_PRO: [MAC] 0x05
21:26:09:650 -> RLB_PRO: 00000000: 03 d2 ad 84                                      ....              
21:26:09:658 -> RLB_PRO: RXParamSetupReq: Rx1DrOffset = 0, rx2DataRate = 3, freq = 869.525
21:26:09:663 -> RLB_PRO: [MAC] 0x08
21:26:09:666 -> RLB_PRO: 00000000: 05                                               .                 
21:26:09:672 -> RLB_PRO: RXTimingSetupReq: delay = 5 sec
21:26:09:677 -> RLB_PRO: Processing CFList
21:26:09:680 -> RLB_PRO: [MAC] 0x07
21:26:09:680 -> RLB_PRO: 00000000: 03 18 4f 84 50                                   ..O.P             
21:26:09:688 -> RLB_PRO: UL:   3 1 867.100 (0 - 5) | DL:   3 1 867.100 (0 - 5)
21:26:09:694 -> RLB_PRO: [MAC] 0x07
21:26:09:697 -> RLB_PRO: 00000000: 04 e8 56 84 50                                   ..V.P             
21:26:09:702 -> RLB_PRO: UL:   4 1 867.300 (0 - 5) | DL:   4 1 867.300 (0 - 5)
21:26:09:708 -> RLB_PRO: [MAC] 0x07
21:26:09:711 -> RLB_PRO: 00000000: 05 b8 5e 84 50                                   ..^.P             
21:26:09:719 -> RLB_PRO: UL:   5 1 867.500 (0 - 5) | DL:   5 1 867.500 (0 - 5)
21:26:09:724 -> RLB_PRO: [MAC] 0x07
21:26:09:724 -> RLB_PRO: 00000000: 06 88 66 84 50                                   ..f.P             
21:26:09:733 -> RLB_PRO: UL:   6 1 867.700 (0 - 5) | DL:   6 1 867.700 (0 - 5)
21:26:09:738 -> RLB_PRO: [MAC] 0x07
21:26:09:738 -> RLB_PRO: 00000000: 07 58 6e 84 50                                   .Xn.P             
21:26:09:746 -> RLB_PRO: UL:   7 1 867.900 (0 - 5) | DL:   7 1 867.900 (0 - 5)
21:26:09:752 -> [ 37406][D][BresserWeatherSensorLW.ino:438] lwActivate(): Saving nonces to flash
21:26:09:768 -> [ 37425][D][BresserWeatherSensorLW.ino:463] lwActivate(): Joined
21:26:10:774 -> [ 38430][D][BresserWeatherSensorLW.ino:627] setup(): Battery level: 0
21:26:10:780 -> [ 38437][I][BresserWeatherSensorLW.ino:633] setup(): RTC sync required
21:26:10:786 -> RLB_PRO: 
21:26:10:786 -> RLB_PRO: PHY:  Frequency UL = 868.300 MHz
21:26:10:793 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:26:10:799 -> [ 38451][D][BresserWeatherSensorLW.ino:646] setup(): Max payload length: 56
21:26:10:804 -> [ 38461][D][BresserWeatherSensorLW.ino:673] setup(): FcntUp: 0
21:26:10:810 -> [ 38467][I][BresserWeatherSensorLW.ino:691] setup(): App status uplink pending
21:26:10:815 -> [ 38474][I][BresserWeatherSensorLW.ino:698] setup(): LoRaWAN node status uplink pending
21:26:10:823 -> [ 38482][I][BresserWeatherSensorLW.ino:722] setup(): Sending uplink; port 1, size 47
21:26:10:833 -> RLB_PRO: Uplink MAC payload:
21:26:10:835 -> RLB_PRO: 00000000: 0b 01 0d                                         ...               
21:26:10:879 -> RLB_PRO: Uplink (FCntUp = 0) decoded:
21:26:10:882 -> RLB_PRO: 00000000: 5b 20 33 38 34 38 32 5d 5b 49 5d 5b 42 72 65 73  [ 38482][I][Bres
21:26:10:888 -> RLB_PRO: 00000010: 40 44 ae 0b 26 83 00 00 2c b5 9d 01 a2 18 f9 8b  @D..&...,.......
21:26:10:896 -> RLB_PRO: 00000020: 6e 1c e4 92 3b ad 2f 81 f0 df f5 0b 48 67 49 39  n...;./.....HgI9
21:26:10:904 -> RLB_PRO: 00000030: fc 0c 92 85 e7 52 c3 3b 3d 3a f0 c0 f6 88 12 5a  .....R.;=:.....Z
21:26:10:911 -> RLB_PRO: 00000040: 0b e5 32 28 df 48 b0 72 aa e9 c0 2c 20 73 69     ..2(.H.r..., si   
21:26:10:918 -> RLB_PRO: 
21:26:10:918 -> RLB_PRO: PHY:  Frequency UL = 867.100 MHz
21:26:10:923 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:26:11:625 -> RLB_PRO: Uplink sent <-- Rx Delay start
21:26:11:627 -> RLB_PRO: 
21:26:11:627 -> RLB_PRO: PHY:  Frequency DL = 867.100 MHz
21:26:11:630 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:26:16:618 -> RLB_PRO: Opening Rx1 window (232 ms timeout)... <-- Rx Delay end 
21:26:16:851 -> RLB_PRO: Closing Rx1 window
21:26:17:003 -> RLB_PRO: Downlink (NFCntDown = 0) encoded:
21:26:17:005 -> RLB_PRO: 00000000: 49 00 00 00 00 01 44 ae 0b 26 00 00 00 00 00 10  I.....D..&......
21:26:17:014 -> RLB_PRO: 00000010: 60 44 ae 0b 26 88 00 00 57 94 1c 5a 7e 61 79 36  `D..&...W..Z~ay6
21:26:17:019 -> RLB_PRO: 00000020: 45 68 63 25                                      Ehc%              
21:26:17:028 -> RLB_PRO: [MAC] 0x0b
21:26:17:030 -> RLB_PRO: 00000000: 01                                               .                 
21:26:17:036 -> RLB_PRO: RekeyConf: server version = 1.1
21:26:17:042 -> RLB_PRO: [MAC] 0x0d
21:26:17:042 -> RLB_PRO: 00000000: 66 26 1f 54 65                                   f&.Te             
21:26:17:049 -> RLB_PRO: DeviceTimeAns: [user]
21:26:17:052 -> [ 44701][D][BresserWeatherSensorLW.ino:754] setup(): <MAC commands only>
21:26:17:058 -> [ 44716][D][BresserWeatherSensorLW.ino:758] setup(): [LoRaWAN] RSSI:            -137.750000 dBm
21:26:17:067 -> [ 44724][D][BresserWeatherSensorLW.ino:761] setup(): [LoRaWAN] SNR:             -9.750000 dB
21:26:17:073 -> [ 44731][D][BresserWeatherSensorLW.ino:764] setup(): [LoRaWAN] Frequency error: 5388.631836 Hz
21:26:17:081 -> [ 44740][D][BresserWeatherSensorLW.ino:767] setup(): [LoRaWAN] Event information:
21:26:17:090 -> [ 44748][D][BresserWeatherSensorLW.ino:768] setup(): [LoRaWAN] Confirmed:       0
21:26:17:095 -> [ 44754][D][BresserWeatherSensorLW.ino:769] setup(): [LoRaWAN] Confirming:      0
21:26:17:104 -> [ 44761][D][BresserWeatherSensorLW.ino:770] setup(): [LoRaWAN] Datarate:        2
21:26:17:109 -> [ 44768][D][BresserWeatherSensorLW.ino:771] setup(): [LoRaWAN] Frequency:       867.100 MHz
21:26:17:118 -> [ 44775][D][BresserWeatherSensorLW.ino:772] setup(): [LoRaWAN] Output power:    16 dBm
21:26:17:126 -> [ 44783][D][BresserWeatherSensorLW.ino:773] setup(): [LoRaWAN] Frame count:     0
21:26:17:132 -> [ 44790][D][BresserWeatherSensorLW.ino:774] setup(): [LoRaWAN] fPort:           0
21:26:17:137 -> [ 44796][D][BresserWeatherSensorLW.ino:775] setup(): [LoRaWAN] Time-on-air:     699 ms
21:26:17:146 -> [ 44804][D][BresserWeatherSensorLW.ino:776] setup(): [LoRaWAN] Rx window: 1
21:26:17:151 -> [ 44810][D][BresserWeatherSensorLW.ino:673] setup(): FcntUp: 0
21:26:17:157 -> [ 44816][I][BresserWeatherSensorLW.ino:691] setup(): App status uplink pending
21:26:17:165 -> [ 44823][I][BresserWeatherSensorLW.ino:698] setup(): LoRaWAN node status uplink pending
21:26:17:174 -> [ 44831][D][BresserWeatherSensorLW.ino:709] setup(): Sending LoRaWAN status uplink.
21:26:17:179 -> [ 44838][D][BresserWeatherSensorLWCmd.cpp:169] encodeCfgUplink(): --- Uplink Configuration/Status ---
21:26:17:191 -> [ 44848][D][adc.cpp:76] getVoltage(): Voltage = 4190mV
21:26:17:194 -> [ 44847][D][BresserWeatherSensorLWCmd.cpp:201] encodeCfgUplink(): Device Status: U_batt=4190 mV, longSleep=0
21:26:17:206 -> [ 44863][D][adc.cpp:76] getVoltage(): Voltage = 4208mV
21:26:17:214 -> [ 44868][D][BresserWeatherSensorLWCmd.cpp:299] encodeCfgUplink(): Configuration uplink: port=56, size=3
21:26:17:221 -> 70 10 00 
21:26:17:221 -> [ 44877][D][BresserWeatherSensorLWCmd.cpp:312] encodeCfgUplink(): Sending uplink in 300 s
21:31:15:186 -> [344886][I][BresserWeatherSensorLW.ino:722] setup(): Sending uplink; port 56, size 3
21:31:15:237 -> RLB_PRO: Uplink (FCntUp = 1) decoded:
21:31:15:240 -> RLB_PRO: 00000000: b0 9a 42 3f 00 00 00 00 00 00 00 00 94 da fb 3f  ..B?...........?
21:31:15:248 -> RLB_PRO: 00000010: 40 44 ae 0b 26 80 01 00 38 51 e5 c4 64 80 fc 3f  @D..&...8Q..d..?
21:31:15:254 -> RLB_PRO: 
21:31:15:254 -> RLB_PRO: PHY:  Frequency UL = 868.500 MHz
21:31:15:259 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:31:15:591 -> RLB_PRO: Uplink sent <-- Rx Delay start
21:31:15:593 -> RLB_PRO: 
21:31:15:593 -> RLB_PRO: PHY:  Frequency DL = 868.500 MHz
21:31:15:596 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:31:20:584 -> RLB_PRO: Opening Rx1 window (232 ms timeout)... <-- Rx Delay end 
21:31:20:815 -> RLB_PRO: Closing Rx1 window
21:31:20:815 -> RLB_PRO: 
21:31:20:818 -> RLB_PRO: PHY:  Frequency DL = 869.525 MHz
21:31:20:821 -> RLB_PRO: LoRa: SF = 9, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:31:21:583 -> RLB_PRO: Opening Rx2 window (129 ms timeout)... <-- Rx Delay end 
21:31:21:712 -> RLB_PRO: Closing Rx2 window
21:31:21:712 -> [351414][D][BresserWeatherSensorLW.ino:673] setup(): FcntUp: 1
21:31:21:718 -> [351421][D][BresserWeatherSensorLW.ino:716] setup(): Sending application status uplink.
21:31:21:726 -> [351429][D][BresserWeatherSensorLWCmd.cpp:169] encodeCfgUplink(): --- Uplink Configuration/Status ---
21:31:21:735 -> [351438][D][BresserWeatherSensorLWCmd.cpp:299] encodeCfgUplink(): Configuration uplink: port=66, size=26
21:31:21:747 -> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 
21:31:21:751 -> [351449][D][BresserWeatherSensorLWCmd.cpp:312] encodeCfgUplink(): Sending uplink in 300 s
21:36:20:928 -> [651463][I][BresserWeatherSensorLW.ino:722] setup(): Sending uplink; port 66, size 26
21:36:20:980 -> RLB_PRO: Uplink (FCntUp = 2) decoded:
21:36:20:983 -> RLB_PRO: 00000000: 5b 36 35 31 34 36 33 5d 5b 49 5d 5b 42 72 65 73  [651463][I][Bres
21:36:20:988 -> RLB_PRO: 00000010: 40 44 ae 0b 26 80 02 00 42 1d 8e 40 2d 6f 4d a2  @D..&...B..@-oM.
21:36:20:997 -> RLB_PRO: 00000020: 47 d1 a1 42 58 2a 50 ef 60 e5 b0 1e 71 04 18 56  G..BX*P.`...q..V
21:36:21:005 -> RLB_PRO: 00000030: 12 6b 53 3a 20 53 65                             .kS: Se           
21:36:21:016 -> RLB_PRO: 
21:36:21:016 -> RLB_PRO: PHY:  Frequency UL = 867.900 MHz
21:36:21:019 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:36:21:520 -> RLB_PRO: Uplink sent <-- Rx Delay start
21:36:21:523 -> RLB_PRO: 
21:36:21:523 -> RLB_PRO: PHY:  Frequency DL = 867.900 MHz
21:36:21:525 -> RLB_PRO: LoRa: SF = 10, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:36:26:513 -> RLB_PRO: Opening Rx1 window (232 ms timeout)... <-- Rx Delay end 
21:36:26:744 -> RLB_PRO: Closing Rx1 window
21:36:26:744 -> RLB_PRO: 
21:36:26:748 -> RLB_PRO: PHY:  Frequency DL = 869.525 MHz
21:36:26:750 -> RLB_PRO: LoRa: SF = 9, TX = 16 dBm, BW = 125.0 kHz, CR = 4/5
21:36:27:512 -> RLB_PRO: Opening Rx2 window (129 ms timeout)... <-- Rx Delay end 
21:36:27:641 -> RLB_PRO: Closing Rx2 window
21:36:27:641 -> RLB_PRO: getBufferSession(): chMask=0x0073
21:36:27:647 -> [658177][D][adc.cpp:76] getVoltage(): Voltage = 4217mV
21:36:27:650 -> [658187][I][BresserWeatherSensorLW.ino:321] gotoSleep(): Sleeping for 360 s
[...]
21:42:42:876 -> [ 18142][D][BresserWeatherSensorLW.ino:394] lwActivate(): Recalling LoRaWAN nonces & session
21:42:42:886 -> RLB_PRO: LoRaWAN session: v1.1
21:42:42:886 -> RLB_PRO: Setting up dynamic channels
21:42:42:891 -> RLB_PRO: UL:   0 1 868.100 (0 - 5) | DL:   0 1 868.100 (0 - 5)
21:42:42:897 -> RLB_PRO: UL:   1 1 868.300 (0 - 5) | DL:   1 1 868.300 (0 - 5)
21:42:42:902 -> RLB_PRO: UL:   2 1 868.500 (0 - 5) | DL:   2 1 868.500 (0 - 5)
21:42:42:908 -> RLB_PRO: [MAC] 0x07
21:42:42:908 -> RLB_PRO: 00000000: 03 18 4f 84 50                                   ..O.P             
21:42:42:916 -> RLB_PRO: UL:   3 1 867.100 (0 - 5) | DL:   3 1 867.100 (0 - 5)
21:42:42:922 -> RLB_PRO: [MAC] 0x07
21:42:42:922 -> RLB_PRO: 00000000: 04 e8 56 84 50                                   ..V.P             
21:42:42:930 -> RLB_PRO: UL:   4 1 867.300 (0 - 5) | DL:   4 1 867.300 (0 - 5)
21:42:42:935 -> RLB_PRO: [MAC] 0x07
21:42:42:939 -> RLB_PRO: 00000000: 05 b8 5e 84 50                                   ..^.P             
21:42:42:946 -> RLB_PRO: UL:   5 1 867.500 (0 - 5) | DL:   5 1 867.500 (0 - 5)
21:42:42:949 -> RLB_PRO: [MAC] 0x07
21:42:42:952 -> RLB_PRO: 00000000: 06 88 66 84 50                                   ..f.P             
21:42:42:960 -> RLB_PRO: UL:   6 1 867.700 (0 - 5) | DL:   6 1 867.700 (0 - 5)
21:42:42:966 -> RLB_PRO: [MAC] 0x07
21:42:42:966 -> RLB_PRO: 00000000: 07 58 6e 84 50                                   .Xn.P             
21:42:42:974 -> RLB_PRO: UL:   7 1 867.900 (0 - 5) | DL:   7 1 867.900 (0 - 5)
21:42:42:980 -> RLB_PRO: [MAC] 0x03
21:42:42:983 -> RLB_PRO: 00000000: 20 00 00 00 00 00 00 00 00 00 00 00 00 00         .............    
21:42:42:988 -> RLB_PRO: LinkAdrReq: dataRate = 2, txSteps = 0, nbTrans = 0
21:42:42:994 -> RLB_PRO: execMacCommand(): chMask0123=0x0000000000000000
21:42:42:999 -> RLB_PRO: execMacCommand(): chMask45=0x0000
21:42:43:002 -> RLB_PRO: ADR: no channels available for datarate 2
21:42:43:009 -> RLB_PRO: LinkAdrAns: 05
21:42:43:018 -> RLB_PRO: UL:   0 1 868.100 (0 - 5) | DL:   0 1 868.100 (0 - 5)
21:42:43:026 -> RLB_PRO: UL:   1 1 868.300 (0 - 5) | DL:   1 1 868.300 (0 - 5)
21:42:43:031 -> RLB_PRO: UL:   2 1 868.500 (0 - 5) | DL:   2 1 868.500 (0 - 5)
21:42:43:035 -> RLB_PRO: UL:   3 1 867.100 (0 - 5) | DL:   3 1 867.100 (0 - 5)
21:42:43:037 -> RLB_PRO: UL:   4 1 867.300 (0 - 5) | DL:   4 1 867.300 (0 - 5)
21:42:43:038 -> RLB_PRO: UL:   5 1 867.500 (0 - 5) | DL:   5 1 867.500 (0 - 5)
21:42:43:043 -> RLB_PRO: UL:   6 1 867.700 (0 - 5) | DL:   6 1 867.700 (0 - 5)
21:42:43:049 -> RLB_PRO: UL:   7 1 867.900 (0 - 5) | DL:   7 1 867.900 (0 - 5)
21:42:43:054 -> RLB_PRO: [MAC] 0x04
21:42:43:054 -> RLB_PRO: 00000000: 07                                               .                 
21:42:43:062 -> RLB_PRO: DutyCycleReq: max duty cycle = 1/2^7
21:42:43:065 -> RLB_PRO: [MAC] 0x05
21:42:43:068 -> RLB_PRO: 00000000: 03 d2 ad 84                                      ....              
21:42:43:076 -> RLB_PRO: RXParamSetupReq: Rx1DrOffset = 0, rx2DataRate = 3, freq = 869.525
21:42:43:082 -> RLB_PRO: [MAC] 0x08
21:42:43:085 -> RLB_PRO: 00000000: 05                                               .                 
21:42:43:090 -> RLB_PRO: RXTimingSetupReq: delay = 5 sec
21:42:43:095 -> RLB_PRO: [MAC] 0x09
21:42:43:095 -> RLB_PRO: 00000000: 00                                               .                 
21:42:43:104 -> RLB_PRO: [MAC] 0x0c
21:42:43:107 -> RLB_PRO: 00000000: 65                                               e                 
21:42:43:112 -> RLB_PRO: ADRParamSetupReq: limitExp = 6, delayExp = 5
21:42:43:121 -> RLB_PRO: [MAC] 0x0f
21:42:43:122 -> RLB_PRO: 00000000: fa                                               .                 
21:42:43:126 -> RLB_PRO: RejoinParamSetupReq: maxTime = 15, maxCount = 10
21:42:43:131 -> RLB_PRO: getBufferSession(): chMask=0x0073
21:42:43:137 -> [ 18394][D][BresserWeatherSensorLW.ino:416] lwActivate(): Succesfully restored session - now activating
21:42:43:154 -> [ 18413][D][BresserWeatherSensorLW.ino:627] setup(): Battery level: 0
21:42:43:154 -> [ 18419][I][BresserWeatherSensorLW.ino:633] setup(): RTC sync required
21:42:43:164 -> RLB_PRO: 
21:42:43:164 -> RLB_PRO: PHY:  Frequency UL =   0.000 MHz
21:42:43:164 -> [ 18427][D][BresserWeatherSensorLW.ino:646] setup(): Max payload length: 254
21:42:43:169 -> [ 18438][D][BresserWeatherSensorLW.ino:673] setup(): FcntUp: 2
21:42:43:174 -> [ 18444][I][BresserWeatherSensorLW.ino:722] setup(): Sending uplink; port 1, size 47
21:42:43:183 -> RLB_PRO: Uplink MAC payload:
21:42:43:186 -> RLB_PRO: 00000000: 0d                                               .                 
21:42:43:231 -> RLB_PRO: Uplink (FCntUp = 3) decoded:
21:42:43:233 -> RLB_PRO: 00000000: 5b 20 31 38 34 34 34 5d 5b 49 5d 5b 42 72 65 73  [ 18444][I][Bres
21:42:43:238 -> RLB_PRO: 00000010: 40 44 ae 0b 26 81 03 00 c3 01 3a 4c dd b5 f3 c4  @D..&.....:L....
21:42:43:247 -> RLB_PRO: 00000020: 3c dc 47 5a dc d5 e5 4c 4b 9e 1a e3 05 0b c5 2f  <.GZ...LK....../
21:42:43:255 -> RLB_PRO: 00000030: a5 28 84 d5 e4 fb e6 4a e3 a2 dc 83 74 90 2b 49  .(.....J....t.+I
21:42:43:261 -> RLB_PRO: 00000040: b7 9e eb 76 d3 ab 3a f5 98 20 31 2c 20           ...v..:.. 1,      
21:42:43:269 -> RLB_PRO: 
21:42:43:269 -> RLB_PRO: PHY:  Frequency UL =   0.000 MHz
21:42:43:274 -> [ 18534][W][config.h:403] debug(): Error in sendReceive - ERR_INVALID_FREQUENCY (-12)
21:42:43:280 -> RLB_PRO: getBufferSession(): chMask=0x0000

StevenCellist · 2024-09-25T21:23:41Z

I have a strong suspicion but missing the log from the join leading up to the failure. If you can catch a complete cycle that would be perfect - the logging is awesome now - and that would likely confirm my suspicion. I don't have time to test myself yet, that would be around the weekend / early next week probably, in case you aren't in a position to continue the debugging.

matthias-bs · 2024-09-26T05:58:06Z

I have prepended the preceding cycle to my previous post. I don't think I can do much to debug this myself.

StevenCellist · 2024-09-26T06:34:05Z

Thanks for the complete log, that confirms my suspicion - it's a bug in RadioLib where it doesn't do the right thing until an ADR downlink is received. Today another The Things Conference day, but I should be able to come up with something fairly soon. Will see if it's going to be a bugfix release or a warning for users to cherry-pick the fix locally.

matthias-bs · 2024-09-26T09:56:02Z

Enjoy the conference!

StevenCellist · 2024-09-28T10:20:48Z

@matthias-bs thanks, and fixed in jgromes/RadioLib@5d076f6

matthias-bs · 2024-09-28T15:33:49Z

@StevenCellist Thanks a lot! Seems to be working now!

matthias-bs · 2024-09-28T15:44:08Z

See jgromes/RadioLib#1238

matthias-bs self-assigned this Sep 17, 2024

matthias-bs linked a pull request Sep 30, 2024 that will close this issue

20240922 bump radiolib7.0.1 #110

Merged

matthias-bs closed this as completed Sep 30, 2024

matthias-bs mentioned this issue Oct 2, 2024

Bump to RadioLib 7.0 matthias-bs/growatt2lorawan-v2#3

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bump to RadioLib 7.0 #106

Bump to RadioLib 7.0 #106

StevenCellist commented Sep 17, 2024

matthias-bs commented Sep 17, 2024

matthias-bs commented Sep 23, 2024

StevenCellist commented Sep 23, 2024

matthias-bs commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 25, 2024 •

edited

Loading

matthias-bs commented Sep 25, 2024

matthias-bs commented Sep 25, 2024

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 25, 2024

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 25, 2024 •

edited

Loading

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 26, 2024

StevenCellist commented Sep 26, 2024

matthias-bs commented Sep 26, 2024

StevenCellist commented Sep 28, 2024

matthias-bs commented Sep 28, 2024

matthias-bs commented Sep 28, 2024

Bump to RadioLib 7.0 #106

Bump to RadioLib 7.0 #106

Comments

StevenCellist commented Sep 17, 2024

matthias-bs commented Sep 17, 2024

matthias-bs commented Sep 23, 2024

StevenCellist commented Sep 23, 2024

matthias-bs commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 24, 2024

StevenCellist commented Sep 24, 2024

matthias-bs commented Sep 25, 2024 • edited Loading

matthias-bs commented Sep 25, 2024

matthias-bs commented Sep 25, 2024

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 25, 2024

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 25, 2024 • edited Loading

StevenCellist commented Sep 25, 2024

matthias-bs commented Sep 26, 2024

StevenCellist commented Sep 26, 2024

matthias-bs commented Sep 26, 2024

StevenCellist commented Sep 28, 2024

matthias-bs commented Sep 28, 2024

matthias-bs commented Sep 28, 2024

matthias-bs commented Sep 25, 2024 •

edited

Loading

matthias-bs commented Sep 25, 2024 •

edited

Loading