circuitpython: time.monotonic_ns sometimes jumps forward, and then returns the correct value on the next call

CircuitPython version

pi@serialpi:~ $ more /media/CIRCUITPY/boot_out.txt 
Adafruit CircuitPython 7.0.0 on 2021-09-20; Adafruit Feather M4 Express with samd51j19
Board ID:feather_m4_express

Code/REPL

# system is bigger than this, but this is the only code making calls to monotonic_ns
def get_new_now(prev):
    global previous_now
    global monotonic_ns_calls

    if prev is not None:
        previous_now = prev

    monotonic_ns_calls += 1
    now = time.monotonic_ns()

    if previous_now is not None:
        if previous_now > now:
            print(f"monotonic_ns MOVED BACKWARD! {previous_now} {now} : {monotonic_ns_calls} {count_string()}")
        elif now - previous_now > SECONDS_PER_NS * 3600 * 24:
            print(f"monotonic_ns JUMPED MORE THAN A DAY! {previous_now} {now} : {monotonic_ns_calls} {count_string()}")
            # monotonic_ns_calls += 1
            # now = time.monotonic_ns()
            # print(f"called monotonic_ns() again, now: {now}")

    return now

Behavior

monotonic_ns JUMPED MORE THAN A DAY! 4194303992614752 4456447999938977 : 13388088 loop_count: 3868063 state_clock: 3868062
[...other stuff...]
monotonic_ns MOVED BACKWARD! 4456447999938977 4194304025573733 : 13388089 loop_count: 3868064 state_clock: 3868063

Description

I have two Adafruit Feather M4 running programs that call time.monotonic_ns ~100 times a second. Each day with approximately a 10% chance it seems one them makes a monotonic_ns call and gets a result more than a day in the future. The next call then seem to be ok.

I have an Adafruit Bluefuit Circuit Playground running similar code that doesn’t seem to present this problem. Aside from the CPU one difference is the M4’s are setting rtc.RTC().datetime once an hour…thought the discontinues in monotonic_ns don’t seem correlated with these calls.

Additional information

No response

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 19 (3 by maintainers)

Commits related to this issue

Most upvoted comments

That is the build with the commit of my changes 😦 . It’s also in 7.2.0-alpha.2.

We hope to give you a test version relatively soon, I think. And we want to try to reproduce this in a simpler way, maybe by presetting the counter value so we don’t have to wait three days 😃. I just talked to @jepler about this, this morning.

here is a more careful implementation: https://github.com/tinygo-org/tinygo/blob/release/src/runtime/runtime_atsamd51.go and a PR which fixed a problem: https://github.com/tinygo-org/tinygo/pull/1870 Long thread about general technique (referenced in the code and PR above): https://www.eevblog.com/forum/microcontrollers/correct-timing-by-timer-overflow-count/