Timestamp errado no log do systemd

Question

Eu li o log do systemd do meu servidor doméstico usando o journalctl e notei que o timestamp do log está totalmente fora de ordem.

Aqui estão alguns logs do meu servidor usando journalctl -o=short-iso --since=yesterday :

2015-06-17T06:00:22+0900 alarm smbd[463]: [2015/06/17 06:00:22.911093,  0] ../source3/printing/print_standard.c:69(std_pcap_cache_reload)
2015-06-17T06:00:22+0900 alarm smbd[463]: Unable to open printcap file /etc/printcap for read!
2015-06-17T06:13:23+0900 alarm smbd[463]: [2015/06/17 06:13:23.161572,  0] ../source3/printing/print_standard.c:69(std_pcap_cache_reload)
2015-06-17T06:13:23+0900 alarm smbd[463]: Unable to open printcap file /etc/printcap for read!
-- Reboot --
1970-01-01T09:00:06+0900 alarm systemd-journal[179]: Runtime journal is using 8.0M (max allowed 87.5M, trying to leave 131.2M free of 867.2M available <E2><86><92> current limit 87.5M).
-- Reboot --
1970-01-01T09:00:06+0900 alarm systemd-journal[177]: Permanent journal is using 336.0M (max allowed 2.9G, trying to leave 420.5M free of 25.2G available <E2><86><92> current limit 2.9G).
1970-01-01T09:00:06+0900 alarm systemd-journal[177]: Time spent on flushing to /var is 5.440ms for 2 entries.
1970-01-01T09:00:06+0900 alarm kernel: Booting Linux on physical CPU 0x0
1970-01-01T09:00:06+0900 alarm kernel: Initializing cgroup subsys cpuset

....

1970-01-01T09:00:21+0900 alarm systemd[1]: Started Update is Completed.
1970-01-01T09:00:21+0900 alarm systemd[1]: Started Create Volatile Files and Directories.
1970-01-01T09:00:21+0900 alarm systemd[1]: Starting Network Time Synchronization...
1970-01-01T09:00:21+0900 alarm systemd[1]: Starting Update UTMP about System Boot/Shutdown...
-- Reboot --
1970-01-01T09:00:05+0900 alarm systemd-timesyncd[187]: System clock time unset or jumped backwards, restoring from recorded timestamp: Thu 2014-07-03 18:46:22 UTC
2014-07-04T03:46:22+0900 alarm systemd[1]: Time has been changed
2014-07-04T03:46:22+0900 alarm systemd[1]: Started Network Time Synchronization.
2014-07-04T03:46:22+0900 alarm systemd[1]: Starting System Time Synchronized.
2014-07-04T03:46:22+0900 alarm systemd[1]: Reached target System Time Synchronized.

...

2014-07-04T03:50:45+0900 alarm dhcpcd[324]: eth0: adding default route via 192.168.0.1
2014-07-04T03:50:45+0900 alarm systemd-timesyncd[187]: Network configuration changed, trying to establish connection.
2014-07-04T03:50:45+0900 alarm systemd-timesyncd[187]: Network configuration changed, trying to establish connection.
2014-07-04T03:50:46+0900 alarm systemd-timesyncd[187]: Using NTP server 216.239.32.15:123 (time4.google.com).
2014-08-30T12:21:54+0900 alarm systemd[255]: Time has been changed
2014-08-30T12:21:54+0900 alarm systemd-timesyncd[187]: interval/delta/delay/jitter/drift 32s/+4955468.150s/0.322s/0.000s/+0ppm
2014-08-30T12:21:54+0900 alarm systemd[1]: Time has been changed
2014-08-30T12:21:54+0900 alarm systemd[1]: Starting Verify integrity of password and group files...

...

2014-08-30T14:12:57+0900 alarm systemd-timesyncd[185]: Network configuration changed, trying to establish connection.
2014-08-30T14:12:57+0900 alarm systemd-timesyncd[185]: Network configuration changed, trying to establish connection.
2014-08-30T14:13:27+0900 alarm systemd-timesyncd[185]: Using NTP server 216.239.36.15:123 (time3.google.com).
2014-09-05T20:47:48+0900 alarm systemd[1]: Time has been changed
2014-09-05T20:47:48+0900 alarm systemd-timesyncd[185]: interval/delta/delay/jitter/drift 32s/+542061.386s/0.335s/0.000s/+0ppm
2014-09-05T20:48:21+0900 alarm systemd-timesyncd[185]: interval/delta/delay/jitter/drift 64s/+0.002s/0.338s/0.001s/+0ppm
2014-09-05T20:49:35+0900 alarm systemd-timesyncd[185]: Timed out waiting for reply from 216.239.36.15:123 (time3.google.com).

....

2014-09-06T22:48:10+0900 alarm systemd[1]: Starting Shutdown.
2014-09-06T22:48:10+0900 alarm systemd[1]: Reached target Shutdown.
2014-09-06T22:48:10+0900 alarm systemd[1]: Starting Final Step.
2014-09-06T22:48:10+0900 alarm systemd[1]: Reached target Final Step.
2014-09-06T22:48:10+0900 alarm systemd[1]: Starting Power-Off...
2014-09-06T22:48:10+0900 alarm systemd[1]: Shutting down.
2014-09-06T22:48:10+0900 alarm systemd-shutdown[1]: Sending SIGTERM to remaining processes...
2014-09-06T22:48:10+0900 alarm systemd-journal[167]: Journal stopped
-- Reboot --
1970-01-01T09:00:04+0900 alarm systemd-journal[169]: Runtime journal is using 8.0M (max allowed 87.5M, trying to leave 131.2M free of 867.2M available <E2><86><92> current limit 87.5M).
1970-01-01T09:00:04+0900 alarm systemd-journal[169]: Runtime journal is using 8.0M (max allowed 87.5M, trying to leave 131.2M free of 867.2M available <E2><86><92> current limit 87.5M).
1970-01-01T09:00:04+0900 alarm kernel: Booting Linux on physical CPU 0x0

...

Como você pode ver, há muitas descontinuações e retorno e retrocesso do timestamp. Isso é apenas um trecho e há muito mais pontos.

Eu verifiquei meu horário, mas não consegui encontrar nada de errado:

$ timedatectl status
      Local time: Thu 2015-06-18 16:46:44 KST
  Universal time: Thu 2015-06-18 07:46:44 UTC
        RTC time: Thu 2015-06-18 07:46:44
       Time zone: Asia/Seoul (KST, +0900)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: no
      DST active: n/a

Como posso consertar essa bagunça?

Meu ambiente:

• Dispositivo: Wandboard Quad (é um computador de placa única)
• SO: Arch Linux ARM

Answer 1

Parece-me que o relógio do seu sistema não está funcionando, provavelmente porque a bateria não está funcionando ou não está fornecendo corrente suficiente para manter o relógio funcionando durante a reinicialização. (Se o chip do relógio estiver ruim, você deve receber um erro diferente, o ntpd deve notar).

É por isso que você reinicia em 1970 quando a "era Unix" é iniciada.

Quando ntpd começa, ouve do resto do mundo que o relógio não estava funcionando e define o horário & data em conformidade

1970-01-01T09:00:21+0900 alarm systemd[1]: Starting Network Time Synchronization...
1970-01-01T09:00:21+0900 alarm systemd[1]: Starting Update UTMP about System Boot/Shutdown...
-- Reboot --
1970-01-01T09:00:05+0900 alarm systemd-timesyncd[187]: System clock time unset or jumped backwards, restoring from recorded timestamp: Thu 2014-07-03 18:46:22 UTC

Você deve ser capaz de salvar a data no desligamento e pelo menos continuar com esse valor em vez de 1970, mas é melhor substituir a bateria do relógio.