[Dovecot] "Time just moved backwards" in Dovecot in a Xen DomU

PGNet Dev pgnet.dev+dovecot at gmail.com
Tue Oct 6 21:23:08 EEST 2009


progress, i think. thanks to all for comments.

referencing,

  http://www.novell.com/communities/node/8629/time-synchronization-xen-setup
  http://www.linux.org.za/Lists-Archives/glug-tech-0905/msg00271.html
  http://www.gossamer-threads.com/lists/linux/kernel/1039416

i've decoupled DomU's time service from Dom0, @ both Dom0 & DomU

	cat /proc/sys/xen/independent_wallclock
		1

checking available kernel clocksources,

	cat /sys/devices/system/clocksource/clocksource0/available_clocksource
		xen jiffies

@ Dom0's /boot/grum/menu.lst, i've added,

	module /vmlinuz-xen ... clocksource=jiffies ...

and, at DomU's .cfg in Dom0,

	extra        = '... clocksource=jiffies ...'

verifying in both Dom0 & DomU, i've

	cat /sys/devices/system/clocksource/clocksource0/current_clocksource
		jiffies

i've removed any pool servers, specifying local/regional Stratum 2/1
server, instead. both DomU & Dom0 have, atm,

	cat  /etc/ntp.conf
		restrict default nomodify notrap noquery
		restrict 127.0.0.1
		restrict 192.168.1.0 mask 255.255.255.0  notrust nomodify notrap
		server ac-ntp0.net.cmu.edu iburst
		server ac-ntp1.net.cmu.edu iburst
		server ac-ntp2.net.cmu.edu iburst
		server clock.sjc.he.net  iburst
		driftfile /var/lib/ntp/drift/ntp.drift
		logfile   /var/log/ntpd/ntp.log
		statsdir  /var/log/ntpd/ # directory for statistics files
		filegen   peerstats  file peerstats  type day enable
		filegen   loopstats  file loopstats  type day enable
		filegen   clockstats file clockstats type day enable

and ntp is running,

	ps ax | grep ntp
		13012 ?        S<s    0:00 /usr/sbin/ntpd -p /var/run/ntp/ntpd.pid
-g -u ntp:ntp -I eth0 -i /var/lib/ntp -c /etc/ntp.conf

after a few minutes, i've got time sync @ Stratum 2/3,

@ Dom0,

	ntpq -p -c rv
		assID=0 status=06f4 leap_none, sync_ntp, 15 events, event_peer/strat_chg,
		version="ntpd 4.2.4p6 at 1.1549-o Fri May  8 08:40:54 UTC 2009 (1)",
		processor="x86_64", system="Linux/2.6.27.29-0.1-xen", leap=00,
->		stratum=2, precision=-8, rootdelay=18.717, rootdispersion=1077.662,
		peer=35633, refid=216.218.254.202,
		reftime=ce7605a0.6d9086a4  Tue, Oct  6 2009 11:06:24.427, poll=6,
		clock=ce7606ac.ba2a0e0c  Tue, Oct  6 2009 11:10:52.727, state=2,
		offset=-119.499, frequency=-37.025, jitter=455.226, noise=42.407,
		stability=0.040, tai=0
			 remote           refid      st t when poll reach   delay   offset  jitter
		==============================================================================
		+AC-NTP0.net.cmu 128.237.148.140  2 u   12   64   37   99.147  -669.34 452.011
		+AC-NTP1.net.cmu 128.237.148.132  2 u   13   64   37   95.951  -667.96 454.264
		+AC-NTP2.net.cmu 128.237.148.132  2 u    5   64   35   89.923  -688.34 496.274
		*clock.sjc.he.ne .CDMA.           1 u   15   64   37   15.566  -673.46 455.158
	ntpdc -c kerninfo
		pll offset:           -0.09179 s
		pll frequency:        -37.025 ppm
		maximum error:        0.135195 s
		estimated error:      0.042407 s
		status:               0001  pll
		pll time constant:    6
		precision:            1e-06 s
		frequency tolerance:  500 ppm

@ DomU,

	ntpq -p -c rv
		assID=0 status=06f4 leap_none, sync_ntp, 15 events, event_peer/strat_chg,
		version="ntpd 4.2.4p6 at 1.1549-o Fri May  8 08:40:54 UTC 2009 (1)",
		processor="x86_64", system="Linux/2.6.27.29-0.1-xen", leap=00,
->		stratum=3, precision=-8, rootdelay=98.154, rootdispersion=357.033,
		peer=50391, refid=216.218.254.202,
		reftime=ce7605c4.85c9d4d7  Tue, Oct  6 2009 11:07:00.522, poll=6,
		clock=ce7606b2.b01ba2b4  Tue, Oct  6 2009 11:10:58.687, state=2,
		offset=-102.003, frequency=-2.249, jitter=367.417, noise=36.248,
		stability=0.409, tai=0
			 remote           refid      st t when poll reach   delay   offset  jitter
		==============================================================================
		+AC-NTP0.net.cmu 128.237.148.140  2 u   35   64   17   91.744  -557.29 359.884
		+AC-NTP1.net.cmu 128.237.148.140  2 u   37   64   17   96.365  -548.70 355.430
		+AC-NTP2.net.cmu 128.237.148.132  2 u   54   64   17   98.517  -509.63 363.221
		*clock.sjc.he.ne .CDMA.           1 u   37   64   17   22.907  -553.69 366.781
	ntpdc -c kerninfo
		pll offset:           -0.080367 s
		pll frequency:        -2.249 ppm
		maximum error:        0.12257 s
		estimated error:      0.036248 s
		status:               0001  pll
		pll time constant:    6
		precision:            1e-06 s
		frequency tolerance:  500 ppm

with this setup,

	service dovecot-custom restart
		Stopping dovecot                                                     done
		Starting dovecot ILoading modules from directory: /usr/local/lib/dovecot/imap
		IModule loaded: /usr/local/lib/dovecot/imap/lib01_acl_plugin.so
		IModule loaded: /usr/local/lib/dovecot/imap/lib10_quota_plugin.so
		IModule loaded: /usr/local/lib/dovecot/imap/lib11_imap_quota_plugin.so
		IEffective uid=65534, gid=65533, home=/tmp
		IQuota root: name=storage=10240 backend=maildir args=
		                                                                      done

and watching,

	tail -f /var/log/dovecot/*log

the problem appears again,

	...
	Oct 06 10:58:37 auth(default): Info: new auth connection: pid=17797
	Oct 06 10:58:37 auth(default): Info: new auth connection: pid=17798
	Oct 06 10:58:37 auth(default): Info: new auth connection: pid=17799
	Oct 06 11:06:23 dovecot: Error: Time just moved backwards by 1
seconds. I'll sleep now until we're back in present.
http://wiki.dovecot.org/TimeMovedBackwards

and, checking syslog,

	...
	Oct  6 11:06:22 mx ntpd[17697]: time reset -2.203456 s
	Oct  6 11:07:00 mx ntpd[17697]: synchronized to 128.2.1.22, stratum 2
	Oct  6 11:08:11 mx ntpd[17697]: synchronized to 216.218.254.202, stratum 1

so it _looks_ like a reset was done, then stratum 2 & 1 sync were achived.

as of,

    date
        Tue Oct  6 11:20:58 PDT 2009

there have been no further, related errors/entries in either dovecot
logs or syslog.

fixed?  improved?  unclear ....


More information about the dovecot mailing list