The way Dovecot works is:
- It finds the next timeout, sees that it happens in e.g. 5 milliseconds.
- Then it calls kqueue() to wait for I/O for max 5 milliseconds
- Then it notices that it actually returned more than 105 milliseconds later, and then logs a warning about it.
So kqueue() apparently isn't very accurate in its timeout handling.
With some googling I found https://lists.freebsd.org/pipermail/freebsd-arch/2012-March/012416.html which suggests this could happen at least if kern.hz is set to 20 or less. Could that be the case?
I guess we could increase IOLOOP_TIME_MOVED_FORWARDS_MIN_USECS higher than 100 ms, but that might start hiding problems. Nowadays some people use rather short timeouts in e.g. some HTTP requests (auth, push-notifications). It could be difficult to understand why 100ms timeout happens only at 200ms without this warning message. Although if it happens only rarely, I guess it's not much of a problem.
Anyway, would be good to understand first why this happens in FreeBSD before growing the warning time.
Also, this is kind of a problem when it does happen. Since Dovecot thinks the time moved e.g. 100ms forward, it adjusts all timeouts to happen 100ms backwards. If this wasn't a true time jump, then these timeouts now happen 100ms earlier. So e.g. a HTTP request with <100ms timeout can actually trigger an immediate timeout. Hiding the log message makes debugging this also more difficult. So I don't think it's a good solution to simply hide it or change it to debug level, as it may mask real problems.
On 19. Aug 2024, at 19.11, Larry Rosenman via dovecot dovecot@dovecot.org wrote:
Comments from the dovecot community?
Aug 19, 2024 11:07:30 AM bugzilla-noreply@freebsd.org:
Bugzilla Automation bugzilla@FreeBSD.org has asked Larry Rosenman ler@FreeBSD.org for maintainer-feedback: Bug 280929: mail/dovecot move bogus warning "Time moved forwards" to debug https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=280929
--- Description --- Dovecot complains about time moving forward, which seems to be due to a broken mechanism (on FreeBSD) used to measure timeouts. This warning spams the maillog up to several hundred times per day.
There's an ongoing thread about this issue in the freebsd forums: https://forums.freebsd.org/threads/dovecot-time-moved-forwards.82886
In post #33 RypPn points out the offending line in main.c and in post #34 msplsh suggests instead of completely removing/commenting out the line, it would be more sensible to move it from 'warning' to 'debug'. This is what this patch does: change the log facility to 'debug' to mute that bogus message for standard configurations, but keep it in 'debug' for anyone who might want to debug that issue in the future.
I tested the patch as a local patch in poudriere and it builds fine on 13.3-RELEASE with the quarterly and latest branch.
dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org