Site logo WebRTC & Real-Time Media Architecture

Tracing One Participant Across SFU Logs

A quality complaint arrives as a name and a vague time: “Priya’s video froze for a few seconds just after two o’clock.” In that same window your forwarding server moved several hundred thousand packets belonging to forty other people, and it knows Priya only as a 32-bit synchronisation source number it never chose and cannot interpret. This guide is part of the SFU Observability & Metrics guide, and it answers one narrow question: what has to be threaded through the signaling handshake, the transport setup and the RTP forwarding path so that a single grep on one identifier returns the whole story of one participant, in order, across every process that touched their media.

Context & Trade-offs

The obstacle is that a participant carries a different name in every layer, and the names are minted by different parties at different times. Your product knows a user id that survives for years. Your signaling server knows a join, which is one person in one room for one call. Your ICE agent knows a username fragment and a DTLS fingerprint, both of which are re-drawn on an ICE restart. Your RTP receive path knows a MID, possibly a RID, and an SSRC — and the SSRC is a random 32-bit value chosen by the sending browser, replaced without warning on renegotiation. A single publisher sending three simulcast layers with RTX occupies six SSRCs simultaneously. Nothing in the RTP header says “Priya”.

Volume forces the second decision. Per-packet logging is not merely expensive, it is arithmetically impossible: one 720p stream at 30 fps is roughly 1,500 packets per second, and a fifty-person room where everyone subscribes to eight others carries about 400 forwarded streams, so packet-level lines would be 600,000 per second for one room. What is affordable is lifecycle events plus a rollup. Log every state transition in full — join, transport connected, track published, subscription created, layer switch, PLI, freeze start and end, leave — which is on the order of 60–200 lines per participant per hour, and emit one summary line per forwarded stream every 10 s, which is 360 lines per stream-hour. At roughly 300 bytes per line and 14-day retention that fits comfortably inside a log budget that per-packet logging would exceed by four orders of magnitude.

The third decision is where the id is minted, and the answer is the signaling layer, on the join RPC, before any media plumbing exists. The SFU is usually a different process on a different host and often a different node than the one the participant will eventually land on, so an id created inside the media server cannot cover the ICE and DTLS phase where a large share of failures actually happen. Mint two identifiers rather than one: a participant_id that is stable for the whole call, and a session_id that is re-minted for each transport attempt. A Wi-Fi to cellular handover produces a genuinely new ICE session for the same human, and collapsing both facts into one field makes it impossible to ask “did this person reconnect, or did two people join?” — the handover mechanics behind that distinction are covered in Handling Wi-Fi to Cellular Network Handover.

How a participant is renamed at each layer, and where each binding is learned Five stacked identifier realms connected top to bottom. The product user id comes from a signed token and is stable. The session and participant ids are minted at the signaling join and are stable for the call. The ICE username fragment and DTLS fingerprint come from the SDP and are re-drawn on every ICE restart. The MID and RID arrive as RTP header extensions and are stable per transceiver. The SSRC is read from the first RTP packet and is re-chosen by the sender without notice. One person, five names — only the top two are yours to control user=u-88 product identity learned from: signed join token claim never put this on a media-path log line stable participant=p-4471 session=9f3a2c minted at the signaling join RPC this is the join key every other layer must carry stable ice-ufrag=Xk2p DTLS fingerprint learned from: the SDP you already relayed re-drawn on every ICE restart — max 3 retries churns mid=1 rid=h RTP header extensions learned from: the first packets of each layer bind here, not on a=ssrc lines in the SDP stable ssrc=0x5a1e77c2 plus RTX ssrc learned from: the first RTP packet on the wire sender may re-choose it with no signaling at all churns Every log line carries row two; rows three to five are attributes of it, never substitutes for it.
The join key lives in row two because it is the only identifier that is both minted by you and stable across the transport churn beneath it.

That lineage settles a question people get wrong repeatedly: which artefact do you use to attach an incoming RTP stream to a participant? The tempting answer is the a=ssrc attribute lines in the SDP you already have. Do not rely on them. Firefox omits a=ssrc lines for simulcast entirely, Chrome will happily change an SSRC on a renegotiation without telling you, and an endpoint that resets its RTP state mid-call re-randomises. The durable binding is the MID header extension, with RID naming the layer within it — both arrive in-band on the packets themselves, so the mapping is established by the traffic it describes. If your forwarding path rewrites those extensions on the way out, the outbound side needs its own explicit binding table, which is exactly the bookkeeping described in Rewriting RTP Header Extensions When Forwarding.

Minimal Runnable Implementation

// 1. SIGNALING: mint once, at join. The participant id outlives transport churn;
//    the session id is re-minted for each new ICE/DTLS attempt by the same person.
function onJoin(socket, claims, roomId) {
  const ctx = {
    participant_id: claims.pid,                     // stable for the whole call
    session_id: crypto.randomUUID().slice(0, 8),    // 8 hex chars is plenty to grep
    room_id: roomId,
    node: process.env.SFU_NODE                      // which media node took the call
  };
  socket.data.ctx = ctx;                            // survives socket reconnects
  log('participant_join', ctx, { ua_family: claims.uaFamily });
  // Hand the SAME ids to the media plane over your control channel. The SFU must
  // never invent its own id: two ids for one person defeats the entire exercise.
  return sfuControl.createTransport({ ...ctx });
}

// 2. MEDIA PLANE: bind the ids to the transport, then to each stream as it appears.
//    ssrcIndex is the only lookup allowed on the hot path, and it is an integer map.
const ssrcIndex = new Map();                        // ssrc (uint32) -> stream record

function onTransportReady(transport, ctx) {
  transport.ctx = ctx;                              // one object reference, no copies
  log('transport_connected', ctx, {
    candidate_pair: transport.selectedPairType,     // 'host' | 'srflx' | 'relay'
    rtt_ms: Math.round(transport.rtt)               // relay adds 20-40 ms one-way
  });
}

// Called when the first packet of a new (mid, rid) arrives. Header extensions are
// authoritative here: a=ssrc lines are missing in Firefox simulcast offers.
function bindStream(transport, ssrc, mid, rid) {
  const rec = { ...transport.ctx, mid, rid, ssrc, direction: 'in' };
  const prev = ssrcIndex.get(ssrc);
  if (prev && prev.participant_id !== rec.participant_id) {
    // An SSRC collision across participants is rare but real at 32 bits and
    // thousands of concurrent streams. Log it loudly; never silently overwrite.
    log('ssrc_collision', rec, { previous_participant: prev.participant_id });
  }
  ssrcIndex.set(ssrc, rec);
  log('stream_bound', rec, {});                     // the SSRC -> participant record
  return rec;
}

// 3. LOGGING: one fixed shape. Identity keys are top-level and never interpolated
//    into the message text, or no query engine can index them.
function log(evt, ctx, fields) {
  process.stdout.write(JSON.stringify({
    ts: new Date().toISOString(),                   // wall clock, for humans
    mono_ns: Number(process.hrtime.bigint()),       // monotonic, for ordering
    evt,                                            // closed vocabulary, snake_case
    session_id: ctx.session_id,
    participant_id: ctx.participant_id,
    room_id: ctx.room_id,
    node: ctx.node,
    mid: ctx.mid ?? null,
    rid: ctx.rid ?? null,
    ssrc: ctx.ssrc ?? null,
    schema_v: 3,                                    // lets old and new lines coexist
    ...fields
  }) + '\n');
}

// 4. HOT PATH: never log per packet. Set a flag and let the 10 s rollup emit it.
function onLayerSwitch(rec, toRid, reason) {
  rec.rid = toRid;
  rec.pending = { evt: 'layer_switch', to_rid: toRid, reason };  // 'bwe_drop' etc.
}
Field groups inside one structured SFU log line A single log record is drawn as one horizontal bar divided into four coloured segments. The identity segment holds session, participant, room and node keys. The event segment holds the event name, reason and monotonic timestamp. The measurement segment holds rid, bitrate, loss and ssrc. The provenance segment holds sample rate, schema version and an optional trace id. Connectors run from each segment down to a panel describing its contents and the rule that governs it. One line, four groups — only the first group may be high-cardinality { "ts": "2026-07-26T14:02:11.418Z", ... } — 214 bytes on the wire identity keys the grep target event keys what happened measurement keys how bad it was provenance how to read it session_id participant_id room_id, node banned as metric labels — logs only evt=layer_switch reason=bwe_drop mono_ns ordering closed vocabulary, never free text rid, bitrate_kbps loss_pct, rtt_ms ssrc, mid numbers stay numbers, not strings sample_rate=0.01 schema_v=3 trace_id (optional) tells the reader what is missing A sampled line without sample_rate is a lie: the reader cannot scale the count back up.
Four groups with four different rules — identity is indexed, events come from a closed vocabulary, measurements stay numeric, and provenance tells the reader what the sampler already threw away.

Two conventions do most of the work here. First, identity keys are top-level JSON fields, not values interpolated into a human-readable message; "msg": "switching p-4471 to rid h" is unqueryable, while participant_id as its own key is an index lookup. Second, sample_rate travels on any line that was sampled, because a reader who finds three NACK lines at a 1% sample rate needs to know the real number was around three hundred.

The mono_ns field deserves a note of its own. Wall-clock timestamps are what a human reads, but they are also what NTP steps backwards during an incident, and a log sorted by a clock that jumped is a log that tells the wrong causal story. Carrying a monotonic counter alongside the ISO timestamp lets the query engine order events within a node exactly as they occurred, while the wall clock remains available for joining against a client beacon or a browser dump. Across nodes you cannot compare monotonic counters at all, which is fine — cross-node ordering in an SFU is only ever needed at second granularity, where wall clocks agree well enough.

Reproduction Steps & Debugging Log Patterns

  1. Start a three-participant room and note the participant_join line for the subscriber you will investigate; copy its session_id.
  2. Shape that subscriber’s downlink to 400 kbps for 10 s so the selector demotes them, producing a causal chain you already know the shape of.
  3. Query the log for that session_id alone, sorted by mono_ns, and confirm you can read the incident top to bottom without adding a second filter.
  4. Repeat the query filtered on participant_id instead, and confirm you now see two sessions if the client reconnected during the test — this is the check that proves the two-id split works.
  5. Force an ICE restart mid-call and verify the stream_bound line re-fires with a new SSRC while participant_id stays constant.

Step 5 is the one people skip and the one that catches the most bugs. An ICE restart re-draws the username fragment and, on several stacks, the SSRC too; if your binding table is keyed on either of those without a path back to the participant, the restarted stream reappears as an anonymous flow and every subsequent line for that person silently stops carrying their name. The symptom in the log is characteristic: events continue at the same rate, but participant_id becomes null partway through the session.

A healthy trace for step 3 reads like this:

// evt=participant_join      sess=9f3a2c part=p-4471 room=r-118 node=sfu-3
// evt=transport_connected   sess=9f3a2c candidate_pair=relay rtt_ms=64
// evt=stream_bound          sess=9f3a2c mid=1 rid=f ssrc=0x5a1e77c2 direction=in
// evt=subscribe             sess=9f3a2c publisher=p-2210 mid=0 rid=f
// evt=rollup                sess=9f3a2c bitrate_kbps=1420 loss_pct=0.1 rtt_ms=64
// --- shaping starts here ---
// evt=rr_loss               sess=9f3a2c loss_pct=14.2 jitter_ms=38
// evt=layer_switch          sess=9f3a2c to_rid=h reason=bwe_drop  <-- the cause
// evt=pli_sent              sess=9f3a2c to_participant=p-2210 trigger=layer_change
// evt=rollup                sess=9f3a2c bitrate_kbps=390 loss_pct=0.4 rtt_ms=71
// evt=participant_leave     sess=9f3a2c duration_s=612

The line that closes the ticket is layer_switch ... reason=bwe_drop, and it is only useful because reason is present. A switch count with no reason cannot distinguish healthy adaptation from a flapping selector, and the reader ends up guessing. When the query returns nothing at all, the fault is almost never the logging — it is that the session lived on a node you did not search, which is the routine consequence of Sharding Rooms Across SFU Nodes. Keep a small join index — session_id → node, start_ts, end_ts — written once at join, so the first query is always a lookup rather than a fan-out.

From a vague complaint to a specific log query A decision tree. The root is a complaint about a freeze around 14:02. The first decision is whether a session id is known. If yes, grep that session on its node; finding events means reading the reason field, while finding none means the session lived on another node. If no, look the session up in the join index by room and timestamp; a single match returns to the grep, while many matches are narrowed by the SSRC seen on the wire. Which query do you actually run first? ticket: froze around 14:02 do you have a session_id? yes no grep it on the node from the index join index lookup room + time window events found read the reason field nothing found wrong node — re-home one match go back to the grep many matches narrow by ssrc or mid Every branch converges on one session_id. If it cannot, the join index is the missing piece, not the log.
Every path ends at a single session id; when it cannot, the gap is the join index rather than the logging itself.

Common Implementation Mistakes

FAQ

Should the correlation id also go to the browser?

Yes, and it is nearly free. Return the session_id in the join response, attach it to every client-side stats beacon and error report, and print it in a corner of your internal debug overlay so support can read it off a screenshot. That one string converts “some time after two” into a query with a start and end timestamp.

How long should the identifiers be?

Eight hex characters for session_id is enough: 4.3 billion values against a few thousand concurrent sessions with 14-day retention leaves collision probability negligible, and short ids stay readable in a terminal and cheap on every line. Keep participant_id in whatever form your product already uses so support does not need a translation step.

Do I need distributed tracing spans, or are structured logs enough?

Structured logs with a consistent join key answer nearly every media question, because the events you care about are seconds apart rather than microseconds and the causal order is obvious from the event names. Spans earn their cost at the join boundary — token check, room lookup, node assignment, transport creation — where a slow join is genuinely a distributed-systems problem. Emit a trace_id on the join lines and leave the forwarding path on logs alone.

Related: return to SFU Observability & Metrics, then pair this with Exporting SFU Metrics to Prometheus and Grafana for the bounded-label side of the same pipeline and Alerting on Freeze and Packet-Loss SLOs for turning these traces into pages that are worth waking up for.

Alerting on Freeze and Packet-Loss SLOs Guide Exporting SFU Metrics to Prometheus and Grafana Guide Media Server Architecture: SFU & MCU Design, Scaling & Production Patterns Guide Load Balancing & Scaling SFUs Guide Autoscaling SFU Nodes on CPU and Bandwidth Guide Sharding Rooms Across SFU Nodes Guide