Conversation
The console loguru sink wrote to sys.stdout synchronously on the event loop thread. A blocking console (Windows QuickEdit with text selected, stalled terminal, full pipe) therefore stalled the whole asyncio loop. Observed stalls of 33s/35s in event_loop_watchdog.log, which killed the websocket heartbeat and dropped the platform connection. File/trace sinks already used enqueue=True; the console sink did not.
There was a problem hiding this comment.
Hey - I've found 1 issue
Prompt for AI Agents
Please address the comments from this code review:
## Individual Comments
### Comment 1
<location path="astrbot/core/log.py" line_range="517" />
<code_context>
sys.stdout,
level=configured_level,
colorize=True,
+ enqueue=True, # NOTE(n100): non-blocking, see above
filter=lambda record: (
not record["extra"].get("is_trace", False)
</code_context>
<issue_to_address>
**issue (bug_risk):** When `configure_logger()` replaces the console sink while its background worker is blocked in `sys.stdout.write()`, `_loguru.remove(cls._console_sink_id)` waits for that queued sink thread to finish. Because `configure_logger()` runs on the event-loop thread, logger reconfiguration still stalls the event loop until the console becomes writable.
**Triggers:** When the log level is reconfigured while the console output is blocked.
**Suggested fix:** Perform sink replacement outside the event-loop thread, or update the sink without synchronously joining a blocked enqueue worker.
```suggestion
enqueue=False, # Avoid joining a blocked worker during reconfiguration
```
</issue_to_address>Sourcery assessment
Approval pending. 1 finding to address first.
Blocking findings: astrbot/core/log.py:517
| sys.stdout, | ||
| level=configured_level, | ||
| colorize=True, | ||
| enqueue=True, # NOTE(n100): non-blocking, see above |
There was a problem hiding this comment.
issue (bug_risk): When configure_logger() replaces the console sink while its background worker is blocked in sys.stdout.write(), _loguru.remove(cls._console_sink_id) waits for that queued sink thread to finish. Because configure_logger() runs on the event-loop thread, logger reconfiguration still stalls the event loop until the console becomes writable.
Triggers: When the log level is reconfigured while the console output is blocked.
Suggested fix: Perform sink replacement outside the event-loop thread, or update the sink without synchronously joining a blocked enqueue worker.
| enqueue=True, # NOTE(n100): non-blocking, see above | |
| enqueue=False, # Avoid joining a blocked worker during reconfiguration |
Problem
The console loguru sink writes to
sys.stdoutsynchronously on the event loopthread. The file sink and the trace sink both pass
enqueue=True, but theconsole sink does not:
When the console blocks (Windows QuickEdit with text selected, a stalled
terminal, a full pipe),
write()blocks, and with it the whole asyncio eventloop.
Evidence
On a Windows deployment,
logs/event_loop_watchdog.logcaptured thread stacksshowing the main thread stuck at:
for 32.938s and 34.828s. The lag monitor separately reported
Event loop lag detected: 201.203s (threshold 15.000s).During that window the platform websocket heartbeat could not be sent
(
ClientConnectionResetError: Cannot write to closing transport), so the botlost its connection for roughly five minutes.
Fix
Add
enqueue=Trueto both console sink registrations, so the console sinkbehaves like the file and trace sinks. Logging then goes through loguru's
background queue and a blocking console can no longer stall the event loop.
Notes
queued lines may be lost.
to file, no errors.
Summary by Sourcery
Bug Fixes: