Observability — logging, tracing & metrics

Previous: Overview

ProcessKit reports its run lifecycle through the three standard .NET diagnostic channels, all opt-in and free when nothing is listening:

• Microsoft.Extensions.Logging — structured lifecycle events on an ILogger you attach.
• System.Diagnostics tracing — one Activity (span) per completed run, on a named ActivitySource.
• System.Diagnostics.Metrics — counters and a histogram on a named Meter.

Secrets never leave the process. argv and environment values are never written to a log message, a trace tag, or a metric tag. Only the program name and non-secret facts (pid, outcome, durations, exit code / signal, retry / restart counts, run id) are emitted. This invariant holds across all three channels.

A resource group's post-run ProcessGroup.LimitEvidence() — per-axis evidence of whether a configured resource cap actually fired — is a separate, pull-based read, not a push notification on any of these three channels: nothing here logs, traces, or counts a cap tripping. Its Unknown-vs-Tripped-vs- NotTripped semantics are documented on Process groups; its opt-in JSONL serialization (a limit_evidence line) is documented on JSONL reports.

Logging

Attach any Microsoft.Extensions.Logging.ILogger with Command.Logger (F#: Command.logger):

let cmd = Command.create "deploy" |> Command.logger logger

var cmd = new Command("deploy").Logger(logger);

No logger set → no-op, no allocation. Each event is emitted through a cached LoggerMessage.Define delegate, so when the level is disabled there is no formatting or boxing on the hot path.

Event taxonomy

Every event has a stable EventId (name + number) so you can filter or route by id — the ids are exposed as ProcessKitDiagnostics.Events.* so you never hard-code a number — and every run-scoped event carries a per-run RunId (plus the Pid on spawn) so a run's lines tie together even across a concurrent fleet, and even in a sink that does not capture logging scopes.

The RunId is stamped once per logical run at the verb layer, so a run and all its retries share one id; a directly-spawned streaming run (StartAsync) gets a fresh per-incarnation id. It is a compact, per-process value — a log sink already scopes by process, and cross-process correlation is the trace's job.

Tracing

ProcessKit publishes an ActivitySource named ProcessKitDiagnostics.ActivitySourceName ("ProcessKit"). A completed run yields one processkit.run span whose duration is the real run length, tagged with:

processkit.program, processkit.run_id, processkit.outcome (exited / signalled / timedout / unobserved), processkit.exit_code (when it exited), processkit.signal (when signalled), processkit.pid — never argv or environment. The span nests under whatever Activity was current when the run started, so a run inside an HTTP request appears under that request's trace.

These four span and metric labels are frozen as spelled here, and they are a different set from the report identifiers published in the generated dictionary spec/identifiers.json (see Stable identifiers), which is the source of truth whenever a consumer needs the identifier of an Outcome, a ProcessError, a Mechanism, a Signal, a LimitVerdict, or a SupervisionEventKind. Three of the four labels are spelled identically in both; the one exception is Outcome.TimedOut, whose span and metric label has always been timedout while its report identifier is timed_out. Neither is being respelled to match the other: both shipped, and a dashboard or an alert keyed on either would break.

Wire it into OpenTelemetry:

services.AddOpenTelemetry().WithTracing(t => t.AddSource(ProcessKitDiagnostics.ActivitySourceName));

Free when no listener subscribes (no span is created). A run that is abandoned (spawned, never finished) emits no span.

Metrics

ProcessKit publishes a Meter named ProcessKitDiagnostics.MeterName ("ProcessKit"), OpenTelemetry- compatible. Tag cardinality is deliberately bounded — instruments are tagged by program name and a small closed set of outcome labels, never by argv.

Units follow the OpenTelemetry/UCUM convention — dimensionless counts use a {…} annotation, and the duration histogram is in seconds (the OTel norm for *.duration).

services.AddOpenTelemetry().WithMetrics(m => m.AddMeter(ProcessKitDiagnostics.MeterName));

runs.active is incremented at spawn and decremented when the run's handle stops being "in flight" — either of two events, whichever happens first: it reaches a terminal verb (Run/Output*/Wait*/ Profile/Finish, or racing it via WaitAnyAsync/WaitAllAsync), or its RunningProcess handle is disposed without ever reaching one (a streaming handle dropped without FinishAsync). Either way runs.active returns to zero for that run — it never leaks upward just because a caller only streamed and disposed. Only the first of those two events counts toward runs.completed/run.duration/the trace span: a handle disposed without a terminal verb is still not counted as completed ("an abandoned run simply isn't counted as completed"), so runs.started/runs.completed can legitimately diverge even though runs.active is exact.

Next: JSONL reports