change log level and fix the broken node predicate to reduce logging - #18
syutogether wants to merge 1 commit into
Conversation
|
Thanks for your PR,
To skip the vendors CIs, Maintainers can use one of:
|
Broly Security ScanWarning Latest baseline snapshot is stale. Broly is running in PR-only fallback mode until the next scheduled baseline refreshes. This does not block the PR. Note ✅ Clean scan Note Re-scan this PR anytime with
|
|
Should we mirror the upstream fix (which is actually an iteration on the actual fix) and use |
| qHandler(q) | ||
| }, | ||
| UpdateFunc: func(ctx context.Context, e event.UpdateEvent, q workqueue.RateLimitingInterface) { | ||
| reflect.DeepEqual(e.ObjectOld.GetLabels(), e.ObjectNew.GetLabels()) |
There was a problem hiding this comment.
reflect.DeepEqual returns a bool, but the return value was never assigned or checked -- it was called as a standalone statement and the result was thrown away. The code then unconditionally fell through to qHandler(q), enqueueing a reconcile on every single Node update regardless of whether labels changed.
This is almost certainly a bug. The intent was clearly to only reconcile when node labels change (since label changes affect which policies apply to which nodes). But as written, it was a no-op -- equivalent to not having the check at all.
|
Bogdan already had a PR fixing the issue. Closing mine. |
2 participants
Summary
The sriov-network-operator controller pod was emitting ~37M log lines/hr (~2.9 GB/hr) due to a combination of a reconcile storm and verbose INFO-level logging on hot paths.
Root cause
The Node watch handler in SetupWithManager had a bug where reflect.DeepEqual was called but its return value was discarded, so every Node update (kubelet heartbeats, status changes) triggered a full reconcile. With ~209 nodes, the controller was saturated doing back-to-back reconciles (~1 every 2 seconds), each walking all nodes and logging multiple lines per node per interface.
Changes (3 files)
controllers/sriovnetworknodepolicy_controller.go -- 3 fixes:
Fixed the broken Node watch predicate: the UpdateFunc now skips reconciliation when node labels haven't changed, dropping reconcile frequency from ~1/2s to only on actual label changes + the 5-min ResyncPeriod
"apply" policy log demoted from INFO to V(1): this fired per-policy × per-node × per-reconcile
Guarded json.Marshal behind V(2).Enabled(): avoids serializing the full NodeState JSON every node every reconcile when the log would be suppressed
api/v1/helper.go -- 1 fix:
"Update interface" log demoted from INFO to V(2): this was the single biggest log line (~40% of controller output), firing once per matching interface per node per reconcile
controllers/helper.go -- 1 fix:
"FindNodePoolConfig():" log demoted from INFO to V(1): fired once per node per reconcile
Expected impact
The predicate fix alone reduces reconcile volume by ~2 orders of magnitude. Combined with the log level changes and a chart-level logLevel: 0 setting, overall controller log output should drop from ~37M lines/hr to low thousands.