Every log line over sixteen kilobytes arrived in pieces and none of them counted as an error

In September a trade customer told us that eleven of his bulk order imports had failed over two weeks. Our import error alert, which counts error level logs from the import service, had not fired once. The service had logged every one of those failures.

The import service writes one JSON object per line to stdout, and a failed import logs a single error with the validation result for every line of the file. For an ordinary order that is a few hundred bytes. For this customer's files, with two thousand lines each, it was between forty and ninety kilobytes in one line.

The container runtime does not keep a long line whole. containerd writes container output to the node's log file in chunks of at most sixteen kilobytes by default, and marks every chunk except the last as partial. Docker does the same. A log agent is expected to join the pieces back together, and Fluent Bit can, but only if its tail input has the cri multiline parser enabled. Ours did not, because our config predated the move from Docker to containerd and nobody had looked at it since. Each piece reached our pipeline on its own, failed to parse as JSON, and went to a fallback index as plain text with no level field. The error count never saw it.

So the errors we lost were precisely the ones with the most information in them, from the customers with the biggest orders.

We enabled the cri multiline parser and replayed two weeks of node logs we still had. The fallback index turned out to hold nine thousand error records, mostly from imports and from two services that log full stack traces with large request bodies. Our services now cap a log line at eight kilobytes; anything larger, such as the validation result, is written to object storage, and the log line carries its key. The pipeline exports a count of records that failed to parse, per service, and that number has an alert above zero. And the log agent's configuration has a test that sends a hundred kilobyte line through a real node and checks that one record arrives.

A log line has a size limit you never chose, set by whatever sits between your process and your search box. Ours cut the biggest errors into pieces that no longer looked like errors.

– Sergey Shinder