What is causing gaps in logs?

Question

I am examining the log of my program, which runs on a Raspbian 9, on an SD card. The program is started and managed by systemd, and the logs are handled by journald.

Occasionally the log contains gaps, such as the one highlighted below:

You can see that a period of almost 24h is not reflected in the log. However, the logic of the software is to log a line once every few minutes, reflecting its current state.

I am also sure that it is not a gap caused by a power outage, because if that were the case, then the first lines on August 27th would have been "start" markers that the program writes when it initializes itself and the periphery it interacts with.

Besides that, my understanding is that journald shows a ----Reboot---- line in the log if the system was booted - I don't see that marker either. Note that persistent logging is enabled and I do see the marker in other spots, where a reboot was expected.

In other words, it seems like those log lines were cut out.

How can such anomalies be explained?

Answer 1

The time gap can be explained because the Raspberry Pi does not have a realtime clock built-in. Raspbian takes effort to make the gap as small as possible and don't always start with 1970-01-01. It stores the date/time from the last shutdown and starts with it. So you will first see this date until the synchronization to the (internet) timeserver is finished. Then the time will jump to the current date/time.

With the journal you do not see the ----Reboot---- delimiter because the journal isn't persistent by default. It is only stored in tmpfs so it will be lost on reboot. There are simply no logs before the last boot that can be delimited by the marker. Raspbian don't log the journal persistent because of storage space consumption. If you want the journal to be persistent then do it with:

rpi ~$ sudo mkdir -p /var/log/journal
rpi ~$ sudo systemd-tmpfiles --create --prefix /var/log/journal

If you enable persistent logging, consider uninstalling rsyslog or any other system-log-daemon, to avoid logging everything twice. With rsyslog running you have the old style log files still available, that are mainly most files in /var/log. For example you will find the same information with journalctl and in /var/log/syslog. And as usual you can configure programs to use rsyslog to log into separate log files.

Answer 2

Another possible reason for a gap in logs is if the disk fills up, so that further logs are generated but can't be written.

(I doubt that's the cause here, though, and I don't know how journald handles it.  I merely mention it for the benefit of anyone else asking this question!  But I've seen it happen on a non-systemd-based machine.  One symptom is that the last line before the gap can get cut off part-way through, without a newline, so that the next line gets appended to it.)