Skip to content

conntrack: summarize stale-entry cleanup logging to cut log noise - #622

Open
yash97 wants to merge 9 commits into
aws:mainfrom
yash97:yathakka/logs-noise-reduction
Open

conntrack: summarize stale-entry cleanup logging to cut log noise#622
yash97 wants to merge 9 commits into
aws:mainfrom
yash97:yathakka/logs-noise-reduction

Conversation

@yash97

@yash97 yash97 commented Jul 21, 2026

Copy link
Copy Markdown
Contributor

What

The userspace conntrack GC logs one info line per stale entry it deletes, every cleanup cycle (CleanupConntrackMap / Cleanupv6ConntrackMap). On an idle cluster this single line dominates the agent's log output — in one measurement it was ~84–98% of all lines (hundreds of lines every 5‑minute cycle with essentially no workload).

Change

  • Demote the per-entry Conntrack cleanup Delete - Conntrack Key : ... line from info to debug (full 5-tuple detail preserved).
  • Emit a single per-cycle info summary instead: Done cleanup of conntrack map: deleted N stale entries out of M tracked (per-entry detail at debug level).
  • Applied symmetrically to both the IPv4 and IPv6 cleanup paths.

Why this shape

The shipped default log level is debug, so this is intentionally not a silent drop:

  • At --log-level=debug (default): behavior is unchanged in content — every deleted flow's full tuple is still logged, just correctly tagged debug, plus the new summary. This preserves debuggability for flow-level issues (e.g. the port-reuse GC race), where the source port of the evicted flow is exactly what you need.
  • At --log-level=info: the per-entry flood disappears and you get one summary line per cycle with the deleted/tracked counts. This makes info a usable, low-volume mode — previously the flood was info, so there was no way to shed it without losing everything.

Live A/B test (fresh nodes, identical load)

Built into an image and deployed on a 3-node EKS cluster. Nodes were recycled via ASG instance refresh first so each started with an empty conntrack map and a fresh log file (rules out any pre-existing entries). Then the same network-policy'd churn workload (client pods doing tight HTTP request loops → large short-lived flow / DNS turnover) was run for two back-to-back windows on one node, changing only the log level between them:

DEBUG window (10 min) INFO window (~11 min)
GC delete cycles observed 3 3
Stale entries GC deleted (sum over window) 51,193 181,107
Per-entry Conntrack cleanup Delete lines emitted 51,193 (all level:debug) 0
Per-cycle summary lines emitted 3 3
Total new log lines in window ~51,555 10

Same GC work in both windows (tens of thousands of stale entries deleted per cycle); the only difference is the log level. At info, the per-entry flood is fully suppressed and each cycle collapses to a single summary line — the three info-window cycles deleted 75,313 / 51,433 / 54,361 entries respectively yet produced just 10 total log lines.

INFO — per-cycle summary (verbatim):

{"level":"info","msg":"Done cleanup of conntrack map: deleted 75313 stale entries out of 80564 tracked (per-entry detail at debug level)"}

DEBUG — per-entry line, full detail preserved (verbatim):

{"level":"debug","msg":"Conntrack cleanup Delete - Conntrack Key : Source IP - 192.168.27.168 Source port - 55006 Dest IP - 10.100.0.10 Dest port - 53 Protocol - 17 Owner IP - 192.168.27.168 Ifindex - 828"}

BEFORE — same line on current main (emitted at info, one per deleted entry):

{"level":"info","msg":"Conntrack cleanup Delete - Conntrack Key : Source IP - 192.168.27.168 Source port - 55006 Dest IP - 10.100.0.10 Dest port - 53 Protocol - 17 Owner IP - 192.168.27.168 Ifindex - 828"}

Note: the per-cycle counts above are from a synthetic high-churn workload chosen to make the effect measurable; they are not steady-state. Near-idle, cleanup deletes ~180–320 entries/cycle — which today is still ~180–320 info lines/cycle and becomes 1 summary line with this change.

Testing

  • go build ./..., go vet ./pkg/ebpf/conntrack/... clean.
  • go test ./pkg/ebpf/... ./controllers/... ./pkg/rpc/... ./pkg/fwruleprocessor/... pass (no test asserts on these log lines).
  • Live fresh-node A/B validation as tabulated above: at info the conntrack-delete flood collapses to one summary per cycle; at debug full per-entry detail remains.

The conntrack GC cleanup logged one info line per stale entry deleted,
per cleanup cycle. On an idle 2-node IPv6 cluster this single line was
~98% of all agent log output (~180 lines every 5-min cycle even with no
workload churn).

Demote the per-entry 'Conntrack cleanup Delete' line to debug and emit a
single per-cycle info summary with the deleted/tracked counts instead.
Full per-entry detail remains available at --log-level=debug, so
debuggability is preserved while default-verbosity volume drops sharply.

Applies to both the IPv4 (CleanupConntrackMap) and IPv6
(Cleanupv6ConntrackMap) paths.
@yash97
yash97 requested a review from a team as a code owner July 21, 2026 19:12
@codecov-commenter

codecov-commenter commented Jul 21, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 0% with 10 lines in your changes missing coverage. Please review.
✅ Project coverage is 28.96%. Comparing base (534ae24) to head (4639b3b).

Files with missing lines Patch % Lines
pkg/ebpf/conntrack/conntrack_client.go 0.00% 10 Missing ⚠️
Additional details and impacted files

Impacted file tree graph

@@            Coverage Diff             @@
##             main     #622      +/-   ##
==========================================
- Coverage   29.00%   28.96%   -0.04%     
==========================================
  Files          27       27              
  Lines        3424     3428       +4     
==========================================
  Hits          993      993              
- Misses       2330     2334       +4     
  Partials      101      101              
Flag Coverage Δ
unittest 28.96% <0.00%> (-0.04%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines Coverage Δ
pkg/ebpf/conntrack/conntrack_client.go 0.00% <0.00%> (ø)
🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

yash97 added 2 commits July 21, 2026 15:07
govulncheck flagged GO-2026-5970 in golang.org/x/text@v0.37.0
(indirect). Bump to v0.39.0 (the fixed version); go mod tidy pulls the
compatible golang.org/x/{sys,net,mod,sync,term,tools} updates alongside.
govulncheck ./... now reports no vulnerabilities.
Comment thread pkg/ebpf/conntrack/conntrack_client.go Outdated
Comment thread pkg/ebpf/conntrack/conntrack_client.go
yash97 and others added 3 commits July 22, 2026 23:14
- Drop the '(per-entry detail at debug level)' suffix from the info
  summary line (both v4 and v6) - low value, standard pattern, and
  reads as if it were part of the conntrack data.
- Capture trackedEntries before the loop in the IPv4 path, mirroring
  the IPv6 path. More readable and robust to future cache-reset changes
  (the IPv4 summary previously relied on the cache reset staying
  commented out).
@yash97
yash97 requested a review from Pavani-Panakanti July 22, 2026 23:34
yash97 and others added 3 commits July 24, 2026 15:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants