manager: add structured log message about clock bump

Requested in https://github.com/systemd/systemd/pull/33214#discussion_r1630251308.
Also, reword error messages a bit. When /usr/lib/clock-epoch was introduced,
"build time" stopped being acurate. Just say "epoch" instead.

The same message ID is used in the manager and timesyncd. The event is
essentially equivalent for the user, and it seems reasonable that to search for
both at the same time.

The catalog entry is dropped. It provided almost no additional information above
the message. When the same message ID is now applied to messages from PID1 and
timesyncd, and the clock can be both advanced and rewound, it becomes very hard
to make the catalog entry provide something useful, because catalog entries don't
allow conditionalization.
This commit is contained in:
Zbigniew Jędrzejewski-Szmek 2024-06-12 11:55:14 +02:00
parent 8905490d94
commit e0c7c9a00d
4 changed files with 31 additions and 28 deletions

View File

@ -704,15 +704,6 @@ Support: %SUPPORT_URL%
For the first time during the current boot an NTP synchronization has been
acquired and the local system clock adjustment has been initiated.
-- 7db73c8af0d94eeb822ae04323fe6ab6
Subject: Initial clock bump
Defined-By: systemd
Support: %SUPPORT_URL%
The system clock has been advanced based on a timestamp file on disk, in order
to ensure it remains roughly monotonic even across reboots if an RTC is not
available or is unreliable.
-- 3f7d5ef3e54f4302b4f0b143bb270cab
Subject: TPM PCR Extended
Defined-By: systemd

View File

@ -723,16 +723,6 @@ Support: %SUPPORT_URL%
Po raz pierwszy podczas obecnego uruchomienia uzyskano synchronizację NTP
i zainicjowano regulację lokalnego zegara systemowego.
-- 7db73c8af0d94eeb822ae04323fe6ab6
Subject: Początkowe przestawienie zegara
Defined-By: systemd
Support: %SUPPORT_URL%
Przestawiono zegar systemowy na podstawie pliku ze znacznikiem czasu na dysku
w celu zapewnienia, że nadal jest w przybliżeniu monotoniczny — nawet między
ponownymi uruchomieniami — jeśli zegar czasu rzeczywistego jest niedostępny
lub zawodny.
-- 3f7d5ef3e54f4302b4f0b143bb270cab
Subject: Rozszerzono PCR układu TPM
Defined-By: systemd

View File

@ -3,6 +3,8 @@
#include <sys/stat.h>
#include <sys/time.h>
#include "sd-messages.h"
#include "clock-util.h"
#include "clock-warp.h"
#include "errno-util.h"
@ -55,14 +57,33 @@ void clock_apply_epoch(bool allow_backwards) {
return; /* Nothing to do. */
r = RET_NERRNO(clock_settime(CLOCK_REALTIME, TIMESPEC_STORE(epoch_usec)));
if (r < 0 && advance)
return (void) log_error_errno(r, "Current system time is before build time, but cannot correct: %m");
else if (r < 0)
return (void) log_error_errno(r, "Current system time is further ahead than %s after build time, but cannot correct: %m",
FORMAT_TIMESPAN(CLOCK_VALID_RANGE_USEC_MAX, USEC_PER_DAY));
else if (advance)
log_info("System time was before build time, advanced clock.");
if (r < 0) {
if (advance)
return (void) log_error_errno(r, "Current system time is before epoch, but cannot correct: %m");
else
return (void) log_error_errno(r, "Current system time is further ahead than %s after epoch, but cannot correct: %m",
FORMAT_TIMESPAN(CLOCK_VALID_RANGE_USEC_MAX, USEC_PER_DAY));
}
const char *from =
epoch_usec == (usec_t) TIME_EPOCH * USEC_PER_SEC ? "built-in epoch" :
epoch_usec == timesyncd_usec ? "timestamp on "TIMESYNCD_CLOCK_FILE :
"timestamp on "EPOCH_CLOCK_FILE;
if (advance)
log_struct(LOG_INFO,
"MESSAGE_ID=" SD_MESSAGE_TIME_BUMP_STR,
"REALTIME_USEC=" USEC_FMT, epoch_usec,
"DIRECTION=forwards",
LOG_MESSAGE("System time advanced to %s: %s",
from,
FORMAT_TIMESTAMP(epoch_usec)));
else
log_info("System time was further ahead than %s after build time, reset clock to build time.",
FORMAT_TIMESPAN(CLOCK_VALID_RANGE_USEC_MAX, USEC_PER_DAY));
log_struct(LOG_INFO,
"MESSAGE_ID=" SD_MESSAGE_TIME_BUMP_STR,
"REALTIME_USEC=" USEC_FMT, epoch_usec,
"DIRECTION=backwards",
LOG_MESSAGE("System time was further ahead than %s after %s, clock reset to %s",
FORMAT_TIMESPAN(CLOCK_VALID_RANGE_USEC_MAX, USEC_PER_DAY),
from,
FORMAT_TIMESTAMP(epoch_usec)));
}

View File

@ -126,6 +126,7 @@ static int load_clock_timestamp(uid_t uid, gid_t gid) {
log_struct(LOG_INFO,
"MESSAGE_ID=" SD_MESSAGE_TIME_BUMP_STR,
"REALTIME_USEC=" USEC_FMT, epoch + 1,
"DIRECTION=forwards",
LOG_MESSAGE("System clock time advanced to %s: %s",
epoch > TIME_EPOCH * USEC_PER_SEC ? "recorded timestamp" : "built-in epoch",
FORMAT_TIMESTAMP(epoch + 1)));