APM: Fix pkg/trace log format-string bugs - #55049
Conversation
24eaac2 to
1501029
Compare
|
🎯 Code Coverage (details) 🔗 Commit SHA: e5743e2 | Docs | View more details | Give us feedback! |
Five call sites passed the wrong argument to a printf-style
pkg/trace/log function: two passed a method value (s.Name, s.Resource)
instead of calling it (s.Name(), s.Resource()) on *idx.InternalSpan,
one passed a method value on the obfuscateSpan interface
(span.Resource), and two Errorf calls had a %v verb with no argument
at all, printing %!v(MISSING) instead of the unknown attribute type.
Enabling the govet check (next commit) also surfaced two sites in
normalizer.go where a %s verb was given a bare *idx.InternalSpan.
That type has no String() method, so the verb rendered the unexported
span pointer and string table as "%!s(*idx.Span=&{...})". Both now log
the identifying fields explicitly. DebugString() is deliberately not
used here: it dumps every span attribute, which is unbounded in size
and may carry request data, making it unsuitable for a log line.
These went undetected because pkg/trace/log was missing from the
govet printf funcs allowlist (fixed in the next commit).
Co-Authored-By: Claude Opus 5 (1M context) <[email protected]>
pkg/trace/log defines its own printf-style Tracef/Debugf/Infof/Warnf/ Errorf/Criticalf wrappers, separate from pkg/util/log, but was absent from govet's printf funcs list. That meant govet never checked format strings in any log.Xf call across the entire pkg/trace tree, letting the bugs fixed in the previous commit go undetected in CI. Co-Authored-By: Claude Opus 5 (1M context) <[email protected]>
1501029 to
76470ac
Compare
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 69c585bb22
ℹ️ About Codex in GitHub
Codex has been enabled to automatically review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".
Files inventory check summaryFile checks results against ancestor 9f2fd1cb: Results for datadog-agent_7.84.0~devel.git.273.e5743e2.pipeline.131653797-1_amd64.deb:No change detected Results for datadog-iot-agent_7.84.0~devel.git.273.e5743e2.pipeline.131653797-1_amd64.deb:No change detected |
Static quality checks✅ Please find below the results from static quality gates Successful checksInfo
|
Regression DetectorRegression Detector ResultsMetrics dashboard Baseline: 3067dd1 Optimization Goals: ✅ No significant changes detected
|
| perf | experiment | goal | Δ mean % | Δ mean % CI | trials | links |
|---|---|---|---|---|---|---|
| ➖ | quality_gate_metrics_logs | memory utilization | +0.97 | [+0.72, +1.23] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_logs | % cpu utilization | +0.84 | [-0.05, +1.72] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_idle | memory utilization | +0.35 | [+0.23, +0.47] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_security_idle | memory utilization | +0.23 | [+0.13, +0.34] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_security_mean_fs_load | memory utilization | +0.06 | [-0.01, +0.13] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_security_no_fs_load | memory utilization | -0.01 | [-0.15, +0.13] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_idle_all_features | memory utilization | -0.13 | [-0.17, -0.09] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_private_action_runner | memory utilization | -0.26 | [-0.38, -0.13] | 1 | Logs bounds checks dashboard |
Bounds Checks: ✅ Passed
| perf | experiment | bounds_check_name | replicates_passed | observed_value | links |
|---|---|---|---|---|---|
| ✅ | quality_gate_idle | intake_connections | 10/10 | 4 = 4 | bounds checks dashboard |
| ✅ | quality_gate_idle | memory_usage | 10/10 | 172.34MiB ≤ 178MiB | bounds checks dashboard |
| ✅ | quality_gate_idle | total_bytes_received | 10/10 | 739.77KiB ≤ 819.20KiB | bounds checks dashboard |
| ✅ | quality_gate_idle_all_features | intake_connections | 10/10 | 4 = 4 | bounds checks dashboard |
| ✅ | quality_gate_idle_all_features | memory_usage | 10/10 | 515.50MiB ≤ 538MiB | bounds checks dashboard |
| ✅ | quality_gate_idle_all_features | total_bytes_received | 10/10 | 1.14MiB ≤ 1.25MiB | bounds checks dashboard |
| ✅ | quality_gate_logs | intake_connections | 10/10 | 18 ≤ 40 | bounds checks dashboard |
| ✅ | quality_gate_logs | memory_usage | 10/10 | 210.78MiB ≤ 229MiB | bounds checks dashboard |
| ✅ | quality_gate_logs | missed_bytes | 10/10 | 0B = 0B | bounds checks dashboard |
| ✅ | quality_gate_logs | total_bytes_received | 10/10 | 264.19MiB ≤ 292MiB | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | cpu_usage | 10/10 | 376.45 ≤ 2000 | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | intake_connections | 10/10 | 18 ≤ 40 | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | memory_usage | 10/10 | 404.72MiB ≤ 439MiB | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | missed_bytes | 10/10 | 0B = 0B | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | total_bytes_received | 10/10 | 0.94GiB ≤ 1.04GiB | bounds checks dashboard |
| ✅ | quality_gate_private_action_runner | memory_usage | 10/10 | 71.40MiB ≤ 76MiB | bounds checks dashboard |
| ✅ | quality_gate_security_idle | cpu_usage | 10/10 | 26.83 ≤ 100 | bounds checks dashboard |
| ✅ | quality_gate_security_idle | memory_usage | 10/10 | 327.19MiB ≤ 335MiB | bounds checks dashboard |
| ✅ | quality_gate_security_mean_fs_load | cpu_usage | 10/10 | 60.30 ≤ 200 | bounds checks dashboard |
| ✅ | quality_gate_security_mean_fs_load | memory_usage | 10/10 | 304.50MiB ≤ 314MiB | bounds checks dashboard |
| ✅ | quality_gate_security_no_fs_load | cpu_usage | 10/10 | 20.94 ≤ 100 | bounds checks dashboard |
| ✅ | quality_gate_security_no_fs_load | memory_usage | 10/10 | 313.55MiB ≤ 343MiB | bounds checks dashboard |
Explanation
Confidence level: 90.00%
Effect size tolerance: |Δ mean %| ≥ 5.00%
Performance changes are noted in the perf column of each table:
- ✅ = significantly better comparison variant performance
- ❌ = significantly worse comparison variant performance
- ➖ = no significant change in performance
A regression test is an A/B test of target performance in a repeatable rig, where "performance" is measured as "comparison variant minus baseline variant" for an optimization goal (e.g., ingress throughput). Due to intrinsic variability in measuring that goal, we can only estimate its mean value for each experiment; we report uncertainty in that value as a 90.00% confidence interval denoted "Δ mean % CI".
For each experiment, we decide whether a change in performance is a "regression" -- a change worth investigating further -- if all of the following criteria are true:
-
Its estimated |Δ mean %| ≥ 5.00%, indicating the change is big enough to merit a closer look.
-
Its 90.00% confidence interval "Δ mean % CI" does not contain zero, indicating that if our statistical model is accurate, there is at least a 90.00% chance there is a difference in performance between baseline and comparison variants.
-
Its configuration does not mark it "erratic".
CI Pass/Fail Decision
✅ Passed. All Quality Gates passed.
- quality_gate_logs, bounds check total_bytes_received: 10/10 replicas passed. Gate passed.
- quality_gate_logs, bounds check missed_bytes: 10/10 replicas passed. Gate passed.
- quality_gate_logs, bounds check intake_connections: 10/10 replicas passed. Gate passed.
- quality_gate_logs, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_mean_fs_load, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_mean_fs_load, bounds check cpu_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_no_fs_load, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_no_fs_load, bounds check cpu_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_idle, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_security_idle, bounds check cpu_usage: 10/10 replicas passed. Gate passed.
- quality_gate_idle, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_idle, bounds check intake_connections: 10/10 replicas passed. Gate passed.
- quality_gate_idle, bounds check total_bytes_received: 10/10 replicas passed. Gate passed.
- quality_gate_private_action_runner, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check total_bytes_received: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check intake_connections: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check missed_bytes: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check cpu_usage: 10/10 replicas passed. Gate passed.
- quality_gate_idle_all_features, bounds check total_bytes_received: 10/10 replicas passed. Gate passed.
- quality_gate_idle_all_features, bounds check memory_usage: 10/10 replicas passed. Gate passed.
- quality_gate_idle_all_features, bounds check intake_connections: 10/10 replicas passed. Gate passed.
|
/merge |
|
View all feedbacks in Devflow UI.
It will be processed automatically as soon as GitHub reports it as mergeable. View in MergeQueue UI.
devflow unqueued this merge request: It did not become mergeable within the expected time |
What does this PR do?
Fix format-string bugs in
pkg/traceand addgithub.com/DataDog/datadog-agent/pkg/trace/logto the govetprintffuncsallowlist in.golangci.ymlso this class of bug is caught by CI going forward.Motivation
pkg/trace logger has printf style commands but the govet rule didn't know about this so there were a few spots where the printf directives were wrong
Describe how you validated your changes
dda inv linter.go --module=pkg/trace→0 issues./All linters passed(after all fixes; before the fixes it reported the 5 originally-known findings plus 2 additional%s-with-non-Stringer findings, all now fixed).dda inv test --targets=./pkg/trace/agent,./pkg/trace/filters→ all tests pass (403 tests, 3 pre-existing skips unrelated to this change).git diff origin/mainreviewed line-by-line to confirm the legacy*pb.Spancode paths (normalize,Truncate) were left untouched — onpb.Span,Resource/Nameare struct fields and the existings.Resource/s.Nameusages there are correct as-is.dda inv linter.go --targets=./cmd/serverless-init,./comp/core/log/impl-trace,./comp/process/gpusubscriber/impl,./pkg/config/remote/uptane,./pkg/privateactionrunner/bundles/helm,./cmd/process-agent/subcommands/status→0 issues.(sanity check that no other consumer ofpkg/trace/logregressed).fixes:release note viareno new trace-log-printf-format-fixes.Additional Notes
Why not
DebugString()*idx.InternalSpandoes have aDebugString()helper, and it would satisfy theverb — but it dumps every span attribute. Attributes are unbounded in size and can
carry request data (URLs, DB statements, custom tags), which makes them unsuitable
for a value interpolated into a log line that fires once per malformed span. Both
sites therefore log the identifying fields explicitly instead.
DebugString()remains available for interactive debugging.