fix: truncate overly long container log lines from pod logs - #395
Conversation
kubedog now caps a single container log line at 64 KiB when it reads Pod logs from the Kubernetes API, truncating anything longer instead of buffering it without limit, so one oversized line can no longer freeze log tracking. Previously `followContainerLogs` accumulated each log line into a buffer unbounded until it saw a newline, then handed the whole line to the logging pipeline. When a line was very long this broke in one of two ways: - the logging library `logboek` stalls while rendering the huge line; the consumer stops draining the buffered `ContainerLogChunk` channel (capacity 1000), the channel fills up, the blocking send stops the log-stream reader goroutine, and the whole tracking pipeline freezes until the context times out (the hang reported in werf#381 for `nelm release install` output) - a stream that never emits a newline grows the buffer without bound, with no upper limit on memory use The read loop already pulls log data in 64 KiB chunks into a line buffer. This adds a `containerLogLineLengthLimit` of 64 KiB (the size of that read buffer) and enforces it per line: once a line reaches the limit kubedog stops appending bytes but keeps scanning until the newline, so log parsing stays in sync, and a flag carried across chunk reads records that the line was cut. When the line is flushed it gets a short marker before the timestamp/message split, so the marker lands in the message body: ``` [truncated by kubedog: line exceeded 65536 bytes] ``` The line is truncated, not dropped — the visible part is still shown and only the overflow is discarded. Reading with a limit through the Kubernetes API itself does not help here: `PodLogOptions.LimitBytes` caps the total bytes of the whole stream, not the length of an individual line, so it cannot express "trim each line". `followContainerLogs` is the single place every tracker reads container logs — the Job tracker has no log loop of its own and reuses the Pod tracker — so this also covers werf#158, where a long line in a job's pod output hangs job tracking. The underlying problem lives in the logging library (werf/logboek#73); this change is a guard on the kubedog side so a single misbehaving container cannot freeze tracking regardless of the renderer. Verified with `go build ./...`, `go vet` and `golangci-lint` clean, and the read-loop logic checked against a standalone replica across boundary cases: a line exactly at the limit is not marked, one byte over it is, the truncation flag is carried across chunk boundaries, a stream with no newline keeps memory bounded at the limit, a multi-byte rune cut mid-character does not panic, and multiple lines in one chunk are split correctly. Closes werf#381 Refs werf#158 Signed-off-by: Alexey Gorovenko <sharvashinho@gmail.com>
|
I tried to make all of this actually efficient one time and it was harder than I expected, so I didn't finish it. If this small fix fixes the hangs of werf/nelm on really long log lines, then it's good, I'm going to merge it. But can you first manually check if it works, let's say you have a pod and there is a 100 megabyte log line in it, does nelm/werf still hangs on it when trying to display it? |
|
I manually checked the long-line case with nelm. Test setup: a pod emitted a single 100 MB log line, and I compared OLD kubedog without this fix against NEW kubedog with this fix. Results:
So for nelm, the fix works: the pathological memory/output blowup is eliminated. It did not deadlock in my run, but the old behavior was clearly not efficient/safe for a 100 MB log line. I did not run an empirical werf test in this pass because that would require replacing Separate note from testing: standalone There is related historical context in #385, which was closed and later addressed on the werf side via werf/werf#7298. I did not find a separate open kubedog issue specifically for this standalone |
|
Thank you! |
kubedog now caps a single container log line at 64 KiB when it reads Pod logs from the Kubernetes API, truncating anything longer instead of buffering it without limit, so one oversized line can no longer freeze log tracking.
Previously
followContainerLogsaccumulated each log line into a buffer unbounded until it saw a newline, then handed the whole line to the logging pipeline. When a line was very long this broke in one of two ways:logboekstalls while rendering the huge line; the consumer stops draining the bufferedContainerLogChunkchannel (capacity 1000), the channel fills up, the blocking send stops the log-stream reader goroutine, and the whole tracking pipeline freezes until the context times out (the hang reported in Hangs on very long container log lines innelm release installoutput #381 fornelm release installoutput)The read loop already pulls log data in 64 KiB chunks into a line buffer. This adds a
containerLogLineLengthLimitof 64 KiB (the size of that read buffer) and enforces it per line: once a line reaches the limit kubedog stops appending bytes but keeps scanning until the newline, so log parsing stays in sync, and a flag carried across chunk reads records that the line was cut. When the line is flushed it gets a short marker before the timestamp/message split, so the marker lands in the message body:The line is truncated, not dropped - the visible part is still shown and only the overflow is discarded. Reading with a limit through the Kubernetes API itself does not help here:
PodLogOptions.LimitBytescaps the total bytes of the whole stream, not the length of an individual line, so it cannot express "trim each line".followContainerLogsis the single place every tracker reads container logs — the Job tracker has no log loop of its own and reuses the Pod tracker — so this also covers #158, where a long line in a job's pod output hangs job tracking. The underlying problem lives in the logging library (werf/logboek#73); this change is a guard on the kubedog side so a single misbehaving container cannot freeze tracking regardless of the renderer.Verified with
go build ./...,go vetandgolangci-lintclean, and the read-loop logic checked against a standalone replica across boundary cases: a line exactly at the limit is not marked, one byte over it is, the truncation flag is carried across chunk boundaries, a stream with no newline keeps memory bounded at the limit, a multi-byte rune cut mid-character does not panic, and multiple lines in one chunk are split correctly.Closes #381
Refs #158