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-nore...@freebsd.org: > > > Bugzilla Automation <bugzi...@freebsd.org> has asked Larry Rosenman > <l...@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-le...@dovecot.org _______________________________________________ dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-le...@dovecot.org
