verifyfirst

Logs and stdout · interleaved-past-the-atomic-limit · documented

Records longer than a pipe's atomic limit are spliced into one another

NS-088 documentedinterleaved-past-the-atomic-limit

Records longer than a pipe's atomic limit are spliced into one another

reads as
`grep 'request_id=abc123' app.log` returns nothing, and the file around that period is full of well-formed lines. Conclusion drawn: that request never reached this service.
actually
pipe(7): POSIX.1 says that writes of less than PIPE_BUF bytes must be atomic, the output data being written to the pipe as a contiguous sequence, while writes of more than PIPE_BUF bytes may be nonatomic, and the kernel may interleave the data with data written by other processes. On Linux PIPE_BUF is 4096 bytes. Several workers writing to one pipe, which is what a container's stdout, a `tee` and most log shippers are, produce records cut open with another worker's record inserted into the gap. The result still ends in a newline, so it is still a line.
blind because
A log reader sees lines, and a spliced line is a line: it has a beginning, an end and plausible contents. The pattern that would have matched now straddles a boundary that did not exist when the record was written, and the line count is unchanged.
the check
Validate each line against the format the writer emits and count the failures, rather than counting lines. Observed on Linux 6.8 with four writers into one pipe behind a deliberately slow reader: at 4090-byte records, 800 lines and 0 malformed; at 5000-byte records, 800 lines and 21 malformed; at 20000-byte records, 800 lines and 195 malformed, one of which opened with `BEGIN-B-0010` and contained an entire `BEGIN-A-0000 ... END-A-0000` record inside it. The line count was 800 in every run.
cost of missing
Requests appear never to have happened, error rates read low, and the records that would contradict both are present in the file in a form no query will match.
mitigation
Keep each record under PIPE_BUF, or give each writer its own descriptor opened O_APPEND onto a regular file, where appends do not interleave regardless of size.
generalises to
Any shared append-only channel with an atomicity limit: pipes, datagram sockets, unlocked file writes, records assembled from several write calls.
source
man7.org

Reported as

Others this instrument misses

plain text · full registry