Network changes PSM timing without notice ?

Hello,

I have a project based on nRF9160 and nRFCloud (CoAP), and uses a SIM from 1NCE. This SIM allows to connect to 3 different MNO at my location in France (Orange, Bouygues telecom, SFR).
For the most part, it's working as expected. However, I noticed a strange behavior when the device is in "standby mode".
In this mode, the device only needs to send a message every 24h. For this purpose, the device requests a TAU timer of 25h to the network, which gets accepted.
On some devices, I have no problem and it works as expected.
On others, the device gets stuck, causing a Watchdog reset, as follow :

#1 - Sleep for 24h
#2 - Wakeup and try to send a message
#3 - Gets stuck in firmware -> Message not send + Watchdog reset
#4 - Reboot FW, re-connect to the network, re-connect to nRFCloud
#5 - Send the message successfully
#6 - Negotiate PSM for 24h sleep
#7 - Back to step #1

Sample log from my device :

--------------------------------
------------ REBOOT ------------
--------------------------------

Reset cause (16): 	RESET_WATCHDOG

* * Perfom all HW inits ** 

- - Inits completed - -

Battery voltage: 3592mv

[Uptime 8 sec]
Build Status frame (acc: -1, 2, -96)

[Uptime 8 sec]
Measure probe ... Ok
Cellular enable ... Done
[MODEM] Searching network
[MODEM] Mode LTE-M
[MODEM] RRC Connected
[MODEM] Search done
[MODEM] Network connected
Connected in 4 sec
Connect to nRFCloud ... Done

Send: {"F":{"1733335826":["170010"],"1733335830":["19C12241330B","100011FF02A00000"],"1733335833":["1940F77409A20000"]}}
Send done
Send RSRP to nRFCloud
Send: {"messageType":"DATA","data":"-96","appId":"RSRP","ts": 1733335843120}
Send done

04/12/2024 18:10:47
First read after boot: full read ... Done

04/12/2024 18:10:47
Delta read nRF shadow ... No new data

04/12/2024 18:10:48
FOTA: Sending device info ... Ok

04/12/2024 18:10:57
Checking for FOTA ... No pending FOTA

04/12/2024 18:10:58
Prepare to sleep ...
PSM: TAU=1800, AT=60 don't match desired: TAU>86700, 0<AT<32
PSM request: TAU=90000, AT=0
(TAU 86700 rounded to 90000)
PSM is: TAU=90000, AT=0
Sleep
[MODEM] RCC Idle

05/12/2024 18:11:02
Build Status frame (acc: -1, 3, -96)

05/12/2024 18:11:02
Measure probe ... Ok	Perm. 4.339	ECb 0.0mS/m	14.0°C
Modem already ready

Send: {"F":{"1733422262":["100011FF03A00000"],"1733422265":["1940F86C21E60000"]}}
[MODEM] Search done
[MODEM] RRC Connected



--------------------------------
------------ REBOOT ------------
--------------------------------

Reset cause (16): 	RESET_WATCHDOG

* * Perfom all HW inits ** 

- - Inits completed - -

Battery voltage: 3602mv

[Uptime 8 sec]
Build Status frame (acc: -1, 3, -97)

[Uptime 8 sec]
Measure probe ... Ok
Cellular enable ... Done
[MODEM] Searching network
[MODEM] Mode LTE-M
[MODEM] RRC Connected
[MODEM] Search done
[MODEM] Network connected
Connected in 4 sec
Connect to nRFCloud ... Done

Send: {"F":{"1733422332":["170010"],"1733422336":["19C12241330B","100011FF039F0000"],"1733422339":["1940F86C226E0000"]}}
Send done
Send RSRP to nRFCloud
Send: {"messageType":"DATA","data":"-103","appId":"RSRP","ts": 1733422347356}
Send done

05/12/2024 18:12:28
First read after boot: full read ... Done

05/12/2024 18:12:28
Delta read nRF shadow ... No new data

05/12/2024 18:12:30
FOTA: Sending device info ... Ok

05/12/2024 18:12:37
Checking for FOTA ... No pending FOTA

05/12/2024 18:12:38
Prepare to sleep ...
PSM: TAU=1800, AT=60 don't match desired: TAU>86700, 0<AT<32
PSM request: TAU=90000, AT=0
(TAU 86700 rounded to 90000)
PSM is: TAU=90000, AT=0
Sleep
[MODEM] RCC Idle

06/12/2024 18:12:42
Build Status frame (acc: -3, 0, -96)

06/12/2024 18:12:42
Measure probe ... Ok
Modem already ready

Send: {"F":{"1733508762":["100011FD00A00000"],"1733508765":["1940F8000A240000"]}}
[MODEM] Search done
[MODEM] RRC Connected


--------------------------------
------------ REBOOT ------------
--------------------------------

Reset cause (16): 	RESET_WATCHDOG

* * Perfom all HW inits ** 

- - Inits completed - -

Battery voltage: 3600mv

[Uptime 8 sec]
Build Status frame (acc: -1, 2, -97)

[Uptime 8 sec]
Measure probe ... Ok
Cellular enable ... Done
[MODEM] Searching network
[MODEM] Mode LTE-M
[MODEM] RRC Connected
[MODEM] Search done
[MODEM] Network connected
Connected in 4 sec
Connect to nRFCloud ... Done

Send: {"F":{"1733508832":["170010"],"1733508836":["19C12241330B","100011FF029F0000"],"1733508839":["1940F7FC0A320000"]}}
Send done
Send RSRP to nRFCloud
Send: {"messageType":"DATA","data":"-98","appId":"RSRP","ts": 1733508847945}
Send done

06/12/2024 18:14:08
First read after boot: full read ... Done

06/12/2024 18:14:08
Delta read nRF shadow ... No new data

06/12/2024 18:14:11
FOTA: Sending device info ... Ok

06/12/2024 18:14:19
Checking for FOTA ... No pending FOTA

06/12/2024 18:14:20
Prepare to sleep ...
PSM: TAU=1800, AT=60 don't match desired: TAU>86700, 0<AT<32
PSM request: TAU=90000, AT=0
(TAU 86700 rounded to 90000)
PSM is: TAU=90000, AT=0
Sleep
[MODEM] RCC Idle

07/12/2024 18:14:23
Build Status frame (acc: -2, 0, -97)

07/12/2024 18:14:23
Measure probe ... Ok
Modem already ready

Send: {"F":{"1733595263":["100011FE009F0000"],"1733595267":["1940F77009420000"]}}
[MODEM] Search done
[MODEM] RRC Connected


--------------------------------
------------ REBOOT ------------
--------------------------------

...


The only difference I was able to spot between a working and non-working device is the network : it looks like the devices with the unexpected reboots always connect to the same MNO: SFR.
Here is what I can see on the SIM events, from the SIM provider:

"events": [
{
  "timestamp": "2024-12-05 06:10:12.677Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-05 18:11:10.332Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-05 18:11:10.723Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-05 18:12:22.368Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-05 18:12:22.496Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-05 18:12:22.605Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-05 18:12:23.230Z",
  "event_type": "Update location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-05 18:12:23.768Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-06 06:11:57.733Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-06 18:12:49.362Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-06 18:12:49.800Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-06 18:14:02.203Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-06 18:14:02.381Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-06 18:14:02.713Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-06 18:14:03.323Z",
  "event_type": "Update location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-06 18:14:03.676Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-07 06:13:50.697Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-07 18:14:30.894Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-07 18:14:31.287Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-07 18:15:43.896Z",
  "event_type": "Delete PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-07 18:15:44.032Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-07 18:15:44.187Z",
  "event_type": "Create PDP Context",
  "operator": "SFR Cegetel",
  "mcc": "208", "mnc": "10",
},
{
  "timestamp": "2024-12-07 18:15:44.836Z",
  "event_type": "Update location",
  "operator": "SFR Cegetel",
},
{
  "timestamp": "2024-12-07 18:15:45.225Z",
  "event_type": "Update GPRS location",
  "operator": "SFR Cegetel",
},
]

My hint it that the network accepts the PSM TAU at 25h (90000 sec), but cancels that after 12h.

Since the device is sleeping, its not notified (I don't have any modem event related). Therefore, when it tries to send a new message after waking up, the modem still considers that it is registered to the network and the nrf_coap_functions() fails/get stuck.

Note that on working devices, which seem to connect to other network, I don't have any "event_type": "Delete PDP Context" on the SIM events.

Is this behavior possible or is my issue comming from something else ? Is there a way to check that the connection is still active, without wasting power and data ? Some sort of ping ?

Thanks !

Related