Unexpected +KCELLMEAS URC prevents PSM from functioning properly

Hi

I have an applicaiton with psm and in the document 2174229 HL78xx Low Power Modes Application Note r7.pdf, SierraW says:

i. The host application must wait until it receives a +KCELLMEASURE URC before attempting data transmission. For details, see Using the +KCELLMEAS URC.

So, I wanted to implement KCELLMEASURE URC before starting data transmisson after waking up from psm dormant into my app.

According to the Signal Quality URC on Wakeup 2174298-1 doc

the +KCELLMEAS URC is triggered by raising the WAKEUP pin during PSM Dormant. When the module wakes to send data and/or a TAU, the +KCELLMEAS URC feature is temporarily disabled, and then re-enabled after the Active Timer expires and a +CEREG: 4 URC is received.

and I followed all the “how to use” instructions to implement here.
image

The problem is that as soon as the modem sends CEREG: 4 and PSMEV: 1 URC, the +KCELLMEAS URC is also reported. This causes the VGPIO and GPIO6 pins to be asserted and the CTS pin to be deasserted, preventing the modem from entering PSM dormant mode.

+CEREG: 4,,,,,,"00001111","00001111"
3948 hl_netfeasa.c 36 |+CEREG: 4,,,,,,"00001111","00001111"|
[00:02:00.263,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3950 hl7812_rx_netfeasa.c msg: +CEREG: 4,,,,,,"00001111","00001111"
[00:02:00.264,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CEREG:  (len:28)
[00:02:00.264,000] <dbg> modem_hl7812_rx: on_cmd_network_report: use URC CEREG parser
[00:02:00.264,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network status: 4,,,,,,"00001111","00001111"
[00:02:00.264,000] <dbg> modem_hl7812_rx: on_cmd_network_report: network state val: 4   0 valid parsed data: 1
[00:02:00.264,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:02:00.264,000] <dbg> modem_hl7812: set_network_state: SET NETWORK STATE: OUT_OF_COVERAGE
[00:02:00.264,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:02:00.264,000] <inf> modem_hl7812: Network State: 4 OUT_OF_COVERAGE
[00:02:00.264,000] <dbg> modem_module: lte_evt_handler: Modem domain event, type: Search done
[00:02:00.264,000] <dbg> modem_hl7812: allow_sleep: Keep awake 2416
[00:02:00.264,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
4,,,,,,"00001111","00001111" 7
[00:02:00.266,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network supports psm, active_timer: 00001111 tau: 00001111 
+PSMEV: 1
3948 hl_netfeasa.c 9 |+PSMEV: 1|
[00:02:00.266,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3950 hl7812_rx_netfeasa.c msg: +PSMEV: 1
[00:02:00.266,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +PSMEV:  (len:1)
[00:02:00.266,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: PSMEV1: 1 sleep state: AWAKE
[00:02:00.266,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1032
[00:02:00.266,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:00.266,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: Current pm status: 1
[00:02:05.266,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1068 0 1 0 0 

1086 Allow sleep
[00:02:05.266,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:05.266,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:05.266,000] <dbg> modem_hl7812: modem_assert_wake: MDM_WAKE_PIN -> DE-ASSERTED 1
[00:02:05.323,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:05.323,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:05.323,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 2 
[00:02:05.323,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:05.323,000] <wrn> modem_hl7812: NOT awake
[00:02:05.323,000] <dbg> modem_hl7812: check_hl7812_awake: set_sleep_state(iface_ctx.desired_sleep_level);
[00:02:05.323,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: AWAKE, now: HIBERNATE
[00:02:05.323,000] <dbg> modem_hl7812: set_sleep_state: entered hibernate cancel shutdown work
[00:02:05.323,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: HIBERNATE gpio6: 0
[00:02:05.323,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_ENTER
[00:02:05.330,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:05.330,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:05.330,000] <wrn> modem_hl7812: Power ON the UART
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep: Keep awake 970
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:05.330,000] <dbg> modem_hl7812: modem_assert_wake: MDM_WAKE_PIN -> ASSERTED
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 974
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:05.330,000] <wrn> modem_hl7812: MDM_UART_CTS:1(42717285)
[00:02:05.330,000] <dbg> modem_hl7812: mdm_uart_cts_callback_isr: iface_ctx.vgpio_state && iface_ctx.gpio6_state VGPIO: 1, GPIO6: 1
[00:02:05.330,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep: Keep awake 1034
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1038
[00:02:05.330,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:05.330,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 2 
[00:02:05.330,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:05.335,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5127)
[00:02:05.335,000] <dbg> modem_hl7812: mdm_uart_cts_callback_isr: iface_ctx.vgpio_state && iface_ctx.gpio6_state VGPIO: 1, GPIO6: 1
[00:02:05.335,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:02:05.335,000] <dbg> modem_hl7812: allow_sleep: Keep awake 1034
[00:02:05.335,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:05.335,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1038
[00:02:05.335,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:05.340,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:05.340,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:05.654,000] <wrn> sensor_module: MODEM_EVT_LTE_PSM_ENTER
[00:02:05.655,000] <dbg> ext_sensors: ext_sensors_all_power_down: sensor power status: 0
[00:02:05.655,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+PRESS_CPOF=0
+KCELLMEAS: ,,,,,,
3948 hl_netfeasa.c 18 |+KCELLMEAS: ,,,,,,|
[00:02:06.593,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3950 hl7812_rx_netfeasa.c msg: +KCELLMEAS: ,,,,,,
[00:02:06.593,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +KCELLMEAS:  (len:6)
[00:02:06.593,000] <inf> modem_hl7812_rx: RSSI (RSRP): UNKNOWN

here is a log that belongs to a successful psm attempt


+CEREG: 4,,,,,,"00001111","00001111"
3947 hl_netfeasa.c 36 |+CEREG: 4,,,,,,"00001111","00001111"|
[00:02:04.186,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3949 hl7812_rx_netfeasa.c msg: +CEREG: 4,,,,,,"00001111","00001111"
[00:02:04.186,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CEREG: (len:28)
[00:02:04.186,000] <dbg> modem_hl7812_rx: on_cmd_network_report: use URC CEREG parser
[00:02:04.186,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network status: 4,,,,,,"00001111","00001111"
[00:02:04.187,000] <dbg> modem_hl7812_rx: on_cmd_network_report: network state val: 4 0 valid parsed data: 1
[00:02:04.187,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4

[00:02:04.187,000] <dbg> modem_hl7812: set_network_state: SET NETWORK STATE: OUT_OF_COVERAGE
[00:02:04.187,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:02:04.187,000] <inf> modem_hl7812: Network State: 4 OUT_OF_COVERAGE
[00:02:04.187,000] <dbg> modem_module: lte_evt_handler: Modem domain event, type: Search done
[00:02:04.187,000] <dbg> modem_hl7812: allow_sleep: Keep awake 2416
[00:02:04.187,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
4,,,,,,"00001111","00001111" 7
[00:02:04.189,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network supports psm, active_timer: 00001111 tau: 00001111
+PSMEV: 1
3947 hl_netfeasa.c 9 |+PSMEV: 1|
[00:02:04.189,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3949 hl7812_rx_netfeasa.c msg: +PSMEV: 1
[00:02:04.189,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +PSMEV: (len:1)
[00:02:04.189,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: PSMEV1: 1 sleep state: AWAKE

[00:02:04.189,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1032

[00:02:04.189,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:04.189,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: Current pm status: 1
[00:02:09.189,000] <dbg> modem_hl7812: allow_sleep_work_callback: 991 0 1 0 0
1009 Allow sleep
[00:02:09.189,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1

[00:02:09.189,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:09.189,000] <dbg> modem_hl7812: modem_assert_wake: MDM_WAKE_PIN -> DE-ASSERTED 1
[00:02:09.246,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:09.246,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:09.246,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 2
[00:02:09.246,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0
[00:02:09.246,000] <wrn> modem_hl7812: NOT awake
[00:02:09.246,000] <dbg> modem_hl7812: check_hl7812_awake: set_sleep_state(iface_ctx.desired_sleep_level);
[00:02:09.246,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: AWAKE, now: HIBERNATE
[00:02:09.246,000] <dbg> modem_hl7812: set_sleep_state: entered hibernate cancel shutdown work
[00:02:09.246,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: HIBERNATE gpio6: 0
[00:02:09.246,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_ENTER
[00:02:09.256,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:09.256,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:09.256,000] <wrn> modem_hl7812: Power ON the UART
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep: Keep awake 893
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:09.256,000] <dbg> modem_hl7812: modem_assert_wake: MDM_WAKE_PIN -> ASSERTED
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 897
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:09.256,000] <wrn> modem_hl7812: MDM_UART_CTS:1(42832519)
[00:02:09.256,000] <dbg> modem_hl7812: mdm_uart_cts_callback_isr: iface_ctx.vgpio_state && iface_ctx.gpio6_state VGPIO: 1, GPIO6: 1

[00:02:09.256,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep: Keep awake 957
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 961
[00:02:09.256,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:09.256,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 2
[00:02:09.256,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1
[00:02:09.261,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5127)
[00:02:09.261,000] <dbg> modem_hl7812: mdm_uart_cts_callback_isr: iface_ctx.vgpio_state && iface_ctx.gpio6_state VGPIO: 1, GPIO6: 1
[00:02:09.261,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:02:09.261,000] <dbg> modem_hl7812: allow_sleep: Keep awake 957
[00:02:09.261,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:09.261,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 961
[00:02:09.261,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:09.266,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 3
[00:02:09.266,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0
[00:02:09.577,000] <wrn> sensor_module: MODEM_EVT_LTE_PSM_ENTER
1475 sensor_module.c
[00:02:09.577,000] <dbg> ext_sensors: ext_sensors_all_power_down: sensor power status: 0

[00:02:09.578,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+PRESS_CPOF=0

[00:02:10.578,000] <dbg> SENSORS_CMD: sn_command_switch: lps22@5c power down!

{"status":{"status":{"echo":"SN+PRESS_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"pressure","power":"PM_DEVICE_STATE_OFF"}}
[00:02:10.628,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+EFLASH_CPOF=0
[00:02:11.628,000] <dbg> SENSORS_CMD: sn_command_switch: mx25r6435f@0 power down!
{"status":{"status":{"echo":"SN+EFLASH_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"extrnal_memory","power":"PM_DEVICE_STATE_OFF"}}

[00:02:11.662,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+ACCEL_CPOF=0
[00:02:12.663,000] <dbg> SENSORS_CMD: sn_command_switch: lis2dw12@0 power down!
{"status":{"status":{"echo":"SN+ACCEL_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"accelorometer","power":"PM_DEVICE_STATE_OFF"}}
1483 sensor_module.c
[00:02:14.261,000] <dbg> modem_hl7812: allow_sleep_work_callback: 991 0 1 0 0
1009 Allow sleep
[00:02:14.261,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1

[00:02:14.261,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:14.261,000] <dbg> modem_hl7812: modem_assert_wake: MDM_WAKE_PIN -> DE-ASSERTED 1
[00:02:14.997,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:14.997,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:14.997,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 2
[00:02:14.997,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0
[00:02:16.332,000] <wrn> modem_hl7812: MDM_UART_DSR:0
[00:02:16.333,000] <wrn> modem_hl7812: VGPIO:0

[00:02:16.333,000] <wrn> modem_hl7812: Preparing IO for reset/sleep

[00:02:16.333,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 0

[00:02:16.333,000] <wrn> modem_hl7812: MDM_PWR_ON -> NOT_ASSERTED

[00:02:16.333,000] <wrn> modem_hl7812: MDM_FAST_SHUTD -> NOT_ASSERTED

[00:02:16.333,000] <dbg> modem_hl7812: check_hl7812_awake: 288 hl7812_netfeasa.c WHEREamIcallingfrom: 1
[00:02:16.333,000] <dbg> modem_hl7812: is_cmd_ready: 274 289 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0
[00:02:17.375,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
[00:03:17.376,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
[00:04:17.376,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
[00:05:17.376,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
HL7812.5.5.8.0-23.10.0.FreeRTOS.w41
HL78xx.5.5.8.0.RK_03_02_00_00_34211_001.20231031
2023/10/31 10:26:07
IMEI-SV: 3511444413608716
Legato RTOS: 23.10.0.FreeRTOS.w41 2023/09/22 11:24:21
atSwi: HL78XX.5.5.7.0-23.10.0.FreeRTOS.w41
UBOOT: 01.03
Apps: RKAPP_03_02_00_00_33241_004__869de8b6ed4b4a7d35a729d4e3fde1db0c676aff
MAC: ALT1250_03_02_00_00_34161_NB
PHY: 0.0.321522
PMP: 322145
AISE: ISE2APP_00_00_00_09
SBUB: 1
SBFW: 1
FPuK1: CBF402DD
FPuK2: 4BE7EB7F
RBUB: 0
RBFW: 0
MCU-Disable: 1
OK

did you put the wakeup pin to low after sending the data?

According to the application note, it also needs to wait for the T3324 to be expired before entering PSM dormant mode:

@jyijyi

did you put the wakeup pin to low after sending the data?

Yes I did. It can be also seen in the log,

  1. firstly, im waiting psmev:1 to start process for psm. When I get it, disabling uart comms,
  2. de asserting mdm wakeupo pin by putting it to low.
  3. Setting mdm-pwr-on high (floating)
  4. observing GPIO6 and VGPIO status to make sure,

According to the application note, it also needs to wait for the T3324 to be expired before entering PSM dormant mode:

isnt it enough to wait for psmev: 1 URC?

  1. How about pulling wakeup pin to low again after receiving the +KCELLMEAS URC?

  2. From the AT command guide, the +KCELLMEAS should be received after wake up, does this mean that module already wakes up when receiving this URC? If so, not quite sure why it wakes up…
    What happens if you disable the +psmev URC?

  3. Btw, how do you configure the timeout parameter of +KCELLMEAS?

  4. Lastly, did you try the latest FW?
    https://source.sierrawireless.com/resources/airprime/software/hl781x-and-hl7845-firmware/hl781x-and-hl7845-release-4,-d-,2/#sthash.PH45bV7z.dpbs

I tried this, it seems to be continuous loop,

Yes, it is according to the command guide. I suspected asserting the wake up pin mistakenly. I double checked this but no I am asserting it. everything is as it needs to be normal.

I cant disable it at the moment, all my sw psm mode is built on psmev URC. Do you really want me to do that?

[AT+KCELLMEAS=1,10]

No, I didnt try this, just saw it. Is there any bug in the 5.5.8 causing this issue and fixed with the sw you recommended there?

Please have a look at this loogs, I am also printing pins’ status

+CEREG: 4,,,,,,"00001111","00001111"
3957 hl_netfeasa.c 36 |+CEREG: 4,,,,,,"00001111","00001111"|
[00:01:49.842,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +CEREG: 4,,,,,,"00001111","00001111"
[00:01:49.842,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CEREG:  (len:28)
[00:01:49.842,000] <dbg> modem_hl7812_rx: on_cmd_network_report: val: 4,,,,,,"00001111","00001111" stat: -1 urc_res_code: 0
[00:01:49.842,000] <dbg> modem_hl7812_rx: on_cmd_network_report: use URC CEREG parser
[00:01:49.842,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network status: 4,,,,,,"00001111","00001111"
[00:01:49.842,000] <dbg> modem_hl7812_rx: on_cmd_network_report: network state val: 4   0 valid parsed data: 1
[00:01:49.842,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:01:49.842,000] <dbg> modem_hl7812: set_network_state: SET NETWORK STATE: OUT_OF_COVERAGE
[00:01:49.842,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:01:49.842,000] <inf> modem_hl7812: Network State: 4 OUT_OF_COVERAGE
[00:01:49.842,000] <dbg> modem_hl7812: allow_sleep_timeout: Keep sleep 2424
[00:01:49.842,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:49.842,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
4,,,,,,"00001111","00001111" 7
[00:01:49.843,000] <wrn> modem_hl7812: MDM_UART_CTS:1(36613526)
[00:01:49.844,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network supports psm, active_timer: 00001111 tau: 00001111 
[00:01:49.844,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

+PSMEV: 1
3957 hl_netfeasa.c 9 |+PSMEV: 1|
[00:01:49.844,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +PSMEV: 1
[00:01:49.844,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +PSMEV:  (len:1)
[00:01:49.844,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: PSMEV1: 1 sleep state: AWAKE
[00:01:49.844,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1032
[00:01:49.844,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:49.844,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: Current pm status: 1
[00:01:49.849,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:49.849,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:54.845,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:01:54.845,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 1 1
[00:01:54.845,000] <wrn> modem_hl7812: Power OFF the UART
[00:01:54.845,000] <wrn> modem_hl7812: VGPIO:0
[00:01:54.845,000] <wrn> modem_hl7812: Preparing IO for reset/sleep
[00:01:54.845,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 1 0
[00:01:54.845,000] <wrn> modem_hl7812: Power OFF the UART
[00:01:54.845,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:01:54.845,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5001220)
[00:01:54.845,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:01:54.845,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 0
[00:01:54.845,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:01:54.845,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:01:54.845,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:54.845,000] <wrn> modem_hl7812: NOT awake
[00:01:54.845,000] <dbg> modem_hl7812: check_hl7812_awake: set_sleep_state(iface_ctx.desired_sleep_level);
[00:01:54.845,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: AWAKE, now: HIBERNATE
[00:01:54.845,000] <dbg> modem_hl7812: set_sleep_state: entered hibernate cancel shutdown work
[00:01:54.845,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: HIBERNATE gpio6: 0
[00:01:54.845,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_ENTER
[00:01:54.845,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:01:54.845,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:54.850,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:54.850,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:54.859,000] <wrn> modem_hl7812: VGPIO:1
[00:01:54.859,000] <dbg> modem_hl7812: mdm_vgpio_callback_isr: iface_ctx.off2: 0
[00:01:54.859,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:01:54.859,000] <wrn> modem_hl7812: Power ON the UART
[00:01:54.859,000] <dbg> modem_hl7812: allow_sleep: Keep awake 907
[00:01:54.859,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:01:54.859,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:01:54.859,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 911
[00:01:54.859,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:54.860,000] <wrn> modem_hl7812: MDM_UART_CTS:1(14893)
[00:01:54.860,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:01:54.860,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:01:54.860,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:01:54.860,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:01:54.860,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:01:54.860,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:01:54.860,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:54.860,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:01:54.860,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:54.860,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:01:54.860,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:54.865,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:54.865,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:54.929,000] <wrn> modem_hl7812: MDM_UART_CTS:0(69580)
[00:01:54.935,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:54.935,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:55.250,000] <wrn> sensor_module: MODEM_EVT_LTE_PSM_ENTER
1464 sensor_module.c
[00:01:55.250,000] <dbg> ext_sensors: ext_sensors_all_power_down: sensor power status: 0
[00:01:55.250,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+PRESS_CPOF=0
[00:01:56.250,000] <dbg> SENSORS_CMD: sn_command_switch: lps22@5c power down!
{"status":{"status":{"echo":"SN+PRESS_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"pressure","power":"PM_DEVICE_STATE_OFF"}}
[00:01:56.301,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+EFLASH_CPOF=0
[00:01:57.301,000] <dbg> SENSORS_CMD: sn_command_switch: mx25r6435f@0 power down!
{"status":{"status":{"echo":"SN+EFLASH_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"extrnal_memory","power":"PM_DEVICE_STATE_OFF"}}
[00:01:57.335,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+ACCEL_CPOF=0
[00:01:58.335,000] <dbg> SENSORS_CMD: sn_command_switch: lis2dw12@0 power down!
{"status":{"status":{"echo":"SN+ACCEL_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"accelorometer","power":"PM_DEVICE_STATE_OFF"}}
1472 sensor_module.c
[00:01:59.860,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:01:59.860,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:01:59.860,000] <wrn> modem_hl7812: Power OFF the UART
[00:01:59.860,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:01:59.913,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:01:59.913,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:01:59.914,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:01:59.914,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:00.068,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:00.068,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:00.068,000] <wrn> modem_hl7812: Power ON the UART
[00:02:00.068,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:02:00.068,000] "00001111","00001111 
<dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:00.068,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:00.068,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:02:00.068,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:00.068,000] <wrn> modem_hl7812: MDM_UART_CTS:1(5138428)
[00:02:00.068,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:00.068,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:00.071,000] <wrn> modem_hl7812: MDM_UART_CTS:0(3418)
[00:02:00.076,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:00.076,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
+CEREG: 5,"2332","02E9F81F",9,,,"00001111","00001111"
3957 hl_netfeasa.c 53 |+CEREG: 5,"2332","02E9F81F",9,,,"00001111","00001111"|
[00:02:00.162,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +CEREG: 5,"2332","02E9F81F",9,,,"00001111","00001111"
[00:02:00.162,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CEREG:  (len:45)
[00:02:00.162,000] <dbg> modem_hl7812_rx: on_cmd_network_report: val: 5,"2332","02E9F81F",9,,,"00001111","00001111" stat: -1 urc_res_code: 4
[00:02:00.162,000] <dbg> modem_hl7812_rx: on_cmd_network_report: use URC CEREG parser
[00:02:00.162,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network status: 5,"2332","02E9F81F",9,,,"00001111","00001111
[00:02:00.162,000] <dbg> modem_hl7812_rx: on_cmd_network_report: network state val: 5 2332 02E9F81F 9 valid parsed data: 4
[00:02:00.162,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 5
[00:02:00.162,000] <dbg> modem_hl7812: set_network_state: SET NETWORK STATE: ROAMING
[00:02:00.162,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 5
[00:02:00.162,000] <inf> modem_hl7812: Network State: 5 ROAMING
[00:02:00.162,000] <dbg> date_time: date_time_netfeasa_core_is_valid: date_time_netfeasa_core_is_valid 52130
[00:02:00.162,000] <wrn> date_time: Cellular network obtained, DATETIME is valied, no need to request
[00:02:00.162,000] <dbg> modem_hl7812: allow_sleep: Keep awake 2419
[00:02:00.162,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:00.162,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
5,"2332","02E9F81F",9,,,"00001111","00001111 7
[00:02:00.164,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network supports psm, active_timer: 00001111 tau: 00001111 
+KCELLMEAS: -108.0,134.0,,,2.0,1,1
3957 hl_netfeasa.c 34 |+KCELLMEAS: -108.0,134.0,,,2.0,1,1|
[00:02:00.166,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +KCELLMEAS: -108.0,134.0,,,2.0,1,1
[00:02:00.166,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +KCELLMEAS:  (len:22)
[00:02:00.166,000] <inf> modem_hl7812_rx: RSSI (RSRP): -108 SINR: 2
[00:02:00.662,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:00.662,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:01.162,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:01.162,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:01.663,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:01.663,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:02.163,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:02.163,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:02.663,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:02.663,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:03.163,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:03.163,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:03.664,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:03.664,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:04.164,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:04.164,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:04.664,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:04.664,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:05.164,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:05.164,000] <dbg> modem_hl7812: iface_status_work_cb: Wait for +KSUP before updating network state
[00:02:05.665,000] <dbg> modem_hl7812: iface_status_work_cb: 649 hl_netfeasa.c 0 1 2
[00:02:05.665,000] <dbg> modem_hl7812: iface_status_work_cb: Give up waiting for
[00:02:05.665,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 0 
[00:02:05.665,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:05.665,000] <wrn> modem_hl7812: awake
[00:02:05.665,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: HIBERNATE, now: AWAKE
[00:02:05.665,000] <dbg> modem_hl7812: set_sleep_state: schedule callback to shutdown modem is PSM is not entered in x minutes
[00:02:05.665,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: AWAKE gpio6: 1
[00:02:05.665,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_EXIT
[00:02:05.665,000] <dbg> modem_hl7812: iface_status_work_cb: Updating network state... 0
[00:02:05.665,000] <dbg> modem_hl7812: send_at_cmd: reset iface_ctx.response_sem: 0
[00:02:05.665,000] <dbg> modem_hl7812: send_at_cmd: OUT: [AT+COPS?]
[00:02:05.665,000] <dbg> modem_hl7812: send_at_cmd: SEND ATCMD k_sem_take RET01 (RESPONSE SEM): 0
+COPS: 0,0,"Vodafone",9
3957 hl_netfeasa.c 23 |+COPS: 0,0,"Vodafone",9|
[00:02:05.669,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +COPS: 0,0,"Vodafone",9
[00:02:05.669,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +COPS:  (len:16)
[00:02:05.669,000] <inf> modem_hl7812_rx: Operator: 0,0,"Vodafone",9
OK
[00:02:05.670,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE OK (len:0)
[00:02:05.670,000] <dbg> modem_hl7812: iface_status_work_cb: Query operator selection
[00:02:05.670,000] <dbg> modem_hl7812: iface_status_work_cb: iface_status: HL7812_ROAMING
[00:02:05.670,000] <dbg> modem_hl7812: iface_status_work_cb: HL7812 iface UP
[00:02:05.670,000] <dbg> modem_hl7812: iface_status_work_cb: 805 hl7812_netfeasa.c hl7812_netfeasa_start_rssi_work
[00:02:05.670,000] <dbg> modem_hl7812: send_at_cmd: reset iface_ctx.response_sem: 0
[00:02:05.670,000] <dbg> modem_hl7812: send_at_cmd: OUT: [AT+CGCONTRDP=1]
[00:02:05.671,000] <dbg> modem_hl7812: send_at_cmd: SEND ATCMD k_sem_take RET01 (RESPONSE SEM): 0
+CGCONTRDP: 1,5,"netfeasavodiot.mnc028.mcc901.gprs",10.149.91.36.255.255.255.248,10.149.91.33,10.105.16.254,10.105.144.254,,,,,,
3957 hl_netfeasa.c 128 |+CGCONTRDP: 1,5,"netfeasavodiot.mnc028.mcc901.gprs",10.149.91.36.255.255.255.248,10.149.91.33,10.105.16.254,10.105.144.254,,,,,,|
[00:02:05.685,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +CGCONTRDP: 1,5,"netfeasavodiot.mnc028.mcc901.gprs",10.149.91.36.255.255.255.248,10.149.91.33,10.105.16.254,10.105.144.254,,,,,,
[00:02:05.685,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CGCONTRDP:  (len:119)
[00:02:05.685,000] <dbg> modem_hl7812_rx: on_cmd_atcmdinfo_ipaddr: IP info: 119 1,5,"netfeasavodiot.mnc028.mcc901.gprs",10.149.91.36.255.255.255.248,10.149.91.33,10.105.16.254,10.105.144.254,,,,,,,,,
[00:02:05.685,000] <dbg> modem_hl7812_rx: on_cmd_atcmdinfo_ipaddr: IP string len: 29
[00:02:05.685,000] <dbg> modem_hl7812_rx: on_cmd_atcmdinfo_ipaddr: IP addr: 10.149.91.36
[00:02:05.685,000] <dbg> modem_hl7812_rx: on_cmd_atcmdinfo_ipaddr: IPv4 DNS addr: 10.105.16.254
OK
[00:02:05.685,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE OK (len:0)
[00:02:05.685,000] <dbg> modem_hl7812: send_at_cmd: reset iface_ctx.response_sem: 0
[00:02:05.685,000] <dbg> modem_hl7812: send_at_cmd: OUT: [AT+KBND?]
[00:02:05.686,000] <dbg> modem_hl7812: send_at_cmd: SEND ATCMD k_sem_take RET01 (RESPONSE SEM): 0
+KBND: 1,0000000000000000080000
3957 hl_netfeasa.c 31 |+KBND: 1,0000000000000000080000|
[00:02:05.691,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +KBND: 1,0000000000000000080000
[00:02:05.691,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +KBND:  (len:24)
OK
[00:02:05.692,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE OK (len:0)
[00:02:05.692,000] <dbg> modem_hl7812: iface_status_work_cb: Network state updated
[00:02:05.692,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 834
[00:02:05.692,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:05.692,000] <dbg> modem_hl7812: allow_sleep: Keep awake 522
[00:02:05.692,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:05.692,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:05.692,000] <dbg> modem_hl7812: wakeup_hl7812: desired_sleep_level 2 1 2 5 2
[00:02:05.692,000] <dbg> modem_hl7812: is_cmd_ready: 274 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:05.692,000] <dbg> modem_hl7812: send_at_cmd: reset iface_ctx.response_sem: 0
[00:02:05.692,000] <dbg> modem_hl7812: send_at_cmd: OUT: [AT+KCELLMEAS=0]
[00:02:05.693,000] <dbg> modem_hl7812: send_at_cmd: SEND ATCMD k_sem_take RET01 (RESPONSE SEM): 0
+KCELLMEAS: -108.0,134.0,,,1.0
3957 hl_netfeasa.c 30 |+KCELLMEAS: -108.0,134.0,,,1.0|
[00:02:05.699,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +KCELLMEAS: -108.0,134.0,,,1.0
[00:02:05.699,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +KCELLMEAS:  (len:18)
[00:02:05.699,000] <inf> modem_hl7812_rx: RSSI (RSRP): -108 SINR: 1
OK
[00:02:05.700,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE OK (len:0)
[00:02:05.700,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1404
[00:02:05.700,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:06.221,000] <dbg> ext_sensors: ext_sensors_all_power_up: sensor power status: 0
[00:02:06.221,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 10 SN+PRESS_CPOF=1
[00:02:07.227,000] <dbg> SENSORS_CMD: sn_command_switch: lps22@5c power up!
{"status":{"status":{"echo":"SN+PRESS_CPOF=1","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_ON","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"pressure","power":"PM_DEVICE_STATE_ACTIVE"}}
[00:02:07.263,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 10 SN+EFLASH_CPOF=1
[00:02:08.267,000] <dbg> SENSORS_CMD: sn_command_switch: mx25r6435f@0 power up!
{"status":{"status":{"echo":"SN+EFLASH_CPOF=1","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_ON","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"extrnal_memory","power":"PM_DEVICE_STATE_ACTIVE"}}
[00:02:08.296,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 10 SN+ACCEL_CPOF=1
[00:02:09.297,000] <dbg> SENSORS_CMD: sn_command_switch: lis2dw12@0 power up!
{"status":{"status":{"echo":"SN+ACCEL_CPOF=1","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_ON","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"accelorometer","power":"PM_DEVICE_STATE_ACTIVE"}}
[00:02:10.700,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:02:10.700,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:10.700,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:10.700,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:12.163,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:12.163,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:12.163,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:12.163,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:12.163,000] <wrn> modem_hl7812: NOT awake
[00:02:12.163,000] <dbg> modem_hl7812: check_hl7812_awake: set_sleep_state(iface_ctx.desired_sleep_level);
[00:02:12.163,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: AWAKE, now: HIBERNATE
[00:02:12.163,000] <dbg> modem_hl7812: set_sleep_state: entered hibernate cancel shutdown work
[00:02:12.163,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: HIBERNATE gpio6: 0
[00:02:12.163,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_ENTER
[00:02:12.253,000] <wrn> sensor_module: MODEM_EVT_LTE_PSM_ENTER
1464 sensor_module.c
[00:02:12.253,000] <dbg> ext_sensors: ext_sensors_all_power_down: sensor power status: 0
[00:02:12.254,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+PRESS_CPOF=0
[00:02:13.254,000] <dbg> SENSORS_CMD: sn_command_switch: lps22@5c power down!
{"status":{"status":{"echo":"SN+PRESS_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"pressure","power":"PM_DEVICE_STATE_OFF"}}
[00:02:13.304,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+EFLASH_CPOF=0
[00:02:13.409,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:13.409,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:13.409,000] <wrn> modem_hl7812: Power ON the UART
[00:02:13.409,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:02:13.409,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:13.409,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:13.409,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:02:13.409,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:13.409,000] <wrn> modem_hl7812: MDM_UART_CTS:1(13338379)
[00:02:13.409,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:13.410,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:13.413,000] <wrn> modem_hl7812: MDM_UART_CTS:0(3418)
[00:02:13.418,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:13.418,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:14.304,000] <dbg> SENSORS_CMD: sn_command_switch: mx25r6435f@0 power down!
{"status":{"status":{"echo":"SN+EFLASH_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"extrnal_memory","power":"PM_DEVICE_STATE_OFF"}}
[00:02:14.305,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+ACCEL_CPOF=0
[00:02:14.872,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
[00:02:15.305,000] <dbg> SENSORS_CMD: sn_command_switch: lis2dw12@0 power down!
{"status":{"status":{"echo":"SN+ACCEL_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"accelorometer","power":"PM_DEVICE_STATE_OFF"}}
1472 sensor_module.c
[00:02:18.410,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:02:18.410,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:18.410,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:18.410,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:21.902,000] <wrn> modem_hl7812: VGPIO:0
[00:02:21.902,000] <wrn> modem_hl7812: Preparing IO for reset/sleep
[00:02:21.902,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 1 0 0
[00:02:21.902,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:21.902,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:21.902,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 0
[00:02:21.902,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:02:21.902,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:02:21.902,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:21.902,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:02:23.718,000] <wrn> modem_hl7812: VGPIO:1
[00:02:23.718,000] <dbg> modem_hl7812: mdm_vgpio_callback_isr: iface_ctx.off2: 0
[00:02:23.718,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:23.718,000] <wrn> modem_hl7812: Power ON the UART
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep: Keep awake 907
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:23.718,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 911
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:23.718,000] <wrn> modem_hl7812: MDM_UART_CTS:1(10304931)
[00:02:23.718,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:23.718,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:23.718,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:02:23.718,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:23.718,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:02:23.718,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:23.718,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:23.718,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:23.723,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:23.723,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:23.788,000] <wrn> modem_hl7812: MDM_UART_CTS:0(69824)
[00:02:23.793,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:23.793,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:28.718,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:02:28.718,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:28.718,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:28.718,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:28.810,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:28.810,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:28.810,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:28.810,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:29.117,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:29.117,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:29.117,000] <wrn> modem_hl7812: Power ON the UART
[00:02:29.117,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:02:29.117,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:29.117,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:29.117,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:02:29.117,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:29.117,000] <wrn> modem_hl7812: MDM_UART_CTS:1(5329590)
[00:02:29.117,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:29.117,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:29.122,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5127)
[00:02:29.128,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:29.128,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:34.117,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:02:34.117,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:34.117,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:34.117,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:34.209,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:34.209,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:34.209,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:34.209,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:34.461,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:02:34.461,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:02:34.461,000] <wrn> modem_hl7812: Power ON the UART
[00:02:34.461,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:02:34.461,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:02:34.461,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:02:34.461,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:02:34.461,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:02:34.461,000] <wrn> modem_hl7812: MDM_UART_CTS:1(5338379)
[00:02:34.461,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:34.461,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:02:34.466,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5127)
[00:02:34.471,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:02:34.471,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:02:39.461,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

This is just to see if there is any luck and improvement in latest FW.

In your log for +CEREG:
T3324 Active timer → 30 seconds
T3412 periodic TAU → 150 minutes

But according to VGPIO status from your log, the module slept at “01:54.845” and woke up at “01:54.859”, so it only slept for a very short period of time.

And the +kcellmeas URC comes 10 seconds after +PSMEV: 1, which seems matches to what you set in the timeout parameter of +kcellmeas.
If you set the timeout to longer period of time, will the modules sleep longer?

As you said before if you disable the +KCELLMEAS URC, there is no problem to go into PSM dormant mode.
I am also wondering what if you only enable the +KCELLMEAS URC (setting 10 seconds timeout) after module waking up.
Another way is that you can set the +KCELLMEAS URC only when you are going to wake up and send data.

Yes, here is a log that shows psm works good without KCELLMEAS=1,10. I think the problem may not be the KCELLMEAS here,

As you said here, something is waking up the module, and automatically I am getting kcellmeas after 10secs as it is expected according to the reference guides. I think the psm loop issue occurs because of my software, that doesn’t expect that much quick kcellmeas. The problem is that the first wake up by something we dont know ATM.

+CEREG: 4,,,,,,"00001111","00001111"
3957 hl_netfeasa.c 36 |+CEREG: 4,,,,,,"00001111","00001111"|
[00:01:53.961,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +CEREG: 4,,,,,,"00001111","00001111"
[00:01:53.961,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +CEREG:  (len:28)
[00:01:53.961,000] <dbg> modem_hl7812_rx: on_cmd_network_report: val: 4,,,,,,"00001111","00001111" stat: -1 urc_res_code: 0
[00:01:53.961,000] <dbg> modem_hl7812_rx: on_cmd_network_report: use URC CEREG parser
[00:01:53.961,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network status: 4,,,,,,"00001111","00001111"
[00:01:53.961,000] <dbg> modem_hl7812_rx: on_cmd_network_report: network state val: 4   0 valid parsed data: 1
[00:01:53.961,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:01:53.961,000] <dbg> modem_hl7812: set_network_state: SET NETWORK STATE: OUT_OF_COVERAGE
[00:01:53.961,000] <dbg> modem_hl7812: get_network_state_string: get_network_state_string 4
[00:01:53.961,000] <inf> modem_hl7812: Network State: 4 OUT_OF_COVERAGE
[00:01:53.961,000] <dbg> modem_hl7812: allow_sleep_timeout: Keep sleep 2424
[00:01:53.961,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:53.961,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
4,,,,,,"00001111","00001111" 7
[00:01:53.963,000] <wrn> modem_hl7812: MDM_UART_CTS:1(37576660)
[00:01:53.963,000] <dbg> modem_hl7812_rx: on_cmd_network_report: Network supports psm, active_timer: 00001111 tau: 00001111 
[00:01:53.963,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

+PSMEV: 1
3957 hl_netfeasa.c 9 |+PSMEV: 1|
[00:01:53.963,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: 3959 hl7812_rx_netfeasa.c msg: +PSMEV: 1
[00:01:53.964,000] <dbg> modem_hl7812_rx: hl7812_netfeasa_rx: HANDLE +PSMEV:  (len:1)
[00:01:53.964,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: PSMEV1: 1 sleep state: AWAKE
[00:01:53.964,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 1032
[00:01:53.964,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:53.964,000] <dbg> modem_hl7812_rx: on_cmd_psm_event: Current pm status: 1
[00:01:53.969,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:53.969,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:58.964,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:01:58.964,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 1 1
[00:01:58.964,000] <wrn> modem_hl7812: Power OFF the UART
[00:01:58.964,000] <wrn> modem_hl7812: VGPIO:0
[00:01:58.964,000] <wrn> modem_hl7812: Preparing IO for reset/sleep
[00:01:58.964,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 1 0
[00:01:58.964,000] <wrn> modem_hl7812: Power OFF the UART
[00:01:58.964,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:01:58.964,000] <wrn> modem_hl7812: MDM_UART_CTS:0(5000488)
[00:01:58.964,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:01:58.964,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 0
[00:01:58.964,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:01:58.964,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:01:58.964,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:58.964,000] <wrn> modem_hl7812: NOT awake
[00:01:58.964,000] <dbg> modem_hl7812: check_hl7812_awake: set_sleep_state(iface_ctx.desired_sleep_level);
[00:01:58.964,000] <dbg> modem_hl7812: set_sleep_state: set_sleep_state was: AWAKE, now: HIBERNATE
[00:01:58.964,000] <dbg> modem_hl7812: set_sleep_state: entered hibernate cancel shutdown work
[00:01:58.964,000] <dbg> modem_hl7812: generate_sleep_state_event: generate_sleep_state_event Sleep State: HIBERNATE gpio6: 0
[00:01:58.964,000] <dbg> modem_module: lte_evt_handler: MODEM MODULE LTE_LC_EVT_MODEM_SLEEP_ENTER
[00:01:58.964,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:01:58.964,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:58.969,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:58.969,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:01:58.985,000] <wrn> modem_hl7812: VGPIO:1
[00:01:58.985,000] <dbg> modem_hl7812: mdm_vgpio_callback_isr: iface_ctx.off2: 0
[00:01:58.985,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 1 0
[00:01:58.985,000] <wrn> modem_hl7812: Power ON the UART
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep: Keep awake 907
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:01:58.985,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 911
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:58.985,000] <wrn> modem_hl7812: MDM_UART_CTS:1(20996)
[00:01:58.985,000] <wrn> modem_hl7812: MDM_GPIO6:1
[00:01:58.985,000] <dbg> modem_hl7812: power_on_uart: UART pm_device_state_get: 0 0
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep: Keep awake 983
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep_with_timeout: Keep awake
[00:01:58.985,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> ASSERTED
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep: Keep sleep 987
[00:01:58.985,000] <dbg> modem_hl7812: allow_sleep_with_timeout: sleep scheduled
[00:01:58.985,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:01:58.985,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:58.985,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:01:58.985,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:58.990,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:58.990,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:1 
[00:01:59.054,000] <wrn> modem_hl7812: MDM_UART_CTS:0(69092)
[00:01:59.059,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 3 
[00:01:59.059,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:59.370,000] <wrn> sensor_module: MODEM_EVT_LTE_PSM_ENTER
1464 sensor_module.c
[00:01:59.370,000] <dbg> ext_sensors: ext_sensors_all_power_down: sensor power status: 0
[00:01:59.370,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+PRESS_CPOF=0
[00:02:00.370,000] <dbg> SENSORS_CMD: sn_command_switch: lps22@5c power down!
{"status":{"status":{"echo":"SN+PRESS_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"pressure","power":"PM_DEVICE_STATE_OFF"}}
[00:02:00.421,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+EFLASH_CPOF=0
[00:02:01.421,000] <dbg> SENSORS_CMD: sn_command_switch: mx25r6435f@0 power down!
{"status":{"status":{"echo":"SN+EFLASH_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"extrnal_memory","power":"PM_DEVICE_STATE_OFF"}}
[00:02:01.455,000] <dbg> SENSORS_CMD: sensors_command_parser: Sub cmd: 9 SN+ACCEL_CPOF=0
[00:02:02.455,000] <dbg> SENSORS_CMD: sn_command_switch: lis2dw12@0 power down!
{"status":{"status":{"echo":"SN+ACCEL_CPOF=0","cmd":"SENSOR","sub_cmd":"DEV_REQ_TURN_OFF","step":"FINISH_TEST","result":"DONE"}},"devices":{"name":"accelorometer","power":"PM_DEVICE_STATE_OFF"}}
1472 sensor_module.c
[00:02:03.985,000] <dbg> modem_hl7812: allow_sleep_work_callback: 1081 0 1 0 0 

1099 Allow sleep
[00:02:03.985,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 0 1 0 1
[00:02:03.985,000] <wrn> modem_hl7812: Power OFF the UART
[00:02:03.985,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:04.729,000] <wrn> modem_hl7812: MDM_GPIO6:0
[00:02:04.729,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 1
[00:02:04.729,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 950 
[00:02:04.729,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:1 GPIO6:0 UART_CTS:0 
[00:02:06.052,000] <wrn> modem_hl7812: MDM_UART_DSR:0
[00:02:06.052,000] <wrn> modem_hl7812: VGPIO:0
[00:02:06.052,000] <wrn> modem_hl7812: Preparing IO for reset/sleep
[00:02:06.052,000] <dbg> modem_hl7812: shutdown_uart: UART pm_device_state_get: 1 0 0 0
[00:02:06.052,000] <wrn> modem_hl7812: MDM_WAKE_PIN -> NOT_ASSERTED
[00:02:06.053,000] <dbg> modem_hl7812: check_hl7812_awake: 289 hl7812_netfeasa.c WHEREamIcallingfrom: 842 
[00:02:06.053,000] <dbg> modem_hl7812: is_cmd_ready: 274 290 LOWPOWER VGPIO:0 GPIO6:0 UART_CTS:0 
[00:02:15.737,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED
[00:03:15.737,000] <dbg> util_module: watchdog_handler: WATCHDOG_EVT_FEED

I cant try this one. But I tried something maybe similar to this. I used +KCELLMEAS=0 instead. I ran +KCELLMEAS=0 every 3 secs for 2mins, though, the device never got valid kcellmeas until I started UDP/TCP comms.

My application needs to send data whenever it wakes up. So, thats why I only set kcellmeas=1,10 on time during modem driver initialization.

And the +kcellmeas URC comes 10 seconds after +PSMEV: 1, which seems matches to what you set in the timeout parameter of +kcellmeas.
If you set the timeout to longer period of time, will the modules sleep longer?

I believe this is not using URC

you can do this:

  1. disable +KCELLNMEAS URC
  2. go to PSM dormant mode
  3. module should be able to sleep
  4. when you need to send data, assert wake up pin
  5. module should wake up
  6. now enable +KCELLNMEAS URC
  7. go to PSM dormant mode
  8. according to you test, module should be wake up immediately
  9. then you will receive the +KCELLNMEAS URC