Do Not Read a Whole Day to See Three Minutes

One-line summary

In a log piled up in time order, you can find without reading. If the time notation is unified, string comparison is time comparison, so you can binary search the file by bytes, mark the start position of the interval first, and read only what comes after.

Why this is needed

The request that comes up most often in an outage retrospective is "just show me the 3 minutes of the incident." But what the hand does first is usually grep '03:5[89]' app.log, and that one line reads the entire file from start to end. If the file is several GB for a day, that one run uses up all the disk bandwidth and memory, and the Pod you were trying to analyze stops first. Even the lab Pod has 2Gi of memory and 6Gi of ephemeral disk.

Worse, this method gives wrong answers too. If the interval straddles a rotation boundary, the result of looking only at app.log is half. The front half of the incident has already moved to app.log.1, and what is earlier than that is compressed inside app.log.2.gz. This is where retrospectives that write "nothing happened at that time" after looking at only one file come from.

How it works

There is one premise — the file is in time order and the time notation is unified. Section 5.1 of RFC 3339 states this property. If the components of date and time are placed from less precise to more precise, the time zone is written as the same string everywhere (for example, all Z), and the number of decimal places is the same everywhere, then sorting those strings with C's strcmp gives time order. So comparing two 2026-04-12T03:58:30.000Z strings is the same as comparing two times. You can first check whether this premise holds with -c of sort(1) (it only checks whether it is sorted and does not sort).

If the premise holds, binary search becomes possible. You halve the file size and seek to that byte, read and discard one line since you probably landed in the middle of a line to stand on a line boundary, then compare that line's time with the start of the interval. If smaller, you narrow the range to the back half, and if larger or equal, to the front half. For a 20 MB file it finishes in twenty-some steps.

Two things must be done exactly here. First, take the interval as half-open [시작, 끝) (start inclusive, end exclusive). That way, even if you extract consecutive intervals side by side, the lines on the boundary are not counted twice. Second, when there are several lines with the same time, what binary search must find is the first line of that time. In a service that piles up dozens of lines per second, having several lines in the same millisecond is not an exception but normal, and if you find an arbitrary line and read only what follows, the few lines before it quietly go missing. You must write it to find "the line that first meets the condition," not "any line that meets the condition."

Sort the rotated copies in time order first. In the default numbered scheme, a larger number is further in the past, and the file with no extension is the one currently being written. If you turn on dateext in logrotate(8), the name becomes a date (the default dateformat is -%Y%m%d, and hourly is -%Y%m%d%H), and then a smaller name is further in the past, so the direction is reversed. The same man page pins down that the date format must be lexicographically sortable, and the reason is interesting — logrotate itself sorts the names of the rotated files to find out which file is older. Making name sorting equal time sorting is the same knack inside a file and in a file name.

Only compressed copies are different. A gzip stream is decoded depending on the content before it, so you cannot jump to an arbitrary point. The file object given by Python's gzip module does accept seek, but if you go backward, it rereads the compressed stream from the beginning (if you measure it yourself, you can see the original bytes being read in again). So if you apply binary search to a compressed copy, you end up decompressing the same spot over and over. The answer is simple — sweep once from the front, and stop the moment you pass the end of the interval. The earlier in the file the interval is, the greater this saving.

If it is the JSON Lines format, where one line is a complete record, all of this works as is. That is because a byte range cut by lines is itself a valid document. A single JSON array cannot be cut in the middle.

What you see in the field

If the premise breaks, binary search is quietly wrong. When several processes write to one file, the line order is slightly off, and a collector sometimes appends late-arriving lines at the end. On such a file, binary search does not raise an error but simply drops a few lines. So when you first handle a new file, check whether it is sorted first, and if it is off, either give up on binary search or widen the interval by the size of the disorder.

"It was fast" is not proof. What you must do together when introducing a fast method is to cross-check against the slow method. Sweep the whole thing to extract the same interval, and compare the line count and hash to see that they match. This cross-check needs to be done only once, and without that one time, nobody knows if lines are missing at the boundary.

What you will do in the next lab

You build six hours of logs that have been through rotation, measure the interval each file holds, and line them up from oldest. You do not open at all the files that do not overlap the incident interval, and in the remaining files, you use binary search to mark the start byte and end byte and read only what lies between. The same technique cannot be used on the compressed copy, so you sweep from the front and stop early. Finally, you cross-check against the slow method of sweeping through everything to prove that the results are the same, and leave the method and the grounds as a report.