When a call is recorded

A record describes a tool call as the middleware saw it: from the moment FastMCP handed it the request to the moment the tool returned or raised. What happens after that, serializing the result and getting it to the client, is outside the middleware’s view.

What the middleware can and cannot see

• duration_ms covers the middleware chain below this one and the tool. It does not include transport time, the client’s own queueing, or the time to send the result back.
• outcome describes what the tool produced. A result that was computed but never arrived (the client disconnected, the HTTP response failed) is still ok. Delivery failures do not show up in these records.
• The record is built in a finally block, after the tool finished. A tool that never finishes produces no record at all, so a hung tool shows up as a gap rather than as a slow row.

If you need to know that a long tool started, record an event at its start: events are written when they are recorded, and one recorded inside the call carries the call’s id.

Consequences you will notice

A tool’s own call is not in its feedback links. submit_feedback collects the calls before it while it is still running, so its own record does not exist yet. The same holds for your own feedback tool calling capture_recent_calls.

Events can be written before the call they belong to. An event recorded inside a tool goes onto the queue immediately; the call’s record follows when the tool returns. In a JsonLinesSink stream, a feedback.submitted event line comes before the submit_feedback call line. That is why ffb_events.call_id has no foreign key, and why you join and sort by timestamp, not by insertion order.

Records arrive in sinks a little later. Delivery is asynchronous, so a query right after a call may not see it yet. Within the process, await mw.flush() waits for the queue; events_for and feedback_context also read the in-memory buffers, so they see records that are still queued.

Identity exists before the tool runs. The identity resolver is called when the call arrives, so events recorded inside the tool carry the caller’s user_sub, and the call’s record, built later, reuses the same answer. When that answer was empty, or lacks a key listed in late_identity_keys because the tool itself creates it (a registration, a login), the resolver is asked again as the record is built, and the record takes the new values only where the first answer had none. Events already recorded keep what they got.

Ids exist before rows. A call’s id is chosen before the tool runs. An event recorded inside the call carries it as call_id even though the call row is written later, and a call that is then sampled out would leave the event pointing at nothing. To prevent that, a call that recorded an event is always kept, whatever its sample rate.