nRF9160-DK - sometimes busy for 1 minute before entering PSM

Using the nRF9160-DK together with the Power Profiler Kit 2, I observe sometimes a longer period (1 minute) of a 50mA consumption before entering PSM mode.

Is there a explanation for that? Could that behavior be "forecasted", or better disabled?

Parents Reply Children
  • modem 1.3.2

    NCS 2.0.1

    nrf connect for desktop 3.11.1, power profiler app 3.4.3

    Just to mention:

    My logs with PSM wakeup and sleep are matching the power consumption indicated by the PPK2. So, I guess, it's something happening in the modem, not an issue of the PPK2.

  • Hi,

    If there is a data transfere ongoing then the device will no go in to PSM mode before it is done, even tough PSM is granted. So this can be the case, but we can not say for sure what is the reason without logs, so if you could provide a modem log then that would be great as we will then be able to see what is going on i more detail. 

    Regards,
    Jonathan

  • I will try it and we will see.

    But I don't think, a pending transfer is the reason. At least not one, my application does. Using CoAP/DTLS CID is one message sent, one received and then the device may sleep again. I also don't see additional logging , which indicates, that something else happens.

    Also to mention: if a transmission is ongoing (see the begin of the power chart), the consumption is much higher than 50mA.

  • trace-2022-07-25T09-18-12.415Z.zip

    The last message exchange results then in a 60s pause until sleep.

    It's not too easy to have the Power Profile Kit also in place, but I hope the raw trace helps you to see the misery.

    From the application log:

    [00:01:40.092,803] <inf> COAP_CLIENT: 100 s, Thingy:91 v0.3, 0*3, 1*0, 2*0, 3*0, failures 0
    [00:01:40.092,895] <inf> COAP_CLIENT: 5175 mV
    [00:01:40.092,926] <inf> COAP_CLIENT: RSSI q,p: 255,255
    [00:01:40.092,987] <inf> COAP_CLIENT: Network: CAT-M1
    [00:01:40.093,078] <inf> COAP_CLIENT: PSM: 3600 s, Released: 11068 ms
    [00:01:40.093,139] <inf> COAP_CLIENT: CoAP request prepared, token 0xeecbbfee, 148 bytes
    [00:01:40.099,060] <inf> COAP_CLIENT: send_to_peer 184
    [00:01:40.167,449] <inf> COAP_CLIENT: LTE modem wakes up
    [00:01:40.723,602] <inf> COAP_CLIENT: RRC mode: Connected
    [00:01:41.031,524] <inf> COAP_CLIENT: received_from_peer 167 bytes
    [00:01:41.031,555] <inf> TINYDTLS: received message (167 bytes), starting with 'application_data', epoch 1

    [00:01:41.031,616] <inf> TINYDTLS: got 'application_data' epoch 1 sequence 4 (167 bytes)

    [00:01:41.032,379] <inf> TINYDTLS: ** application data:

    [00:01:41.032,409] <inf> COAP_CLIENT: CoAP response received. code: 2.04, token 0xeecbbfee, 128 bytes
    [00:01:41.032,409] <inf> COAP_CLIENT:   payload: 100 s, Thingy:91 v0.3, 0*3, 1*0, 2*0, 3*0, failures 0
    5175 mV
    RSSI q,p: 255,255
    Network: CAT-M1
    PSM: 3600 s, Released: 11068 ms
    [00:01:41.032,531] <inf> COAP_CLIENT: 4/629ms/938ms: success
    [00:01:41.032,531] <inf> COAP_CLIENT: retrans: 0*4, 1*0, 2*0, 3*0, failures 0
    [00:01:41.032,562] <inf> COAP_CLIENT: rtt: 0-2s: 4, 2-4s: 0, 4-6s: 0, 6-8s: 0, 8-10s: 0
    [00:01:41.032,562] <inf> COAP_CLIENT: rtt: 10-12s: 0, 12-14s: 0, 14-16s: 0, 16-18s: 0, 18-20: 0
    [00:01:41.032,592] <inf> COAP_CLIENT: rtt: avg. 1s (4#)
    [00:01:41.032,592] <inf> COAP_CLIENT: vbat: 5175, 5171, 5179, 5148, 0
    [00:01:41.032,623] <inf> COAP_CLIENT:       0, 0, 0, 0, 0
    [00:01:52.025,787] <inf> COAP_CLIENT: RRC mode: Idle after 11302 ms (10994 ms inactivity)
    [00:02:00.015,563] <inf> COAP_CLIENT: LTE modem sleeps
    [00:02:33.159,149] <inf> COAP_CLIENT: 153 s, Thingy:91 v0.3, 0*4, 1*0, 2*0, 3*0, failures 0
    [00:02:33.159,240] <inf> COAP_CLIENT: 5175 mV
    [00:02:33.159,301] <inf> COAP_CLIENT: RSSI q,p: 255,255
    [00:02:33.159,362] <inf> COAP_CLIENT: Network: CAT-M1
    [00:02:33.159,454] <inf> COAP_CLIENT: PSM: 3600 s, Released: 10994 ms
    [00:02:33.159,515] <inf> COAP_CLIENT: CoAP request prepared, token 0xefcbbfee, 148 bytes
    [00:02:33.165,405] <inf> COAP_CLIENT: send_to_peer 184
    [00:02:33.236,511] <inf> COAP_CLIENT: LTE modem wakes up
    [00:02:33.775,878] <inf> COAP_CLIENT: RRC mode: Connected
    [00:02:34.136,352] <inf> COAP_CLIENT: received_from_peer 167 bytes
    [00:02:34.136,383] <inf> TINYDTLS: received message (167 bytes), starting with 'application_data', epoch 1

    [00:02:34.136,444] <inf> TINYDTLS: got 'application_data' epoch 1 sequence 5 (167 bytes)

    [00:02:34.137,176] <inf> TINYDTLS: ** application data:

    [00:02:34.137,207] <inf> COAP_CLIENT: CoAP response received. code: 2.04, token 0xefcbbfee, 128 bytes
    [00:02:34.137,237] <inf> COAP_CLIENT:   payload: 153 s, Thingy:91 v0.3, 0*4, 1*0, 2*0, 3*0, failures 0
    5175 mV
    RSSI q,p: 255,255
    Network: CAT-M1
    PSM: 3600 s, Released: 10994 ms
    [00:02:34.137,329] <inf> COAP_CLIENT: 5/615ms/977ms: success
    [00:02:34.137,359] <inf> COAP_CLIENT: retrans: 0*5, 1*0, 2*0, 3*0, failures 0
    [00:02:34.137,359] <inf> COAP_CLIENT: rtt: 0-2s: 5, 2-4s: 0, 4-6s: 0, 6-8s: 0, 8-10s: 0
    [00:02:34.137,390] <inf> COAP_CLIENT: rtt: 10-12s: 0, 12-14s: 0, 14-16s: 0, 16-18s: 0, 18-20: 0
    [00:02:34.137,390] <inf> COAP_CLIENT: rtt: avg. 1s (5#)
    [00:02:34.137,420] <inf> COAP_CLIENT: vbat: 5175, 5175, 5171, 5179, 5148
    [00:02:34.137,451] <inf> COAP_CLIENT:       0, 0, 0, 0, 0
    [00:02:45.107,086] <inf> COAP_CLIENT: RRC mode: Idle after 11332 ms (10971 ms inactivity)
    [00:03:41.611,358] <inf> COAP_CLIENT: LTE modem sleeps

    Extract the "going to sleep":

    [00:01:52.025,787] <inf> COAP_CLIENT: RRC mode: Idle after 11302 ms (10994 ms inactivity)
    [00:02:00.015,563] <inf> COAP_CLIENT: LTE modem sleeps

    (8 seconds,matchs active time, OK)

    [00:02:45.107,086] <inf> COAP_CLIENT: RRC mode: Idle after 11332 ms (10971 ms inactivity)
    [00:03:41.611,358] <inf> COAP_CLIENT: LTE modem sleeps

    (60 seconds, drains the battery)

Related