timesyncd: write structured log messages whenever we bump the clock based on disk...

It's useful being able to easily detect if a disk-based clock bump was
done, let's make it a structure message, the same way as acquiring an
NTP fix already is.

Also, set the clock to 1 µs further than the timestamp from the disk,
after all we know that that timestamp was current when it was written,
hence it can't be the right one right now anymore.

diff --git a/catalog/systemd.catalog.in b/catalog/systemd.catalog.in
index 8d1812afcf104a5762cf65ab28bfaa6096609969..975e77fcec1112db63af7946c48a97d0b655d19f 100644 (file)
--- a/catalog/systemd.catalog.in
+++ b/catalog/systemd.catalog.in
@@ -528,6 +528,15 @@ 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

diff --git a/src/systemd/sd-messages.h b/src/systemd/sd-messages.h
index 51241c942602dbe868b7b51065c5e9acd20465a7..00fdbad2c56e91112977b17742fe2c83adf25b05 100644 (file)
--- a/src/systemd/sd-messages.h
+++ b/src/systemd/sd-messages.h
@@ -183,6 +183,9 @@ _SD_BEGIN_DECLARATIONS;
 #define SD_MESSAGE_TIME_SYNC                          SD_ID128_MAKE(7c,8a,41,f3,7b,76,49,41,a0,e1,78,0b,1b,e2,f0,37)
 #define SD_MESSAGE_TIME_SYNC_STR                      SD_ID128_MAKE_STR(7c,8a,41,f3,7b,76,49,41,a0,e1,78,0b,1b,e2,f0,37)
 
+#define SD_MESSAGE_TIME_BUMP                          SD_ID128_MAKE(7d,b7,3c,8a,f0,d9,4e,eb,82,2a,e0,43,23,fe,6a,b6)
+#define SD_MESSAGE_TIME_BUMP_STR                      SD_ID128_MAKE_STR(7d,b7,3c,8a,f0,d9,4e,eb,82,2a,e0,43,23,fe,6a,b6)
+
 #define SD_MESSAGE_SHUTDOWN_SCHEDULED                 SD_ID128_MAKE(9e,70,66,27,9d,c8,40,3d,a7,9c,e4,b1,a6,90,64,b2)
 #define SD_MESSAGE_SHUTDOWN_SCHEDULED_STR             SD_ID128_MAKE_STR(9e,70,66,27,9d,c8,40,3d,a7,9c,e4,b1,a6,90,64,b2)
 

diff --git a/src/timesync/timesyncd.c b/src/timesync/timesyncd.c
index 887b323d96a5373f0c0f770df993a765598f5184..709c64375eb928e713f75f39243ec00ee4788766 100644 (file)
--- a/src/timesync/timesyncd.c
+++ b/src/timesync/timesyncd.c
@@ -5,6 +5,7 @@
 
 #include "sd-daemon.h"
 #include "sd-event.h"
+#include "sd-messages.h"
 
 #include "capability-util.h"
 #include "clock-util.h"
@@ -69,16 +70,22 @@ static int load_clock_timestamp(uid_t uid, gid_t gid) {
 
 settime:
         ct = now(CLOCK_REALTIME);
-        if (ct < min) {
-                char date[FORMAT_TIMESTAMP_MAX];
-
-                log_info("System clock time unset or jumped backwards, restoring from recorded timestamp: %s",
-                         format_timestamp(date, sizeof(date), min));
-
-                if (clock_settime(CLOCK_REALTIME, TIMESPEC_STORE(min)) < 0)
-                        log_error_errno(errno, "Failed to restore system clock, ignoring: %m");
+        if (ct > min)
+                return 0;
+
+        /* Not that it matters much, but we actually restore the clock to n+1 here rather than n, simply
+         * because we read n as time previously already and we want to progress here, i.e. not report the
+         * same time again. */
+        if (clock_settime(CLOCK_REALTIME, TIMESPEC_STORE(min+1)) < 0) {
+                log_warning_errno(errno, "Failed to restore system clock, ignoring: %m");
+                return 0;
         }
 
+        log_struct(LOG_INFO,
+                   "MESSAGE_ID=" SD_MESSAGE_TIME_BUMP_STR,
+                   "REALTIME_USEC=" USEC_FMT, min+1,
+                   LOG_MESSAGE("System clock time unset or jumped backwards, restored from recorded timestamp: %s",
+                               FORMAT_TIMESTAMP(min+1)));
         return 0;
 }