Skip to content

fix(microvm-worker): log timer failures after lock - #838

Merged
ParidelPooya merged 2 commits into
mainfrom
fix/microvm-worker-timer-log-lock
Oct 25, 2026
Merged

ParidelPooya merged 2 commits into
mainfrom
fix/microvm-worker-timer-log-lock

Conversation

@ParidelPooya

@ParidelPooya ParidelPooya commented Oct 25, 2026 •

Copy link
Copy Markdown
Contributor

Fixes #832.

Summary

When a timer cannot start, the MicroVM worker now logs the failure after it releases the listener lock. The log text and fields are unchanged.

Why

  1. Every caller of _start_idle_time and _start_grace holds self._lock.
  2. When threading.Timer.start() raised, each method logged through the caller's logger while it still held that lock.
  3. The lock is not reentrant.
  4. So a logger that blocks blocked every hook and job request. A logger that calls back into the listener, for example with close(), deadlocked it.
  5. refactor(microvm-worker): log one suspend warning #831 fixed the same pattern for the failed-SuspendMicrovm warning.

Changes

  • _start_idle_time and _start_grace record a failure in _timer_failures under the lock. They no longer call the logger.
  • A new context manager, _locked(), takes the lock and runs the block. In a finally, it takes the recorded failures, releases the lock, and logs each one with describe(error). So the logging also runs when the block raises or returns early.
  • Every block that can start a timer, directly or through _end_suspending or _suspend_call_ended, uses with self._locked():. That is 10 blocks.
  • _start_idle_time and _start_grace first check that a _locked() block runs, and raise RuntimeError otherwise. So a later block that takes self._lock directly and starts a timer fails at once, instead of leaving its failure for an unrelated block to log.
  • The failure paths change no state. The idle time stays off, and the refusal stays until the resume hook, as before.

Testing

  • An AST check of all 30 locked blocks found no call of the logger, describe, str, repr, or caller code while the lock is held.
  • 4 new tests, for the idle timer and the grace timer, make the timer start fail with a logger whose error() calls listener.close() or sends a hook over HTTP. They fail on main (a deadlock, and a TimeoutError) and pass here. Each test is bounded by a timeout.
  • hatch run dev-microvm-worker:cov: 453 tests, worker.py 100 %. Typecheck and hatch fmt --check pass. A stress run with -n 8 passed 3 times.
  • A cloud run in a dev account, with this change and test(examples): suspend and resume a MicroVM #839 merged locally, passed all three MicroVM tests.

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

A timer that could not start was logged under the listener lock. A
logger that calls the listener then deadlocked it. Now the failure is
recorded under the lock and logged after the lock is released.

Fixes #832.
This addresses the review of #838. A timer start now raises
RuntimeError outside _locked(), and the tests and docstrings are fixed.

@yaythomas yaythomas left a comment

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.

:shipit:

@ParidelPooya
ParidelPooya marked this pull request as ready for review October 25, 2026 21:14
@ParidelPooya
ParidelPooya merged commit ed1dbb1 into main Oct 25, 2026
21 checks passed
@ParidelPooya
ParidelPooya deployed to ai-pr-review-runtime October 25, 2026 21:14 — with GitHub Actions Active
@ParidelPooya
ParidelPooya deleted the fix/microvm-worker-timer-log-lock branch October 25, 2026 21:14

This branch was successfully deployed

1 active deployment
ai-pr-review-runtime — 781c8e38 Deployed Oct 25, 2026 by ParidelPooya via notify / Generate notification summary #298
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

microvm-worker: a failed timer start logs under the listener lock

2 participants