TopolearnWhen latency goes wrong in production you need to see whether DNS, connecting, the pool or the server is slow.
aiohttp.TraceConfig lets you attach coroutines to events in the client's request lifecycle, without wrapping every call. Create one, append callbacks to its signals, and pass it to the session with ClientSession(trace_configs=[trace_config]).
Available signals include:
on_request_start,on_request_end,on_request_exception,on_request_redirect,on_connection_queued_start/_end(waiting for a free pooled connection),on_connection_create_start/_end(opening a new connection) andon_connection_reuseconn,on_dns_resolvehost_start/_end,on_dns_cache_hit/on_dns_cache_miss,on_request_chunk_sent,on_response_chunk_received,on_request_headers_sent.
Each callback receives (session, trace_config_ctx, params). params holds event data (method, URL, response, exception). trace_config_ctx is a fresh namespace per request, so you can store a start time in on_request_start and read it in on_request_end. Pass request-specific data with session.get(url, trace_request_ctx={...}), available as trace_config_ctx.trace_request_ctx.
This is how metrics exporters and OpenTelemetry's aiohttp client instrumentation work: they record durations per phase and propagate trace headers. The connection-queued signals are particularly valuable, because time spent waiting for the pool looks exactly like a slow server from the outside.
On the server side, the equivalent tools are middlewares, access logs (configurable access_log_format) and signals such as on_response_prepare.
Example
import asyncio
import aiohttp
async def on_start(session, ctx, params):
ctx.start = asyncio.get_running_loop().time()
async def on_end(session, ctx, params):
ms = (asyncio.get_running_loop().time() - ctx.start) * 1000
tag = ctx.trace_request_ctx["tag"]
print(f"{tag} {params.method} {params.url.path} {params.response.status} {ms:.0f}ms")
async def on_new_conn(session, ctx, params):
print(" new connection")
trace = aiohttp.TraceConfig()
trace.on_request_start.append(on_start)
trace.on_request_end.append(on_end)
trace.on_connection_create_end.append(on_new_conn)
async def main():
async with aiohttp.ClientSession(trace_configs=[trace]) as s:
for i in range(2):
async with s.get("https://httpbin.org/get", trace_request_ctx={"tag": f"req{i}"}) as r:
await r.read()
asyncio.run(main())
# " new connection", "req0 GET /get 200 120ms", then "req1 GET /get 200 40ms" (connection reused)Remember
- TraceConfig signals cover request, connection, DNS and chunk events
- trace_config_ctx is per request; trace_request_ctx passes your own data
- Queued-connection signals reveal pool contention
Watch out for
- Doing slow work inside trace callbacks, which adds latency to every request.