fix(logs): Isolate partial container logs by stream - #55594
Conversation
There was a problem hiding this comment.
AI review by Codex (OpenAI) - workflow run
Patch is incorrect. Per-stream buffering breaks file checkpoint accounting when streams emit out of physical file order, risking replay, malformed records, or log loss after restart.
| content := make([]byte, state.buffer.Len()) | ||
| copy(content, state.buffer.Bytes()) | ||
| state.bufferedMsg.RawDataLen = state.rawDataLen |
There was a problem hiding this comment.
[P1] Preserve physical-order checkpoint accounting. RawDataLen advances the file tailer's checkpoint for every emitted message, but assigning only this stream's bytes means an interleaved later record can emit before bytes already buffered from another stream. If the Agent stops between those emissions, the saved offset points into an earlier CRI/Docker record. Restart can then replay, misparse, or lose logs. The decoder needs offset accounting independent from per-stream message aggregation.
|
🎯 Code Coverage (details) 🔗 Commit SHA: d672ace | Docs | View more details | Give us feedback! |
Files inventory check summaryFile checks results against ancestor e318062a: Results for datadog-agent_7.84.0~devel.git.432.d672ace.pipeline.134061774-1_amd64.deb:No change detected Results for datadog-iot-agent_7.84.0~devel.git.432.d672ace.pipeline.134061774-1_amd64.deb:No change detected |
Static quality checks✅ Please find below the results from static quality gates Successful checksInfo
8 successful checks with minimal change (< 2 KiB)
|
Regression DetectorRegression Detector ResultsMetrics dashboard Baseline: e318062 Optimization Goals: ✅ No significant changes detected
|
| perf | experiment | goal | Δ mean % | Δ mean % CI | trials | links |
|---|---|---|---|---|---|---|
| ➖ | quality_gate_logs | % cpu utilization | +3.67 | [+2.78, +4.57] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_security_no_fs_load | memory utilization | +0.59 | [+0.50, +0.67] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_security_idle | memory utilization | +0.47 | [+0.42, +0.52] | 1 | Logs bounds checks dashboard |
| ➖ | dsd_uds_10mb_3k_timestamped_contexts_cpu | % cpu utilization | +0.41 | [+0.17, +0.65] | 1 | Logs |
| ➖ | quality_gate_idle | memory utilization | +0.30 | [+0.25, +0.34] | 1 | Logs bounds checks dashboard |
| ➖ | dsd_uds_10mb_3k_timestamped_contexts_memory | memory utilization | +0.28 | [+0.07, +0.49] | 1 | Logs |
| ➖ | quality_gate_security_mean_fs_load | memory utilization | +0.06 | [+0.02, +0.09] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_idle_all_features | memory utilization | -0.04 | [-0.08, -0.01] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_private_action_runner | memory utilization | -0.75 | [-0.87, -0.63] | 1 | Logs bounds checks dashboard |
| ➖ | quality_gate_metrics_logs | memory utilization | -1.68 | [-1.91, -1.46] | 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 | 175.97MiB ≤ 178MiB | bounds checks dashboard |
| ✅ | quality_gate_idle | total_bytes_received | 10/10 | 745.16KiB ≤ 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 | 524.96MiB ≤ 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.98MiB ≤ 229MiB | bounds checks dashboard |
| ✅ | quality_gate_logs | missed_bytes | 10/10 | 0B = 0B | bounds checks dashboard |
| ✅ | quality_gate_logs | total_bytes_received | 10/10 | 263.47MiB ≤ 292MiB | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | cpu_usage | 10/10 | 413.11 ≤ 2000 | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | intake_connections | 10/10 | 19 ≤ 40 | bounds checks dashboard |
| ✅ | quality_gate_metrics_logs | memory_usage | 10/10 | 397.78MiB ≤ 453MiB | 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.91MiB ≤ 76MiB | bounds checks dashboard |
| ✅ | quality_gate_security_idle | cpu_usage | 10/10 | 28.74 ≤ 100 | bounds checks dashboard |
| ✅ | quality_gate_security_idle | memory_usage | 10/10 | 328.15MiB ≤ 335MiB | bounds checks dashboard |
| ✅ | quality_gate_security_mean_fs_load | cpu_usage | 10/10 | 63.57 ≤ 200 | bounds checks dashboard |
| ✅ | quality_gate_security_mean_fs_load | memory_usage | 10/10 | 302.46MiB ≤ 314MiB | bounds checks dashboard |
| ✅ | quality_gate_security_no_fs_load | cpu_usage | 10/10 | 22.69 ≤ 100 | bounds checks dashboard |
| ✅ | quality_gate_security_no_fs_load | memory_usage | 10/10 | 315.94MiB ≤ 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 memory_usage: 10/10 replicas passed. Gate 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_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_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.
- 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_metrics_logs, bounds check total_bytes_received: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check cpu_usage: 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 missed_bytes: 10/10 replicas passed. Gate passed.
- quality_gate_metrics_logs, bounds check intake_connections: 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_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_private_action_runner, bounds check memory_usage: 10/10 replicas passed. Gate passed.
This reverts commit 265b7c2.
What does this PR do?
This PR prevents partial container log fragments from stdout and stderr from being combined into the same logical message.
It propagates normalized stream identity from the CRI and Docker JSON-file parsers, replaces the decoder partial-line parser single accumulator with per-stream state, and gives each stream independent timeout and truncation handling. Parsers without stream identity continue to use the original default accumulator.
Motivation
Fixes #54873.
CRI records contain both a stream and a partial/final flag, but the decoder previously accumulated every partial fragment in one shared buffer. A complete stdout record arriving between two stderr fragments could therefore be included in the stderr message, and the inverse ordering had the same problem. Docker JSON-file logs used the same partial-line path and had the same structural issue.
Describe how you validated your changes
stderr P,stdout F,stderr P,stderr F.agent stream-logsemitted stdout separately and reconstructed both stderr fragments into one logical message. The harness passed again through its reusable--skip-buildpath. The Agent namespace used a private-network-only egress policy and a dummy API key.Checkpointing consideration
The file tailer currently advances its decoded checkpoint by each emitted message's
RawDataLen. That field therefore represents both a logical message's source-byte size and positional progress through the file.Per-stream buffering can make logical emission order differ from source-file order. For example, when a partial stderr CRI record is followed by a complete stdout record, stdout can now be emitted while the earlier stderr record remains buffered. If the Agent terminates abruptly in that window, the checkpoint is calculated from the emitted stdout bytes without their original file position. Depending on record sizes, it can land within either buffered or already-emitted CRI data, so restart may re-read a record, start in the middle of one, or fail to replay the buffered fragment. A graceful decoder shutdown flushes the remaining stream buffers, after which the total byte count is correct.
Eliminating that crash-window risk requires decoupling source-position acknowledgement from
RawDataLen(or holding completed messages until all preceding source ranges are complete). That is a broader file-tailer/decoder pipeline change than the stream-isolation fix and should include restart-at-interleaving-boundary coverage. This PR keepsRawDataLenaccurate for each reconstructed logical message and does not claim to solve that separate checkpoint-ordering problem.