Embedded etcd logs every unary request as a `warn` (`request stats`), flooding the journal
Los mantenedores suelen responder en 1 día
Nadie ha tomado este issue todavía.
Evaluación
- Dificultad
- 3/5
- Tiempo estimado
- 1-2 días
- Aptitud para principiantes
- 72/100
- Tipo de issue
- Error
- Claridad
- Bastante claro
- Estado de actividad
- Activo
- Stack tecnológico
- go
- Área
- backend, distributed-systems
Línea de trabajo
Comienza rastreando dónde MicroShift construye la embed.Config de etcd integrada, usando server/etcdserver/api/v3rpc/interceptor.go para confirmar cómo WarningUnaryRequestDuration controla el registro de estadísticas de las solicitudes. El cambio estará completo cuando el umbral tenga un valor predeterminado de 300 ms, cualquier configuración de etcd expuesta sea coherente y las solicitudes rutinarias ya no aparezcan como advertencias, mientras que las solicitudes realmente lentas sigan haciéndolo.
Escrito por el modelo de indexación a partir del texto del issue.
Descripción
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.logLevelonly goes in the more-verbose direction (Normal/Debug/Trace).microshift-etcdis registered as a scope unit, not a service. Scopes have no
exec context, soLogRateLimitIntervalSec=/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:
themicroshift-etcdbinary contains noETCD_*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 etcd3.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 OCP4.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.
- Lenguaje dominante
- Go
- Estrellas
- 843
- Forks
- 233
- Merge medio
- 1 d 17 h
- PR fusionados (30 d)
- 121
Preparar el entorno
Primeros pasos
- Lee el issue completo y luego la guía de contribución del proyecto.
- Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
- Haz un fork del repositorio y trabaja en una rama.
- Abre un pull request que haga referencia al número del issue.
Más de openshift/microshift
-
tide/merge-blocker
Dificultad 1/5 Menos de una hora Aptitud para principiantes 30/100
openshift/microshift#6699 ·
Los mantenedores suelen responder en 1 día
Todos los issues de openshift/microshift
Issues similares
-
bug
Dificultad 1/5 Menos de una hora Aptitud para principiantes 92/100
open-telemetry/opentelemetry-go-compile-instrumentation#1417 ·
Los mantenedores suelen responder en 2 días
-
agent-research-finding agent-research-recommend chore ready-for-agent
Dificultad 2/5 1-3 horas Aptitud para principiantes 85/100
jordansmall/spindrift#4068 · 1 comentario ·
Los mantenedores suelen responder en 1 día
-
Type/Task
Dificultad 2/5 1-3 horas Aptitud para principiantes 74/100
OpenNSW/nsw-srilanka#537 ·
Los mantenedores suelen responder en 1 día
-
security
Dificultad 2/5 1-2 días Aptitud para principiantes 62/100
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 90/100
Los mantenedores suelen responder en 1 día