Observability — logging, tracing & metrics

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.

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.

EventEventIdProcessKitDiagnostics.EventsLevelFields
Process spawned1 ProcessSpawned.ProcessSpawnedDebugprogram, pid, run id
Process exited2 ProcessExited.ProcessExitedDebugprogram, outcome, duration, run id
Process timed out3 ProcessTimedOut.ProcessTimedOutWarningprogram, timeout, run id
Run retry4 ProcessRetry.ProcessRetryDebugprogram, attempt, delay, run id
Supervisor restart5 SupervisorRestart.SupervisorRestartDebugprogram, restart #, delay
Supervisor storm pause6 SupervisorStormPause.SupervisorStormPauseWarningprogram, pause

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), processkit.exit_code (when it exited), processkit.signal (when signalled), processkit.pidnever 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.

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).

InstrumentKindUnitTags
processkit.runs.startedCounter{run}program
processkit.runs.completedCounter{run}program, outcome
processkit.runs.activeUpDownCounter{run}program
processkit.run.durationHistogramsprogram, outcome
processkit.retriesCounter{retry}program
processkit.supervisor.restartsCounter{restart}program
processkit.supervisor.storm_pausesCounter{pause}program
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.