LowPowerTimeout: Inconsistent delay when using multilple timeout objects

[fkjagodzinski]

Description

• Type: Bug
• Priority: Major

Bug

Target
K64F, NUCLEO_F070RB, NUCLEO_L476RG

Toolchain
GCC_ARM, ARM, IAR

Toolchain version
GCC_ARM -- 6.3.1,
ARM -- 5.24 (Flex) ARM Compiler 5.06 update 5 (build 528),
IAR -- ANSI C/C++ Compiler V7.80.4.12462/W32 for ARM

mbed-cli version
1.2.0

mbed-os sha
003dd7c

Code

#include "mbed.h"

#define NUM_TIMEOUTS 8
#define TEST_DELAY_US 800000ULL

int main() {
    Timer timers[NUM_TIMEOUTS];
    LowPowerTimeout timeouts[NUM_TIMEOUTS];

    for (size_t i = 0; i < NUM_TIMEOUTS; i++) {
        timers[i].start();
        timeouts[i].attach_us(mbed::callback(&timers[i], &Timer::stop), TEST_DELAY_US);
    }

    // Wait for all callbacks to fire;
    // (TEST_DELAY_US / 1000) is not enough in this case.
    Thread::wait(3000);

    for (size_t i = 0; i < NUM_TIMEOUTS; i++) {
        printf("%03u:%10i\n", i, timers[i].read_us());
    }
    putchar('\n');

    return 0;
}

Expected behavior
All callbacks fire after given delay so time measurements returned by timers[] equal TEST_DELAY_US.

Actual behavior
Not all callbacks fire with given delay -- some of them are further delayed by 0.8-2.0 s.

Sample output for K64F board:

# board power up
000:    864386  # not very accurate
001:    864373
002:    864358
003:    864345
004:    864330
005:    864315
006:    864300
007:    864285

# RESET button pressed
000:    799894  # OK
001:    799880  # OK
002:   2799544  # ?!
003:   2799530
004:   2799516
005:   2799500
006:   2799486
007:   2799470

# RESET button pressed
000:    799868
001:   2799540
002:   2799526
003:   2799512
004:   2799498
005:   2799482
006:   2799468
007:   2799452

Sample output for NUCLEO_F070RB board when compiled with GCC_ARM:

# board power up
000:    800714
001:    800476
002:    800233
003:   2242847
004:   2242595
005:   2242352
006:   2242108
007:   2241857

# RESET button pressed
000:    800707
001:    800479
002:    800226
003:   2242847
004:   2242601
005:   2242350
006:   2242106
007:   2241862

Sample output for NUCLEO_F070RB board when compiled with IAR:

# board power up
000:    800701
001:    800521
002:    800351
003:    800179
004:   1598718
005:   1598538
006:   1598344
007:   1598173

# RESET button pressed
000:    800721
001:    800552
002:    800379
003:    800179
004:   1598718
005:   1598546
006:   1598375
007:   1598196

Sample output for NUCLEO_L476RG board when compiled with ARM:

# board power up
000:    800696
001:    800597
002:    800497
003:    800394
004:    800297
005:    800197
006:   1599611
007:   1599511

# RESET button pressed
000:    800719
001:    800599
002:    800498
003:    800398
004:    800298
005:    800192
006:   1599611
007:   1599511

CC @bulislaw @0xc0170

[0xc0170]

I assume this is related to lp ticker. If you run the same test on regular Timeout class, all is fine?

cc @mmahadevan108 @bcostm @adustm @LMESTM @jeromecoutant

[fkjagodzinski]

Yes, regular Timeout is fine, only LowPowerTimeout behaves that way.

[0xc0170]

@mmahadevan108 @bcostm @adustm @LMESTM @jeromecoutant

bump

[fkjagodzinski]

#5347 resolves this issue for K64F board.

---

However, for K64F LowPowerTimeout behaviour is quite strange immediately after board power up, e.g. for TEST_DELAY_US set to 30000ULL:

# board power up
000:     94832  # not even near 30000 us!
001:     94817
002:     94802
003:     94788
004:     94772
005:     94756
006:     94740
007:     94725

# RESET button pressed
000:     30029
001:     30068
002:     30053
003:     30037
004:     30023
005:     30065
006:     30048
007:     30033

# board power up
000:     96987
001:     96972
002:     96957
003:     96943
004:     96927
005:     96911
006:     96896
007:     96880

# RESET button pressed
000:     30019
001:     30057
002:     30042
003:     30027
004:     30011
005:     30055
006:     30038
007:     30067

# board power up
000:     93825
001:     93810
002:     93795
003:     93781
004:     93765
005:     93749
006:     93733
007:     93718

# RESET button pressed
000:     30018
001:     30056
002:     30041
003:     30070
004:     30054
005:     30040
006:     30023
007:     30066

@bulislaw @0xc0170 I suppose this should be reported as another issue, right?
Regualr Timeout works as expected.