microbit-foundation / micropython-microbit-v2

Temporary home for MicroPython for micro:bit v2 as we stablise it before pushing upstream
MIT License
44 stars 25 forks source link

Unexpected CPU cycle count with `time.tick_cpu()` #179

Closed microbit-carlos closed 5 months ago

microbit-carlos commented 6 months ago

With a CPU clock of 64 MHz I would expect time.tick_cpu() to overflow after 17 seconds (2^30 / 64_000_000 = 16.77 sec), and for sleep(1000) to take roughly 64 M cycles, however this script yields differnet results:

from microbit import *
import time

def one_sec_cycles():
    ticks_start = time.ticks_cpu()
    sleep(1000)
    ticks_end = time.ticks_cpu()
    return ticks_end - ticks_start

def time_to_overflow():
    # If this is the first call it will start the counter, so give it some headstart
    ticks_start = time.ticks_cpu()
    sleep(20)
    ticks_start = time.ticks_cpu()
    # Wait until it overflows
    while ticks_start < time.ticks_cpu():
        sleep(1)

    time_start = time.ticks_ms()
    ticks_start = time.ticks_cpu()
    while ticks_start < time.ticks_cpu():
        sleep(1)
    time_end = time.ticks_ms()
    return time_end- time_start

while True:
    print("1 sec: {} cycles".format(one_sec_cycles()))
    print("time to overflow: {} ms".format(time_to_overflow()))

Output:

1 sec: 10834428 cycles
time to overflow: 83293 ms
microbit-carlos commented 5 months ago

Also, it looks pressing the reset button also break ticks_ms().

Commenting out the last line from the previous script (so that it doesn't run the long time_to_overflow ()):

1 sec: 10292874 cycles
1 sec: 10259788 cycles
1 sec: 10297728 cycles
1 sec: 10285216 cycles
1 sec: 10281097 cycles
# Reset button pressed here
1 sec: 0 cycles
1 sec: 0 cycles
1 sec: 0 cycles
1 sec: 0 cycles
dpgeorge commented 5 months ago

Note that ticks_cpu() only counts cycles of the CPU when it's running. Doing a sleep(...) puts the CPU to sleep (using wfi) and so the CPU counter stops.

microbit-carlos commented 5 months ago

Thanks Damien, you are right, the CPU goes with sleep and that'd be reason it only counts 10M cycles instead of 64, however I am not sure why the count is zero when the reset button is pressed?

I guess it's possible the DWT->CTRL enable bit CYCCNTENA is maintained between resets (SWD triggered reset on the micro:bit), but not the CoreDebug->DEMCR enable bit TRCENA. https://github.com/microbit-foundation/micropython-microbit-v2/blob/8d9067d91bcfe316cd3aea5af1a873a37ca23d13/src/codal_port/mphalport.h#L48-L54

microbit-carlos commented 5 months ago

This PR fixes the issue for me: