Skip to content

fix: port upstream log fixes, JSON log attributes and trace context (B7 of #369) - #380

Merged
mayankpande88 merged 9 commits into
mainfrom
port/upstream-b7-logs
Oct 9, 2026
Merged

mayankpande88 merged 9 commits into
mainfrom
port/upstream-b7-logs

Conversation

@mayankpande88

@mayankpande88 mayankpande88 commented Oct 8, 2026 •

Copy link
Copy Markdown
Contributor

Summary

B7 of #369: the log fixes from upstream coroot-node-agent, on top of nudgebee/logparser#34, which merges coroot/logparser v1.4.2 into our logparser fork. Merge nudgebee/logparser#34 first, with a merge commit. go.mod here pins its head commit.

Upstream Change
coroot/coroot-node-agent@e1cd714 JSON logs are exported over OTLP with their message as the body, their level as the severity and the other fields as attributes. --disable-json-log-parsing turns this off.
coroot/coroot-node-agent@18cfe3c A trace_id/span_id field in a JSON log sets the OTLP record's trace context.
coroot/coroot-node-agent@cd65ce5 A container log file that doesn't exist yet is retried instead of failing.
coroot/coroot-node-agent@ab9b049 --log-pattern-extraction-limit: a per-container cap on pattern extraction under log storms. Default 0 (off) here; upstream uses 100/s.
coroot/coroot-node-agent@e4be150 When the fd of a just-opened /var/log file is already gone (freopen), the process's open log files are found from /proc/<pid>/fd.

All five are by Nikolay Sivko.

What changes by default:

  • JSON logs: the OTLP log body for a JSON line is now its message, with the other fields as attributes and the trace context set. OTLP log export is off by default (--logs-endpoint unset), so this only affects installs that send logs.
  • Pattern metrics: container_log_messages_total keeps the same pattern hashes.
Engineering detail

Why the extraction limit defaults to 0:

  • Measured: in a storm of about 59,000 error lines in 30s, 100/s saved 139 ms of agent CPU (about 4.6 millicores).
  • Cost: 55,070 of those messages were counted under the "event was sampled" pattern, so the storm's own pattern showed about 4,000.
  • Conclusion: pattern extraction is cheap here, and pattern spikes are what matters, so the flag stays for installs that need the cap.

Over the limit: the logparser sync emits over-limit messages instead of dropping them (see nudgebee/logparser#34).

Conflicts with this fork:

  • Logparser import: this fork imports github.com/nudgebee/logparser (upstream imports github.com/coroot/logparser), so upstream's go.mod bumps are replaced by the sync commit.
  • NewParser keeps this fork's SensitiveConfig.
  • logs.Init, flag style and the fd-closing paths in TailReader are kept.
  • The freopen fallback sits behind --enable-dynamic-log-tailing, which still gates tailing of files a process opens.
  • windows/ isn't part of this fork.
  • Test: common/log_parser_test.go is updated for the new NewParser signature.

From review (e345645):

CI: gofmt, goimports, vet, golangci-lint, go test (excluding /containers) and the build all pass in a Linux container with Go 1.26.5.

Local e2e: I built agent binaries from this branch and from main and ran them as systemd services on a local Debian 12 VM (kernel 6.1), exporting logs over OTLP to a local OpenTelemetry collector.

  • JSON log line ({"level":"error","msg":"payment failed","order_id":...,"trace_id":...,"span_id":...}): this branch sent body payment failed, severity error, attribute order_id, and the trace and span IDs. Main sent the raw JSON line, with no trace context.
  • Pattern hash: the same in both builds.
  • Error-line storm through /var/log tailing (about 59,000 lines in 30s, same binary): with no limit, the agent used 1109 ms of CPU and counted 59,200 messages under one pattern. With a limit of 100/s, it used 970 ms and counted 59,000 messages, 55,070 of them under the sampled pattern.
  • Re-run on the current logparser pin (single JSON decode, CRLF): JSON lines arrived with their order_id attributes. JSON lines ending in \r\n arrived with body crlf line and their n attribute.

def and others added 7 commits October 9, 2026 01:05
(cherry picked from commit e1cd714d00d10de91b4596835cdc8d962d83a215)

Conflicts: this fork imports github.com/nudgebee/logparser, which is
bumped to the commit that merges coroot/logparser v1.4.2 (JSON parser,
pattern rate limit). NewParser keeps this fork's SensitiveConfig argument;
the rate limiter is nil until the next port. windows/ is not part of
this fork.
(cherry picked from commit 18cfe3ce6740e741a10b4d5a0a791ee114474549)
(cherry picked from commit cd65ce5581bc73e989a8941e3a86c47d710349de)

Conflict: this fork closes the file when Stat or Seek fails; kept.
(cherry picked from commit ab9b04971fbe16977cc224fc574c5b7622dbd3c8)

Conflicts: kept this fork's logs.Init, flag style and SensitiveConfig
argument. With the logparser sync, an over-limit message is still
exported (under the sampled pattern); only extraction is skipped.
… bump logparser to v1.4.2

(cherry picked from commit e4be15099c51ac92116a3a231b8775d54c1a2eba)

In this fork, tailing log files a process opens stays behind
--enable-dynamic-log-tailing; the freopen fallback is inside that gate.
The logparser bump is the nudgebee/logparser sync from the first commit.
In a storm of about 59,000 error lines in 30s, a limit of 100/s saved
139 ms of agent CPU (about 4.6 millicores), but counted 55,070 of the
messages under the 'event was sampled' pattern: the storm's own pattern
showed about 4,000. Pattern extraction is cheap here, and log pattern
spikes are what incident detection looks at. Keep the flag for installs
that need the cap.

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces several enhancements to log parsing and tailing. Key changes include extracting trace and span IDs from log attributes to associate them with OpenTelemetry log records, implementing a rate limiter for log pattern extraction, and allowing the tail reader to start even if the target log file does not exist yet by polling until it is created. Additionally, it adds a flag to disable JSON log parsing and introduces a mechanism to find log files held by a process when a file descriptor is redirected. Feedback on these changes highlights two issues: first, the rate limiter burst size can evaluate to zero and reject all events if the extraction limit is set below 0.1; second, findLogFiles may return duplicate log paths if a process has multiple file descriptors open for the same file, which can be resolved by deduplicating the results.

Comment thread logs/otel.go
Comment thread containers/container.go
…parser

With a limit below 0.1/s, int(limit*10) was 0 and a zero-burst limiter
rejects every event, so pattern extraction stopped entirely. Also pin
nudgebee/logparser to the commit that decodes a JSON line once and
accepts CRLF line endings.
@blue4209211

Copy link
Copy Markdown
Contributor

LGTM. One note on masking first: there's no regression. The fork's SensitiveConfig only detects and counts sensitive data; it never redacted the OTLP body, which was the raw line on main. So the new attributes carry nothing that wasn't already exported, and detection still scans the full line. A few things for a later pass:

  1. A JSON field can duplicate or spoof pattern.hash (logs/otel.go:116, logRecordAttrs). The agent's pattern.hash is appended first, then every JSON field, so {"pattern.hash":"x"} yields two pattern.hash keys. OTLP expects unique keys, and a backend that keeps the last one loses the agent's hash. Skip, or prefix, user keys that collide with keys the agent sets.
  2. The freopen fallback runs on the event loop with no throttle (containers/container.go ~713, findLogFiles). This is behind --enable-dynamic-log-tailing, so it's off by default. When enabled, processes that open and close a /var/log file on every write (PHP error_log, shell >>) trigger a full /proc/<pid>/fd readdir plus readlinks on every write, synchronously in the registry loop. A per-pid cooldown would bound it. The path filtering is tight, so it can't tail arbitrary files, sockets or pipes.
  3. Missing log files are retried forever, silently (logs/tail_reader.go). There's no leak, but a wrong log path now produces an idle poller and no warning. Log once (Info) when a reader starts in the waiting-for-file state.
  4. Minor:
    • Records over the rate limit are exported with the "event was sampled" hash, so they lose their real pattern.
    • The limiter is created per NewParser, so per log source, not per container as the flag text says.
    • A 16-digit decimal dd.span_id would be read as hex.
    • A span id with no trace id is still set.
    • JSON with no message key is exported twice: the full line as the body and every field as attributes.

@mayankpande88
mayankpande88 merged commit ac46657 into main Oct 9, 2026
7 checks passed
@mayankpande88
mayankpande88 deleted the port/upstream-b7-logs branch October 9, 2026 08:45
mayankpande88 added a commit that referenced this pull request Oct 9, 2026
…cimal, throttle the freopen scan

From the #380 review:
- A JSON field named pattern.hash no longer duplicates or replaces the
  agent's attribute.
- dd.span_id is decimal (Datadog's log injection); a 16-digit value was
  read as hex. A span id without a trace id stays an attribute.
- The freopen fallback reads a process's fds at most every 10s: a process
  that opens its /var/log file for every write triggered it on every write.
- A tail reader waiting for its file to appear logs that once.
- The pattern extraction limit is per log source, not per container: say so.
mayankpande88 added a commit that referenced this pull request Oct 10, 2026
…cimal, throttle the freopen scan (#390)

* fix(logs): keep the agent's pattern.hash, read Datadog span ids as decimal, throttle the freopen scan

From the #380 review:
- A JSON field named pattern.hash no longer duplicates or replaces the
  agent's attribute.
- dd.span_id is decimal (Datadog's log injection); a 16-digit value was
  read as hex. A span id without a trace id stays an attribute.
- The freopen fallback reads a process's fds at most every 10s: a process
  that opens its /var/log file for every write triggered it on every write.
- A tail reader waiting for its file to appear logs that once.
- The pattern extraction limit is per log source, not per container: say so.

* fix(logs): read Datadog's decimal dd.trace_id as the lower half of the trace id

Datadog's log injection writes 64-bit trace ids in decimal. They were not
parsed, so with this branch's decimal span ids a record still got no trace
context: a span id without a trace id stays an attribute (#390 review).

---------

Co-authored-by: Shiv <3078106+blue4209211@users.noreply.github.com>
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