feat(observability): correlate logs by MoQ session - #217
Merged
Conversation
A MoQ session has no identity today, so no log record can be attributed to a connection. Add the type that will carry one. The payload is `Arc<str>` rather than `String` because the id is cloned into `Session`, `Publisher`, `Subscriber`, both halves of the session run loop and the relay's per-session context; cloning must be a refcount bump. `generate()` renders 32 lowercase hex characters via `Uuid::simple()`, matching the shape of a 16-byte QUIC connection ID. The hyphenated 36-character form is never produced: one alphabet means a reader never has to strip separators before comparing an id against a qlog or mlog filename. Not yet wired into anything.
…Subscriber Every session now owns a correlation id. `Session::new` clones it into the `Publisher` and `Subscriber` it builds, so all three expose `session_id()` and the id is reachable from any session-scoped log site. The id is taken by value rather than `Option`, so a connection cannot silently end up without one; the compiler then located all 21 call sites. Two of them were discarding the value: - relay.rs, the --announce forward connection - remote.rs, the upstream relay-to-relay connection both bound as `_quic_client_initial_cid`. That is why relay-to-relay sessions are anonymous in the logs today. The client binaries already held the CID and logged "use this to look up qlog/mlog on server" without ever passing it on. Measured: cloning is a 4.3ns refcount bump against 23.9ns for the equivalent String clone, and every clone site is per-request rather than per-object. No log site emits the field yet.
Every log record under the moq_transport::control target now carries the session id, so control-plane activity can be attributed to a connection. The plan assumed all 35 sites sat inside `log_control_message` and that one parameter would cover them. Only 22 do. The remaining 13 are spread across the setup handshake, the receive loop and the request-completion helpers, so the id has to be threaded through 11 associated functions: they take owned parameters rather than `&self`, having been written to be spawned into `select!` arms, so none of them could reach the field Phase 2 added. The four setup-handshake sites needed nothing threaded — `connect_with_config` and `accept_with_config` already take the id as a parameter. This adds no new records; it widens existing ones. Measured earlier: a disabled `debug!` costs the same with the field as without it, and nothing on this path runs at media rate. Pre-existing rustfmt drift in serve/subgroup.rs and serve/tracks.rs is left alone; it is present on the base commit and unrelated.
Adds the session id to 27 log sites: 14 in subscriber.rs, 7 in publisher.rs, and 6 across published.rs, subscribe.rs and subscribed.rs. None of these needed new plumbing. Publisher and Subscriber carry the id from Phase 2, and the remaining types reach it through a field they already hold: Published owns a Publisher, Subscribe owns a Subscriber, and ObjectForwarder owns a Publisher. Four sites sit inside `async move` blocks that cannot capture `self`, so they take a cloned id alongside the clones already being made there. One associated function, recv_subgroup_objects, took the id as a parameter. Seven sites in this crate still lack the id: they live on Reader, Writer, SubgroupOutput, SubscribedNamespace and RequestId, none of which can reach a session today. Those need new struct fields and are kept separate.
Completes session/ coverage: all 74 error/warn/info/debug sites in the crate's
session module now carry the id.
These seven sites lived on types with no route to a session, so each needed a
decision rather than a field access:
- Reader and Writer gained a session_id field. Ten construction sites, all
inside session/, all with the id already in scope.
- SubgroupOutput takes its id from the Writer it wraps, so `stream()` needed
no new argument. The test-only Buffer variant generates one.
- serve_subgroup_objects needed nothing: it already receives the
SubgroupOutput that now carries the id.
- SubscribedNamespaceRecv::run already receives both a Writer and a Reader.
- RequestId::handle_requests_blocked takes the id as a parameter. It has one
caller, which made that cheaper than a field and nine constructor changes.
An earlier estimate put Reader/Writer at 38 construction sites. That was wrong;
the pattern used to count them also matched TrackWriter, MlogWriter and others.
The real number is ten.
…ite fields
Relay-side correlation is carried by a tracing span around the whole session
rather than a session_id argument on each of the 66 call sites.
SessionContext gains the id and a span() builder. Session::run wraps its body
in that span, so the transport, producer and consumer tasks all inherit it; the
upstream connection in remote.rs instruments its spawned task the same way.
Three reasons this beats editing every call site:
- The fields are recorded once per session instead of being re-formatted per
record. A measured field slot costs ~94ns on an enabled record, and this
path is only reached when debug logging is on.
- The 45 trace sites and any log line added later are covered for free.
- Calls into remote.rs inherit the span of the *calling* session, which is
the correct attribution: one upstream connection is shared by many
downstream sessions, so an id on the connection itself would be a lie.
The three tokio::spawn sites that escape the span — the UpstreamNamespaces
runner, namespace pulls, and locals — are exactly the shared infrastructure
that must not claim a single session. The span boundary and the ownership rule
coincide.
Five sites in relay.rs run before or after the session and take the id
explicitly. Two of them log connection_path, which is credential-bearing; they
are marked FIXME for the redaction change and left otherwise alone.
Also adds the session-established line, carrying interface, scope and peer
socket address. Never the relay URL: its path is the credential. Two tests
cover this — one asserts the id reaches formatted output from a record that
names none of the fields itself, the other asserts the span exposes no url
field.
A browser cannot read the QUIC connection id, so the error id is the handle a user quotes back. The uuid already reached the client — Display embeds it and the wire reason is built from Display — but the line recording it lives in serve/error.rs, which has no session in scope. Rather than move that line, log the reason where the message goes out. The REQUEST_ERROR and PUBLISH_DONE arms of log_control_message already carry session_id, so adding `reason` puts the error id and the session id on one record. The constructors now emit `error_id` as a field and the two join on the uuid. The id was being printed twice in those constructors, once as a field and again interpolated into the message; the interpolation is gone. Also closes a hole: SubscribedNamespace sends REQUEST_ERROR through its own mpsc and writer, bypassing log_control_message entirely, so those errors reached peers with no log record at all. Its Writer already carries the id. Adds ServeError::error_id(), and a test pinning the id into the wire reason phrase — if it ever stops being embedded there, a client still sees an error but nobody can trace it to a session. Not addressed: SessionError carries no uuid, and sends neither reason text nor a code — code() has zero callers and no SESSION_CLOSE is ever constructed, so a peer sees only an implicit QUIC close. That is a behaviour change rather than a logging one.
Keep credential-bearing scope values out of session spans while retaining useful correlation metadata. Path-formatted scopes contribute only their first segment as relay_uid; non-path scopes remain hidden, and scope_present records whether a scope exists. Preserve the public relay context and session construction APIs by adding run_with_context rather than storing new required fields. Accepted-session records run before that span, so attach session_id directly there. Sanitize and quote peer-controlled reason phrases, emit their exact bytes as lowercase hex, and log messages received on dedicated SUBSCRIBE_NAMESPACE response streams. Preserve the enabled-level root span so warning and error records retain session correlation under restrictive filters. Existing connection-path diagnostics remain unchanged.
englishm
force-pushed
the
session-correlation-id
branch
from
August 28, 2026 23:46
742beb6 to
069a5b4
Compare
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Adds end-to-end session correlation across MoQT transport and relay logs using a stable
SessionId.Changes
SessionIdfrom the peer-observed QUIC connection ID when available.session_id, interface, and scope presence.ConnectionTagger.*_with_session_idvariants.Validation
cargo test -p moq-transportcargo test -p moq-relay-ietf --all-featurescargo check --workspace --all-targets --all-features