Skip to content

Timer consistency across backends - #29062

Open
greglucas wants to merge 6 commits into
matplotlib:mainfrom
greglucas:timer-consistency
Open

greglucas wants to merge 6 commits into
matplotlib:mainfrom
greglucas:timer-consistency

Conversation

@greglucas

@greglucas greglucas commented Nov 1, 2024 •

Copy link
Copy Markdown
Contributor

PR summary

Backend timers currently differ in how they handle property updates, slow callbacks, single-shot completion, and restarts from inside callbacks. This PR makes those behaviors consistent and adds cross-backend tests for the expected semantics.

Timer property updates

Assigning timer.interval or timer.single_shot now updates a running timer across all backends. Assigning the existing value is a no-op, so repeatedly setting the same property no longer restarts or postpones the timer.

Changing properties on a timer that has never been started, or on a completed single-shot timer, does not start it.

Repeating timers

Repeating timers that need to reschedule themselves use the expected firing time as their reference. Therefore, a slow callback does not introduce cumulative drift. If a callback overruns one or more intervals, those missed firings are skipped.

Qt is configured as a PreciseTimer now (I was having problems with the test assertions on the macos runners without this).

Timer lifecycle

Backends now preserve a replacement timer started from inside its callback. Completed single-shot timers clear their active handle before invoking the callback, allowing the callback to restart the timer safely and ensuring later
property updates do not restart the completed timer.

Event loops

FigureCanvasBase.start_event_loop now measures elapsed time instead of counting polling iterations, so callback and event-processing time no longer extends the requested timeout. (Previously slow callbacks caused this to extend the requested event loop duration)

GTK gains a native GLib.MainLoop implementation.

Tests

The timer tests cover:

  • interval and single-shot changes on running timers
  • property changes on idle and completed timers
  • repeating timers with slow callbacks
  • restarting a single-shot timer from its callback
  • exact Asyncio and Tornado single-shot callback counts
  • event-loop timeout behavior
  • timer behavior across the interactive backend worker suite

closes #28647
closes #29029
closes #29076

PR checklist

@greglucas

Copy link
Copy Markdown
Contributor Author

With this PR all backends produce 7 events for this script:
#29029 (comment)

@greglucas

Copy link
Copy Markdown
Contributor Author

I added tests and they all pass locally for me, but I can't seem to get things working on the CI runners, so I'm going to put some thoughts/notes down here. I'm wondering if there are issues with trying to assert against timing on shared resources? Thinking it was just trying to run things too fast on limited resources, I increased the timer interval to 500ms and that didn't seem to help. Currently, I am asserting against the expected number of calls, is there possibly a delay involved in first timer spin-up so I should be asserting against the final timer interval somehow instead? If anyone has ideas for better tests here let me know.

@QuLogic

QuLogic commented Nov 6, 2024

Copy link
Copy Markdown
Member

Since this is only failing on 3.13 (on macOS at least), one possibly suspicious change is in time.perf_counter:

Changed in version 3.13: Use the same clock as time.monotonic().

But I thought you had used time.monotonic before? Did it fail then as well?

@QuLogic

QuLogic commented Nov 6, 2024

Copy link
Copy Markdown
Member

I can reproduce the failure on AppVeyor locally (Expected 8, got 5); given #28647 (comment), I think that means it is re-evaluating the timeout after the slow callback and not attempting to create a consistent time.

@greglucas

Copy link
Copy Markdown
Contributor Author

That is actually a different failure than the one we are seeing here of course 😂 https://github.com/matplotlib/matplotlib/actions/runs/11688137387/job/32547874573?pr=29062#step:15:200

AssertionError: Event loop: Expected to run for around 2s, but ran for 4.47s

These tests on CI systems seem flakey because I had a job right before this push where all the tests passed. I think this gets to the comment you left about system resources and scheduling because sometimes QT is the one failing in CI, others it is GTK. We are running pytest with as many processors as possible -n auto, then submitting subprocesses that spin up GUI event loops from within those processes on potentially shared resources in a CI environment. (One thought I had was whether we could only run one subprocess per backend rather than starting/stopping so many of them, something like MPLBACKEND=gtk4agg pytest -m all_gui_tests which would keep the same backend for all the interactive test session, but that seems like quite a bit of a rework)

Running locally with this script:

import time
import matplotlib.pyplot as plt

fig = plt.figure()

last_time = orig_time = time.perf_counter()

x = 0

def on_timer():
    global x
    global last_time
    t = time.perf_counter()
    print(f"{x:02d}: {t - last_time:.3f} ({t - orig_time:.3f})")
    last_time = t
    if x == 0:
        time.sleep(0.5)
    else:
        time.sleep(0.1)
    x += 1

timer = fig.canvas.new_timer(interval=150)
timer.add_callback(on_timer)
timer.start()
fig.canvas.start_event_loop(3)

GTK has an ~8ms drift associated with it, whereas all the other backends hit within ~1ms.

00: 0.151 (0.151)
01: 0.502 (0.653)
02: 0.157 (0.811)
03: 0.159 (0.969)
04: 0.157 (1.126)
05: 0.158 (1.284)
06: 0.158 (1.442)
07: 0.158 (1.600)
08: 0.159 (1.759)
09: 0.157 (1.916)
10: 0.157 (2.073)
11: 0.158 (2.231)
12: 0.158 (2.389)
13: 0.158 (2.547)
14: 0.158 (2.704)
15: 0.157 (2.861)
16: 0.156 (3.018)
17: 0.157 (3.175)
18: 0.158 (3.333)
19: 0.157 (3.490)
20: 0.158 (3.648)
21: 0.158 (3.806)
22: 0.155 (3.961)

@greglucas

Copy link
Copy Markdown
Contributor Author

It looks like GTK has no plans on changing this: https://gitlab.gnome.org/GNOME/glib/-/issues/503
I tried moving the logic from Tk over to GTK as well and recreating a singleshot timer with our own calculated interval and got values above and below 150ms rather than consistently 158ms. So theoretically might reduce some of the accumulated error, but it also still has a pretty significant error compared to all of the other frameworks which are closer to 1ms.

00: 0.153 (0.153)
01: 0.514 (0.667)
02: 0.234 (0.901)
03: 0.156 (1.057)
04: 0.144 (1.201)
05: 0.157 (1.358)
06: 0.146 (1.504)
07: 0.157 (1.661)
08: 0.146 (1.807)
09: 0.146 (1.953)
10: 0.158 (2.111)
11: 0.147 (2.258)
12: 0.147 (2.405)
13: 0.147 (2.551)
14: 0.156 (2.707)
15: 0.146 (2.853)

@greglucas

Copy link
Copy Markdown
Contributor Author

Rebased and pushed again. All tests passing locally, going to see how this does on CI now...

Comment thread src/_macosx.m Outdated
// we shouldn't do it ourselves when the object is deleted.
self->timer = NULL;
}
self->timer = [NSTimer scheduledTimerWithTimeInterval: interval

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

While I realize that this is an old PR, I'm going through all of the old issues and pull requests tagged with as Apple/macOS.

+scheduledTimerWithTimeInterval:… does the following:

CFRunLoopAddTimer(CFRunLoopGetCurrent(), timer, NSDefaultRunLoopMode));

CFRunLoopGetCurrent() will create a run loop for the current thread if one does not already exist. I'm not sure if this is the behavior that you want if this is called on a background thread created from Python.

That said, in the case of a background thread, the previous behavior of calling -addTimer:forMode: on the main thread is also technically wrong - NSRunLoop is marked as a thread-unsafe class. It works, but only because CFRunLoopAddTimer() is currently implemented to take out a pthread mutex.

I think the right behavior is to dispatch_async() over to the main queue and then add the timer from there.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤔 I have went through and removed the dispatch_async() updates I had previously and this is now more minimal and focused on just getting the timing/functionality consistent. I think we should defer the better macos timer implementation to your PRs rather than try to fit that into this one.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be easiest to ignore the macosx backend in this PR since everything is changing and then we can go back and patch it up once the dust settles?

The new macos timer implementation has been specifically written with this PR in mind.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Potentially. Look at the new updates though because they are very minimal and just add an update() method and rearrange the call order. The tests will be the important part that will need to pass for the new branch too.

I'm fine rebasing this if your PR goes in first. This has been open for 2 years now, so I don't anticipate it getting in soon at all :)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see that now - I was looking at the old files still. In any case: this is going to be a high priority in my review queue!

Comment thread src/_macosx.m Outdated
repeats: !single
block: ^(NSTimer *timer) {
dispatch_async(dispatch_get_main_queue(), ^{
gil_call_method((PyObject*)self, "_on_timer");

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a rare crash.

  1. The timer fires and queues up a block onto the main dispatch queue. This will execute the block on the next run loop cycle.
  2. Timer_dealloc gets called on this runloop cycle. While the timer is invalidated, it has has already fired and we have "lost track" of the queued block.
  3. The queued block runs and tries to use a de-allocated self.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: I ended up implementing an Objective-C class that mimics the behavior of a QTimer - changing the interval of a running timer will restart, singleShot is a simple flag that gets checked on fire, etc. It's also thread-safe if that is desired.

I wrote it with compatibility with this PR in mind so it should (hopefully) not conflict when this PR lands someday.

@greglucas

Copy link
Copy Markdown
Contributor Author

I had AI do a code review of the previous implementation I had for me since it had been sitting for so long. After that I made some updates to:

  • Use QT PreciseTimer
  • Add a GTK mainloop so we aren't falling back to the backend_bases implementation

@iccir

iccir commented Sep 15, 2026

Copy link
Copy Markdown
Contributor

@greglucas - Regarding your recent commits, are you sure that this is an issue with CPU contention (other threads are saturating the CPU) and not a CPU scheduling/napping issue? Are our CI machines shared at all or running in a VM? Would thread_policy_set to THREAD_TIME_CONSTRAINT_POLICY or using NSActivityLatencyCritical help?

@greglucas

Copy link
Copy Markdown
Contributor Author

@greglucas - Regarding your recent commits, are you sure that this is an issue with CPU contention (other threads are saturating the CPU) and not a CPU scheduling/napping issue? Are our CI machines shared at all or running in a VM? Would thread_policy_set to THREAD_TIME_CONSTRAINT_POLICY or using NSActivityLatencyCritical help?

Nope, I am just taking shots in the dark here. I'm having AI try to do some debugging on this now for me... This is also why the PR wasn't merged before because I was playing whack-a-mole with CI. These are the macos runners failing, but not just the macos backend, it is even the asyncio timers with no GUI toolkit.

@iccir

iccir commented Sep 15, 2026

Copy link
Copy Markdown
Contributor

Nope, I am just taking shots in the dark here. I'm having AI try to do some debugging on this now for me... This is also why the PR wasn't merged before because I was playing whack-a-mole with CI. These are the macos runners failing, but not just the macos backend, it is even the asyncio timers with no GUI toolkit.

Point the AI at the taskpolicy shell command and see if that helps. Let me see if there's an internal flag that can turn off dispatch timer jitter.

@greglucas

Copy link
Copy Markdown
Contributor Author

Great suggestions, thank you!

The "no callback work" probe is essentially perfect (48–53ms spread around a 50ms nominal, exactly matching Linux). But the "40ms blocking callback" probe shows gaps snapping to near-exact multiples of 50ms — 100.0, 150.0, 200.0ms — a clean quantized/coalesced pattern, not smooth jitter. That's a strong signature of macOS timer coalescing (App Nap-style), not scheduling noise.

I think we are potentially getting somewhere now... A few more things to try here.

@iccir

iccir commented Sep 15, 2026

Copy link
Copy Markdown
Contributor

My best guess based on your latest commits is that this is an artifact of how Microsoft is virtualizing the machine in Azure Pipelines.

Agents that run macOS images run on Mac pros with a 3-core CPU, 14 GB of RAM, and 14 GB of SSD disk space, except the macOS 15 Sequoia ARM64 image which runs on Apple Silicon hardware with 3 cores, 7 GB of RAM, and 14 GB of SSD disk space.

There's never been a real Mac with only 3 cores and 14GB of RAM, so that definitely points to some kind of virtualization.

@github-actions github-actions Bot added the CI: Run cibuildwheel Run wheel building tests on a PR label Sep 17, 2026
Only notify the backend when the value actually changes, so reassigning
the same interval no longer restarts the timer, and give every backend a
way to apply both to a timer that is already running.
start_event_loop() counted sleeps rather than elapsed time, so it ran
long by however much time flush_events() took.  GTK used that polling
fallback; give it a GLib.MainLoop instead.
Use absolute schedules for repeating timers so slow callbacks skip missed
firings without accumulating drift.  Preserve timers restarted from callbacks
and clear completed single-shot handles before callbacks so later property
updates do not restart them.

Use Qt's native repeating QTimer with PreciseTimer for tighter scheduling.
Cover interval and single-shot updates, callback overrun scheduling,
callback-triggered restarts, and exact event-loop durations across interactive
and WebAgg timers.
@iccir iccir mentioned this pull request Sep 18, 2026
1 task

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

4 participants