Embedded etcd logs every unary request as a `warn` (`request stats`), flooding the journal

まず、MicroShift が組み込みの etcd embed.Config を構築している場所を追跡し、server/etcdserver/api/v3rpc/interceptor.go を使って、WarningUnaryRequestDuration がリクエスト統計のログ出力をどのように制御しているかを確認します。しきい値のデフォルトが 300 ms になり、公開されている etcd 設定に一貫性があり、通常のリクエストが警告として表示されなくなり、実際に遅いリクエストは引き続き警告として表示されれば、変更は完了です。

What happens

microshift-etcd emits a "level":"warn" / "msg":"request stats" line for every
unary etcd request, not just slow ones. On an idle single-node install this is
30,544 lines/hour and accounts for 99.8 % of all etcd output (30,544 of 30,615
lines in a one-hour sample) and roughly 91 % of the entire systemd journal on the
host.

This is not a transient regression: the behaviour is unchanged across four months of
nightlies, from 4.22.0_202604200420 (April 2026) to 4.22.0_202608270614
(August 2026), measured on the same host.

Sample line — a routine Range on an empty key, served in 118 µs and logged as a
warning:

{"level":"warn","ts":"2026-09-02T09:19:07.119668+0200","caller":"v3rpc/interceptor.go:202",
 "msg":"request stats","start time":"2026-09-02T09:19:07.119529+0200","time spent":"117.678µs",
 "remote":"[::1]:46076","response type":"/etcdserverpb.KV/Range","request count":0,
 "request size":31,"response count":0,"response size":31,
 "request content":"key:\"/kubernetes.io/podtemplates\" limit:1 "}

Why this is wrong

logUnaryRequestStats (etcd server/etcdserver/api/v3rpc/interceptor.go) only logs at
warn when the request exceeded warning-unary-request-duration; otherwise it logs at
debug or not at all. etcd's default for that threshold is 300 ms.

Measured distribution over a 30-minute sample of 15,415 warned requests:

min	p25	median	p95	max
0.021 ms	0.103 ms	0.146 ms	3.234 ms	305.7 ms

The median is 2,049× below the default threshold. That only happens if
WarningUnaryRequestDuration is left at its zero value when MicroShift builds the
embedded embed.Config, so duration > warnLatency is true for every request.

The diagnostic cost is concrete. In that same 30-minute sample, exactly one
request — 305.7 ms — actually exceeded etcd's 300 ms default and genuinely deserved a
warning. It is buried under 15,414 that did not:

warned requests in 30 min	of those, actually > 300 ms	signal-to-noise
15,415	1	1 : 15,415

So the feature does not merely produce noise, it destroys the signal it exists to
provide: the one real slow-request warning is indistinguishable from the flood. On top
of that it dominates the host's journal.

Why it can't be worked around on the host

• MicroShift's config exposes only etcd.memoryLimitMB; there is no knob for the
  warning threshold or for etcd's log level.
• debugging.logLevel only goes in the more-verbose direction (Normal/Debug/Trace).
• microshift-etcd is registered as a scope unit, not a service. Scopes have no
  exec context, so LogRateLimitIntervalSec= / LogRateLimitBurst= / LogNamespace=
  drop-ins do not apply to it.
• A global journald rate limit low enough to catch etcd would indiscriminately drop
  bursts from every other unit.
• Setting etcd's own ETCD_* environment variables on the unit does not work either:
  the microshift-etcd binary contains no ETCD_* variable names at all
  (strings /usr/bin/microshift-etcd | grep -cE '^ETCD_[A-Z_]+$' → 0), because the
  config is built programmatically and etcd's environment-parsing layer is not linked
  in. This closes the most obvious operator-side workaround.

The only remaining option for operators is to spend disk on journal retention, which is
what we did (SystemMaxUse=500M → 16G just to keep ~4 weeks of history).

Prior art: k3s hit the same bug and fixed it

k3s embeds etcd the same way and ran into the identical zero-threshold problem. Their
etcd fork carries a patch titled server/embed: default WarningUnaryRequestDuration,
shipped in every recent release — including
v3.6.5-k3s1, which is the
same etcd base version MicroShift uses here, and continuing through
v3.6.12-k3s1.

That patch is both the precedent and a reference implementation for the fix suggested
below.

Suggested fix

Set WarningUnaryRequestDuration to etcd's default (300 ms) when constructing the
embedded config, and ideally surface it in the MicroShift config's etcd: section
alongside memoryLimitMB.

Environment

• MicroShift 4.22.0_202608270614_gaed751f15_4.22.0_okd_scos.ec.16
• Base OCP 4.22.0-0.nightly-2026-08-23-191303, base etcd 3.6.5
• Fedora release 43, kernel 7.1.12-100.fc43.x86_64, systemd 258, single node
• Also reproduced on 4.22.0_202604200420_g4ce2befbd_4.22.0_okd_scos.ec.11
  (base OCP 4.22.0-0.nightly-2026-04-01-223038) — four months earlier, same behaviour

Reproduce

# share of etcd output that is "request stats"
journalctl _SYSTEMD_UNIT=microshift-etcd.scope -S "1 hour ago" -o cat \
  | grep -c '"msg":"request stats"'

# durations of the warned requests
journalctl _SYSTEMD_UNIT=microshift-etcd.scope -S "30 min ago" -o cat \
  | grep '"msg":"request stats"' | grep -o '"time spent":"[^"]*"'

# no ETCD_* environment variables are linked into the binary
strings /usr/bin/microshift-etcd | grep -cE '^ETCD_[A-Z_]+$'

Use the indexed _SYSTEMD_UNIT= field match rather than -u: on a journal this
large a full-text scan takes minutes, the field match milliseconds.