Skip to main content

Module trace

Module trace 

Source
Expand description

IPC trace emission - the client half of the trace ring events holds (utilities/47_events.md). IPC trace emission - the client half of the trace ring that events holds (utilities/47_events.md).

§Why the instrumentation is HERE and not in the kernel

The kernel is at the routing point holding sender, receiver and endpoint, so a trace ring there looks obvious. It is the wrong place, and the reason is worth stating where the code is: the kernel is FORBIDDEN to know what a message means (§4.4, §26.10), so a kernel ring can only ever record endpoint 7, op 11. A service knows its own protocol exactly, so instrumenting the SDK - the layer every service already calls - is the only place fs.read can come from. The constraint the constitution imposes and the feature the requirement wanted point the same way.

It also means the kernel gains nothing at all: no ring, no retention policy, no message-identity scheme, no control syscall, no new capability, and no write on the IPC fast path.

§Cost when not tracing

One Relaxed load, branch not taken. A service is tracing only if its spawn request granted it a send cap to events (declared in its contract as ipc_send = ["events"], CLAUDE.md 13.6) and the lazy resolution below found that cap - so tracing is AUTHORITY, visible in caps <service>, revocable, and absent by default (§3.1: no ambient anything).

§Never blocks, never fails loudly

Emission is try_send and the result is discarded. An observer must not be able to slow, block or break the thing it observes: a full events queue costs the emitting service nothing and loses one event, which the ring counts and events status reports. That is the correct trade here, and the opposite of the one made on a correctness path.

Modules§

spin_name
A fixed 12-byte name cell. No lock: a service is single-threaded, and this is written once at startup and read on every emit.

Constants§

EV_LEN
Wire length of one event: seq(4) + at_s(4, STAMPED BY THE SINK) + caller[12] + peer[12] + op(1) + kind(1).
KIND_ABORTED
The USER abandoned the wait (q at a ReqOutcome::Aborted call). Not a failure of anything, and recorded so a gap in a chain is explained rather than mysterious.
KIND_PEER_LOST
The peer’s endpoint died while the call was outstanding (ReplyDead, §8.6), or the send failed.
KIND_QUEUE_FULL
The peer is ALIVE and its queue is FULL - congestion, not absence. A distinct kind because answering it like a lost peer is a real bug this project has already paid for once (net-stack reacquiring a capability that was never stale; see DeadlineOutcome::QueueFull).
KIND_REPLY
A reply came back.
KIND_REQUEST
A request was sent and the caller is now awaiting a reply.
KIND_TIMEOUT
The call reached its deadline with no reply - the peer is alive but did not answer in time.
LOG_TEXT_MAX
Longest log text carried in one copy. A longer line still reaches serial in full - only the queryable copy is clipped - so the loss is bounded and the authoritative record is untouched.
MET_LEN
Wire length of one metric: owner[12] + name[20] + value(8).
MET_NAME_LEN
Bytes of a METRIC’s name. Deliberately NOT PEER_LEN.
PEER_LEN
Bytes of the peer’s NAME carried in an event. Short on purpose: it identifies a service, and the longest that matters here is block-driver (12).
SINK_NAME
The service that holds the ring. A call to THIS peer is never traced: the reader reaches the ring through it, so recording those calls would fill the ring with the reader’s own questions.
TRACE_OP_DUMP
Ask for the most recent events; byte 1 = how many are wanted.
TRACE_OP_EVENT
Message opcodes understood by the ring in events (byte 0 of the payload).
TRACE_OP_LOG
A LOG COPY: [6][owner:12][utf-8 text], variable length.
TRACE_OP_LOGS
Ask for recent log lines: [7][since:u64 le], where since is the last line number the caller has already seen (absent or 0 = everything held). The reply is a 25-byte header - next cursor (u64), oldest line still held (u64), lines in the window (u64), wrapped (u8) - then the text, one line per \n, owner and text separated by 0x1f. (This said byte 1 was a byte count.)
TRACE_OP_METRIC
Publish a METRIC sample: [4][owner:12][name:20][value(8, le)] - value at offset 33.
TRACE_OP_METRICS
Ask for the metric table.
TRACE_OP_STATUS
Ask for ring capacity / accepted / dropped.

Functions§

caller_set
True once this service has declared a name.
encode
Build one event payload. Split out from the send so the caller owns the buffer and this stays allocation-free (§26.6.1 - fixed stack, no heap).
encode_log
Encode one log copy. Text past LOG_TEXT_MAX bytes is cut HERE, at that byte count and not at a character boundary, so a clipped copy can end mid-character. (This said the CALLER truncated at a char boundary; ServiceContext::log_copy passes the text through unclipped.)
encode_metric
Encode one metric sample.
op_offset
The byte of a request to peer that carries its opcode. 0 unless declared otherwise.
resolved
True once resolution has run - the fast path’s only check on the common (untraced) call.
set_caller
Declare the emitting service’s own name; see [CALLER].
set_op_offset
Declare that peer’s protocol keeps its opcode at byte at of the request.
set_sink_slot
Record the outcome of resolution. A VALID slot latches for the life of the service; a MISS does NOT.
should_resolve
Whether the caller should attempt (re)resolution now. False once resolved; after a miss, true only every RESOLVE_RETRY_EVERYth call, so recovery is bounded work rather than a lookup per emission.
sink_slot
The cap slot to emit on, or u32::MAX if this service is not tracing.
take_late_resolve
If this service resolved the sink only AFTER one or more misses, return how many and consume the fact so it is reported exactly once. None on the healthy path (resolved first try) and on every call thereafter, so a normal boot prints nothing.
take_sink_changed
True ONCE after the sink changed, then false until it changes again.