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.