Serial Modem: PPP connection floor current

[buh]

Hello together!

I am trying to reproduce the ultra low power connection as described in this whitepaper: /cfs-file/__key/communityserver-discussions-components-files/4/3482.Ultra-low-power-PPP-connection-using-nRF9151.pdf 

Therefore, I am using the same hardware, i.e. the nRF9151-DK and the nRF54L15-DK. I downloaded the ncs-serial-modem v1.0.0 and compiled the firmware for both DKs using the description from https://docs.nordicsemi.com/bundle/addon-serial_modem-latest/page/samples/sm_ppp_shell.html and added the required overlays to both the serial modem app and the PPP shell sample. As described, I also disabled VCOM0 on the nRF54L15-DK. I used the exact same wiring as described and a PPK2 in source meter mode at 3.7 V to measure the current of the nRF9151-DK.

Everything works fine and I can connect to a network through the UART shell on the nRF54L15-DK, achieving IP connectivity.

But unfortunately, I am not able to achieve the floor current of 2 uA as described in the whitepaper, instead it is around 40 uA. Even after reset (without sending anything over the UART) the current does not drop below those 40 uA.

When trying the AT client shell sample from https://docs.nordicsemi.com/bundle/addon-serial_modem-latest/page/samples/sm_at_client_shell.html with the exact same setup I am able to achieve a floor/idle current of around 3 uA, which I would accept to be close enough to the "ideal" 2 uA from the whitepaper.

After all, I found a temporary way to reduce the current to 3 uA using the PPP shell sample too, which is:
- bring up IP connectivity
- reset the nRF9151-DK (push button)
- reset the nRF54L15-DK (push button)
I guess, through that procedure I probably break some CMUX or PPP state machine and it's not the intended way how it should work. Doing another reset on the nRF9151-DK the current goes back up to 40 uA.

Is there any additional configuration required to reproduce the setup from the whitepaper? Alternatively, would it be possible to share the source code and test procedure that were used for the measurements in the whitepaper?

Best regards
Bernhard

[Hakon]

Modem team;

It’s difficult to analyze without seeing the current measurement graph. But if the measured current stays at approximately 40uA level (instead of mainly 3uA + some high spikes that raise average), this sounds to me more like eDRX idle floor current without suspending SIM card. It might be worth trying with PSM only and disabling eDRX altogether with AT+CEDRXS=0.

[buh]

Hi!

Here's a screenshot of my PPK2 current measurement of the nRF9151-DK:

This is what I did:
- The very first peak is due to a hardware reset on the nRF9151-DK.
- After around 20 seconds or so I sent "net iface up 1" through the UART shell on the nRF54L15-DK
- After around 1 min I sent "net ping 8.8.8.8"
- After around 1min 30 seconds I sent "net iface down 1"

Here's the log output from the shell (slightly sanitized):

WARNING: A print request was detected on not active shell backend.
[00:00:00.255,401] <dbg> modem_cellular: modem_cellular_init: Ring GPIO interrupt configured
*** Booting nRF Connect SDK v3.2.2-74845e169be2 ***
*** Using Zephyr OS v4.2.99-fe4f0106803e ***
[00:00:04.400,665] <dbg> modem_cellular: modem_cellular_log_event: event RING
uart:~$ net iface
Hostname: zephyr
Default interface: 1


Interface ppp0 (0x20002e7c) (PPP) [1]
==============================
Interface is down.
uart:~$ net iface up 1
EVENT: L3 [1] IPv4 mcast address add 224.0.0.1
Interface 1 is up
EVENT: L2 [1] interface admin up
[00:00:17.280,944] <dbg> modem_cellular: modem_cellular_log_event: event resume
[00:00:17.281,066] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from idle to run init script
[00:00:17.281,097] <dbg> modem_cellular: modem_cellular_log_event: event bus opened
[00:00:17.674,896] <dbg> modem_cellular: modem_cellular_log_event: event script success
[00:00:17.674,987] <dbg> modem_cellular: modem_cellular_log_event: event bus closed
[00:00:17.675,048] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from run init script to connect cmux
[00:00:17.675,537] <dbg> modem_cellular: modem_cellular_log_event: event bus closed
[00:00:17.775,115] <dbg> modem_cellular: modem_cellular_log_event: event timeout
[00:00:17.775,207] <dbg> modem_cellular: modem_cellular_log_event: event bus opened
[00:00:18.139,343] <dbg> modem_cmux: modem_cmux_on_control_frame_ua: CMUX connected
[00:00:18.139,465] <dbg> modem_cellular: modem_cellular_log_event: event cmux connected
[00:00:18.139,526] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from connect cmux to open dlci1
[00:00:18.173,553] <dbg> modem_cmux: modem_cmux_on_dlci_frame_ua: DLCI 1 opened
[00:00:18.173,583] <dbg> modem_cmux: modem_cmux_send_msc: Sending MSC command for DLCI 1, FC:0 RTR: 1 DV: 1
[00:00:18.173,645] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:1,type:MSC
[00:00:18.173,706] <dbg> modem_cellular: modem_cellular_log_event: event dlci1 opened
[00:00:18.173,767] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from open dlci1 to open dlci2
[00:00:18.173,950] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 6 bytes at once.
[00:00:18.209,106] <dbg> modem_cmux: modem_cmux_on_control_frame: Drop a response frame
[00:00:18.209,136] <dbg> modem_cmux: modem_cmux_log_received_command: ea:1,cr:1,type:MSC
[00:00:18.209,167] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:0,type:MSC
[00:00:18.209,228] <dbg> modem_cmux: modem_cmux_on_msc_command: MSC command received for DLCI 1
[00:00:18.209,228] <dbg> modem_cmux: modem_cmux_on_dlci_frame_ua: DLCI 2 opened
[00:00:18.209,289] <dbg> modem_cmux: modem_cmux_send_msc: Sending MSC command for DLCI 2, FC:0 RTR: 1 DV: 1
[00:00:18.209,320] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:1,type:MSC
[00:00:18.209,503] <dbg> modem_cellular: modem_cellular_log_event: event dlci2 opened
[00:00:18.209,625] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from open dlci2 to run apn script
[00:00:18.244,628] <dbg> modem_cmux: modem_cmux_on_control_frame: Drop a response frame
[00:00:18.244,689] <dbg> modem_cmux: modem_cmux_log_received_command: ea:1,cr:1,type:MSC
[00:00:18.244,720] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:0,type:MSC
[00:00:18.244,750] <dbg> modem_cmux: modem_cmux_on_msc_command: MSC command received for DLCI 2
[00:00:18.309,661] <dbg> modem_cellular: modem_cellular_log_event: event timeout
[00:00:18.356,719] <dbg> modem_cellular: modem_cellular_log_event: event script success
[00:00:18.356,811] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from run apn script to run dial script
[00:00:18.356,903] <dbg> modem_cellular: modem_cellular_log_event: event timeout
[00:00:18.594,787] <dbg> modem_cellular: modem_cellular_log_event: event script success
[00:00:18.594,879] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from run dial script to await registered
[00:00:20.594,940] <dbg> modem_cellular: modem_cellular_log_event: event timeout
[00:00:22.091,918] <dbg> modem_cellular: modem_cellular_log_event: event deregistered
EVENT: L2 [1] interface up
[00:00:24.357,635] <dbg> modem_cellular: modem_cellular_log_event: event registered
[00:00:24.357,727] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from await registered to carrier on
[00:00:26.357,818] <dbg> modem_cellular: modem_cellular_log_event: event timeout
EVENT: L4 [1] DNS server add 8.8.8.8
EVENT: L4 [1] DNS server add 1.1.1.1
EVENT: L3 [1] IPv6 address add <LOCAL_IPV6_ADDR>
EVENT: L3 [1] IPv6 neighbor add <LOCAL_IPV6_NEIGHBOR>
EVENT: L3 [1] IPv4 address add <PRIVATE_IPV4_ADDR>
EVENT: L4 [1] connected 
EVENT: L4 [1] IPv4 connectivity available
[00:00:29.357,513] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 57 bytes at once.
[00:00:29.360,870] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 35 bytes at once.
[00:00:29.387,725] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 39 bytes at once.
[00:00:29.391,082] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 56 bytes at once.
[00:00:34.439,788] <dbg> modem_cmux: modem_cmux_runtime_pm_handler: Idle timeout, entering power saving mode
[00:00:34.439,849] <dbg> modem_cmux: modem_cmux_send_psc: Sending PSC command
[00:00:34.439,880] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:1,type:PSC
[00:00:34.474,243] <dbg> modem_cmux: modem_cmux_log_received_command: ea:1,cr:0,type:PSC
[00:00:34.474,243] <dbg> modem_cmux: modem_cmux_on_control_frame_uih: Received response command
[00:00:34.474,273] <dbg> modem_cmux: modem_cmux_on_psc_response: Enter power saving
uart:~$ net iface
Hostname: zephyr
Default interface: 1


Interface ppp0 (0x20002e7c) (PPP) [1]
==============================
Link addr : <LINK_ADDR>
MTU       : 1460
Flags     : NO_AUTO_START,IPv4,IPv6
Device    : modem_ppp_ppp_nordic_nrf91_slm0 (0x34ccc)
Status    : oper=UP, admin=UP, carrier=ON
IPv6 unicast addresses (max 2):
        <LOCAL_IPV6_ADDR> autoconf preferred infinite
IPv6 multicast addresses (max 3):
        <none>
IPv6 prefixes (max 2):
        <none>
IPv6 hop limit           : 64
IPv6 base reachable time : 30000
IPv6 reachable time      : 36314
IPv6 retransmit timer    : 0
IPv4 unicast addresses (max 1):
        <PRIVATE_IPV4_ADDR>/255.255.255.0 manual preferred infinite
IPv4 multicast addresses (max 2):
        224.0.0.1
IPv4 gateway : 0.0.0.0
uart:~$ net ping 8.8.8.8
PING 8.8.8.8
28 bytes from 8.8.8.8 to <PRIVATE_IPV4_ADDR>: icmp_seq=1 ttl=118 time=465 ms
[00:00:59.360,015] <dbg> modem_cmux: powersave_wait_wakeup: Power saving mode, wake up first
[00:00:59.475,097] <dbg> modem_cmux: powersave_wait_wakeup: Woke up from power saving mode
[00:01:00.360,107] <dbg> modem_cmux: modem_cmux_transmit_handler: Transmitted only 0 out of 43 bytes at once.
uart:~$ net28 bytes from 8.8.8.8 to <PRIVATE_IPV4_ADDR>: icmp_seq=2 ttl=118 time=178 ms
28 bytes from 8.8.8.8 to <PRIVATE_IPV4_ADDR>: icmp_seq=3 ttl=118 time=1572 ms
[00:01:07.932,098] <dbg> modem_cmux: modem_cmux_runtime_pm_handler: Idle timeout, entering power saving mode
[00:01:07.932,159] <dbg> modem_cmux: modem_cmux_send_psc: Sending PSC command
[00:01:07.932,189] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:1,type:PSC
[00:01:07.966,522] <dbg> modem_cmux: modem_cmux_log_received_command: ea:1,cr:0,type:PSC
[00:01:07.966,552] <dbg> modem_cmux: modem_cmux_on_control_frame_uih: Received response command
[00:01:07.966,552] <dbg> modem_cmux: modem_cmux_on_psc_response: Enter power saving
uart:~$ net iface down 1
EVENT: L3 [1] IPv4 mcast address del 224.0.0.1
EVENT: L3 [1] IPv4 mcast leave 224.0.0.1
EVENT: L3 [1] IPv4 address del <PRIVATE_IPV4_ADDR>
Interface 1 is down
EVENT: L3 [1] IPv6 address del <LOCAL_IPV6_ADDR>
EVENT: L3 [1] IPv6 neighbor del <LOCAL_IPV6_NEIGHBOR>
EVENT: L2 [1] interface admin down
EVENT: L2 [1] interface down
EVENT: L4 [1] disconnected 
[00:01:34.000,244] <dbg> modem_cmux: powersave_wait_wakeup: Power saving mode, wake up first
[00:01:34.115,386] <dbg> modem_cmux: powersave_wait_wakeup: Woke up from power saving mode
[00:01:34.162,658] <dbg> modem_cellular: modem_cellular_log_event: event ppp dead
[00:01:34.163,116] <dbg> modem_cellular: modem_cellular_log_event: event suspend
[00:01:34.163,177] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from carrier on to init power off
[00:01:34.163,269] <dbg> modem_cmux: modem_cmux_log_transmit_command: ea:1,cr:1,type:CLD
[00:01:34.198,028] <dbg> modem_cmux: modem_cmux_on_dlci_frame: Unexpected DLCI frame in state 7
[00:01:34.198,089] <dbg> modem_cmux: modem_cmux_log_received_command: ea:1,cr:0,type:CLD
[00:01:34.198,089] <dbg> modem_cmux: modem_cmux_on_control_frame_uih: Received response command
[00:01:34.198,120] <dbg> modem_cmux: disconnect: CMUX disconnected
[00:01:34.198,211] <dbg> modem_cellular: modem_cellular_log_event: event cmux disconnected
[00:01:34.198,333] <dbg> modem_cellular: modem_cellular_log_state_changed: switch from init power off to idle
EVENT: L4 [1] IPv4 connectivity lost
uart:~$ net iface
Hostname: zephyr
Default interface: 1


Interface ppp0 (0x20002e7c) (PPP) [1]
==============================
Interface is down.
uart:~$ 

Regarding the new settings (PSM only and disabling eDRX altogether with AT+CEDRXS=0): May I ask for some Kconfig or code snippets etc.?

Best regards
Bernhard

[Hakon]

Modem team;

I’m able to reproduce similar current consumption that the customer sees, when I enable eDRX only, and disable PSM. So it looks like eDRX and PSM are either not configured correctly, or the network operates so that eDRX setting is dominant, and PSM idle is not used.

eDRX and PSM settings are saved to modem flash when AT+CFUN=0 is issued. My recommendation for testing that PSM idle works correctly:

1. Flash sm_at_client_shell sample to nRF54 to be able to send AT commands.

2. Connect terminal to nRF54 UART

3. Power on modem:

   sm AT+CFUN=1

4. Disable eDRX:

   sm AT+CEDRXS=0

5. Enable PSM (with sm_at_client_shell, double quotes need to be escaped):

   sm AT+CPSMS=1,,,\”00101100\”,\”00000111\”

6. Power off modem to save settings to flash:

   sm AT+CFUN=0

7. Flash sm_ppp_shell sample to nRF54

8. Reset both DKs.

9. Start current measurement

10. Connect terminal to nRF54 UART

11. Bring up network interface:

    net iface up 1

Idle current should be ~3uA after DUT has entered PSM idle, and UARTs are powered off: