Observability

Detail levels

Base operational messages (startup, warnings, shutdown) always print. --log-detail adds a line per request on top, at one of three levels — each a strict superset of the one before, so this is a level, not a set of things to combine:

• log — no per-request lines at all, just the base messages.
• access (default) — one summary line per request: identity, host, method, profile, which layer decided, how long it took. This is what you watch to see traffic.
• audit — the same line with everything else added: status code, whether the verdict was cached, would_deny, and the full evidence trail. Noticeably bulkier — reach for it while a policy is still being worked out, and drop back to access once it’s settled.

INFO allow identity=unidentified profile=default host=example.com method=GET layer=default_action duration_ms=51

Where it goes

Whatever --log-detail is set to, it all goes to the same place and renders the same way — one destination and one format, not one per level.

--log-sink (auto by default) picks the destination:

1. journald, if JOURNAL_STREAM is set (true for any systemd unit whose stdout/stderr is the journal) and the socket connection actually succeeds;
2. else classic syslog (/dev/log or /var/run/syslog), the common case on non-systemd or minimal Linux;
3. else plain stdout.

Each tier is a real connection attempt, not a guess. stdout / journald / syslog force one, erroring out if it’s not actually reachable rather than silently landing somewhere else — useful when you want plain stdout while running under something that sets JOURNAL_STREAM.

--log-format (auto by default; stdout only — journald and syslog format themselves) decides how stdout renders every line. auto checks whether stdout is actually a terminal: a human watching marshal serve in a shell gets short, coloured lines; anything reading the stream programmatically (docker logs, a file redirect, a collector that doesn’t set JOURNAL_STREAM) gets one JSON object per line, unprompted, no flag needed. pretty / json forces one regardless.

Under journald

Every field lands as a real, structured journal field (identity → F_IDENTITY, host → F_HOST, …), so journalctl is the follow command:

journalctl -u bot-marshal -f                                       # follow, human-readable (systemd service)
journalctl -u bot-marshal -o json -f | jq -c 'select(.TARGET=="access")'
journalctl -u bot-marshal F_HOST=api.github.com               # everything for one host

-u bot-marshal only works when marshal is running as the bot-marshal systemd unit (see production.md). Running marshal directly from the CLI has no unit to filter by — journald still records it, but tagged by the binary’s _COMM, not a unit. Use that field instead:

journalctl _COMM=marshal -f                                        # follow a CLI-run marshal process

tracing’s fields are flat, so audit’s evidence trail travels as a JSON string rather than a nested value there and in the json stdout format — still fully queryable (jq '.trail | fromjson'), just not natively nested.

The audit log

For a pristine, natively-nested, durable copy independent of all of the above:

marshal serve --audit-log /var/log/bot-marshal/audit.jsonl

One JSON object per line, append mode, created if missing, never truncated or rotated by bot-marshal itself — point logrotate at it.

Each record carries the resolved identity, whether it was attributed, which resolver matched, the profile, the deciding layer, the full evidence trail, status and timing, and — see below — every header name from both directions. Injected secrets are scrubbed from every audit path and log line.

facts and flags

reason says which layer decided. facts and flags say what every layer and transform observed along the way — and those are frequently the interesting part:

{ "action": "allow", "method": "POST", "path": "/mcp",
  "reason": { "layer": "allowlist", "code": "host_allowed", "rule": "github.com" },
  "facts": { "mcp.method": "tools/call", "mcp.tool": "create_issue",
             "secrets.injected.GIT_TOKEN": true },
  "flags": ["WriteOperation"] }

Both are omitted when empty, so a record with nothing to say is byte-identical to one from before these fields existed. Values are layer-supplied and redacted like everything else.

Two things worth knowing about what does not appear:

• A layer that returns a terminal allow or deny contributes no facts. Verdict::Allow and Verdict::Deny carry a Reason and nothing else, by design — evidence is what a layer hands forward to the next one, and a terminal verdict has no next one. The detail is not lost: it is in reason, including reason.rule. Facts come from layers that passed.
• secrets.not_injected.<host><path> marks an endpoint deliberately left unauthenticated — an OAuth2 swap’s own token or authorization endpoint. Its absence of a credential is intentional, and this is what says so.

request_headers and response_headers

Every header name on both directions, but the value only for a header this recognises as never carrying a credential — content-type, content-encoding, content-length, accept-encoding, cache-control, date, server, and similar transport/negotiation metadata. Everything else — authorization, cookie, set-cookie, location (an authorization redirect carries the code in its query string), and any header this does not recognise at all — keeps its name but shows "[redacted]" in its place. An unrecognised header is redacted by default, not allowlisted by default: a vendor’s own auth scheme under a header name nothing here has ever seen still gets blanked.

{ "action": "allow", "method": "POST", "path": "/v1/oauth/token", "status_code": 200,
  "request_headers": { "authorization": "[redacted]", "content-type": "application/x-www-form-urlencoded" },
  "response_headers": { "content-encoding": "br", "content-type": "application/json" } }

This is independent of, and in addition to, the credential redaction described above: that scrubs a value once something has learned it is secret, which cannot cover a header on an exchange that never completed — exactly the case debugging why it never completed needs to see the shape of, without ever seeing the credential itself. Name-based redaction applies before that question can even be asked.

Omitted when there is nothing to show: a CONNECT carries no headers of its own at this level, a denial before a request was parsed has none either, and a plain (non-TLS) absolute-form request through the explicit proxy is relayed byte-for-byte rather than parsed, so it never has response headers to show (see Capture).

A request marshal answered itself

action: allow no longer implies the request reached the upstream. A RequestResponder may answer it instead, and the record says so in reason:

{ "action": "allow", "method": "POST", "path": "/oauth2/token", "status_code": 200,
  "reason": { "layer": "oauth2.token", "code": "oauth2_terminated",
              "message": "marshal completed this OAuth2 exchange itself ..." } }

reason.code identifies the answer: oauth2_terminated is emitted when in-band capture answers a token request; model_catalog identifies the LLM router answering model discovery. These allowed responses do not imply an upstream request was forwarded. Synthesized responses carry proxy-agent: bot-marshal on the wire.

OAuth2 log lines

Credential acquisition logs at info on the base log, independently of --log-detail (these are not per-request lines):

message	fields	when
obtained an oauth2 access token from the provider's token endpoint	secret, grant, expires_in_secs	a real token request completed; once per expiry, not once per request
substituted marshal's PKCE challenge into an authorization request	secret	in-band capture rewrote an authorization request
captured an authorization code in band and exchanged it	secret, scope	capture succeeded
captured an authorization code but could not exchange it	secret, error	at error — the agent’s flow appears to have succeeded, but requests needing the credential will be refused
answered a token request locally	secret	the agent’s exchange was terminated at the proxy
the provider rotated this refresh token, but it comes from a source marshal does not own	secret, source	at warn — the configured value is now dead; see grant: refresh_token

No value appears in any of them. secret is the swap name.

A repeated obtained an oauth2 access token from the provider's token endpoint at high frequency means the cache is not holding — usually a provider that omits expires_in, which is never cached because treating a token with no stated lifetime as immortal would mean a revoked credential is never re-fetched.

Native decision judge reasons summarize the chosen label, returned confidence and required threshold. They are not model-generated explanations. A low-confidence result records judge.pass_reason in evidence and proceeds to the next layer; see Decision APIs.

Metrics

GET /v1/metrics on the management listener exposes Prometheus counters:

marshal_requests_total{profile="coding-agent",action="allow"}
marshal_requests_total{profile="coding-agent",action="deny"}
marshal_would_deny_total{profile="coding-agent"}
marshal_identity_requests_total{identity="agent-a",action="allow"}

Counters are per-request, not per-connection: once TLS is intercepted a single CONNECT carries many requests, and counting tunnels would understate an agent’s activity by whatever its connection reuse happens to be.

marshal_would_deny_total is the warn mode signal — the requests a profile forwarded but would have refused.