# 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`](https://developer.mozilla.org/docs/Web/HTTP/Headers/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 `_timing` into the response **body**, but only in
  development (`EDRI_API_RESPONSE_TIMING`). A header is the production-safe,
  tooling-native alternative: DevTools and APMs parse `Server-Timing`; they do
  not parse a custom body field.

---

## The middleware

```python
# 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

```python
# 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

```bash
curl -D - -o /dev/null http://localhost:8080/slow -H "Accept: application/json"
```

```text
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_send` adds stamps (`...:Returned from worker`), so a slow worker appears
  as its own segment.
* **Header size.** With deep traces the header grows; emit only `total` plus 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-ID` and echo it here, so a slow `Server-Timing` line and the
  matching cross-process logs share one identifier.