Issues with configuring PSM on the nRF9160

[Tester013]

I'm currently attempting to get the nRF 9160 to enter PSM mode when not transmitting along with the asset_tracker_v2 application just so we can do some power consumption measurements for the 9160. However, I'm running into an issue where the nRF9160 seems to stop transmitting to nRF Cloud whenever I've set up the PSM mode.

To enable PSM mode I've included lte_lc_psm_req(true); in main.c. I've also tried an alternative implementation by defining the following function and calling setup_psm(); in the main, to the same effect.

void setup_psm(void)
{
	char psm_settings[] = CONFIG_LTE_PSM_REQ_RPTAU;
	printk("PSM bits: %c%c%c\n", psm_settings[0], psm_settings[1],
	       psm_settings[2]);
	printk("PSM Interval: %c%c%c%c%c\n", psm_settings[3], psm_settings[4],
	       psm_settings[5], psm_settings[6], psm_settings[7]);
	int err = lte_lc_psm_req(true);
	if (err < 0) {
		printk("Error setting PSM: %d Errno: %d\n", err, errno);
	}
}

The following is the output on the terminal when I run the modified asset_tracker_v2 application:

*** Booting Zephyr OS build v3.0.99-ncs1  ***

Attempting to boot slot 0.

Attempting to boot from address 0x8200.

Verifying signature against key 0.

Hash: 0x0c...0d

Firmware signature verified.

Firmware version 1

Booting (0x8200).

*** Booting Zephyr OS build v3.0.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: Swap type: none

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: Swap type: none

I: Bootloader chainload address offset: 0x28000

I: Jumping to the first image slot

*** Booting Zephyr OS build v3.0.99-ncs1  ***

APPLICATION START!

[00:00:00.508,209] 



[1;31m<err> settings: set-value failure. key: data_module/config error(40)



[0m

[00:00:00.516,876] 



[0m<inf> app_event_manager: APP_EVT_START



[0m

[00:00:00.517,700] 



[0m<inf> app_event_manager: DATA_EVT_CONFIG_INIT



[0m

[00:00:00.518,218] 



[0m<inf> app_event_manager: APP_EVT_ACTIVITY_DETECTION_DISABLE



[0m

[00:00:00.573,120] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_CONNECTING



[0m

%CESQ: 57,2,8,1

+CEREG: 2,"2042","00378F1E",7

+CSCON: 1

%CESQ: 52,2,11,1

[00:00:03.878,112] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_DISCONNECTED



[0m

[00:00:03.878,692] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_CELL_UPDATE



[0m

%XTIME: ,"22708190509240","01"

%MDMEV: SEARCH STATUS 2

+CEREG: 5,"2042","00378F1E",7,,,"11100000","11100000"

AT+COPS=3,2

OK

AT+COPS?

+COPS: 0,2,"23415",7

OK

AT%XCBAND

%XCBAND: 20

OK

AT+CGDCONT?

+CGDCONT: 0,"IP","wlapn.com","10.111.7.191",0,0

OK

AT+CGACT?

+CGACT: 0,1

OK

[00:00:04.906,524] 



[0m<inf> app_event_manager: DATA_EVT_DATE_TIME_OBTAINED



[0m

[00:00:05.326,995] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_CONNECTED



[0m

[00:00:05.327,575] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_PSM_UPDATE



[0m

[00:00:05.328,857] 



[1;33m<wrn> cloud_module: Cloud connection establishment in progress



[0m

[00:00:05.328,887] 



[1;33m<wrn> cloud_module: New connection attempt in 32 seconds if not successful



[0m

[00:00:05.329,040] 



[0m<inf> app_event_manager: CLOUD_EVT_CONNECTING



[0m

[00:00:09.040,008] 



[0m<inf> app_event_manager: CLOUD_EVT_CONFIG_RECEIVED



[0m

[00:00:09.047,302] 



[0m<inf> app_event_manager: DATA_EVT_CONFIG_SEND



[0m

[00:00:09.048,034] 



[0m<inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS



[0m

[00:00:09.829,315] 



[0m<inf> app_event_manager: CLOUD_EVT_CONNECTED



[0m

[00:00:09.830,505] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, MOD_STAT)



[0m

[00:00:09.832,061] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:00:09.940,216] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY



[0m

[00:00:09.991,821] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY



[0m

%NCELLMEAS: 0,"00378F1E","23415","2042",64,6300,104,57,13,9585,6300,103,59,16,0,9453

[00:00:10.105,285] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:00:10.115,173] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

[00:00:10.116,088] 



[0m<inf> app_event_manager: DATA_EVT_DATA_READY



[0m

[00:00:10.120,391] 



[0m<inf> app_event_manager: DATA_EVT_NEIGHBOR_CELLS_DATA_SEND



[0m

[00:00:10.130,828] 



[0m<inf> app_event_manager: DATA_EVT_DATA_SEND_BATCH



[0m

[00:00:10.131,591] 



[0m<inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS



[0m

[00:00:10.131,866] 



[0m<inf> app_event_manager: CLOUD_EVT_DATA_SEND_QOS



[0m

%CESQ: 50,2,16,2

%CESQ: 48,2,11,1

%NCELLMEAS: 0,"00378F1E","23415","2042",65,6300,104,56,9,30057,6300,103,58,14,0,26955

[00:00:30.518,280] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET_ALL



[0m

[00:00:30.518,951] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, GNSS)



[0m

[00:00:30.519,866] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:00:30.576,690] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY



[0m

[00:00:30.656,005] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:00:30.672,119] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

%CESQ: 46,2,6,0

+CSCON: 0

%CESQ: 57,2,14,2

+CEREG: 5,"2042","00378F14",7,,,"11100000","11100000"

AT+COPS=3,2

OK

AT+COPS?

+COPS: 0,2,"23415",7

OK

AT%XCBAND

%XCBAND: 20

OK

%CESQ: 52,2,13,1

AT+CGDCONT?

+CGDCONT: 0,"IP","wlapn.com","10.111.7.191",0,0

OK

AT+CGACT?

+CGACT: 0,1

OK

[00:00:38.913,330] 



[0m<inf> app_event_manager: MODEM_EVT_LTE_CELL_UPDATE



[0m

%NCELLMEAS: 0,"00378F14","23415","2042",65535,6300,103,55,11,59676,0

[00:01:00.518,280] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET_ALL



[0m

[00:01:00.518,951] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, GNSS)



[0m

[00:01:00.519,805] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:01:00.600,769] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY



[0m

[00:01:00.673,858] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:01:00.688,293] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

%CESQ: 53,2,8,1

%CESQ: 53,2,13,1

%NCELLMEAS: 0,"00378F14","23415","2042",65535,6300,103,53,17,89756,0

[00:01:30.518,280] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET_ALL



[0m

[00:01:30.518,951] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, GNSS)



[0m

[00:01:30.519,805] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:01:30.600,036] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY



[0m

[00:01:30.679,443] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:01:30.693,054] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

%CESQ: 53,2,18,2

%CESQ: 53,2,13,1

%NCELLMEAS: 0,"00378F14","23415","2042",65535,6300,103,52,15,119836,0

[00:02:00.518,280] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET_ALL



[0m

[00:02:00.518,951] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, GNSS)



[0m

[00:02:00.519,805] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:02:00.600,250] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_NOT_READY



[0m

[00:02:00.673,309] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:02:00.687,896] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

%CESQ: 51,2,8,1

%NCELLMEAS: 0,"00378F14","23415","2042",65535,6300,103,51,9,149916,0

[00:02:30.518,280] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET_ALL



[0m

[00:02:30.518,951] 



[0m<inf> app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, ENV, NEIGHBOR_CELLS, GNSS)



[0m

[00:02:30.519,805] 



[0m<inf> app_event_manager: SENSOR_EVT_ENVIRONMENTAL_NOT_SUPPORTED



[0m

[00:02:30.606,384] 



[0m<inf> app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY



[0m

[00:02:30.673,339] 



[0m<inf> app_event_manager: MODEM_EVT_BATTERY_DATA_READY



[0m

[00:02:30.687,744] 



[0m<inf> app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY



[0m

%CESQ: 51,2,13,1

%CESQ: 46,2,9,1

%CESQ: 48,2,3,0

%NCELLMEAS: 0,"00378F14","23415","2042",65535,6300,103,48,6,179996,0

%CESQ: 48,2,8,1

active_wait_timeout is currently set to be 30 seconds

The PSM TAU setting is 10000001 and the requested active time is 00100001.

[Elfving]

Tester013 said:

and from the CEREG, it would seem that PSM is working correctly..? 

Where are you seeing this? To me it seems that it is still not enabling it as "11100000","11100000" is still a zero.

Tester013 said:

I wanted to try a shorter interval so I didn't have to wait around for 10 minutes to see if PSM had indeed been enabled. 

You don't have to wait it out, you can just check it with these AT commands. 

Could you try to increase it even more, to lets say 320H. Just to check if that makes a difference. 

Regards,

Elfving

[Tester013]

Hi, I ran XMONITOR and the results are below. The values for active time and Periodic-TAU-ext match, but I was wondering what the value for Periodic-TAU represented and why it's different from Perodic-TAU-ext?

AT%XMONITOR
%XMONITOR: 5,"Vodafone","VF","23415","242A",9,20,"00378F15",,,,,"","00011110","11000001","01001001"OKAT+CEREG?+CEREG: 5,5,"242A","00378F15",9,,,"00011110","11000001"
OK

[Elfving]

Tester013 said:

I was wondering what the value for Periodic-TAU represented and why it's different from Perodic-TAU-ext?

That is a bit complex, and not something you would necessarily have to worry about. You would just preferably refer to Tau-extended instead of the other.

What version of modem FW are you using?

Regards,

Elfving