Never Arrived Is Not the Same as Never Happened

One-line summary

When a log is empty, what separates "it did not arrive" from "nothing happened" is not time but the number the sender attached. Without a number, loss is never proven, and even with a number, it lies in the face of a restart.

Why this is needed

The moment we look at the logs piled up in the collector and say "there were no requests in these 5 minutes," we have said something we cannot prove. There may have been no requests, or there may have been requests and their lines vanished on the way. The two have opposite conclusions, yet you cannot tell them apart from the file alone.

RFC 5424 writes this very clearly in section 8.5. The syslog protocol has no mechanism to guarantee delivery, and the underlying transport (such as UDP) is unreliable too, so some messages can simply vanish. And the same section adds a more uncomfortable point — reliable delivery is not always desirable either. The sender must block when the receiver can no longer accept more, but on Unix, syslogd is a high-priority system process, so if it blocks, the whole system stops. So realistic implementations, instead of blocking, deliberately discard but report that they discarded. That is said to be better than vanishing with no indication.

Size is also a reason. Section 6.1 of the same document writes that a transport receiver only needs to support at least 480 octets and may truncate or discard messages exceeding 2048 octets. That is why section 8.3 recommends putting important information at the front of the message. The back can be cut off.

How it works

The only way to count loss is a monotonically increasing number from the sender. If the sender attaches a seq and periodically reports how far it has sent, subtracting the set of received numbers from the sent range alone yields what is missing. It is even more useful to group them into ranges — scattered single-record losses and 50 records dropped as one lump have different causes.

But numbers go back at a restart. When a process comes back up, seq starts again from 1. So if you judge the same line by number alone, two things collapse at once. The same number before and after the restart looks like a duplicate, and a number missing after the restart is hidden by the pre-restart record and looks like not a loss. There is one solution — bind a boot identifier to the number. That is also why the systemd journal leaves _BOOT_ID.

The same line arriving twice is normal. If a sender that did not receive a response sends again, the receiver gets the same line twice (at-least-once). What is needed then is a definition of "what to treat as the same line." If you have (host, boot identifier, number), that is the answer, and if not, you have to use a fingerprint of the content, but then even two truly identical events get folded into one.

The order received is not the order that happened. If the collection path is blocked, lines arrive minutes later. This is why the OpenTelemetry log data model splits the time field in two. Timestamp is the time the event occurred, measured by the original clock, and ObservedTimestamp is the time the collection system observed that event. When converting to a format that can hold only one time, the specification recommends using "Timestamp if present, otherwise ObservedTimestamp." The difference between the two is the arrival delay, and looking at its distribution shows the health of the collection path.

What you see in the field

The cutoff time changes the number. If you count "how many errors were there yesterday" right after midnight, lines that have not yet arrived are missing. If you run the same query a few days later, the number grows. It is not a bug but late arrival. So aggregation needs a cutoff allowance (late window), and that allowance is set by looking at the p95 or p99 of the delay distribution.

There are lines that do not arrive even if you extend retention. RateLimitIntervalSec= and RateLimitBurst= of journald.conf(5) discard the rest of an interval if one service writes more than a set number within a set interval. The default is 10000 per 30 seconds, applied per service, and a message reporting the number discarded is left. It is at the very moment logs flood during an outage that the most get discarded.

The loss rate differs by interval. A number like 6 percent overall is usually useless. What matters is in which 5 minutes 50 records dropped out as a whole, and whether that interval overlaps the incident interval changes the conclusion.

What you will do in the next lab

You build the file the collector received and the sender's counters together, and count loss by comparing the two. You group the missing numbers into ranges, fold the duplicates created by at-least-once, and work out the distribution of arrival delay. Then you calculate how many you would have missed if you had aggregated at the cutoff time, and finally show in numbers how loss and duplicates swap places if you ignore the boot identifier on a host whose numbers went back because of a restart.