On 30. Aug 2024, at 19.00, dco2024--- via dovecot <dovecot@dovecot.org> wrote:
>
> This is not limited to FreeBSD. I'm seeing it on Gentoo Linux. Kernel is
> 6.6.47-gentoo-x86_64, dovecot 2.3.21.1 (d492236fa0). The warning is logged
> once every 12-15 hours.
>
> Syslog:
> 2024-08-24 18:03:49 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100068 seconds - adjusting timeouts.
> 2024-08-25 06:18:49 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100063 seconds - adjusting timeouts.
> 2024-08-26 06:52:16 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100062 seconds - adjusting timeouts.
> 2024-08-26 18:57:54 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100068 seconds - adjusting timeouts.
> 2024-08-27 07:24:34 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100061 seconds - adjusting timeouts.
> 2024-08-27 19:38:48 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100060 seconds - adjusting timeouts.
> 2024-08-28 20:21:44 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100071 seconds - adjusting timeouts.
> 2024-08-29 08:41:44 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100070 seconds - adjusting timeouts.
> 2024-08-29 21:04:37 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100071 seconds - adjusting timeouts.
> 2024-08-30 09:30:36 UTC myhost dovecot: master: Warning: Time moved forwards
> by 0.100066 seconds - adjusting timeouts.
>
> Chrony ntp keeps the time in sync and the time has been in sync to within
> 30us of UTC for many days. I noticed that it reports that the unadjusted
> system clock is about 2.31 ppm fast of UTC. Doing the math for dovecot's 12
> hour warning interval:
> 12 hours * 3600 secs/hour * 2.3/1000000 = 0.0998 seconds.
> Could it be that dovecot is effectively measuring intervals of the
> uncorrected system clock time instead of the longer term adjusted time, and
> it complains when the accumulated NTP adjustments sum to 0.1 seconds.
I don't see how that would be possible. The check is using only just generated
timestamps, not anything from a long time ago.
I wonder if this kind of a simple patch would be good enough of a fix:
diff --git a/src/lib/ioloop.c b/src/lib/ioloop.c
index 98c2dc2bf4..a63f861330 100644
--- a/src/lib/ioloop.c
+++ b/src/lib/ioloop.c
@@ -18,6 +18,7 @@
Dovecot generally doesn't have very important short timeouts, so to avoid
logging many warnings about this, use a rather high value. */
#define IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS (100000)
+#define IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS_LARGE (1000000)
time_t ioloop_time = 0;
struct timeval ioloop_timeval;
@@ -654,9 +655,13 @@ static void io_loop_handle_timeouts_real(struct ioloop
*ioloop)
/* the callback may have slept, so check the time again. */
i_gettimeofday(&ioloop_timeval);
} else {
+ int max_diff = diff_usecs <
IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS_LARGE ?
+ IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS :
+ IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS_LARGE;
+
diff_usecs = timeval_diff_usecs(&ioloop->next_max_time,
&ioloop_timeval);
- if (unlikely(-diff_usecs >=
IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS)) {
+ if (unlikely(-diff_usecs >= max_diff)) {
io_loops_timeouts_update(-diff_usecs);
/* time moved forward */
ioloop->time_moved_callback(&ioloop->next_max_time,
_______________________________________________
dovecot mailing list -- dovecot@dovecot.org
To unsubscribe send an email to dovecot-le...@dovecot.org
