Plan routing klog into the structured logger (Step 6)
Found while watching the Step 5 validation, not a review finding: the leader election lines ignore the zap encoder because they are not ours. client-go calls klog.FromContext, controller-runtime hands the elector a context with no logr in it, and klog falls back to its own stderr writer. Nothing in the repo configures klog; it is an indirect dependency that ~60 linked packages use. Plain klog.SetLogger rather than the contextual form the klog docs recommend: the contextual option disables klog verbosity checking and hands the decision to zap, which at Development level would let client-go V(1) chatter through that klog suppresses today. Same fix to the format, no new volume. Also the one other in-process stderr bypass (the discovery http.Server has no ErrorLog) and json/rfc3339 encoder flags on the deployment. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -21,7 +21,8 @@ Precedent for this shape: `docs/plans/2026-09-10-2222-kvm-review-fixes.md`.
|
||||
- [ ] **Step 3** — H3: `address()` swallows every error and demotes healthy proxies.
|
||||
- [ ] **Step 4** — H4: the base image cache is shared across provider entries.
|
||||
- [ ] **Step 5** — Validate H1-H4 in-cluster against the real hypervisor (detailed below).
|
||||
- [ ] **Step 6+** — the mediums, from `review/REPORT.md`. Detailed when reached.
|
||||
- [ ] **Step 6** — Route klog into the structured logger (found during Step 5; detailed below).
|
||||
- [ ] **Step 7+** — the mediums, from `review/REPORT.md`. Detailed when reached.
|
||||
|
||||
---
|
||||
|
||||
@@ -478,6 +479,124 @@ pre-existing orphan volumes the review found.
|
||||
|
||||
---
|
||||
|
||||
## Step 6 — Route klog into the structured logger
|
||||
|
||||
**Not a review finding.** Found while watching the Step 5 validation: some lines ignore the
|
||||
zap encoder entirely, so no amount of `--zap-encoder=json` makes the stream parseable.
|
||||
|
||||
```
|
||||
I0917 19:50:02.580097 1 leaderelection.go:258] "Attempting to acquire leader lease..." lock="..."
|
||||
```
|
||||
|
||||
That is klog's own text sink. client-go's leader elector does `logger := klog.FromContext(ctx)`
|
||||
(`leaderelection.go:257`), and controller-runtime hands the elector a context with no logr in it
|
||||
(`pkg/manager/internal.go:461-473` — `mgr.Start` gets `ctrl.SetupSignalHandler()`, which carries
|
||||
no logger). `klog.FromContext` falls back to `Background()`, and with no logger registered that
|
||||
is klog's stderr writer. Nothing in this repo imports or configures klog; it is an indirect
|
||||
dependency (`k8s.io/klog/v2 v2.140.0`) that ~60 linked packages use, including
|
||||
`client-go/tools/{leaderelection,cache,record}`, `client-go/transport` and `client-go/rest`.
|
||||
controller-runtime does not route it either — its only `klog.SetLogger` call is in its own test
|
||||
suite.
|
||||
|
||||
### 6a. `cmd/main.go` — one line and an import
|
||||
|
||||
```go
|
||||
logger := zap.New(zap.UseFlagOptions(&opts))
|
||||
ctrl.SetLogger(logger)
|
||||
klog.SetLogger(logger)
|
||||
```
|
||||
|
||||
**Plain `SetLogger`, deliberately not `SetLoggerWithOptions(logger, klog.ContextualLogger(true))`.**
|
||||
The contextual form is what klog's own docs recommend, because it skips a klogr round trip — but
|
||||
it also disables klog's verbosity gate ("Such a logger cannot rely on verbosity checking in
|
||||
klog", `contextual.go:83-86`), handing the decision to zap's level. With `Development: true`
|
||||
that level is Debug, which enables V(1), so client-go's V(1) chatter that klog currently
|
||||
suppresses at its default `-v=0` would start appearing. Plain `SetLogger` keeps klog's own check
|
||||
in front ("klog will do its own verbosity checks before calling logger.V().Info",
|
||||
`contextual.go:43-44`) and still redirects everything it does emit ("all log lines will be
|
||||
suppressed from the regular output, and redirected to the logr implementation", `:47-48`).
|
||||
Same fix, no new volume. Performance is irrelevant at this scale.
|
||||
|
||||
`go.mod` promotes `k8s.io/klog/v2` from indirect to direct. It is already in the module graph,
|
||||
so nothing new is downloaded.
|
||||
|
||||
### 6b. `internal/discovery/server.go` — the other stderr bypass
|
||||
|
||||
The discovery API's `http.Server` (`:113-119`) sets no `ErrorLog`, so `net/http`'s own errors —
|
||||
`Accept` failures, handler panics that escape — go to `log.Default()` and out to stderr in
|
||||
stdlib format. `s.log` is already in scope two lines above:
|
||||
|
||||
```go
|
||||
srv := &http.Server{
|
||||
Handler: s.handler(),
|
||||
ErrorLog: slog.NewLogLogger(logr.ToSlogHandler(s.log), slog.LevelError),
|
||||
ReadHeaderTimeout: readHeadTimeout,
|
||||
...
|
||||
}
|
||||
```
|
||||
|
||||
`logr.ToSlogHandler` is the pattern the repo already uses for the same purpose in
|
||||
`internal/provider/gcp/wirelog.go:31-36`. This server is plain HTTP with no TLS, so `ErrorLog`
|
||||
carries genuine faults rather than handshake noise from scanners — Error level is right.
|
||||
|
||||
### 6c. `config/manager/manager.yaml` — make the deployed stream parseable
|
||||
|
||||
```yaml
|
||||
args:
|
||||
- --leader-elect
|
||||
- --health-probe-bind-address=:8081
|
||||
- --providers-config=/etc/proxy-operator/providers.yaml
|
||||
- --zap-encoder=json
|
||||
- --zap-time-encoding=rfc3339
|
||||
```
|
||||
|
||||
Verified that the flag wins over the in-code default: `addDefaults` only fills `NewEncoder`
|
||||
`if o.NewEncoder == nil` (`zap.go:176-191`), and `BindFlags` sets it from `--zap-encoder`.
|
||||
`--zap-time-encoding=rfc3339` matters because the JSON encoder defaults to `epoch`, which would
|
||||
give `1758138422.31` instead of a timestamp anyone can read. Verbosity is left at debug, so the
|
||||
per-RPC lines stay — that was the choice.
|
||||
|
||||
### Deliberately not doing
|
||||
|
||||
`opts := zap.Options{Development: true}` (`cmd/main.go:154-155`) stays. Flipping it to a
|
||||
production default would change the format for every existing deployment, not just this one, and
|
||||
the flags in 6c get the same result here without that blast radius.
|
||||
|
||||
### What stays unformatted regardless, and why that is fine
|
||||
|
||||
Flag-parse errors and `--version` (`cmd/main.go:160-163`) print before any logger exists, and
|
||||
`utilruntime.Must` panics in `init()` run before `main`. controller-runtime's own metrics and
|
||||
health servers also set no `ErrorLog` (`pkg/internal/httpserver/server.go:11-19`) and expose no
|
||||
option to set one. All three are outside reach; none can fire during steady-state operation.
|
||||
|
||||
### Tests
|
||||
|
||||
None. All three changes are wiring: two struct fields and one manifest key. `cmd/main.go` has no
|
||||
test coverage at all, and pinning `klog.SetLogger` hermetically means mutating global state that
|
||||
would leak into every other test in the package. Verified by observation instead — see below.
|
||||
Same call as H1's: a test that costs more than it protects does not earn its place.
|
||||
|
||||
### Verification
|
||||
|
||||
Rebuild, redeploy, and watch the rollout produce the line that started this:
|
||||
|
||||
```bash
|
||||
kubectl -n egress-proxies-operator-system logs deploy/egress-proxies-operator-controller-manager \
|
||||
| grep -i 'leader' | head -3
|
||||
```
|
||||
|
||||
It must be JSON with an rfc3339 `ts`, not `I0917 ...`. Then confirm the whole stream parses:
|
||||
|
||||
```bash
|
||||
kubectl -n egress-proxies-operator-system logs deploy/egress-proxies-operator-controller-manager \
|
||||
| jq -e -s 'length > 0' >/dev/null && echo "every line is JSON"
|
||||
```
|
||||
|
||||
That second command is the real check — it fails if *any* line is not JSON, which is exactly the
|
||||
property being fixed.
|
||||
|
||||
---
|
||||
|
||||
## Ordering
|
||||
|
||||
**H2 → H3 → H4**, three commits.
|
||||
|
||||
Reference in New Issue
Block a user