저는 홈 서버의 시스템 로그를 읽곤 했는데 journalctl
로그의 타임스탬프가 완전히 잘못된 것을 발견했습니다.
내 서버의 일부 로그는 다음과 같습니다 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
...
보시다시피, 타임스탬프 중단과 앞뒤로 이동이 많이 있습니다. 이것은 단지 단편일 뿐이며 이와 같은 점이 더 많이 있습니다.
시간 설정을 확인했는데 잘못된 점을 찾지 못했습니다.
$ 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
이 혼란을 어떻게 해결합니까?
내 환경:
- 장비:네 개의 지팡이 판(단일 보드 컴퓨터입니다)
- 운영 체제: 아치 리눅스 ARM
답변1
제가 보기에는 시스템 시계가 제대로 작동하지 않는 것 같습니다. 아마도 배터리가 재부팅 중에 시계를 계속 작동할 만큼 충분한 전류를 제공하지 않거나 더 이상 제공하지 않기 때문일 것입니다. (클럭 칩이 불량한 경우 다른 오류가 발생하고 ntpd가 이를 인지해야 합니다).
그래서 '유닉스 시대'가 시작된 1970년에 리부트를 하신 겁니다.
시작 되면 ntpd
전 세계에서 시계가 작동하지 않는다는 소식을 듣고 이에 따라 시간과 날짜를 설정합니다.
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
종료 시 날짜를 저장하고 적어도 1970년 대신 해당 값을 계속 사용할 수 있어야 하지만 시계 배터리를 교체하는 것이 더 좋습니다.