Help with LTE connection after loss of connection

[AnnaQ]

We have noticed that several of our nRF9160 in production have problem with reconnecting to the LTE-M network after temporarily losing connection. We have tried reproducing this issue by deactivating the sim for about 10 seconds and then activating it again. After the default six retries it gives up and stop trying to reconnect to the network. the only way we can achieve a connection is if we do a sys_reboot() or a hard reboot with watchdog. Why is the reconnect attempts not enough? Why do we have to force a reboot? Attached are relevant logs.

[AnnaQ]

More info: 

• We are using NSC version 2.6.0 and mfw 1.3.6.
• The sims are global (EU, Nordics, Baltics), see image of subscription details.We have mainly worked with Telia sims but some of our clients have tried using other with no improvement. 

[dejans]

Hi,

Could you AnnaQ and Matias Marti please confirm that all your questions and logs are related to the same application (based on lwm2m_client in NCS v2.6.1)?

Could you please provide more information about your application? What exactly do you try to achieve? What does your application do?

We have noticed that several of our nRF9160 in production have problem with reconnecting to the LTE-M network after temporarily losing connection.

Can you provide more information on how devices lose connection? Do they work normally and suddenly lose connection? How often does this happen and on how many devices? Where are your failing devices located?

We have tried reproducing this issue by deactivating the sim for about 10 seconds and then activating it again. After the default six retries it gives up and stop trying to reconnect to the network.

Why do you think that the issue might be related to SIM? How do you do deactivation/activation of the SIM?

Matias Marti said:

It looks like the EXCHANGE_LIFETIME is set to 247s (4 minutes 7s) in the code here. Is there any way we can modify this value? Or is there another way to "give up" the exchange earlier?

Have you tried changing the value directly in the code?

Best regards,
Dejan

[dejans]

Hi Matias Marti ,

Matias Marti said:

We will try to provide you with Wireshark logs shortly.

If needed, please provide server log and Wireshark capture for further analysis.

Best regards,
Dejan

[Matias Marti]

SeppoTakalo said:

LwM2M engine uses those mentioned CONFIG_COAP values. So all CoAP confirmable messages use same values. I don't see why it would make sense to modify these per message type. Any CoAP confirmable message refreshes the NAT mappings and allows server to communicate.

Thank you for your answer.

The reason it would make sense, for us at least, to modify these CONFIG_COAP values per message type is the following:

We are satisfied with how lwm2m + COAP is working in all aspects apart from these 4min7s registation update timeouts. Here is some more concrete context:

Let us suppose 1 out of every 1000 (0,1%) of all registration updates of a device end up reaching the default timeout. With a ping every 20s (180 pings/h), the board will become unreachable (i.e. unusable) for a whole 4min7s every 5h34min if these timeouts are evenly distributed.

The issue we are dealing with is specific to the registration updates, and therefore we would like the solution to be specific to these requests. By changing the CONFIG_COAP values globally, we will be affecting all other lwm2m/COAP requests, which is something we rather not do.

Maybe I am missing something, but why would we want to change the timeout for every single type of request when it is only one specific type of request that is problematic for us?

[SeppoTakalo]

Matias Marti said:

The issue we are dealing with is specific to the registration updates, and therefore we would like the solution to be specific to these requests.

I would like to disagree with this claim. If you think about the communication layers

When LwM2M messages are not going through, then there is problem on the CoAP layer. If CoAP messages are not going through, there is problem in DTLS layer. And same goes to DTLS; UDP, IP, etc..

So if you cannot see response to messages on certain level, you cannot expect the layer below it works. On all confirmable CoAP messages, the server must respond. If it denies the request, it send either CoAP RESET or respond with a valid error code.

All LwM2M messages are confirmable CoAP messages, so there must be a response.

If you cannot see response for LwM2M Update message, then there must be a problem with the communication channel, either DTLS or UDP.

• CoAP can only fail, if any of the layer below fails or there is too much packet loss.
• DTLS can fail, if server has dropped the connection and is ignoring our messages.
• UDP can fail if NAT mapping times out and server is therefore ignoring our messages.
• IP and all layers below it can fail on various reasons.

So my opinion is that registration failures are symptoms, not the root cause. If you tweak the solution around it, you might just hide the problem for now and cause issues somewhere else.

Wireshark capture might reveal what the issue was.

In the mean time try

CONFIG_LTE_PSM_REQ=n
CONFIG_LTE_EDRX_REQ=n
CONFIG_LWM2M_UPDATE_PERIOD=20
CONFIG_LWM2M_DTLS_CID=y
CONFIG_LWM2M_TLS_SESSION_CACHING=y
CONFIG_LWM2M_RD_CLIENT_LISTEN_AT_IDLE=y

And make sure you have latest modem firmware so DTLS CID is able to work, also verify from Wireshark that Leshan also supports it.

[Matias Marti]

So today, Tue 3 Sep around 08:33 GMT, we captured these logs through Wireshark:

"457","136.143577","","","AT","16","Rcvd AT Command: OK "

"458","136.144005","","","AT","22","Sent AT Command: AT+CSCON=1"

"459","136.144005","","","AT","16","Rcvd AT Command: OK "

"460","136.144401","","","AT","21","Sent AT Command: AT+CFUN=1"

"461","136.175651","","","AT","16","Rcvd AT Command: OK "

"462","142.327901","","","AT","30","Sent AT Command: AT%XMODEMTRACE=1,2"

"463","142.328725","","","AT","16","Rcvd AT Command: OK "

"464","142.335225","","","AT","34","Sent AT Command: AT%XSYSTEMMODE=1,0,0,0"

"465","142.336934","","","AT","16","Rcvd AT Command: OK "

"466","142.337330","","","AT","46","Sent AT Command: AT+CPSMS=1,,,""00000110"",""00001111"""

"467","142.337453","","","AT","16","Rcvd AT Command: OK "

"468","142.338002","","","AT","19","Rcvd AT Command: ERROR "

"469","142.338399","","","AT","32","Sent AT Command: AT+CEDRXS=2,4,""0001"""

"470","142.338490","","","AT","16","Rcvd AT Command: OK "

"471","142.338887","","","AT","28","Sent AT Command: AT%XPTW=4,""0000"""

"472","142.338978","","","AT","16","Rcvd AT Command: OK "

"473","142.339345","","","AT","32","Sent AT Command: AT+CEDRXS=2,5,""0000"""

"474","142.339375","","","AT","16","Rcvd AT Command: OK "

"475","142.339772","","","AT","28","Sent AT Command: AT%XPTW=5,""0000"""

"476","142.339802","","","AT","16","Rcvd AT Command: OK "

"477","142.340321","","","AT","20","Sent AT Command: AT%RAI=0"

"478","142.340352","","","AT","16","Rcvd AT Command: OK "

"479","142.340748","","","AT","20","Sent AT Command: AT+CMEE?"

"480","142.340779","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

"481","142.347340","","","AT","21","Sent AT Command: AT+CMEE=1"

"482","142.347371","","","AT","16","Rcvd AT Command: OK "

"483","142.347798","","","AT","19","Sent AT Command: AT%CMNG"

"484","142.350331","","","AT","29","Rcvd AT Command: +CME ERROR: 513 "

"485","142.350728","","","AT","21","Sent AT Command: AT+CMEE=0"

"486","142.350758","","","AT","16","Rcvd AT Command: OK "

"487","142.351369","","","AT","19","Sent AT Command: AT+CGSN"

"488","142.351430","","","AT","33","Rcvd AT Command: 350457792623843 OK "

"489","142.352132","","","AT","24","Sent AT Command: AT%HWVERSION"

"490","142.352254","","","AT","46","Rcvd AT Command: %HWVERSION: nRF9160 SIAA B1A OK "

"491","142.392537","","","AT","20","Sent AT Command: AT+CMEE?"

"492","142.392537","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

"493","142.392995","","","AT","21","Sent AT Command: AT+CMEE=1"

"494","142.392995","","","AT","16","Rcvd AT Command: OK "

"495","142.393452","","","AT","19","Sent AT Command: AT%CMNG"

"496","142.422169","","","AT","16","Rcvd AT Command: OK "

"497","142.422627","","","AT","21","Sent AT Command: AT+CMEE=0"

"498","142.422627","","","AT","16","Rcvd AT Command: OK "

"499","142.423054","","","AT","20","Sent AT Command: AT+CMEE?"

"500","142.423085","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

"501","142.423482","","","AT","21","Sent AT Command: AT+CMEE=1"

"502","142.423512","","","AT","16","Rcvd AT Command: OK "

"503","142.423939","","","AT","19","Sent AT Command: AT%CMNG"

"504","142.452687","","","AT","16","Rcvd AT Command: OK "

"505","142.453145","","","AT","21","Sent AT Command: AT+CMEE=0"

"506","142.453145","","","AT","16","Rcvd AT Command: OK "

"507","142.453572","","","AT","20","Sent AT Command: AT+CMEE?"

"508","142.453602","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

"509","142.460164","","","AT","21","Sent AT Command: AT+CMEE=1"

"510","142.460194","","","AT","16","Rcvd AT Command: OK "

"511","142.460591","","","AT","19","Sent AT Command: AT%CMNG"

"512","142.489369","","","AT","16","Rcvd AT Command: OK "

"513","142.489827","","","AT","21","Sent AT Command: AT+CMEE=0"

"514","142.489827","","","AT","16","Rcvd AT Command: OK "

"515","142.526112","","","AT","20","Sent AT Command: AT+CMEE?"

"516","142.526112","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

"517","142.532704","","","AT","21","Sent AT Command: AT+CMEE=1"

"518","142.532735","","","AT","16","Rcvd AT Command: OK "

"519","142.533192","","","AT","19","Sent AT Command: AT%CMNG"

"520","142.561970","","","AT","16","Rcvd AT Command: OK "

"521","142.562428","","","AT","21","Sent AT Command: AT+CMEE=0"

"522","142.562428","","","AT","16","Rcvd AT Command: OK "

"523","142.668873","","","AT","21","Sent AT Command: AT+CEREG?"

"524","142.668965","","","AT","29","Rcvd AT Command: +CEREG: 0,4 OK "

"525","142.669392","","","AT","20","Sent AT Command: AT+CFUN?"

"526","142.669453","","","AT","26","Rcvd AT Command: +CFUN: 0 OK "

"527","142.669881","","","AT","22","Sent AT Command: AT+CEREG=5"

"528","142.669911","","","AT","16","Rcvd AT Command: OK "

"529","142.670430","","","AT","36","Sent AT Command: AT%XT3412=1,5000,1200000"

"530","142.670460","","","AT","16","Rcvd AT Command: OK "

"531","142.670918","","","AT","22","Sent AT Command: AT+CSCON=1"

"532","142.670918","","","AT","16","Rcvd AT Command: OK "

"533","142.671315","","","AT","21","Sent AT Command: AT+CFUN=1"

"534","142.702687","","","AT","16","Rcvd AT Command: OK "

"535","143.473561","","","LTE RRC DL_SCH","117","SystemInformationBlockType1"

"536","143.519642","","","LTE RRC DL_SCH","117","SystemInformation [ SIB2 SIB3 ]"

"537","443.552145","","","AT","30","Sent AT Command: AT%XMODEMTRACE=1,2"

"538","443.552969","","","AT","16","Rcvd AT Command: OK "

"539","443.553457","","","AT","34","Sent AT Command: AT%XSYSTEMMODE=1,0,0,0"

"540","443.555166","","","AT","16","Rcvd AT Command: OK "

"541","443.555563","","","AT","46","Sent AT Command: AT+CPSMS=1,,,""00000110"",""00001111"""

"542","443.555685","","","AT","16","Rcvd AT Command: OK "

"543","443.556234","","","AT","19","Rcvd AT Command: ERROR "

"544","443.556631","","","AT","32","Sent AT Command: AT+CEDRXS=2,4,""0001"""

"545","443.556723","","","AT","16","Rcvd AT Command: OK "

"546","443.563131","","","AT","28","Sent AT Command: AT%XPTW=4,""0000"""

"547","443.563223","","","AT","16","Rcvd AT Command: OK "

"548","443.563620","","","AT","32","Sent AT Command: AT+CEDRXS=2,5,""0000"""

"549","443.563650","","","AT","16","Rcvd AT Command: OK "

"550","443.564047","","","AT","28","Sent AT Command: AT%XPTW=5,""0000"""

"551","443.564077","","","AT","16","Rcvd AT Command: OK "

"552","443.564596","","","AT","20","Sent AT Command: AT%RAI=0"

"553","443.564627","","","AT","16","Rcvd AT Command: OK "

"554","443.565023","","","AT","20","Sent AT Command: AT+CMEE?"

"555","443.565054","","","AT","26","Rcvd AT Command: +CMEE: 0 OK "

We will not be able to provide your with the full logs here because of security reasons. However, it is interesting to see that at entry 536 (143 s after 08:33 ) there is no more logs until the watchdog kicks in at 573 (5 minutes after entry 536 ).

Here is a part of the logs from our Leshan server:

2024-09-03T08:32:21.870346474Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:32:21.871047635Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:32:21.871058483Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:32:35.711550532Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#4] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:32:35.711585469Z - Updated receive window with sequence number [56]: new upper boundary [56], new bit vector [111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:32:35.713250473Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:32:35.713261494Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<MY_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:32:35.713266901Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:32:35.713271063Z - Dispatching UPDATED event from endpoint <MY_DEVICE>

2024-09-03T08:32:41.308167383Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#5] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:32:41.308198335Z - Updated receive window with sequence number [2878]: new upper boundary [2878], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:32:41.310311673Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:32:41.310326868Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:32:41.310919136Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:32:41.310929923Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:32:55.149629159Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#1] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:32:55.149658003Z - Updated receive window with sequence number [57]: new upper boundary [57], new bit vector [1111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:32:55.151266445Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:32:55.151277885Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<MY_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:32:55.151290799Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:32:55.151295040Z - Dispatching UPDATED event from endpoint <MY_DEVICE>

2024-09-03T08:33:00.668352512Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#3] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:33:00.668385496Z - Updated receive window with sequence number [2879]: new upper boundary [2879], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:33:00.670205199Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:33:00.670221346Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxxby RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:33:00.670227034Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:33:00.670231204Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:33:14.591684922Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#2] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:33:14.591719922Z - Updated receive window with sequence number [58]: new upper boundary [58], new bit vector [11111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:33:14.593289049Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:33:14.593300720Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<MY_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:33:14.593306013Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:33:14.593310286Z - Dispatching UPDATED event from endpoint <MY_DEVICE>

2024-09-03T08:33:20.035205405Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#4] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:33:20.035237700Z - Updated receive window with sequence number [2880]: new upper boundary [2880], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:33:20.039082463Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:33:20.039098124Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:33:20.039103674Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:33:20.039107919Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:33:39.395464146Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#5] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:33:39.395505894Z - Updated receive window with sequence number [2881]: new upper boundary [2881], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:33:39.398320629Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:33:39.398336298Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:33:39.398341549Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:33:39.398345621Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:33:58.828434694Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#1] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:33:58.828468411Z - Updated receive window with sequence number [2882]: new upper boundary [2882], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:33:58.830074886Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:33:58.830089843Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:33:58.830095358Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:33:58.830099536Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:34:18.188468784Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#3] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:34:18.188500726Z - Updated receive window with sequence number [2883]: new upper boundary [2883], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:34:18.190197737Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:34:18.190213112Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:34:18.190218550Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:34:18.190222728Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:34:37.628483161Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#2] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:34:37.628520857Z - Updated receive window with sequence number [2884]: new upper boundary [2884], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:34:37.630136697Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

2024-09-03T08:34:37.630152299Z - Updated registration org.eclipse.leshan.server.registration.UpdatedRegistration@xxxx by RegistrationUpdate [registrationId=<REG_ID>, identity=Identity /<IP_ADDRESS>:<PORT>[psk=<OTHER_DEVICE>], lifeTimeInSec=null, smsNumber=null, bindingMode=null, objectLinks=null]

2024-09-03T08:34:37.630166175Z [CoapServer(main)#1] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:34:37.630170366Z - Dispatching UPDATED event from endpoint <OTHER_DEVICE>

2024-09-03T08:34:47.599038933Z [Presence Service] DEBUG c.q.iot.servlet.EventServlet

2024-09-03T08:34:47.599071673Z - Dispatching SLEEPING event from endpoint <MY_DEVICE>

2024-09-03T08:34:57.068415605Z [DTLS-Worker-0.0.0.0/0.0.0.0:5684#4] DEBUG o.e.c.s.dtls.DTLSSession

2024-09-03T08:34:57.068446187Z - Updated receive window with sequence number [2885]: new upper boundary [2885], new bit vector [1111111111111111111111111111111111111111111111111111111111111111]

2024-09-03T08:34:57.070463768Z [CoapServer(main)#1] DEBUG o.e.l.s.r.RegistrationHandler

We can see that Leshan considers the device to have fallen asleep 93s after its last (successful) registration update.

We also managed to capture logs through Cellular Monitor. How would you like us to send the .mtrace file? We would rather not do it here in the forum, since these logs might contain sensitive data.

In the meantime, we will try the other config values that you suggested SeppoTakalo 

[SeppoTakalo]

I see that you still have these quite agressive power saving settings enabled:

Request active time of 30s, then sleep for one hour.

AT+CPSMS=1,,,""00000110"",""00001111"""

Request eDRX cycle of 10.24s.

AT+CEDRXS=2,4,""0001"""

Request paging time window of 1.28s.

AT%XPTW=5,""0000"""

AT%XPTW=4,""0000"""

 

I don't think this is a root case, but it may cause timeout issues.

If you are willing to share the .pcap or .mtrace file, you can send me an email. firstname.surname at nordicsemi.no.
first= seppo, surname=takalo.

[Matias Marti]

Thank you SeppoTakalo 

# Configure PSM mode

CONFIG_LTE_PSM_REQ=y

# Request periodic TAU of 3600 seconds (60 minutes)

CONFIG_LTE_PSM_REQ_RPTAU="00000110"

# Set Requested Active Time (RAT) to 30 seconds. Preferably same as the

# configured LWM2M_QUEUE_MODE_UPTIME. Due to NAT/firewall UDP connections are usually

# closed within 30-60 seconds so there is in general no point in setting a longer

# Queue mode uptime / LTE PSM active time.

CONFIG_LTE_PSM_REQ_RAT="00001111"

# Request eDRX mode

CONFIG_LTE_EDRX_REQ=y

# Requested eDRX cycle length for LTE-M and Nb-IoT

# This should be fine-tuned for the network and the chosen server.

# Lowest value is the most responsive, but uses more energy during the active eDRX period.

# Longer period may cause more CoAP packet drops on server requests.

# "0000" is 5.12 s

# "0001" is 10.24 s

# "0010" is 20.48 s.

CONFIG_LTE_EDRX_REQ_VALUE_LTE_M="0001"

Do you think we could try to do anything more than disable PSM mode as well as eDRX (and the other flags that you suggested earlier)? What other values concerning power saving could we disable?

[SeppoTakalo]

Try first disabling both PSM and eDRX.

Then if you proceed later on, consider if eDRX can bring some power saving.
See https://academy.nordicsemi.com/courses/cellular-iot-fundamentals/lessons/lesson-1-cellular-fundamentals/topic/lesson-1-power-saving-techniques/

[Matias Marti]

Thank you.

We have now set those config values, and we have managed to extract some more logs as well. We are getting a lot of "X messages dropped", but we hope these logs can tell us something more of value.

Her we have the logs from 00:40 - 00:49 + first restart logs. This is a board that has around -105/-111 dBm:

uart:~$ [00:40:04.797,943] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:40:04.797,973] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:40:04.798,034] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:40:04.798,187] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:40:04.798,217] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:40:04.798,248] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:40:04.798,248] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:40:04.798,278] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:40:04.898,071] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:40:04.898,132] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:40:04.898,162] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:40:05.292,388] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 26,1,19,2
uart:~$ [00:40:05.292,449] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:40:07.852,905] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,14,2
uart:~$ [00:40:07.852,935] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 45 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 93 messages dropped ---
uart:~$ [00:40:18.626,708] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:40:18.626,770] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:40:18.626,770] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:40:20.896,148] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,9,1
uart:~$ [00:40:20.896,209] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:40:24.070,770] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:40:24.070,800] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:40:24.070,831] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:40:24.071,014] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:40:24.071,044] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:40:24.071,044] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:40:24.071,075] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:40:24.071,075] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:40:24.170,898] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:40:24.170,959] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:40:24.170,959] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:40:24.493,774] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:40:24.493,804] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:40:27.053,894] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,12,1
uart:~$ [00:40:27.053,924] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 100 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ [00:40:43.592,651] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:40:43.592,681] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:40:43.592,712] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:40:43.592,895] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:40:43.592,895] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:40:43.592,926] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:40:43.592,926] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:40:43.592,956] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:40:43.692,749] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:40:43.692,840] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:40:43.692,871] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:40:44.334,838] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:40:44.334,869] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 43 messages dropped ---
uart:~$ --- 40 messages dropped ---
uart:~$ --- 70 messages dropped ---
uart:~$ --- 100 messages dropped ---
uart:~$ [00:40:57.548,614] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:40:57.548,645] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:41:02.952,423] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:41:02.952,423] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:41:02.952,453] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:41:02.952,636] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:41:02.952,667] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:41:02.952,697] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:41:02.952,697] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:41:02.952,728] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:41:03.052,520] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:41:03.052,581] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:41:03.052,642] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:41:04.815,338] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:41:04.815,399] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:41:04.815,612] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 97 messages dropped ---
uart:~$ --- 3 messages dropped ---
uart:~$ [00:41:16.899,475] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:41:16.899,536] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:41:22.083,221] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:41:22.083,251] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:41:22.083,282] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:41:22.083,465] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:41:22.083,496] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:41:22.083,496] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:41:22.083,526] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:41:22.083,557] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:41:22.183,349] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:41:22.183,410] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:41:22.183,441] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:41:25.296,203] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:41:25.296,264] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 45 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ [00:41:36.069,946] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ --- 88 messages dropped ---
[00:41:36.070,007] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:41:36.070,007] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:41:36.170,166] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:41:36.170,166] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:41:36.170,196] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:41:36.170,379] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:41:36.170,379] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:41:36.170,410] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:41:36.170,440] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:41:36.170,440] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:41:41.777,313] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:41:41.777,343] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:41:41.777,374] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:41:41.777,587] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:41:41.777,587] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:41:41.777,618] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:41:41.777,618] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:41:41.777,648] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:41:41.877,441] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:41:41.877,502] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:41:41.877,563] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:41:41.977,569] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,12,1
uart:~$ [00:41:41.977,630] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 42 messages dropped ---
uart:~$ --- 40 messages dropped ---
uart:~$ --- 71 messages dropped ---
uart:~$ --- 2 messages dropped ---
uart:~$ --- 93 messages dropped ---
uart:~$ [00:41:55.600,769] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:41:55.600,799] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:41:55.600,830] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:01.194,854] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:42:01.194,885] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:42:01.194,915] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:42:01.195,098] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:42:01.195,129] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:42:01.195,159] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:42:01.195,159] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:42:01.195,190] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:42:01.294,982] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:42:01.295,043] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:01.295,074] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:06.257,812] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,5,0
uart:~$ [00:42:06.257,873] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:42:06.258,087] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ [00:42:07.537,872] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,10,1
uart:~$ [00:42:07.537,963] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:42:08.818,176] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,15,2
uart:~$ [00:42:08.818,237] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ --- 39 messages dropped ---
uart:~$ --- 46 messages dropped ---
uart:~$ --- 70 messages dropped ---
uart:~$ --- 87 messages dropped ---
uart:~$ [00:42:15.131,622] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:42:15.131,652] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:15.131,683] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:15.231,811] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:42:15.231,842] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:42:15.231,872] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:42:15.232,055] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:42:15.232,055] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:42:15.232,086] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:42:20.795,715] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:42:20.795,745] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:42:20.795,776] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:42:20.795,959] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:42:20.795,989] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:42:20.795,989] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:42:20.796,020] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:42:20.796,051] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:42:20.895,843] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:42:20.895,874] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:20.895,904] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:20.978,698] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:42:20.978,729] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 43 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 92 messages dropped ---
uart:~$ [00:42:34.622,406] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:42:34.622,467] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:34.622,497] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:34.822,753] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,11,1
uart:~$ [00:42:34.822,814] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:42:40.164,520] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:42:40.164,550] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:42:40.164,581] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:42:40.164,764] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:42:40.164,794] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:42:40.164,794] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:42:40.164,825] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:42:40.164,855] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:42:40.264,678] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:42:40.264,739] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:40.264,770] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:40.819,549] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:42:40.819,580] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 40 messages dropped ---
uart:~$ --- 70 messages dropped ---
uart:~$ --- 92 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ [00:42:54.073,242] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:42:54.073,272] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:54.073,303] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:42:54.273,498] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,10,1
uart:~$ [00:42:54.273,559] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:42:59.509,338] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:42:59.509,368] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:42:59.509,399] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:42:59.509,582] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:42:59.509,613] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:42:59.509,643] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:42:59.509,643] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:42:59.509,674] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:42:59.609,497] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:42:59.609,558] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:42:59.609,588] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:43:00.020,294] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 26,1,19,2
uart:~$ [00:43:00.020,355] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 93 messages dropped ---
uart:~$ --- 7 messages dropped ---
uart:~$ [00:43:13.504,058] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:43:13.504,119] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:43:13.504,119] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:43:13.704,406] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,11,1
uart:~$ [00:43:13.704,467] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:43:13.704,711] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ [00:43:19.135,223] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:43:19.135,253] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:43:19.135,284] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:43:19.135,467] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:43:19.135,467] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:43:19.135,498] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:43:19.135,528] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:43:19.135,528] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:43:19.235,351] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:43:19.235,412] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:43:19.235,443] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:43:19.335,479] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,19,2
uart:~$ [00:43:19.335,510] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:43:20.501,220] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,14,2
uart:~$ [00:43:20.501,251] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 43 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 86 messages dropped ---
uart:~$ [00:43:32.964,904] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:43:32.964,935] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:43:32.964,965] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:43:33.064,971] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:43:33.065,002] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:43:33.065,032] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:43:33.065,216] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:43:33.065,216] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:43:33.065,246] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:43:35.056,335] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,9,1
uart:~$ [00:43:35.056,396] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:43:36.976,379] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,4,0
uart:~$ [00:43:36.976,440] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:43:39.942,108] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:43:39.942,108] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:43:39.942,138] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:43:39.942,321] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:43:39.942,352] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:43:39.942,382] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:43:39.942,413] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:43:39.942,413] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:43:40.042,236] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:43:40.042,297] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:43:40.042,327] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:43:40.342,254] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,19,2
uart:~$ [00:43:40.342,315] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 97 messages dropped ---
uart:~$ --- 2 messages dropped ---
uart:~$ [00:43:52.586,059] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:43:52.586,151] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:43:57.999,816] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:43:57.999,847] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:43:57.999,847] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:43:58.000,061] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:43:58.000,061] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:43:58.000,091] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:43:58.000,091] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:43:58.000,122] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:43:58.099,945] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:43:58.099,975] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:43:58.100,006] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:44:02.103,179] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:44:02.103,240] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 96 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 2 messages dropped ---
uart:~$ [00:44:11.957,489] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,11,1
uart:~$ [00:44:11.957,519] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:44:17.288,635] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:44:17.288,665] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:44:17.288,665] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:44:17.288,879] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:44:17.288,879] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:44:17.288,909] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:44:17.288,909] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:44:17.288,940] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:44:17.388,763] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:44:17.388,824] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:44:17.388,854] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:44:19.383,300] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:44:19.383,361] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:44:19.383,575] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ uart:~$ --- 47 messages dropped ---
uart:~$ --- 41 messages dropped ---
uart:~$ --- 69 messages dropped ---
uart:~$ --- 100 messages dropped ---
uart:~$ --- 3 messages dropped ---
uart:~$ [00:44:31.307,678] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,11,1
uart:~$ [00:44:31.307,739] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:44:36.591,247] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:44:36.591,278] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:44:36.591,308] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:44:36.591,491] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:44:36.591,522] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:44:36.591,552] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:44:36.591,552] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:44:36.591,583] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:44:36.691,375] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:44:36.691,436] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:44:36.691,467] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:44:39.864,166] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,16,2
uart:~$ [00:44:39.864,227] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 45 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 97 messages dropped ---
uart:~$ [00:44:50.678,405] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,10,1
uart:~$ [00:44:50.678,466] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:44:55.852,264] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:44:55.852,264] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:44:55.852,294] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:44:55.852,478] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:44:55.852,508] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:44:55.852,539] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:44:55.852,539] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:44:55.852,569] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:44:55.952,362] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:44:55.952,423] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:44:55.952,484] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:00.345,031] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:45:00.345,092] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 92 messages dropped ---
uart:~$ [00:45:09.919,006] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:45:09.919,036] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:09.919,067] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:10.119,232] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,11,1
uart:~$ [00:45:10.119,262] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:45:15.523,101] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:45:15.523,132] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:45:15.523,162] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:45:15.523,345] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:45:15.523,345] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:45:15.523,376] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:45:15.523,406] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:45:15.523,406] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:45:15.623,199] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:45:15.623,260] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:15.623,291] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:21.466,339] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,16,2
uart:~$ [00:45:21.466,369] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:45:21.466,583] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ uart:~$ --- 48 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 91 messages dropped ---
uart:~$ [00:45:29.359,832] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:45:29.359,863] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:29.359,893] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:29.459,930] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:45:29.560,028] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,10,1
uart:~$ [00:45:29.560,089] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:45:34.811,920] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:45:34.811,950] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:45:34.811,950] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:45:34.812,164] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:45:34.812,164] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:45:34.812,194] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:45:34.812,225] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:45:34.812,225] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:45:34.912,017] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:45:34.912,078] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:34.912,139] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:35.544,769] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,15,2
uart:~$ [00:45:35.544,830] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 45 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 92 messages dropped ---
uart:~$ [00:45:48.790,649] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:45:48.790,710] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:48.790,710] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:48.890,899] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:45:49.630,035] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,10,1
uart:~$ [00:45:49.630,096] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:45:54.404,724] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:45:54.404,785] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:45:54.404,815] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:45:54.404,968] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:45:54.404,998] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:45:54.404,998] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:45:54.405,029] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:45:54.405,059] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:45:54.504,852] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:45:54.504,913] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:45:54.504,943] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:45:54.747,833] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,15,2
uart:~$ [00:45:54.747,894] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 41 messages dropped ---
uart:~$ --- 70 messages dropped ---
uart:~$ --- 94 messages dropped ---
uart:~$ [00:46:08.241,455] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:46:08.241,516] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:08.241,516] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:08.441,711] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,8,1
uart:~$ [00:46:08.441,741] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:46:13.773,559] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:46:13.773,590] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:46:13.773,620] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:46:13.773,803] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:46:13.773,803] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:46:13.773,834] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:46:13.773,864] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:46:13.773,864] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:46:13.873,687] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:46:13.873,748] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:13.873,779] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:13.948,303] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:46:13.948,364] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 42 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 93 messages dropped ---
uart:~$ --- 5 messages dropped ---
uart:~$ [00:46:27.672,271] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:46:27.672,302] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:27.672,332] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:27.872,619] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,11,1
uart:~$ [00:46:27.872,650] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:46:27.872,894] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ [00:46:32.224,792] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,6,0
uart:~$ [00:46:32.224,822] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:46:33.279,418] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:46:33.279,449] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:46:33.279,479] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:46:33.279,663] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:46:33.279,693] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:46:33.279,693] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:46:33.279,724] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:46:33.279,724] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:46:33.381,958] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:46:33.382,049] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:33.382,080] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:33.789,337] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 26,1,19,2
uart:~$ [00:46:33.789,398] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 43 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 95 messages dropped ---
uart:~$ [00:46:47.053,161] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:46:47.053,192] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:47.053,222] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:52.727,203] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:46:52.727,233] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:46:52.727,233] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:46:52.727,447] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:46:52.727,447] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:46:52.727,478] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:46:52.727,478] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:46:52.727,508] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:46:52.827,301] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:46:52.827,362] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:46:52.827,392] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:46:52.989,929] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 26,1,18,2
uart:~$ [00:46:52.990,020] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 95 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 3 messages dropped ---
uart:~$ [00:47:06.674,285] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:47:06.674,316] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:47:12.088,012] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:47:12.088,043] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:47:12.088,104] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:47:12.088,256] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:47:12.088,287] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:47:12.088,287] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:47:12.088,317] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:47:12.088,348] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:47:12.188,140] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:47:12.188,201] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:47:12.188,201] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:47:23.711,486] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,19,2
uart:~$ [00:47:23.711,547] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ --- 95 messages dropped ---
uart:~$ [00:47:25.874,847] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:47:25.874,877] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:47:25.874,908] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:47:25.976,226] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:47:31.304,840] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:47:31.304,870] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:47:31.304,870] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:47:31.305,084] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:47:31.305,084] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:47:31.305,114] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:47:31.305,145] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:47:31.305,145] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:47:31.404,998] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:47:31.405,029] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:47:31.405,059] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:47:33.951,782] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:47:33.951,843] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:47:33.952,056] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ [00:47:44.192,352] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 26,1,9,1
uart:~$ [00:47:44.192,413] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ [00:47:45.365,600] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:47:45.365,661] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:47:45.365,692] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:47:45.465,728] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:47:45.465,759] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:47:45.465,789] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:47:45.465,972] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:47:45.466,003] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:47:45.466,033] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:47:45.466,064] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:47:45.466,094] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ --- 87 messages dropped ---
uart:~$ [00:47:45.971,923] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,2,0
uart:~$ [00:47:45.971,954] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:47:49.715,118] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,7,1
uart:~$ [00:47:49.715,148] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:47:51.301,025] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:47:51.301,086] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:47:51.301,086] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:47:51.301,269] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:47:51.301,300] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:47:51.301,300] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:47:51.301,330] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:47:51.301,361] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ [00:47:51.401,184] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:47:51.401,245] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:47:51.401,275] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:47:51.501,281] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,12,1
uart:~$ [00:47:51.501,312] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:47:54.432,952] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:47:54.432,983] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 111 messages dropped ---
uart:~$ [00:48:05.156,402] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:48:05.156,433] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:48:05.156,463] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:48:05.256,622] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:48:05.256,652] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:48:05.256,683] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:48:05.256,835] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:48:05.256,866] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:48:05.256,896] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:48:05.256,896] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:48:05.256,927] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ --- 80 messages dropped ---
[00:48:05.356,781] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:48:05.356,842] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:48:10.724,517] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:48:10.724,548] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:48:10.724,578] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:48:10.724,761] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:48:10.724,761] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:48:10.724,822] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:48:10.724,822] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:48:10.724,853] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:48:10.825,988] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:48:10.826,049] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:48:10.826,049] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:48:16.833,618] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:48:16.833,648] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 40 messages dropped ---
uart:~$ --- 71 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 98 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ [00:48:24.837,249] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:48:25.041,870] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,12,1
uart:~$ [00:48:25.041,900] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:48:30.266,143] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:48:30.266,174] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:48:30.266,204] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:48:30.266,357] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:48:30.266,418] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:48:30.266,418] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:48:30.266,448] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:48:30.266,479] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:48:30.366,302] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:48:30.366,333] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:48:30.366,363] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:48:37.314,605] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,17,2
uart:~$ [00:48:37.314,666] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:48:37.314,880] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x200398a6, len:2
uart:~$ uart:~$ --- 48 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ [00:48:44.338,073] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ --- 85 messages dropped ---
[00:48:44.338,134] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:48:44.338,134] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:48:44.438,140] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:48:44.438,171] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:48:44.438,201] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:48:44.438,415] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:48:44.438,415] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:48:44.438,446] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:48:44.438,476] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:48:44.438,507] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:48:49.933,197] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:48:49.933,227] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:48:49.933,227] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:48:49.933,441] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:48:49.933,441] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:48:49.933,471] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:48:49.933,502] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:48:49.933,502] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:48:50.033,355] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:48:50.033,386] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:48:50.033,416] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:48:55.875,396] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:48:55.875,427] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 44 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 91 messages dropped ---
uart:~$ --- 2 messages dropped ---
uart:~$ [00:49:03.838,867] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:49:03.838,928] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:49:03.838,958] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:49:03.939,117] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:49:04.039,245] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 23,1,10,1
uart:~$ [00:49:04.039,276] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:49:09.222,961] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:49:09.222,991] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:49:09.223,022] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:49:09.223,205] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:49:09.223,205] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:49:09.223,236] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:49:09.223,266] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:49:09.223,266] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:49:09.323,181] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:49:09.323,211] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:49:09.323,242] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:49:09.323,455] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,19,2
uart:~$ [00:49:09.323,547] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ --- 46 messages dropped ---
uart:~$ --- 112 messages dropped ---
uart:~$ --- 1 messages dropped ---
uart:~$ --- 90 messages dropped ---
uart:~$ [00:49:23.289,703] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:49:23.289,733] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:49:23.289,794] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:49:23.389,801] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:49:23.389,831] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:49:23.489,898] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 24,1,11,1
uart:~$ [00:49:23.489,959] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ [00:49:28.893,798] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:49:28.893,829] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39ded
uart:~$ [00:49:28.893,859] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:49:28.894,042] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:49:28.894,073] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003CCF5
uart:~$ [00:49:28.894,073] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00041091
uart:~$ [00:49:28.894,104] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:49:28.894,134] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:49:28.993,927] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 86399999
uart:~$ [00:49:28.993,988] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39c9d
uart:~$ [00:49:28.994,018] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:49:36.837,493] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 25,1,18,2
uart:~$ [00:49:36.837,554] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3c265
uart:~$ uart:~$ *** Booting nRF Connect SDK v3.5.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Image index: 0, Swap type: none
I: Bootloader chainload address offset: 0x10000
I: Jumping to the first image slot
�

[SeppoTakalo]

Too much debug logs from lte_lc and at_monitor. Those hide most of the relevant stuff.

All that you can see that it repeats a cycle of about 20 seconds.

CSCON: 0 appears when connection has been idle for 5 seconds (depends on network). This is when the network releases the connection and starts idling.

%XT3412 notification looks like the network would allow 24 hours of sleep between Tracking area updates.

%CESQ is just a connection quality updates.

[Matias Marti]

Thank you @seppo . Here are some more interesing logs:

uart:~$ [00:49:29.217,254] <dbg> app_lwm2m_client: rd_client_event: Registration update complete
uart:~$ [00:49:29.217,285] <dbg> app_lwm2m_client: watchdog_Kick: Watchdog feed ok!
uart:~$ [00:49:29.217,376] <inf> net_lwm2m_rd_client: Update Done
uart:~$ [00:49:29.217,559] <dbg> net_lwm2m_message_handling: lwm2m_udp_receive: reply 0x2000d7c0 handled and removed
uart:~$ [00:49:29.217,620] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 9
uart:~$ [00:49:29.252,838] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 39,1,17,2
uart:~$ [00:49:29.252,899] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3bef9
uart:~$ uart:~$ [00:49:34.666,595] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:49:34.666,625] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:49:34.666,656] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:49:34.666,809] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:49:34.666,839] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:49:34.666,839] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:49:34.666,870] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:49:34.666,900] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:49:34.766,723] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 3239999
uart:~$ [00:49:34.766,754] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:49:34.766,815] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ uart:~$ [00:49:35.249,389] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 37,1,12,1
uart:~$ [00:49:35.249,450] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3bef9
uart:~$ uart:~$ *** Booting nRF Connect SDK v3.5.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x2, copy_done=0x1, image_ok=0x1
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Image index: 0, Swap type: none
I: Bootloader chainload address offset: 0x10000
I: Jumping to the first image slot
�

uart:~$ [00:00:00.252,258] <dbg> clock_control: clkstarted_handle: lfclk: Clock started
uart:~$ *** Booting nRF Connect SDK v3.5.99-ncs1 ***
uart:~$ [00:00:00.253,814] <dbg> net_lwm2m_obj_qlocx_manage: management_create: Create IPSO Management instance: 0
uart:~$ [00:00:00.253,845] <dbg> net_lwm2m_obj_qlocx_barcode: barcode_create: Create IPSO Barcode instance: 0
uart:~$ [00:00:00.254,577] <dbg> net_lwm2m_engine: lwm2m_engine_init: LWM2M engine socket receive thread started
uart:~$ [00:00:00.254,699] <dbg> net_lwm2m_obj_security: security_create: Create LWM2M security instance: 0
uart:~$ [00:00:00.254,821] <dbg> net_lwm2m_obj_device: device_create: Create LWM2M device instance: 0
uart:~$ [00:00:00.255,187] <dbg> net_lwm2m_obj_conn_mon: connmon_create: Create LWM2M connectivity monitoring instance: 0
uart:~$ [00:00:00.255,249] <dbg> net_lwm2m_obj_firmware: firmware_create: Create LWM2M firmware instance: 0
uart:~$ [00:00:00.255,798] <inf> app_lwm2m_client: Run LWM2M client
uart:~$ [00:00:00.255,828] <dbg> app_lwm2m_client: watchdog_Init: Watchdog started: 0
uart:~$ uart:~$ [00:00:00.487,518] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x3bdf9
uart:~$ [00:00:00.495,758] <dbg> lte_lc: lte_lc_system_mode_set: System mode set to 1, preference 0
uart:~$ [00:00:00.495,819] <dbg> lte_lc: lte_lc_psm_param_set: RPTAU set to 00000110
uart:~$ [00:00:00.495,849] <dbg> lte_lc: lte_lc_psm_param_set: RAT set to 00001111
uart:~$ [00:00:00.495,910] <dbg> lte_lc: on_modem_init: PSM configs set from string: tau=00000110, rat=00001111
uart:~$ [00:00:00.495,971] <dbg> lte_lc: lte_lc_psm_req: enable=0, tau=00000110, rat=00001111
uart:~$ [00:00:00.503,906] <inf> app_lwm2m_client: Clearing PSK
uart:~$ [00:00:00.533,843] <dbg> app_lwm2m_client: watchdog_Kick: Watchdog feed ok!
uart:~$ [00:00:00.533,905] <dbg> app_lwm2m_client: watchdog_Kick: Watchdog feed ok!
uart:~$ [00:00:00.534,606] <inf> app_lwm2m_client: endpoint: <MY_ENDPOINT>
uart:~$ [00:00:00.534,637] <dbg> app_lwm2m_client: watchdog_Kick: Watchdog feed ok!

We have noticed that the device keeps restarting every 49.5 minutes... Is there any value in prj.conf that might be causing this?

Another point:

It seems like disabling PSM mode prevents the device from disconnecting:

uart:~$ [00:25:43.377,349] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coaps://<MY_URL>:5684
uart:~$ uart:~$ uart:~$ [00:25:47.265,747] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:25:47.265,808] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:25:47.265,808] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:25:47.265,960] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:25:47.265,991] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:25:47.266,021] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:25:47.266,021] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:25:47.266,052] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:25:47.365,875] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 3239999
uart:~$ [00:25:47.365,905] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:25:47.365,966] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ uart:~$ [00:25:47.465,972] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:25:47.466,003] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:25:47.466,033] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:25:47.475,524] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fc3, buflen:1
uart:~$ [00:25:47.485,900] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:25:47.485,931] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:25:47.485,961] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:25:47.486,083] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:25:47.486,114] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:25:47.486,145] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:25:47.486,175] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:25:47.486,206] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ [00:25:47.667,907] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031f8b, buflen:1
uart:~$ [00:25:47.667,999] <dbg> lwm2m_security: load_credentials_to_modem: Existing credentials found on modem
uart:~$ [00:25:47.668,548] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fcb, buflen:1
uart:~$ [00:25:47.840,270] <inf> net_lwm2m_engine: Connected, sock id 2
uart:~$ [00:25:47.841,003] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20031ff0, buflen:4
uart:~$ [00:25:47.842,407] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [<MY_IP>]
uart:~$ [00:25:47.843,383] <dbg> app_lwm2m_client: rd_client_event: Disconnected
uart:~$ [00:25:47.843,505] <inf> net_lwm2m_rd_client: Stop LWM2M Client: <MY_ENDPOINT>
uart:~$ [00:25:47.845,031] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 17
uart:~$ [00:25:47.846,618] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 0
uart:~$ uart:~$ [00:25:47.929,077] <inf> app_lwm2m_client: Client connect to server
uart:~$ [00:25:47.929,168] <inf> net_lwm2m_rd_client: Start LWM2M Client: <MY_ENDPOINT>
uart:~$ [00:25:47.929,443] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 1
uart:~$ [00:25:47.929,779] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 6
uart:~$ [00:25:47.929,809] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20032020, buflen:4
uart:~$ [00:25:47.929,840] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/0/0, level 3, buf:0x20032040, buflen:2
uart:~$ [00:25:47.929,931] <inf> net_lwm2m_rd_client: RD Client started with endpoint '<MY_ENDPOINT>' with client lifetime 86400 using server object 0
uart:~$ [00:25:47.929,992] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coaps://<MY_URL>:5684
uart:~$ [00:25:47.930,633] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fc3, buflen:1
uart:~$ [00:25:48.056,610] <inf> app_lwm2m_client: LwM2M is connecting to server
uart:~$ uart:~$ [00:25:48.096,557] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031f8b, buflen:1
uart:~$ [00:25:48.096,649] <dbg> lwm2m_security: load_credentials_to_modem: Existing credentials found on modem
uart:~$ [00:25:48.097,198] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fcb, buflen:1
uart:~$ [00:25:48.258,239] <inf> net_lwm2m_engine: Connected, sock id 2
uart:~$ [00:25:48.258,819] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20031ff0, buflen:4
uart:~$ [00:25:48.260,192] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [<MY_IP>]
uart:~$ [00:25:48.262,390] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 8
uart:~$ [00:25:48.393,890] <dbg> net_lwm2m_rd_client: do_registration_reply_cb: Registration callback (code:2.1)
uart:~$ [00:25:48.394,592] <dbg> lte_lc: parse_psm: TAU: 3240 sec, active time: -1 sec
uart:~$ [00:25:48.394,622] <dbg> lte_lc: lte_lc_psm_get: TAU: 3240 sec, active time: -1 sec
uart:~$ [00:25:48.394,653] <dbg> lwm2m_sec_con_man: lwm2m_utils_update_rptau: PSM deactivated
uart:~$ [00:25:48.394,683] <dbg> app_lwm2m_client: rd_client_event: Registration complete
uart:~$ [00:25:48.394,805] <inf> net_lwm2m_rd_client: Registration Done (EP='XXXXXXX')
uart:~$ [00:25:48.394,989] <dbg> net_lwm2m_message_handling: lwm2m_udp_receive: reply 0x2000d7c0 handled and removed
uart:~$ [00:25:48.395,050] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 9
uart:~$ uart:~$ uart:~$ [00:25:48.477,661] <inf> app_lwm2m_client: LwM2M is connected to server
uart:~$ [00:25:48.477,722] <dbg> date_time: date_time_update_thread: Updating date time UTC...
uart:~$ [00:25:48.477,752] <dbg> date_time: date_time_update_thread: Using previously obtained time
uart:~$ [00:25:48.477,783] <inf> app_lwm2m_client: Obtained date-time from modem
uart:~$ [00:25:48.477,813] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:3/0/13, buf:0x2003275c, len:4
uart:~$ uart:~$ [00:25:52.857,696] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:25:52.857,727] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:25:52.857,757] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:25:52.857,910] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:25:52.857,910] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:25:52.857,940] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:25:52.857,971] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:25:52.857,971] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:25:52.957,794] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 3239999
uart:~$ [00:25:52.957,855] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:25:52.957,885] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ uart:~$ [00:25:53.120,452] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 34,1,17,2
uart:~$ [00:25:53.120,513] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3bef9
uart:~$ [00:25:53.120,727] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:4/0/2, buf:0x2003989e, len:2
uart:~$ uart:~$ [00:26:02.080,841] <dbg> at_monitor: at_monitor_task: AT notif: %CESQ: 33,1,12,1
uart:~$ [00:26:02.080,902] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3bef9
uart:~$ uart:~$ [00:26:07.393,768] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 9
uart:~$ [00:26:07.393,829] <dbg> app_lwm2m_client: rd_client_event: Registration update started
uart:~$ [00:26:07.493,347] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 11
uart:~$ [00:26:07.493,865] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20031ff8, buflen:4
uart:~$ [00:26:07.494,018] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [<MY_IP>]
uart:~$ [00:26:07.501,403] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 12
uart:~$ [00:26:07.604,492] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:26:07.604,522] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:26:07.604,553] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:26:07.704,925] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:26:07.704,986] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:26:07.705,017] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:26:07.705,169] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:26:07.705,200] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:26:07.705,200] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:26:07.705,230] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:26:07.705,230] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ uart:~$ [00:26:08.495,117] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 12
uart:~$ [00:26:08.495,147] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State machine have timed out
uart:~$ [00:26:08.495,239] <dbg> app_lwm2m_client: rd_client_event: Registration update failure!
uart:~$ [00:26:08.495,300] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 1
uart:~$ [00:26:08.502,868] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 6
uart:~$ [00:26:08.502,899] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20032020, buflen:4
uart:~$ [00:26:08.502,960] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/0/0, level 3, buf:0x20032040, buflen:2
uart:~$ [00:26:08.503,021] <inf> net_lwm2m_rd_client: RD Client started with endpoint '<MY_ENDPOINT>' with client lifetime 86400 using server object 0
uart:~$ [00:26:08.503,112] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coaps://<MY_URL>:5684
uart:~$ [00:26:08.503,784] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fc3, buflen:1
uart:~$ uart:~$ [00:26:08.641,876] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031f8b, buflen:1
uart:~$ [00:26:08.641,998] <dbg> lwm2m_security: load_credentials_to_modem: Existing credentials found on modem
uart:~$ [00:26:08.642,822] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fcb, buflen:1
uart:~$ [00:26:08.827,178] <inf> net_lwm2m_engine: Connected, sock id 2
uart:~$ [00:26:08.827,911] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20031ff0, buflen:4
uart:~$ [00:26:08.829,315] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [<MY_IP>]
uart:~$ [00:26:08.830,291] <dbg> app_lwm2m_client: rd_client_event: Disconnected
uart:~$ [00:26:08.830,413] <inf> net_lwm2m_rd_client: Stop LWM2M Client: <MY_ENDPOINT>
uart:~$ [00:26:08.831,481] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 17
uart:~$ [00:26:08.833,190] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 0
uart:~$ uart:~$ [00:26:08.916,229] <inf> app_lwm2m_client: Client connect to server
uart:~$ [00:26:08.916,290] <inf> net_lwm2m_rd_client: Start LWM2M Client: <MY_ENDPOINT>
uart:~$ [00:26:08.916,564] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 1
uart:~$ [00:26:08.916,900] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 6
uart:~$ [00:26:08.916,931] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20032020, buflen:4
uart:~$ [00:26:08.916,992] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/0/0, level 3, buf:0x20032040, buflen:2
uart:~$ [00:26:08.917,053] <inf> net_lwm2m_rd_client: RD Client started with endpoint '<MY_ENDPOINT>' with client lifetime 86400 using server object 0
uart:~$ [00:26:08.917,114] <dbg> net_lwm2m_message_handling: lwm2m_parse_peerinfo: Parse url: coaps://<MY_URL>:5684
uart:~$ [00:26:08.917,999] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fc3, buflen:1
uart:~$ [00:26:09.040,771] <inf> app_lwm2m_client: LwM2M is connecting to server
uart:~$ uart:~$ [00:26:09.082,366] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031f8b, buflen:1
uart:~$ [00:26:09.082,489] <dbg> lwm2m_security: load_credentials_to_modem: Existing credentials found on modem
uart:~$ [00:26:09.083,099] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:0/1/2/0, level 3, buf:0x20031fcb, buflen:1
uart:~$ [00:26:09.207,244] <inf> net_lwm2m_engine: Connected, sock id 2
uart:~$ [00:26:09.207,824] <dbg> net_lwm2m_registry: lwm2m_engine_get: path:1/0/1/0, level 3, buf:0x20031ff0, buflen:4
uart:~$ [00:26:09.209,197] <dbg> net_lwm2m_rd_client: sm_send_registration: registration sent [<MY_IP>]
uart:~$ [00:26:09.211,395] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 8
uart:~$ uart:~$ [00:26:13.028,656] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 0
uart:~$ [00:26:13.028,717] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:26:13.028,747] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:26:13.028,869] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:26:13.028,900] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:26:13.028,930] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:26:13.028,930] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:26:13.028,961] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ [00:26:13.128,784] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 3239999
uart:~$ [00:26:13.128,814] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:26:13.128,875] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ uart:~$ [00:26:15.004,791] <dbg> at_monitor: at_monitor_task: AT notif: %XT3412: 0
uart:~$ [00:26:15.004,821] <dbg> at_monitor: at_monitor_task: Dispatching to 0x3992d
uart:~$ [00:26:15.004,852] <dbg> lte_lc: at_handler_xt3412: %XT3412 notification
uart:~$ [00:26:15.105,010] <dbg> at_monitor: at_monitor_task: AT notif: +CSCON: 1
uart:~$ [00:26:15.105,041] <dbg> at_monitor: at_monitor_task: Dispatching to 0x39a7d
uart:~$ [00:26:15.105,072] <dbg> lte_lc: at_handler_cscon: +CSCON notification
uart:~$ [00:26:15.105,224] <dbg> lte_lc: event_handler_list_dispatch: Dispatching event: type=3
uart:~$ [00:26:15.105,224] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0003C989
uart:~$ [00:26:15.105,255] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x00040D25
uart:~$ [00:26:15.105,285] <dbg> lte_lc: event_handler_list_dispatch:  - handler=0x0001A8A5
uart:~$ [00:26:15.105,316] <dbg> lte_lc: event_handler_list_dispatch: Done
uart:~$ uart:~$ [00:26:15.150,085] <dbg> net_lwm2m_rd_client: do_registration_reply_cb: Registration callback (code:2.1)
uart:~$ [00:26:15.150,909] <dbg> lte_lc: parse_psm: TAU: 3240 sec, active time: -1 sec
uart:~$ [00:26:15.150,970] <dbg> lte_lc: lte_lc_psm_get: TAU: 3240 sec, active time: -1 sec
uart:~$ [00:26:15.151,000] <dbg> lwm2m_sec_con_man: lwm2m_utils_update_rptau: PSM deactivated
uart:~$ [00:26:15.151,000] <dbg> app_lwm2m_client: rd_client_event: Registration complete
uart:~$ [00:26:15.151,153] <inf> net_lwm2m_rd_client: Registration Done (EP='XXXXXXX')
uart:~$ [00:26:15.151,336] <dbg> net_lwm2m_message_handling: lwm2m_udp_receive: reply 0x2000d7c0 handled and removed
uart:~$ [00:26:15.151,397] <dbg> net_lwm2m_rd_client: lwm2m_rd_client_service: State: 9
uart:~$ [00:26:15.236,083] <inf> app_lwm2m_client: LwM2M is connected to server
uart:~$ [00:26:15.236,145] <dbg> date_time: date_time_update_thread: Updating date time UTC...
uart:~$ [00:26:15.236,175] <dbg> date_time: date_time_update_thread: Using previously obtained time
uart:~$ [00:26:15.236,206] <inf> app_lwm2m_client: Obtained date-time from modem
uart:~$ [00:26:15.236,236] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:3/0/13, buf:0x2003275c, len:4
uart:~$ uart:~$ [00:26:17.922,058] <dbg> net_lwm2m_observation: engine_observe_node_init: OBSERVER ADDED 10351/0/50/0(3)
uart:~$ [00:26:17.922,149] <dbg> net_lwm2m_observation: engine_observe_node_init: token:'afd3250c8d52644c' addr:<MY_IP>
uart:~$ [00:26:17.922,180] <dbg> net_lwm2m_registry: lwm2m_engine_set: path:10351/0/50, buf:0x20031e9f, len:1

After Registration update failure! we see lwm2m_utils_update_rptau: PSM deactivated. Our assumption is that in this situation the board previously went into LTE_OFFLINE and stayed offline.

It seems like we are making some progress here!