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

bcwong71

Dear Gijs,

Many thanks for your importunate support. Alright, on TTN, the status returned by the RegionCommonLinkAdrReqVerifyParams function was "7". Whereas, on Chirpstack, the status returned by the function was "6".

The parent function RegionAS923LinkAdrReq which returns the status value from RegionCommonLinkAdrReqVerifyParams is called in function ProcessMacCommands.c in LoRaMac.c. I could see that the data rate and the tx power for the next frame will only be set if the status value is 7. See code:

 case SRV_MAC_LINK_ADR_REQ:
                {
                    LinkAdrReqParams_t linkAdrReq;
                    int8_t linkAdrDatarate = DR_0;
                    int8_t linkAdrTxPower = TX_POWER_0;
                    uint8_t linkAdrNbRep = 0;
                    uint8_t linkAdrNbBytesParsed = 0;

                    // Fill parameter structure
                    linkAdrReq.Payload = &payload[macIndex - 1];
                    linkAdrReq.PayloadSize = commandsSize - ( macIndex - 1 );
                    linkAdrReq.AdrEnabled = AdrCtrlOn;
                    linkAdrReq.UplinkDwellTime = LoRaMacParams.UplinkDwellTime;
                    linkAdrReq.CurrentDatarate = LoRaMacParams.ChannelsDatarate;
                    linkAdrReq.CurrentTxPower = LoRaMacParams.ChannelsTxPower;
                    linkAdrReq.CurrentNbRep = LoRaMacParams.ChannelsNbRep;

                    // Process the ADR requests
                    status = RegionLinkAdrReq( LoRaMacRegion, &linkAdrReq, &linkAdrDatarate,
                                               &linkAdrTxPower, &linkAdrNbRep, &linkAdrNbBytesParsed );

                    if( ( status & 0x07 ) == 0x07 )
                    {
                        LoRaMacParams.ChannelsDatarate = linkAdrDatarate;
                        LoRaMacParams.ChannelsTxPower = linkAdrTxPower;
                        LoRaMacParams.ChannelsNbRep = linkAdrNbRep;
                    }

So, now we know that the root cause in the conditional checking in function RegionCommonLinkAdrReqVerifyParams. The body of the function is in RegionCommon.c. There are two conditional evaluations in the function:

 if( RegionCommonChanVerifyDr( verifyParams->NbChannels, verifyParams->ChannelsMask, datarate,
                                      verifyParams->MinDatarate, verifyParams->MaxDatarate, verifyParams->Channels  ) == false )
        {
            status &= 0xFD; // Datarate KO
        }

        // Verify tx power
        if( RegionCommonValueInRange( txPower, verifyParams->MaxTxPower, verifyParams->MinTxPower ) == 0 )
        {
            // Verify if the maximum TX power is exceeded
            if( verifyParams->MaxTxPower > txPower )
            { // Apply maximum TX power. Accept TX power.
                txPower = verifyParams->MaxTxPower;
            }
            else
            {
                status &= 0xFB; // TxPower KO
            }
        }

I found that our suspicion earlier about the tx power from LinkAdrReq being out of range was wrong since the RegionCommonValueinRange works fine and will always return a value of "1" if the tx power in LinkAdrReq is between the value of 0 and 7. With a value of 1 returned, the status value will remain unmodified and will stay constant at the value of 0x07 set initially at the beginning of the RegionAS923LinkAdrReq function.

So, we know now the culprit has to be the RegionCommonChanVerifyDr function. I suspect now that the root cause may be the channel masks in the LinkAdrReq. Can you add on to the debug print, the channel mask variable for the parsed variables in the AdrReq packet? Also, can you also add some debug prints in the body of function RegionCommonLinkAdrReqVerifyParams to visualise how the value of the status variable changes.

I think we are getting very near to solving the problem with ADR on Chirpstack server. If I may ask for your kind assistance to try using the Chirpstack server to see if you can identify the root cause on your end. Thanks.

Regards,
Wong

Gijs

Hi,
Sorry for the long wait.

I could see that the data rate and the tx power for the next frame will only be set if the status value is 7.

You're correct here. I added a debug statement in the RegionLinkAdrReq(...) function, before calling the RegionCommonLinkAdrReqVerifyParams(...) to check the variable parameters, do you have an output there (it should be along the lines of [RegionAS923] LinkAdrReq: (before verify) linkAdrParams.Datarate %d, TxPower %d, NbRep %d\n". Then, we can (hopefully) figure out which parameter is the issue there. As the function RegionCommon is the same for all regions.

Though I think the status = 0x06 is caused by setting the channel masks before calling the verifyparams method, as 0x07 &= 0xFE is the only math that can result in status = 0x06. It could then be only related to setting Chirpstack trying to set incorrect channelmasks (whatever that means).

Let me know what you get! And while I enjoy trying to figure it out, it might be faster for you to add the debug statements in your own copy?

Gijs

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