Route LokiHandler emits without a running loop through sync fallback - #13
Route LokiHandler emits without a running loop through sync fallback#13woodwardmw wants to merge 5 commits into
Conversation
emit() raised RuntimeError when called from threads with no running event loop (e.g. work dispatched via asyncio.to_thread), causing logs to be dropped with the unhelpful "RuntimeError" failure message. Now LokiHandler lazily spawns an internal SyncLokiHandler the first time it sees a loopless thread, and hands off the prebuilt payload via a new enqueue_payload() helper. Async-only callers pay nothing — the fallback is built on demand. Set enable_thread_fallback=False on the constructor to restore strict async-only behaviour. close()/aclose() now tear the fallback worker down alongside the aiohttp session. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
…p signalling - aclose() now offloads fallback.close() (which joins the worker thread) to the default executor so it doesn't block the event loop for ~7s. - close()/aclose() clear self._fallback and disable the fallback flag so a stray emit() after close doesn't enqueue into a stopped worker. - __del__ also tears down the fallback so daemon-thread queues drain on GC. - emit() now log_send_failure()'s when enqueue_payload returns False (queue full), restoring the drop signal the async path used to emit. - Stronger test_close_tears_down_fallback assertions; added aclose teardown test, emit-after-close test, and queue-full signalling test. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
Pull request overview
This PR updates LokiHandler.emit() to avoid dropping log records when called from a thread without a running asyncio event loop by lazily routing those records through a background-threaded SyncLokiHandler fallback. It also adds configurability to disable this behavior and expands test coverage around the new fallback lifecycle.
Changes:
- Add
enable_thread_fallbackoption and a lazy_get_thread_fallback()path to route looplessemit()calls toSyncLokiHandler. - Add
SyncLokiHandler.enqueue_payload()to accept pre-built Loki payloads from the async handler. - Extend handler tests to cover fallback routing, laziness/reuse, teardown, queue-full behavior, and post-close behavior.
Reviewed changes
Copilot reviewed 3 out of 3 changed files in this pull request and generated 5 comments.
| File | Description |
|---|---|
observability_library/handler.py |
Implements lazy sync fallback for loopless threads; adds teardown of fallback in close()/aclose()/__del__. |
observability_library/sync_handler.py |
Adds enqueue_payload() helper to enqueue pre-built payloads. |
tests/test_handler.py |
Adds tests validating fallback routing, lifecycle (lazy/reuse/teardown), and failure cases. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| try: | ||
| self._fallback = SyncLokiHandler( | ||
| url=self.url, | ||
| labels=self.labels, | ||
| timeout=self.timeout, | ||
| auth_token=self.auth_token, | ||
| ) | ||
| except Exception: | ||
| # If we can't build the fallback, disable the path | ||
| # so we don't retry on every emit. | ||
| self._enable_thread_fallback = False | ||
| return self._fallback |
| fallback = self._get_thread_fallback() | ||
| if fallback is not None: | ||
| if not fallback.enqueue_payload(payload): | ||
| log_send_failure("async", RuntimeError("thread fallback queue full")) | ||
| return | ||
|
|
||
| log_send_failure("async", RuntimeError("no running event loop")) |
| fallback = getattr(self, "_fallback", None) | ||
| if fallback is not None: | ||
| try: | ||
| fallback.close() | ||
| except Exception: | ||
| pass | ||
| self._fallback = None | ||
| self._enable_thread_fallback = False |
| if fallback is not None: | ||
| try: | ||
| fallback.close() | ||
| except Exception: |
| fallback = getattr(self, "_fallback", None) | ||
| if fallback is not None: | ||
| try: | ||
| fallback.close() |
- Surface SyncLokiHandler construction failures via log_send_failure before disabling the fallback path — previously the cause was silently swallowed. - Replace the two generic RuntimeError signals on the no-loop / queue- full drop paths with NoRunningEventLoopError and ThreadFallbackQueueFullError. log_send_failure only logs the class name, so distinct subclasses give operators an actionable hint. - close()/aclose() now take _fallback_lock during teardown so they cannot race with a concurrent emit() spinning up a new fallback. - close() offloads fallback.close() (which joins the worker thread) to the default executor when a loop is running, matching the session-close pattern and keeping the call non-blocking on the loop thread. - __del__ no longer calls fallback.close() — only signals _stop so it doesn't block interpreter shutdown for up to `timeout + 2`s. - Added tests for the failure-then-disable path, the distinct error types, the loop-aware close offload, and the non-blocking __del__. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Two follow-ups based on prod telemetry: 1. emit() now wraps loop.create_task() in try/except RuntimeError and falls through to the thread fallback when the loop has closed between get_running_loop() succeeding and create_task() being called. This race fires at worker/interpreter shutdown — observed in Modal teardown where a log line emitted after the function returns finds a still-discoverable but already-closing loop. 2. log_send_failure() now consults LOKI_DEBUG=1 (or true/yes). When set, it appends a sanitised str(exc) to the failure log so timeouts and other transport errors are diagnosable without changing the default credential-safe behaviour. URL basic-auth in the exception message is stripped before logging. Tests cover both: a loop-closed race emit, an opt-in debug message, sanitisation of embedded credentials, and the default-off behaviour. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Hit in production with LOKI_DEBUG=1: every emit failed with 'RuntimeError: Timeout context manager should be used inside a task'. Cause: aiohttp.ClientSession's internal timeout bookkeeping is bound to the loop that created it. When a Modal worker's logging fires from a task on a secondary loop (the original was torn down between function invocations), the cached session's timer can't enter the new task's context and aiohttp raises that RuntimeError. _async_send now checks `session._loop is asyncio.get_running_loop()` and rebuilds the session on mismatch, alongside the existing None/closed checks. We can't safely close the stale session from a different loop, so we just drop the reference; the old loop's GC handles it. Test covers the mismatch path; the existing auth-header test is updated to pin its mock session's `_loop` to the running loop so the new check sees it as fresh. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
|
Review summary — 5 findings across integrity, consistency, and test coverage. [Integrity, medium] Lock race in [Integrity, medium] [Integrity, low] Stale session not closed on loop change (handler.py:132-139): when [Consistency, low] [Integrity, very low] Overall the PR is well-structured, the test coverage is thorough, and the lazy-fallback and double-checked locking patterns are sound — the race described above is the only correctness gap. |
|
Finding 1/4 — [Integrity, medium] Lock race in The double-checked locking pattern is almost correct but the inner guard — inside the lock — only checks The race:
Fix: change the inner guard from |
|
Finding 2/4 — [Integrity, medium] This pre-existing test does not set session_loop = (
getattr(self._session, '_loop', None) if self._session else None
)
if ... or session_loop is not current_loop:
self._session = aiohttp.ClientSession(...) # real session created
Compare: fake_session._loop = _asyncio.get_running_loop()The same one-liner is needed in |
|
Finding 3/4 — [Integrity, low] Stale session not closed on loop change (handler.py:132-139) When if (
self._session is None
or self._session.closed
or session_loop is not current_loop # old session silently dropped
):
self._session = aiohttp.ClientSession(...)In the Modal-worker scenario the old loop may already be torn down, making a proper async close impossible. Either document this explicitly in the comment (e.g. "old loop is torn down; best-effort close not attempted") or attempt |
|
Finding 4/4 — [Consistency, low] Private 4a — 4b (very low) — |
Code Review — PR #13: Route LokiHandler emits without a running loop through sync fallbackOverall this is a well-motivated, well-documented change. The lazy-init pattern, TOCTOU-guarded construction, and teardown sequencing are solid. Test coverage is comprehensive. A few issues worth addressing before merge, ordered by severity. 🔴 Medium — Race:
|
|
@claude-reviewer |
| getattr(self._session, "_loop", None) if self._session else None | ||
| ) | ||
| # Recreate the session when the loop it was bound to doesn't | ||
| # match the one we're running on. aiohttp's internal timeout |
There was a problem hiding this comment.
Fragile private API access — will silently break with aiohttp ≥ 3.9
ClientSession._loop is an aiohttp implementation detail that was removed in 3.9 when the library dropped explicit-loop support. With the project's constraint aiohttp>=3.8.0, any installation on 3.9+ will return None here, making session_loop is not current_loop (None is not <running loop>) permanently True. The result is that _async_send recreates the session on every call — connectors are never reused, and the abandoned sessions/connectors accumulate until GC collects them.
The tests don't catch this because they mock the session and set _loop manually:
fake_session._loop = _asyncio.get_running_loop()so they pass regardless of what real aiohttp exposes.
Suggested fix — track the loop explicitly on the handler, not via aiohttp internals:
# in __init__
self._session_loop: Optional[asyncio.AbstractEventLoop] = None
# in _async_send, replace the session_loop / getattr lines with:
session_loop = self._session_loop
current_loop = asyncio.get_running_loop()
if (
self._session is None
or self._session.closed
or session_loop is not current_loop
):
self._session = aiohttp.ClientSession(
timeout=aiohttp.ClientTimeout(total=self.timeout)
)
self._session_loop = current_loopThis avoids private-attribute coupling and works across all aiohttp versions.
|
@claude-reviewer |
| if self._fallback is not None: | ||
| return self._fallback | ||
| with self._fallback_lock: | ||
| if self._fallback is None: |
There was a problem hiding this comment.
Bug: inner lock check doesn't re-validate _enable_thread_fallback — zombie worker thread on close race
The double-checked locking pattern here is incomplete. Consider this interleaving:
- Thread A passes the outer
if not self._enable_thread_fallbackcheck (seesTrue) - Thread B calls
close(), acquires the lock, sets_enable_thread_fallback = False, sets_fallback = None, releases the lock - Thread A acquires the lock, finds
_fallback is None→ True, and builds a newSyncLokiHandler
The code comment ("Flip the gate before joining so a concurrent emit() in _get_thread_fallback() can't spin up a new worker after we've torn the current one down") describes the intention correctly, but the guard isn't checked inside the lock. This new handler's worker thread leaks — _enable_thread_fallback is now False so nobody will ever call close() on it.
| if self._fallback is None: | |
| with self._fallback_lock: | |
| if self._fallback is None and self._enable_thread_fallback: |
| if ( | ||
| self._session is None | ||
| or self._session.closed | ||
| or session_loop is not current_loop | ||
| ): | ||
| self._session = aiohttp.ClientSession( | ||
| timeout=aiohttp.ClientTimeout(total=self.timeout) | ||
| ) |
There was a problem hiding this comment.
Session leak when loop mismatch is detected
When session_loop is not current_loop, the old self._session is silently overwritten without being closed. The underlying aiohttp.TCPConnector (and any open sockets) are leaked and Python will emit ResourceWarning: Unclosed client session noise. Since we're already in an async context here, the old session can be closed before replacement:
old_session = self._session
if (
old_session is None
or old_session.closed
or session_loop is not current_loop
):
self._session = aiohttp.ClientSession(
timeout=aiohttp.ClientTimeout(total=self.timeout)
)
if old_session is not None and not old_session.closed and session_loop is not current_loop:
# old_session belongs to a different loop; schedule its close on
# the new loop so we don't block.
try:
await old_session.close()
except Exception:
passThe loop-mismatch case is admittedly awkward (the old session may already be broken), but at minimum the try/except prevents a close attempt from hiding real errors.
| if self._session is None or self._session.closed: | ||
| current_loop = asyncio.get_running_loop() | ||
| session_loop = ( | ||
| getattr(self._session, "_loop", None) if self._session else None |
There was a problem hiding this comment.
Fragile dependency on aiohttp private attribute
aiohttp.ClientSession._loop is undocumented and has already been removed in some aiohttp builds. If it disappears, getattr(..., "_loop", None) returns None, making session_loop is not current_loop always True, which forces a new session on every _async_send call — effectively a connector-per-log-record regression.
If you need to handle the loop-mismatch case, consider storing the loop yourself when the session is created:
# in _async_send, after creating the session:
self._session = aiohttp.ClientSession(...)
self._session_loop = asyncio.get_running_loop()Then check self._session_loop is not current_loop instead of accessing _loop on the aiohttp object. Add self._session_loop: Optional[asyncio.AbstractEventLoop] = None to __init__.
| # cause once so operators don't see only the | ||
| # downstream "no running event loop" symptom. | ||
| self._enable_thread_fallback = False | ||
| log_send_failure("async", e) |
There was a problem hiding this comment.
Double-logging on first emit() when fallback construction fails
When SyncLokiHandler(...) raises here, this line logs the construction error. Control then returns None to emit(), which falls through to line 117:
log_send_failure("async", NoRunningEventLoopError())So the same emit() call produces two error lines: one for the construction failure and one for NoRunningEventLoopError. An operator tailing the log will see a confusing pair with no explanation that they're from the same record.
Consider either:
- Not calling
log_send_failurehere (let theNoRunningEventLoopErrorat the call site be the sole signal; the construction failure is usually a config issue that will recur), or - Setting
_fallbackto a sentinel and adjusting the caller to emit a single combined message.
| the queue is full (silently dropped, like `emit`). | ||
| """ | ||
| try: | ||
| self._queue.put_nowait(payload) |
There was a problem hiding this comment.
enqueue_payload silently succeeds on a stopped handler
After SyncLokiHandler.close() has joined the worker thread, this method still returns True — put_nowait succeeds because the queue isn't flushed, but no thread is left to drain it. The record is silently discarded.
LokiHandler.close() guards against this by zeroing _fallback before calling fallback.close(), so the normal sequential close-then-emit path is safe. However, a thread that already holds the _fallback reference (via the outer fast-path in _get_thread_fallback()) can still call enqueue_payload after the worker has stopped and get a false True.
Adding a _stop.is_set() guard makes the contract explicit and avoids misleading callers:
| self._queue.put_nowait(payload) | |
| try: | |
| if self._stop.is_set(): | |
| return False | |
| self._queue.put_nowait(payload) | |
| return True |
Review summaryThe motivation and general approach are sound — lazy fallback construction, the Issues found1. Zombie worker thread on 2. Stale aiohttp session leak on loop mismatch (handler.py lines 132–139 — blocking) 3. Private 4. Double-logging when fallback construction fails (handler.py line 85 — minor) 5. 6. README not updated (documentation — required per contributing guidelines) What's good
|
Code Review1. 🔴 Race:
|
| # | Severity | File | Issue |
|---|---|---|---|
| 1 | 🔴 Critical | handler.py:70 |
Post-close worker created; _enable_thread_fallback not re-checked inside lock |
| 2 | 🔴 Critical | handler.py:132–139 |
Open aiohttp session leaked when loop changes |
| 3 | 🔴 Critical | tests/test_handler.py:244 |
Loop-mismatch guard silently breaks existing test; wrong path covered |
| 4 | 🟡 Moderate | sync_handler.py:63–67 |
Non-Full exceptions escape enqueue_payload into emit() |
The overall design (lazy fallback, double-checked locking intent, LOKI_DEBUG credential scrubbing, teardown via close/aclose/__del__) is sound and the new test coverage is thorough. Issues 1–3 need to be addressed before merge.
Summary
LokiHandler.emit()no longer drops logs with a generic"RuntimeError"when called from threads that have no running event loop (e.g. work dispatched viaasyncio.to_thread, or any thread-pool task inside an async app).SyncLokiHandlerthe first time it sees a loopless thread, and hands off the prebuilt payload via a newSyncLokiHandler.enqueue_payload()helper. Async-only callers pay nothing — the fallback is built on demand.enable_thread_fallback=Falseon the constructor to restore the strict async-only behaviour.close()andaclose()now tear the fallback worker down alongside the aiohttp session.Motivation
Caller-side symptom was the unhelpful repeated line:
with no detail (the handler intentionally suppresses the exception's
str()). The actual cause isasyncio.get_running_loop()raisingRuntimeError("no running event loop")insideemit, because the calling thread isn't the one running the loop. This is normal in async apps that do CPU/IO work viaasyncio.to_threador a thread pool, and the dropped records are typically the most useful ones (deep helper functions).Test plan
enable_thread_fallback=Falsestill logs the send-failure_fallbackisNoneuntil first loopless emitclose()tears the fallback worker downpytest -q→ 55 passed