Pycom FiPy ADR not working on AS923 (TTN and Chirpstack)

bcwong71

@Gijs
Hi Gijs, adding my own debug prints means I need to compile the source code to generate the firmware file?

I knew that you had added the debug print to check the linkadreq data before the verification function. However, I am afraid that the number of parameters included in the debug print is not exhaustive enough. Maybe, the status variable should be added at the end of LinkAdrReq: (before verify).... so that we can determine if the status variable is already set to "6" prior to the RegionCommonVerify function. Let me share with you the debug prints from TTN and Chirpstack as follows:

On TTN:

[RegionAS923] AdrNext: AdrAckCounter 64, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 0, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[LoRaMac] SendFrameOnChannel: channel 0
[LoRaMac] SendFrameOnChannel: uplink frequency 923200000
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 0, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:0, nbRepOut 1, nbBytesParsed:5, status: 7
[modlora] McpsConfirm: Giving semaphore 4
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 5
datarate out 5, txpowout 0
[modlora] TASK_LoRa: taking semaphore 1
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 5
datarate out 5, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 1, RX channel DR: 5
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 5
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[LoRaMac] SendFrameOnChannel: channel 1
[LoRaMac] SendFrameOnChannel: uplink frequency 923400000
[RegionAS923] RegionAS923RxConfig: RX config channel 1, frequency 923400000, datarate 5
[RegionAS923] RegionAS923RxConfig: RX config channel 1, frequency 923200000, datarate 2

On Chirpstack:

[modlora] TASK_LoRa: taking semaphore 1
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 0, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 0
[LoRaMac] SendFrameOnChannel: channel 0
[LoRaMac] SendFrameOnChannel: uplink frequency 923200000
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 2, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:2, nbRepOut 1, nbBytesParsed:5, status: 6
[modlora] McpsConfirm: Giving semaphore 4
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[modlora] TASK_LoRa: taking semaphore 1

The only different I can see is the different Tx Power, which I have confirmed that it is not the culprit in the failed ADR issue on Chirpstack. So the only culprit would be the few lines of code related to channel mask setup before the verify function.

Thanks.

Wong

Gijs

Hi Gijs, adding my own debug prints means I need to compile the source code to generate the firmware file?

Yes, theres some instructions about that here: https://github.com/pycom/pycom-micropython-sigfox

Maybe, the status variable should be added at the end of LinkAdrReq: (before verify).... so that we can determine if the status variable is already set to "6" prior to the RegionCommonVerify function.

Well, what I determined looking at the code, is the status must be set to 0x06 before the VerifyParams method is called (From what I see, there is no way it can change to 0x06 in the VerifyParams method, only to 0x05 and 0x04)

Meaning the status changes from any of these:

    while( bytesProcessed < linkAdrReq->PayloadSize )
        {
            // Get ADR request parameters
            nextIndex = RegionCommonParseLinkAdrReq( &( linkAdrReq->Payload[bytesProcessed] ), &linkAdrParams );
            printf("[RegionAS923] LinkAdrReq: nextIndex %d \n", nextIndex);
    
            if( nextIndex == 0 )
                break; // break loop, since no more request has been found
    
            // Update bytes processed
            bytesProcessed += nextIndex;
    
            // Revert status, as we only check the last ADR request for the channel mask KO
            status = 0x07;
    
            // Setup temporary channels mask
            chMask = linkAdrParams.ChMask;
            printf("\t status %d, chMask %d\n", status, chMask);
            // Verify channels mask
            if( ( linkAdrParams.ChMaskCtrl == 0 ) && ( chMask == 0 ) )
            {
                status &= 0xFE; // Channel mask KO <-- HERE
                printf("\t chMaskCTRl1 == %d AND chMask == %d, status = %d\n", linkAdrParams.ChMaskCtrl, chMask, status);
            }
            else if( ( ( linkAdrParams.ChMaskCtrl >= 1 ) && ( linkAdrParams.ChMaskCtrl <= 5 )) ||
                    ( linkAdrParams.ChMaskCtrl >= 7 ) )
            {
                // RFU
                status &= 0xFE; // Channel mask KO <-- HERE
                printf("\t (RFU) chMaskCTRl == %d status = %d\n", linkAdrParams.ChMaskCtrl, status);
            }
            else
            {
                for( uint8_t i = 0; i < AS923_MAX_NB_CHANNELS; i++ )
                {
                    if( linkAdrParams.ChMaskCtrl == 6 )
                    {
                        if( Channels[i].Frequency != 0 )
                        {
                            chMask |= 1 << i;
                        }
                    }
                    else
                    {
                        if( ( ( chMask & ( 1 << i ) ) != 0 ) &&
                            ( Channels[i].Frequency == 0 ) )
                        {// Trying to enable an undefined channel
                            status &= 0xFE; // Channel mask KO <-- HERE
                            printf("\t Channels[%d].Frequency == %d, AND chMask == %d, status = %d\n",i, Channels[i].Frequency, chMask, status);
                        }
                    }
                }
            }
        }
        printf("\t exiting While loop, status %d\n", status);

I have no clue what function these methods have, but I'll add some debug statements there:
firmware

Edit: I just got the status 6 to appear on TTN as well, and the datarate did not update, but I forgot to keep the log :/ It has not occured since

bcwong71

@Gijs

Hi, thanks for your help. Below are the results from TTN and Chirpstack respectively:

TTN:

[modlora] TASK_LoRa: taking semaphore 1
[RegionAS923] AdrNext: AdrAckCounter 64, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 1, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[LoRaMac] SendFrameOnChannel: channel 1
[LoRaMac] SendFrameOnChannel: uplink frequency 923400000
[RegionAS923] RegionAS923RxConfig: RX config channel 1, frequency 923400000, datarate 2
[RegionAS923] LinkAdrReq: nextIndex 5 
         status 7, chMask 3
         exiting While loop, status 7
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 0, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:0, nbRepOut 1, nbBytesParsed:5, status: 7     
[modlora] McpsConfirm: Giving semaphore 4
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 5
datarate out 5, txpowout 0

Chirpstack:

[modlora] TASK_LoRa: taking semaphore 1
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 0, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 0
[LoRaMac] SendFrameOnChannel: channel 0
[LoRaMac] SendFrameOnChannel: uplink frequency 923200000
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] LinkAdrReq: nextIndex 5 
         status 7, chMask 7
         Channels[2].Frequency == 0, AND chMask == 7, status = 6
         exiting While loop, status 6
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 2, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:2, nbRepOut 1, nbBytesParsed:5, status: 6
[modlora] McpsConfirm: Giving semaphore 4
[RegionAS923] AdrNext: AdrAckCounter 0, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0

From what I understand, on Chirpstack, the status was converted to "6" when an attempt was made to enable an undefined channel.

Thanks,

Denver

Gijs

Indeed. It seems Chirpstack tries to set the ADR for the 3rd (i = 2) channel which is undefined (frequency = 0). To be honest I have no clue on how it works exactly and what to do about that. Also it does not seem to happen regularly on TTN.

         Channels[2].Frequency == 0, AND chMask == 7, status = 6

Could you confirm that you never get next tx channel 2 in this line: (As I feel like they would be related)

[LoRaMac] ScheduleTx: next channel 1, RX channel DR: 2

You could also try to use the following to add a channel on index 2. At the moment there is no method to check the available channels.

lora.add_channel(index, frequency, dr_min, dr_max)

bcwong71

@Gijs
Okay gijs,

Based on the debug prints, my team has finally been able to narrow down the root cause to be the wrong channel mask set in the Chirpstack server. We have editted the LoRa parameters in the Chirpstack server. Now, FiPy is able to work with ADR on both TTN and Chirpstack. Our Chirpstack server setting was inherited from the EU868 plan during our deployment in London. The number of default channels in EU868 is 3 while the number of default channels in AS923 is 2. The extra 3rd channel returned by LinkAdrReq caused the channel mask setup routine to fail resulting in the status value being changed to 0x06, which prevented the setting of the data rate and tx power for the next frame.

It is now time to rest the case. I hope any exposure or changes to the source code that have been implemented in our discussion will be introduced in the next firmware update so that users can benefit from them.

Thank you so much.

Wong

Gijs

Great that we were able to find the root cause in the end!

I will further evaluate the changes. Though what you mention here is interesting (not sure exactly which default channels you're talking about); this is essentially the only line that I changed in the AS923 configuration

// Re-enable default channels
ChannelsMask[0] |= LC( 1 ) + LC( 2 );

to

// Re-enable default channels
ChannelsMask[0] |= LC( 1 ) + LC( 2 ) + LC( 3 );

from the EU868 region config. This does seem odd to me, definitely after you mentioned the 2 vs 3 default channels in the respective regions. Could you elaborate on that, I was not able to find a lot more information there..

bcwong71

@Gijs

I was referring to the default channels under the ISM Band Channel Frequencies in https://lora-alliance.org/wp-content/uploads/2020/11/lorawan_regional_parameters_v1.0.2_final_1944_1.pdf.

The number of default channels for EU868 is 3 under 2.1.2 while the number of default channels for AS923 is 2 under 2.7.2. So apparently, our Chirpstack server channel masks were configured to 3 channels which conflicted with the default number of channels for AS923 which is 2. We initially thought we only had to make some changes to some common parameters like the frequency plan on Chirpstack server, previously on the EU868 plan to accommodate our experiment on the AS923 plan. We did not realise that the channel mask configuration was still set to that of the EU868 plan while the server in general operates on the AS923 plan. There was no way to easily edit the channel mask configuration. So, we created a new instance of the Chirpstack server instead.

Anyways, thanks so much for your help.

Regards,
Wong

Gijs

@bcwong71 Returning to this issue. I tested with the 'default' firmware (ie, where I only added debug statements): I got this after the first 64 messages (when the ADR changes), on TTN, AS923:

[modlora] TASK_LoRa: taking semaphore 1 
[RegionAS923] AdrNext: AdrAckCounter 64, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 0, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[LoRaMac] SendFrameOnChannel: channel 0
[LoRaMac] SendFrameOnChannel: uplink frequency 923200000
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] RegionAS923RxConfig: RX config channel 0, frequency 923200000, datarate 2
[RegionAS923] LinkAdrReq: nextIndex 5 
         status 7, chMask 127
         Channels[2].Frequency == 0, AND chMask == 127, status = 6
         Channels[3].Frequency == 0, AND chMask == 127, status = 6
         Channels[4].Frequency == 0, AND chMask == 127, status = 6
         Channels[5].Frequency == 0, AND chMask == 127, status = 6
         Channels[6].Frequency == 0, AND chMask == 127, status = 6
         exiting While loop, status 6
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 0, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:0, nbRepOut 1, nbBytesParsed:5, status: 6
[modlora] McpsConfirm: Giving semaphore 4

It seems like we're trying to set channels 2-6, which are not default to the AS923 configuration. Also, I could not find any packets sent which were not on channles 0 and 1. the datarate did not change after this.

Next, this happend after the second 64 packets:

[modlora] TASK_LoRa: taking semaphore 1 
[RegionAS923] AdrNext: AdrAckCounter 64, AdrEnabled: 1, old datarate 2
datarate out 2, txpowout 0
[LoRaMac] PrepareFrame: adrNext[LoRaMac] ScheduleTx: next channel 1, RX channel DR: 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[RegionAS923] RegionAS923ComputeRxWindowParameters: datarate 2
[LoRaMac] SendFrameOnChannel: channel 1
[LoRaMac] SendFrameOnChannel: uplink frequency 923400000
[RegionAS923] RegionAS923RxConfig: RX config channel 1, frequency 923400000, datarate 2
[RegionAS923] LinkAdrReq: nextIndex 5 
         status 7, chMask 3
         exiting While loop, status 7
[RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate 5, TxPower 0, NbRep 1
[RegionAS923] LinkAdrReq: status variables drOut: 5, txPowOut:0, nbRepOut 1, nbBytesParsed:5, status: 7
[modlora] McpsConfirm: Giving semaphore 4

Note that the datare did change after this to 5, with txpow 0.

On the third set of 64 messages, it again resulted in what I got for the first set, trying to set channels 2-6. For the fourth set, we get the same as the second set..

Not sure what this means, or of the workings on ABP.

Could you verify that for me on TTN and Chirpstack, where you adapted the configuration (just upload 1.20.2.r4 and see in the TTN monitor if the datarate changes after ~125 packets)

Let me know of your result!

Gijs

bcwong71

@Gijs

Hello Gijs,

Might take me some time to return with the results since the gateway and the nodes have been passed to the installation company. All the FiPys have been flashed with the last firmware you shared. Thanks.

Wong

João SOARES

@Gijs
Hello,
I am currently using FiPy and LoPy4 and I am also trying to activate the ADR but using this firmware "pycom_firmware_updater_1.16.6". I have read here that you were able to achieve ADR with this firmware FiPy-1.20.2.r4_adr4.tar.gz I have yet to try with this. I also read that the change of SF was only after 70 packets, isn't possible to change after 2/3? In my use case, the gateway will pass by the end-node at a high speed.

Explore Pybytes | Official Documentation | Report a Firmware Bug/Issue | GitHub

Pycom FiPy ADR not working on AS923 (TTN and Chirpstack)

Pycom on Twitter