Middleware: per-stage latency as a Server-Timing header¶
A response middleware that turns EDRI's built-in event._timing trace into a
standard Server-Timing
header. Open the browser DevTools → Timing tab and you see exactly where a
request spent its time — broker queue, routing, the handler itself, a worker —
per request, in the client, no log digging.
Why this is a natural process_response job:
In EDRI one request crosses several processes (Listener → Broker → Router → Manager → Worker → back). Each hop stamps
event._timing. That breakdown is only meaningful once the response is on its way out — which is where response middleware runs.EDRI already injects
_timinginto the response body, but only in development (EDRI_API_RESPONSE_TIMING). A header is the production-safe, tooling-native alternative: DevTools and APMs parseServer-Timing; they do not parse a custom body field.
The middleware¶
# middlewares/server_timing.py
from edri.api.middleware import Middleware, MiddlewareControl
from edri.dataclass.directive.http import HeaderResponseDirective
from edri.dataclass.event import Event
class ServerTimingMiddleware(Middleware):
"""Publishes event._timing as a Server-Timing header on every response."""
def process_response(self, event: Event, info) -> MiddlewareControl:
timing = getattr(event, "_timing", None)
stamps = sorted(timing.events, key=lambda e: e.timestamp) if timing else []
def label(stamp) -> str:
return f"{stamp.name}:{stamp.description}" if stamp.description else stamp.name
if len(stamps) >= 2:
total = (stamps[-1].timestamp - stamps[0].timestamp).total_seconds() * 1000
metrics = [f"total;dur={total:.1f}"]
for i in range(1, len(stamps)):
dur = (stamps[i].timestamp - stamps[i - 1].timestamp).total_seconds() * 1000
metrics.append(f'seg{i};dur={dur:.1f};desc="{label(stamps[i - 1])}->{label(stamps[i])}"')
event.response.add_directive(
HeaderResponseDirective(name="Server-Timing", value=", ".join(metrics))
)
return MiddlewareControl.continue_processing()
Each consecutive pair of stamps becomes one Server-Timing metric whose dur
is the gap between them in milliseconds; total is first-to-last. Returning
continue_processing() leaves the response otherwise untouched.
Wiring it up¶
# main.py
import time
from http import HTTPMethod
from edri import EDRI
from edri.abstract import ManagerBase, request
from edri.api.dataclass.api_event import api, ApiType
from edri.dataclass.event import Event
from edri.dataclass.response import Response, response
from middlewares.server_timing import ServerTimingMiddleware
@response
class SlowResponse(Response):
message: str
@api(url="/slow", method=HTTPMethod.GET, resource="slow", exclude={ApiType.HTML, ApiType.WS})
class SlowEvent(Event):
response: SlowResponse
class DemoManager(ManagerBase):
@request
def slow(self, event: SlowEvent) -> None:
time.sleep(0.05) # pretend the handler does real work
event.response.message = "ok"
if __name__ == "__main__":
app = EDRI()
app.add_component(DemoManager())
app.start_api(middlewares=[ServerTimingMiddleware()])
app.run()
What it produces¶
curl -D - -o /dev/null http://localhost:8080/slow -H "Accept: application/json"
Server-Timing: total;dur=54.6,
seg1;dur=3.0;desc="RESTHandler:Created->Broker:Received",
seg2;dur=0.3;desc="Broker:Received->Router:Received",
seg3;dur=0.3;desc="Router:Received->DemoManager:Received",
seg4;dur=50.2;desc="DemoManager:Received->DemoManager:Resolved",
seg5;dur=0.4;desc="DemoManager:Resolved->Router:Received",
seg6;dur=0.3;desc="Router:Received->Broker:Received",
seg7;dur=0.0;desc="Broker:Received->ServerTimingMiddleware:Started"
(The header is a single line; wrapped here for readability.) seg4 —
DemoManager:Received -> DemoManager:Resolved — is the handler's own 50 ms,
clearly separated from the sub-millisecond broker/router hops. A growing
Broker:Received -> Router:Received would instead point at router-queue
backpressure.
Things to watch¶
Coverage ends at the broker. Response middleware runs inside the Broker, so the trace reaches up to
ServerTimingMiddleware:Started; the final serialization in the Listener is not included. It captures essentially all of the server-side processing, which is what you want for spotting hot spots.Worker time shows up too. If the handler offloads to a Worker, the worker's
event_sendadds stamps (...:Returned from worker), so a slow worker appears as its own segment.Header size. With deep traces the header grows; emit only
totalplus a few key segments if you need to keep it small, or gate the middleware behind a debug flag / sampling in production.Pairs well with a request id. Add a request-middleware that sets an
X-Request-IDand echo it here, so a slowServer-Timingline and the matching cross-process logs share one identifier.