Mbed-os: Sleep/deepsleep and Serial class

[ua1arn]

Description

Issue request type

[X] Question
[ ] Enhancement
[ ] Bug

target: NUCLEO_F446ZE
toolchain: 6 2017-q2-update
mbed_cli: 1.8.3
SHA: 1bf6b20df9 (HEAD, tag: mbed-os-5.13.4, origin/mbed-os-5.13)

On page https://os.mbed.com/docs/mbed-os/v5.13/apis/power-management-sleep.html mentioned about possibility of locking deepsleep from Serial class.
In test application I create instance of Serial.
Application send small amount of data and (after complete operation) invoke enable_input(false) and enable_output(false).
But, deepsleep still locked (and current indicator on test board say same).
It is a bug or expected behavior?
Configs on proper places:

“target.tickless-from-us-ticker”: false,
“target.deep-sleep-latency”: 50,

and
"macros_add": ["MBED_TICKLESS"],

[ua1arn]

Test application source code:

    #include "mbed.h"

    void txcb(int v)
    {
      //printf("txcb(%d)\n", v);
    }

    int main(void) {
      // low power mode clocks off
      __HAL_RCC_USB_OTG_FS_CLK_SLEEP_DISABLE();
      __HAL_RCC_USB_OTG_HS_CLK_SLEEP_DISABLE();
      __HAL_RCC_USB_OTG_HS_ULPI_CLK_SLEEP_DISABLE();
      __HAL_RCC_DAC_CLK_SLEEP_DISABLE();
      __HAL_RCC_ADC1_CLK_SLEEP_DISABLE();
      __HAL_RCC_ADC2_CLK_SLEEP_DISABLE();
      __HAL_RCC_ADC3_CLK_SLEEP_DISABLE();
      __HAL_RCC_SAI1_CLK_SLEEP_DISABLE();
      __HAL_RCC_CAN1_CLK_SLEEP_DISABLE();
      __HAL_RCC_CAN2_CLK_SLEEP_DISABLE();
      __HAL_RCC_CEC_CLK_SLEEP_DISABLE();
      __HAL_RCC_FMPI2C1_CLK_SLEEP_DISABLE();
      __HAL_RCC_WWDG_CLK_SLEEP_DISABLE();

       mbed_file_handle(STDIN_FILENO)->enable_input(false);


      Serial serial(PA_9, PA_10, 115200);
      event_callback_t serialEventCb;

      serialEventCb = txcb;
      serial.enable_input(false);
      serial.write((const uint8_t *) "hello", 5, serialEventCb);
      ThisThread::sleep_for(1000);
      serial.enable_output(false);

      printf("sleep_manager_can_deep_sleep()=%d\r\n", sleep_manager_can_deep_sleep());    
      for (;;) {
        printf("sleep_manager_can_deep_sleep()=%d\r\n", sleep_manager_can_deep_sleep());    
        ThisThread::sleep_for(1000);

        //serial.enable_output(false);
        //serial.abort_write();
        //serial.abort_read();
        //serialEventCb = NULL;
        //serial.attach(NULL);
      }
    }

[kjbracey-arm]

The deep sleep might be locked for some other reason? I can't see any reason for serial to be causing it here.

Note that the enable_input(false) is only effective for the buffered UARTSerial. If using unbuffered Serial, deep sleep shouldn't be locked anyway, unless you use its attach method, which you're not. (enable_input controls UARTSerial's built-in attach). Here both your ports are unbuffered. Console buffering is controlled via platform.stdio-buffered-serial.

[ua1arn]

As a fact, test board drawn 8..9 mA at point before create Serial object instance (tested with infinity loop with 1000 mS delay). After complete sending data rise to 40 mA.
Any ideas?

[kjbracey-arm]

Oh, this is using the asynchronous API. I'm not familiar with that. Personally, I wouldn't recommend it - use UARTSerial and let it do interrupt-driven PIO.

Looking at it, deep sleep gets locked by the call to write, as the transfer starts (SerialBase::write-> start_write)

It should get unlocked when the transfer finishes - after txcb is called (SerialBase::interrupt_handler_asynch). Does your callback get called?

[ua1arn]

Does your callback get called?

Yes, but power consumption sill high.

[ghseb]

There might be power drain over RX/TX pins after UART is initialized.

Also #10924 might be interesting for you.

[kjbracey-arm]

I still can't see how this fails due to sleep locks. Do you have the ability to attach a debugger, and breakpoint sleep_manager_lock_deep_sleep and sleep_manager_unlock_deep_sleep?

It may be an issue in the STM HAL rather than the generic Mbed OS code. Looking at the implementation, maybe serial_is_tx_ongoing() is returning true - that acts as an interlock in its deep sleep:

https://github.com/ARMmbed/mbed-os/blob/8ef742a49c1682f9ef3ba50148b871e38c3866cc/targets/TARGET_STM/sleep.c#L154-L164

[kjbracey-arm]

CC @LMESTM

[LMESTM]

Could you try enabling MBED_SLEEP_TRACING_ENABLED ?

[LMESTM]

@kjbracey-arm if you're right, then it's maybe time to address #4408 which is still open ...

[kjbracey-arm]

That'll teach me to open my big mouth.

[ua1arn]

Your messageabout serial_is_tx_ongoing() is really helps!

[kjbracey-arm]

Note that this is related to https://github.com/ARMmbed/mbed-os/issues/11401. Both platforms are doing the same basic thing with the "wait for serial in deep sleep call".

[ua1arn]

How about add __WEAK to serial_is_tx_ongoing() ?

[LMESTM]

How about add __WEAK to serial_is_tx_ongoing() ?

Can you elaborate some more about this proposal ?
the right thing to do is for serial class to lock deep sleep as long as there is an ongoing TX. I think that the serial class needs to make use of "serial_is_tx_ongoing()" and release the lock when TX is over.

In your case, I'm not sure what the reason for not entering deep sleep.
Of course your printf cannot be positive because print is ongoing, but that doesn't prove that deep sleep will not be entered later on.
printf("sleep_manager_can_deep_sleep()=%d\r\n", sleep_manager_can_deep_sleep());

Or have you checked with CPU stats the % of time spent in each CPU state ?

[ua1arn]

Next line after printfis a ThisThread::sleep_for(1000);
I am measure CPU current consumption.

[LMESTM]

Ok that's the point. Can you also confirm your power figures by tracing as well CPU stats (% of time in idle / sleep / deep sleep ..) ?

I am measure CPU current consumption.

Just to confirm. Are you measuring the MCU current only on the IDD measurement point or the complete board ? The board includes a 2nd STM32 in the st-link debug side of the board that you want to exclude from your power measurement ...

[ua1arn]

Original ST-LINK V2 is not drawn significant current (only IO reference) - at programming stage I measure about 2 mA. I measure only MCU. Test code with deep aleep consume 18 mA, without - at 36..40 mA.
CPU time consumption now I can not provide.

[LMESTM]

Just made a quick test by modifying your code and adding tracing of CPU stats. It shows that deep sleep is well entered ...

=============================== SYSTEM INFO  ================================
Mbed OS Version: 0
CPU ID: 0x0
Compiler ID: 0
Compiler Version: 0
sleep_manager_can_deep_sleep()=0
================= CPU STATS =================
Idle: 92% Usage: 8%
Sleep: 5%, Deep_sleep: 87%

sleep_manager_can_deep_sleep()=1
================= CPU STATS =================
Idle: 93% Usage: 7%
Sleep: 5%, Deep_sleep: 88%

[LMESTM]

and I also can reproduce the current consumption issue you're seeing
Most probably we're indeed looping in :

     if (serial_is_tx_ongoing()) { 
         return; 
     } 

[LMESTM]

Just pushed #11688 to fix the issue.
@ua1arn Please confirm if fix is verified at your end