Alerting on Event Loop Saturation¶
An asyncio service has one thread doing all the work, and when that thread is busy, everything waits — timers fire late, sockets are read late, responses go out late. CPU percentage for the process shows it only indirectly; the direct signals are how late the loop runs scheduled callbacks (loop lag) and what fraction of the time it spends running code (loop busy). Measured with an open-loop load where each request used 2 ms of CPU and waited 10 ms on I/O: at 21% busy, p99 loop lag was 5.1 ms and request p99 21 ms; at 60% busy, 13.5 ms and 43 ms; at 88% busy, 149 ms and 321 ms; at 97% busy, lag p99 reached 653 ms and even the median request took 174 ms. Latency stays flat until the loop nears saturation and then climbs steeply — which is why the alert must fire on loop metrics before users notice. This guide measures both signals and turns them into alerts.
Prerequisites¶
- Python 3.11+,
pip install prometheus-client(or your metrics library). - Metrics export, from exporting Prometheus metrics from asyncio.
- Load shedding, from load shedding when the event loop is overloaded.
1. Measure loop lag with a heartbeat task¶
A task that sleeps for a fixed interval and measures how late it wakes up sees exactly what every other callback experiences:
import time
from prometheus_client import Histogram
LOOP_LAG = Histogram("event_loop_lag_seconds", "How late the loop ran a scheduled wakeup",
buckets=(0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5))
async def lag_monitor(interval: float = 0.1) -> None:
loop = asyncio.get_running_loop()
while True:
start = loop.time()
await asyncio.sleep(interval)
LOOP_LAG.observe(max(0.0, loop.time() - start - interval))
Measured p99 lag: 5.1 ms at 21% busy, 13.5 ms at 60%, 149 ms at 88%, 653 ms at 97%. Use a histogram, not a gauge: the tail is what matters, and a gauge sampled by the scraper misses short stalls. A 100 ms interval costs nothing measurable. Lag also catches the other cause of a slow loop — a single blocking call — which shows up as an isolated large observation rather than a steady rise; see finding blocking calls with asyncio debug mode for tracking those down.
Verify: a test that blocks the loop for 200 ms produces an observation in the 0.25 s bucket.
2. Measure how busy the loop is¶
Lag tells you that callbacks are late; busy fraction tells you why — the loop is spending its time running code rather than waiting. Measure it from the loop's own idle time:
import selectors
class BusyMeter:
"""Fraction of wall time the loop spends outside its selector (i.e. running code)."""
def __init__(self, loop: asyncio.AbstractEventLoop) -> None:
self.idle = 0.0
selector = loop._selector # private: diagnostics only
original_select = selector.select
def timed_select(timeout=None):
start = time.perf_counter()
try:
return original_select(timeout)
finally:
self.idle += time.perf_counter() - start
selector.select = timed_select
async def busy_reporter(meter: BusyMeter, interval: float = 5.0) -> None:
while True:
idle_before, wall_before = meter.idle, time.perf_counter()
await asyncio.sleep(interval)
wall = time.perf_counter() - wall_before
LOOP_BUSY.set(1.0 - (meter.idle - idle_before) / wall)
Time spent inside select() is time the loop had nothing to do; everything else is work. In the measurement, latency was flat up to about 60% busy and degraded sharply above 85%. The hook relies on a private attribute of the default selector loop; uvloop does not expose it, but the process's CPU time (time.process_time() deltas) is a reasonable proxy for a single-threaded loop. A busy fraction is the capacity metric to plan with: it says how much headroom remains before lag explodes.
Verify: at idle the busy fraction is near zero; under a CPU-heavy load test it approaches one.
3. Alert on lag and busy, not just on latency¶
Latency alerts fire when users are already affected. Loop metrics fire earlier and say what kind of problem it is:
groups:
- name: event-loop
rules:
- alert: EventLoopLagHigh
expr: histogram_quantile(0.99, sum by (instance, le) (rate(event_loop_lag_seconds_bucket[5m]))) > 0.1
for: 5m
labels: {severity: page}
annotations:
summary: "p99 event loop lag above 100 ms on {{ $labels.instance }}"
- alert: EventLoopNearSaturation
expr: avg_over_time(event_loop_busy_ratio[10m]) > 0.8
for: 10m
labels: {severity: ticket}
annotations:
summary: "event loop more than 80% busy: add capacity or shed load"
The thresholds come from the measurement: 100 ms of p99 lag first appeared near 88% busy, where request p99 had already grown fifteen-fold; 80% busy sustained for ten minutes is the point to add capacity before reaching it. Page on lag, which is user-visible; open a ticket on busy, which is a capacity trend. A single instance with high lag while others are fine usually means a blocking call or a hot key on that instance, not overall saturation.
Verify: a load test that pushes busy above 85% triggers the lag alert within its for window, and stays silent at 60%.
4. Tell saturation apart from blocking calls¶
Two different problems raise loop lag, and they need different fixes:
LOOP_STALLS = Counter("event_loop_stalls_total", "Wakeups later than 250 ms")
async def lag_monitor(interval: float = 0.1) -> None:
loop = asyncio.get_running_loop()
while True:
start = loop.time()
await asyncio.sleep(interval)
lag = max(0.0, loop.time() - start - interval)
LOOP_LAG.observe(lag)
if lag > 0.25:
LOOP_STALLS.inc()
log.warning("event loop stalled for %.0f ms", lag * 1000)
Saturation raises lag gradually across all observations as the busy fraction climbs; a blocking call produces rare, large stalls while the busy fraction stays moderate. Counting and logging stalls above a threshold separates them — and the log line's timestamp lines up with whatever request was running, which is how you find the blocking call. For continuous evidence of what the loop is spending its time on, a sampling profiler answers the question directly, as in continuous profiling of async services.
Verify: inserting a deliberate time.sleep(0.5) in one handler increments the stall counter without moving the busy fraction much.
5. Act on the alert: shed load or add capacity¶
Saturation alerts are only useful with a planned response:
async def admission(request, call_next):
if LOOP_LAG_P99.value() > 0.2 or loop_busy() > 0.9:
return JSONResponse({"error": "overloaded"}, status_code=503,
headers={"Retry-After": "1"}) # shed early, cheaply
return await call_next(request)
Short-term, shed load: reject new work cheaply when lag or busy cross a high threshold, so the requests already admitted finish in reasonable time instead of everyone timing out. Medium-term, add processes (one event loop per core), move CPU-heavy steps to process pools, or remove work per request. The measured curve gives the capacity number: at 2 ms of CPU per request, one loop sustained about 250 requests per second with healthy tails, and degraded beyond 400.
Verify: under deliberate overload, the service returns fast 503s for a fraction of requests while admitted requests keep their normal latency.
Verification¶
Loop saturation is monitored well when:
- A heartbeat task records lag into a histogram, and stalls are counted and logged.
- The loop's busy fraction is exported, from selector time or CPU time.
- Alerts page on p99 lag and ticket on sustained busy, with thresholds from measurement.
- Overload triggers load shedding, and capacity plans use the busy fraction.
Diagnostic Hook: plot p99 loop lag against busy fraction for each instance over a week. Points along a smooth curve are normal load variation, and the knee of the curve is your real capacity; points far above the curve at low busy are blocking calls — each one worth a profile.
Pitfalls & edge cases¶
- Alerting on process CPU only. It hides which part of the work saturates the loop.
- Gauges for lag. Scrapes miss short stalls; use a histogram.
- Thresholds from guesses. Measured: tails stay healthy to ~60% busy and collapse past ~85%.
- No response plan. An alert without shedding or scaling only documents the outage.
Frequently Asked Questions¶
How do I measure event loop lag in asyncio?
Run a task that sleeps for a fixed interval and records how much later than expected it wakes up, in a histogram. In testing, p99 lag was 5 ms at 21% busy and 653 ms at 97% busy.
What event loop lag should trigger an alert?
A p99 above about 100 ms sustained for several minutes; in testing that appeared near 88% busy, when request p99 had already risen from 21 ms to 321 ms.
How do I know how busy the asyncio event loop is?
Measure the time the loop spends waiting in its selector and subtract it from wall time, or use the process's CPU time as a proxy for a single-threaded loop.
How do I tell a blocking call from an overloaded event loop?
Overload raises lag gradually as the busy fraction climbs; a blocking call causes rare, large stalls while the loop is otherwise moderately busy. Count and log stalls above a threshold to find them.
Related¶
- Observability & Tracing — up to the topic overview.
- Finding the saturation point of an async service — measuring the curve these alerts are based on.
- Resilience, Cancellation & Error Handling — the section overview.