Issue with AT+CNMI on nRF9160

[Cammie]

We are having an issue with 

This happens to us because we are using the NRF carrier library, and in the carrier library, when you are trying to power off the modem, the carrier library uses the NRF sms library to unregister the device from SMS notifications.  The code in sms.c executes the following modem command:

 

AT+CNMI=0,0,0,0

 

When it does that, the modem library replies with an odd error – error 196910 (decimal), which is undocumented.  This happens every time we try to shut down the modem (in an effort to save power).

I actually have distilled the problem down to a very small program that causes this same error, and it’s enclosed.  It turns out that command causes that error if you just run it from a very simple program.  I’m using SDK 2.6.2 (although this happens with 2.4.2 as well).  The problem occurs with our proprietary board as well as the DK – so it's easy replicate this problem on the nRD9160DK.

Here’s the output I get from the DK:

 

*** Booting nRF Connect SDK v3.5.99-ncs1-2 ***

[00:00:00.431,304] <inf> MAIN: ----------------------------------------------

[00:00:00.431,335] <inf> MAIN: Test program to demonstrate CNMI Issue!

[00:00:00.431,335] <inf> MAIN: ----------------------------------------------

[00:00:00.676,635] <inf> MAIN: LTE Initialization complete

[00:00:00.714,355] <inf> MAIN: Waiting for network...

[00:00:01.744,873] <inf> MAIN: LTE cell changed: Cell ID: 78800405, Tracking area: 22527

[00:00:01.812,866] <inf> MAIN: RRC mode: Connected

[00:00:03.287,811] <inf> MAIN: Network registration status: Connected - roaming

[00:00:03.287,994] <inf> MAIN: LTE Connected

[00:00:03.288,909] <inf> MAIN: PSM parameter update: TAU: 3240, Active time: -1

[00:00:03.288,909] <inf> MAIN: PSM parameter update: TAU: 3240, Active time: -1

[00:00:03.289,794] <err> MAIN: Error 196910 on modem command AT+CNMI=0,0,0,0

Although this isn’t necessarily a show-stopper – it doesn’t seem right that the NRF-supplied libraries (the carrier and sms libraries) should be making calls that cause error conditions – so I’m checking with to see if there’s any know solution to this.

A (very small) sample program that demonstrates the issue is attached.

Thanks!

CC

TestApp.zip

[Devon W]

In addition to your proprietary board and your nrf9160DK board, I was able to replicate this issue on my Thingy91 using the provided attachment "TestApp.zip".

Here are the outputs for TWO tests with the Thingy91 running "TestApp":

BOOT 1:
*** Booting nRF Connect SDK 4040aa0bf581 ***
[00:00:00.255,523] <inf> MAIN: ----------------------------------------------
[00:00:00.255,523] <inf> MAIN: Test program to demonstrate CNMI Issue!
[00:00:00.255,523] <inf> MAIN: ----------------------------------------------
[00:00:00.495,147] <inf> MAIN: LTE Initialization complete
[00:00:00.534,240] <inf> MAIN: Waiting for network...
[00:00:03.445,404] <inf> MAIN: LTE cell changed: Cell ID: 227695366, Tracking area: 21999
[00:00:03.930,725] <inf> MAIN: RRC mode: Connected
[00:00:05.314,971] <inf> MAIN: Network registration status: Connected - roaming
[00:00:05.315,155] <inf> MAIN: LTE Connected
[00:00:05.315,795] <inf> MAIN: PSM parameter update: TAU: 3240, Active time: -1
[00:00:05.316,680] <err> MAIN: Error 196910 on modem command AT+CNMI=0,0,0,0
[00:00:12.005,798] <inf> MAIN: RRC mode: Idle

BOOT 2:
*** Booting nRF Connect SDK 4040aa0bf581 ***
[00:00:00.255,554] <inf> MAIN: ----------------------------------------------
[00:00:00.255,554] <inf> MAIN: Test program to demonstrate CNMI Issue!
[00:00:00.255,584] <inf> MAIN: ----------------------------------------------
[00:00:00.497,467] <inf> MAIN: LTE Initialization complete
[00:00:00.536,560] <inf> MAIN: Waiting for network...
[00:00:03.197,814] <inf> MAIN: LTE cell changed: Cell ID: 89285397, Tracking area: 21233
[00:00:03.267,425] <inf> MAIN: RRC mode: Connected
[00:00:04.732,971] <inf> MAIN: Network registration status: Connected - roaming
[00:00:04.733,123] <inf> MAIN: LTE Connected
[00:00:04.733,734] <inf> MAIN: PSM parameter update: TAU: 3240, Active time: -1
[00:00:04.734,436] <err> MAIN: Error 196910 on modem command AT+CNMI=0,0,0,0
[00:00:11.183,898] <inf> MAIN: RRC mode: Idle
[00:00:11.270,507] <inf> MAIN: LTE cell changed: Cell ID: 227695366, Tracking area: 21999
[00:00:23.996,734] <inf> MAIN: RRC mode: Connected
[00:00:25.527,832] <inf> MAIN: RRC mode: Idle

*EDIT: 10/16/2024 14:48* - Formatted output logs in monospace font

[dejans]

Hi,

I have replicated your issue. We will look into it. I will get back to you probably during next week.

Best regards,
Dejan

[dejans]

Hi,

nrf_modem_at_cmd() specifies these return values

Return values
0	On "OK" responses.
Returns
A positive value On "ERROR", "+CME ERROR", and "+CMS ERROR" responses. 
The type of error can be distinguished using nrf_modem_at_err_type. 
The error value can be retrieved using nrf_modem_at_err.

Looking at nrf_modem_at_cmd() and nrf_modem_at.h source code, knowing the error code 196910 (decimal) which is 0x3012E, and passing this error code to nrf_modem_at_err_type() gives the error type #define NRF_MODEM_AT_CMS_ERROR 3. Error number is obtained from nrf_modem_at_err() and the value is 0x12E = 302 (decimal). Decimal value 302 has the meaning of "Not Allowed" as it is specified in the +CNMI Cellular AT Command documentation.
EDIT: The CNMI error "Not Allowed" is given for unregistering SMS when there is no active registration.

Best regards,
Dejan

[Cammie]

OK - I understand.

Then - the next question is - why does the carrier library call that function (and cause that error) when you turn off the lte connection?  I would think that the Nordic-supplied carrier library would not do something that would cause an error.

[dejans]

Hi,

Please note that the error does not cause any harm. It is a consequence of the interplay between carrier library and SMS library. We are looking into the ways to handle this.

Best regards,
Dejan

[dejans]

Hi,

LwM2M carrier library always calls SMS deregister procedure sms_uninit when shutting down. This releases LwM2M carrier library of being a client of the SMS library. Next, SMS library attempts to deregister itself (in case there are no other clients left) as a global SMS client. LwM2M carrier library does not know if it is the last subscriber of the SMS library at the time it deregisters (there might be other subscribers) and hence does not know if the SMS library call to the modem will fail.
The warning is harmless and can safely be ignored. The warning can be avoided by calling CFUN=4 before CFUN=0 or by letting the LwM2M carrier library control the disconnection by calling lwm2m_carrier_request(LWM2M_CARRIER_REQUEST_LINK_DOWN).
The issue will be addressed possibly in NCS v2.9.0.

Best regards,
Dejan

[dejans]

Hi,

There is pull request which addresses this issue.

Thank you for pointing this out.

Best regards,
Dejan