The function SysTimeSet() is not working

yqmlove commented 1 year ago

When I test FUOTA with multicast, the STM32 board received the message (CLOCK_SYNC_APP_TIME_ANS) from network server, the function SysTimeSet() can't set correct time to the system.

in LmhpClockSync.c

case CLOCK_SYNC_APP_TIME_ANS: { LmhpClockSyncState.NbTransmissions = 0;

            // Check if a more precise time correction has been received.
            // If yes then don't process and ignore this answer.
            if( mcpsIndication->DeviceTimeAnsReceived == true )
            {
                cmdIndex += 5;
                break;
            }
            int32_t timeCorrection = 0;
            timeCorrection  = ( mcpsIndication->Buffer[cmdIndex++] << 0  ) & 0x000000FF;
            timeCorrection += ( mcpsIndication->Buffer[cmdIndex++] << 8  ) & 0x0000FF00;
            timeCorrection += ( mcpsIndication->Buffer[cmdIndex++] << 16 ) & 0x00FF0000;
            timeCorrection += ( mcpsIndication->Buffer[cmdIndex++] << 24 ) & 0xFF000000;
            if( ( mcpsIndication->Buffer[cmdIndex++] & 0x0F ) == LmhpClockSyncState.TimeReqParam.Fields.TokenReq )
            {
                SysTime_t curTime = { .Seconds = 0, .SubSeconds = 0 };
                curTime = SysTimeGet( );
                curTime.Seconds += timeCorrection;
                SysTimeSet( curTime );
                LmhpClockSyncState.TimeReqParam.Fields.TokenReq = ( LmhpClockSyncState.TimeReqParam.Fields.TokenReq + 1 ) & 0x0F;
                if( LmhpClockSyncPackage.OnSysTimeUpdate != NULL )
                {
                    if( ( timeCorrection >= -1 ) && ( timeCorrection <= 1 ) )
                    {
                        LmhpClockSyncPackage.OnSysTimeUpdate( );
                    }
                }
            }
            break;
        }

Since SysTimeSet() is not working, which cause multicast class C session can't be created.

in LmhpRemoteMcastSetup.c

case REMOTE_MCAST_SETUP_MC_GROUP_CLASS_C_SESSION_REQ: { uint8_t status = 0x00; int32_t timeToSessionStart = 0; id = mcpsIndication->Buffer[cmdIndex++] & 0x03;

            McSessionData[id].SessionTime =  ( mcpsIndication->Buffer[cmdIndex++] << 0  ) & 0x000000FF;
            McSessionData[id].SessionTime += ( mcpsIndication->Buffer[cmdIndex++] << 8  ) & 0x0000FF00;
            McSessionData[id].SessionTime += ( mcpsIndication->Buffer[cmdIndex++] << 16 ) & 0x00FF0000;
            McSessionData[id].SessionTime += ( mcpsIndication->Buffer[cmdIndex++] << 24 ) & 0xFF000000;

            // Add Unix to Gps epoch offset. The system time is based on Unix time.
            McSessionData[id].SessionTime += UNIX_GPS_EPOCH_OFFSET;

            McSessionData[id].SessionTimeout =  mcpsIndication->Buffer[cmdIndex++] & 0x0F;

            McSessionData[id].RxParams.ClassC.Frequency =  ( mcpsIndication->Buffer[cmdIndex++] << 0  ) & 0x000000FF;
            McSessionData[id].RxParams.ClassC.Frequency |= ( mcpsIndication->Buffer[cmdIndex++] << 8  ) & 0x0000FF00;
            McSessionData[id].RxParams.ClassC.Frequency |= ( mcpsIndication->Buffer[cmdIndex++] << 16 ) & 0x00FF0000;
            McSessionData[id].RxParams.ClassC.Frequency *= 100;

            McSessionData[id].RxParams.ClassC.Datarate = mcpsIndication->Buffer[cmdIndex++];

            LmhpRemoteMcastSetupState.DataBuffer[dataBufferIndex++] = REMOTE_MCAST_SETUP_MC_GROUP_CLASS_C_SESSION_ANS;
            if( LoRaMacMcChannelSetupRxParams( ( AddressIdentifier_t )id, &McSessionData[id].RxParams, &status ) == LORAMAC_STATUS_OK )
            {
                SysTime_t curTime = { .Seconds = 0, .SubSeconds = 0 };
                curTime = SysTimeGet( );

                timeToSessionStart = McSessionData[id].SessionTime - curTime.Seconds;
                if( timeToSessionStart > 0 )
                {
                    // Start session start timer
                    TimerSetValue( &SessionStartTimer, timeToSessionStart * 1000 );
                    TimerStart( &SessionStartTimer );

                    MW_LOG(TS_OFF, VLEVEL_M, "Time2SessionStart: %d ms\r\n", timeToSessionStart * 1000);
                }
                else
                {
                    // Session start time before current device time
                    status |= 0x10;
                }
            }

Since SysTimeSet() is not working, SysTimeGet() will get small number(156s), then timeToSessionStart will be a big number, after it times 1000, it will overflow (-1950170440ms)

========== MCPS-Confirm =============

Time2SessionStart: -1950170440 ms 156s372:TX on freq 903500000 Hz at DR 3 ID : 0 McAddr : 01E8165C McKey : 34-01-33-57-BD-1F-3C-AC-09-D1-E5-A9-03-A1-8A-F6 McFCountMin : 0 McFCountMax : 65535 SessionTime : 1673087231 SessionTimeT: 4096 s Rx Freq : 923300000 Rx DR : DR_9 156s425:MAC txDone 158s405:RX_1 on freq 926900000 Hz at DR 13 158s448:IRQ_RX_TX_TIMEOUT 158s448:MAC rxTimeOut 159s419:RX_2 on freq 923300000 Hz at DR 8 159s487:IRQ_RX_TX_TIMEOUT 159s487:MAC rxTimeOut

Please take a look at this issue, thanks.

mluis1 commented 1 year ago

Have you commented the following line https://github.com/Lora-net/LoRaMac-node/blob/2bf36bde72f68257eb96b5c00900619546bedca8/src/apps/LoRaMac/common/LmHandler/packages/LmhpClockSync.c#L343-L347

If you have not the following lines will prevent the rest of the code in LmhpClockSyncOnMcpsIndication function to be run as the time has already been set by the answer to DeviceTimeReq MAC command. https://github.com/Lora-net/LoRaMac-node/blob/2bf36bde72f68257eb96b5c00900619546bedca8/src/apps/LoRaMac/common/LmHandler/packages/LmhpClockSync.c#L239-L245

From your description it looks like that the DeviceTimeReq did not receive an answer from the network server.

In order to debug can you please comment the line https://github.com/Lora-net/LoRaMac-node/blob/2bf36bde72f68257eb96b5c00900619546bedca8/src/apps/LoRaMac/common/LmHandler/packages/LmhpClockSync.c#L347

Then run your test again. If it works then you need to figure out why the network server did not answer the DeviceTimeReq MAC command.

As a side note, your FUOTA procedure should not continue if any of the end-devices is not fully time synchronized.

yqmlove commented 1 year ago

Thanks @mluis1, actually I checked the log and found device receive DeviceTimeAns from network server, as we know, every time we burned the new image for STM32, it will automatically reboot, but it is not enough, the function SystimeSet() is not working, but if we unplug the cable between STM32 with laptop and plug, the STM also reboot, this time the function is working, the below is the log.

= [SBOOT] SECURE ENGINE INITIALIZATION SUCCESSFUL = [SBOOT] STATE: CHECK STATUS ON RESET INFO: A Reboot has been triggered by a Software reset! = [SBOOT] STATE: CHECK NEW FIRMWARE TO DOWNLOAD = [SBOOT] STATE: CHECK KMS BLOB TO INSTALL = [SBOOT] STATE: CHECK USER FW STATUS A FW is detected in the slot SLOT_ACTIVE_1 = [SBOOT] STATE: VERIFY USER FW SIGNATURE = [SBOOT] STATE: EXECUTE USER FIRMWAREAPP_VERSION: V1.1.0 MW_LORAWAN_VERSION: V2.3.0 MW_RADIO_VERSION: V1.1.0

OTAA

AppKey: 2B:7E:15:16:28:AE:D2:A6:AB:F7:15:88:09:CF:4F:3C

NwkKey: 2B:7E:15:16:28:AE:D2:A6:AB:F7:15:88:09:CF:4F:3C

ABP

AppSKey: 2B:7E:15:16:28:AE:D2:A6:AB:F7:15:88:09:CF:4F:3C

NwkSKey: 2B:7E:15:16:28:AE:D2:A6:AB:F7:15:88:09:CF:4F:3C

DevEui: 00:80:E1:15:00:03:DF:BB

AppEui: 01:01:01:01:01:01:01:01

DevAddr: 00:03:DF:BB

KMS ENABLED

1673132963s998:TX on freq 902300000 Hz at DR 0 1673132964s372:MAC txDone 1673132965s002:temp= 26 1673132966s002:temp= 25 1673132967s002:temp= 25 1673132968s002:temp= 24 1673132969s002:temp= 24 1673132969s356:RX_1 on freq 923300000 Hz at DR 10 1673132969s487:MAC rxDone

You will see the time was changed to 1673132963s998. I think you can reproduce this issue, it is a potential bug. Again, thank you very much.

Lora-net / LoRaMac-node