Skip to content

ADR 0063: One logging configuration for every binary

Status: Accepted Date: 2026-08-16 Issue: #1635 Related: #1632 (the stack traces, fixed first), #1607 (a flood buries the line that matters)

Context

Eleven shipped binaries and the scaffolded manager each built their own zap.Options literal. Nine passed Development: true and two passed Development: false. Git says why, which is that nobody said why. The true came from the kubebuilder scaffold and propagated by copy into every binary added after it, and the two commits that introduced the false give no reason.

That one field is five decisions in controller-runtime's wrapper. It selects the console encoder over JSON, it selects the Debug level over Info, it lowers the stack-trace threshold from Error to Warn, it makes DPanic panic, and it makes KubeAwareEncoder print a logged Kubernetes object in full rather than as its identity. #1632 measured the third and removed it, deliberately leaving the rest: each binary kept whichever mode it already had, through a dcslog.Development() or dcslog.Production(). Both constructors preserved the split. Neither decided it.

Two things ride on what is left, and both are load-bearing.

The encoder is a published surface. The Diagnose panel's Logs tab and dcs health --logs both serve a pod's stdout as raw text into a preformatted block. Nothing parses it. The tab offers eight components in one list. Seven of them printed console and Audit Archiver printed JSON, so which format an operator got depended on which card they opened. Meanwhile docs/security-operations.md § SIEM Integration listed the gateway access log as one of three streams a SIEM ingests, and described its format as structured JSON. It was not.

The level is volume nobody chose. Development mode selects Debug, so nine shipped binaries emitted every V(1) line in production. There are 158 V(1) call sites. The largest by volume is the gateway's own request line, and it fires once per HTTP request including every static asset. Measured against the real binary: one cold load of the engineering app shell wrote 95 Debug lines with no API traffic at all, against the 2000-line window the Logs tab and dcs health --logs both serve. That is the same burial #1632 removed, arriving by a different route. The split failed the other way too. The nine V(1) sites in cmd/audit-archiver and pkg/auditfluxbridge have never emitted a line in any deployment.

#1607 had already found this shape from the other end. Its fix note records that the historian's per-dropped-record line became a flood because the same debug verbosity being on is how it reached the Logs tab in the first place.

Decision

All twelve binaries log the same way, through one constructor in pkg/dcslog. A deployment overrides it for the whole release.

Console, at Info, with no sampling, and stack traces only for DPanic and above. dcslog.Options() is the only exported constructor. A second would be a mode, and a mode is what twelve binaries drifted across.

Console, because this product ships its own log reader. The reader who has no other option gets the default. An operator triaging from the Logs tab cannot re-encode what is on screen, whereas a plant shipping logs to Loki, Elasticsearch or a SIEM is by definition configuring its deployment.

Info, because Debug is not free and this tree spends V(1) on per-event detail. One line went the other way. The gateway logs a request to /api/ at Info, because the Security Operations page lists that access log as a SIEM stream, and a documented security stream cannot sit below the verbosity the product ships at. Requests for static assets stay at V(1), which is what made the line a flood.

No sampling, which is why Development stays true under the hood. That field reads like the one this ADR is deciding, and once the encoder, the level and the trace threshold are all set explicitly, the only behaviour left on it that matters is the sampler. Development: false turns zap's sampler on and offers no way back, because controller-runtime appends the sampler's WrapCore after any option a caller supplies. The sampler keeps the first hundred entries per second and then one in a hundred, and it counts per level and message while ignoring the fields. Our access log spells every entry request, so a plant busy enough to exceed a hundred requests a second would silently lose 99% of that stream. Dropping records by a rule nobody in this tree wrote is also the opposite of what pkg/caplog does. That package caps a flood at the site that emits it, and says so in the log.

The chart carries a logging block, and it reaches all twelve. Three keys render as zap flags: encoder, level and stacktraceLevel. Nine components take them from their own template. unit-runtime and io-probe have no template, because the physical operator writes their pod specs. The values reach that operator as environment variables and it passes them on. A key that reached ten of twelve would rebuild the per-binary split one layer down, and it would do so invisibly. A runtime pod printing console beside a gateway printing JSON reads as a broken collector, and nobody would look at the chart.

An empty key renders nothing at all, so pkg/dcslog keeps ownership of the shipped default. deploy/helm/cloud-native-dcs/tests/logging.sh holds both directions. TestEveryBinaryTakesTheSameOptions holds the Go side.

Alternatives Considered

JSON by default. The Security Operations page already claimed JSON, so this would have made a published statement true. Rejected on the asymmetry. Choosing JSON degrades the Logs tab and dcs health --logs for every deployment, including the ones with no log pipeline at all, to serve a reader that has to configure a collector regardless. Choosing console costs a pipeline deployment one Helm value. The page is corrected either way, because its field list was also wrong.

Revisit this if the Logs tab ever learns to parse and render structured entries. Console wins today because the tab cannot do that yet. It is not the better wire format.

Keep Debug and move the two flood sites to V(2). Cheaper, and it would have removed the measured volume. Rejected because it makes "every V(1) line ships" the standing default and puts the burden on every future author of a V(1) line to think about production volume. This tree already uses V(1) for per-request, per-publish and per-scan detail, and Info is the level that matches that usage.

A per-component logging block. Rejected. Per-component configuration is exactly the shape this ADR replaces, and a release whose components log in different formats is the state that made the Logs tab render two.

Leave Development: false and accept the sampler. Rejected. A DCS that silently discards log records during the busiest minute of an incident is trading the wrong thing for the right-looking one, and the discard is invisible in the output.

Consequences

A deployment that upgrades sees less log volume and one format everywhere. The two binaries that shipped JSON at Info now ship console at Info, which changes what a collector parsing them receives. A deployment doing that sets logging.encoder: json. That value should have existed all along, and it now applies to every component.

V(1) detail is no longer on by default. It is one flag away per pod (--zap-log-level=debug) or one Helm value away for a release (logging.level: debug), and the nine V(1) sites in the two binaries that never emitted are reachable for the first time.

The gateway access log is now at the shipped verbosity for /api/ requests and below it for everything else. A collector that was ingesting page and asset requests loses them unless it asks for Debug. That log still carries only method, path, status and duration. The Security Operations page's promise of a subject, client IP, user-agent and request ID on each entry therefore remains unfulfilled, and #1637 tracks it. The gap is in the line's content, and this record settles its level. That content gap closed afterwards in #1637, which carried the client IP and the authenticated subject up to a line written above the middleware that resolves them and left the level decided here untouched.

A thirteenth binary cannot arrive with its own literal, and cannot pick a mode, because there is only one constructor and a source scan over cmd/ fails on anything else. If a second configuration is ever genuinely needed, that test is where the reason has to be written down.

Every V(1) line now has to say what its silence costs

Moving the default to Info made one question load-bearing that nobody had ever asked: what is lost when a given V(1) line does not emit. For a line that reports progress the answer is nothing, and that is the case this ADR was written for. For a line that reports a failure and is the only record of it, the answer is the record itself. The level does not distinguish the two, and neither does the message. #1638 audited all of them and scripts/.v1-signal-audit.tsv carries the verdicts, one row per site, in four values:

Verdict Means
progress Not a failure report. Nothing is lost when it is invisible.
second-signal A failure that something durable already records. The row names that record.
only-signal-ok A failure whose only record is this line, and losing it is acceptable. The row says why.
only-signal-gap A failure whose only record is this line, and that is a loss. The row names an open issue.

make lint-v1-signals fails on a V(1) site with no row and on a row that matches no site, so the question is asked when a line is written by the person who knows the answer.

Scope is every V(1) site. #1638 started from a keyword list over the messages and that list was the wrong instrument. "accept-and-skip: reconcile event missing revision" is a dropped audit record and "Probe failed" is a status field being set, and no lexicon separates them. A gate that reads its own scope out of the text reports success on the sites it did not think to look at. ADR 0060 rejected that shape once already.

The audit also found that a durable signal has to be one that actually fires. dcs_runtime_healthy held its last reading on every path where the operator could not reach the runtime. An unreachable unit therefore reported healthy for as long as the operator process ran. dcs_runtime_reads_total and dcs_runtime_writes_total were registered, documented, and incremented by nothing at all. Three of the second-signal rows name a record that only became true in the same commit as the row.