Sunday, 31 August 2008

Dovecot terminates unexpectedly

Recently my dovecot IMAP server died regularly. In my log files I found the following message:
...
dovecot: 2008-08-31 09:12:50 Fatal: Time just moved backwards by 11 seconds. This might cause a lot of problems, so I'll just kill myself now. http://wiki.dovecot.org/TimeMovedBackwards
...
The wiki describes the cause - the clock of my server is not in sync - but does not offer much of help. Usage of ntp is suggested.

Openntpd syncs the system clock but does not slow it down (effectively causing the same problem). ntp offers to slow down the clock with side effects to database and CMS.

Examination of the logfile reveals that webmin runs a time sync just before dovecots unnatural death. OK, here's the cause.
...
Aug 31 09:13:01 myserver /USR/SBIN/CRON[12345]: (root) CMD (/etc/webmin/time/sync.pl)
dovecot: 2008-08-31 09:12:50 Fatal: Time just moved backwards by 11 seconds. This might cause a lot of problems, so I'll just kill myself now. http://wiki.dovecot.org/TimeMovedBackwards
...
Restarting dovecot right after the time sync will solve the problem. You can do that from the webmin user interface:
System/Scheduled Cron Job/Create a new scheduled cron job
enter
/etc/init.d/dovecot restart
select time right after /etc/webmin/time/sync.pl
and you are done.

6 comments:

Jamie said...

You might want to check the clock on your system - if it is off by 11 seconds every day, your clock must be seriously lagging.

Webmin uses the ntpdate command to sync with a time server, but this will only do a nice slow adjustment (which doesn't crash dovecot) if the difference is less than 128ms.

Wolf Rogner said...

In fact my clock is quite accurate. Dovecot terminates, it does not crash.

I have not looked into the source so I can only report on my workaround.

Jamie said...

So assuming that Dovecot is correct about the clock jumping by 11 seconds when the time sync happens, I wonder where that 11 second daily difference is coming from?

Wolf Rogner said...

Rooting through the log files its not 11 secs every day. But is significant.

Curiously comparing date to my notebook does not reveal much of a difference (any time I check). My notebook syncs with an NTP server.

So frankly, I have no idea (and currently no time to investigate).

Any ideas?

Jamie said...

Some time skew on typical systems is expected, which NTP is supposed to correct. 11 seconds per day is more than expected though.. Perhaps the hardware clock on your system is slightly slow or fast?

Not really my area of expertise, sorry..

Anonymous said...

Genial post and this post helped me alot in my college assignement. Say thank you you for your information.