This is truly an odd one. I have a vm running ubuntu 10.10 - works fine. Except I noticed every time I reboot the VM, dovecot (IMAP server) complains the time has gone backward 100 seconds (it can be a second or two more - normal skew?) Anyway, after much init script debugging, I discovered the culprit is the vmware tools. If I disable them, everything is dandy. The moment I start them manually (via "start vmware-tools"), I see this in the syslog:
Oct 27 11:24:07 sphinx init: Connection from private client
Oct 27 11:24:07 sphinx init: vmware-tools goal changed from stop to start
Oct 27 11:24:07 sphinx init: vmware-tools state changed from waiting to starting
Oct 27 11:24:07 sphinx init: Handling starting event
Oct 27 11:24:07 sphinx init: vmware-tools state changed from starting to pre-start
Oct 27 11:24:07 sphinx init: vmware-tools pre-start process (1597)
Oct 27 11:24:07 sphinx kernel: [ 35.984085] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
Oct 27 11:24:07 sphinx init: Handling module-device-added event
Oct 27 11:24:07 sphinx init: Handling slots-device-added event
Oct 27 11:24:07 sphinx kernel: [ 35.984324] acpiphp: Slot [32] registered
(snip a bunch more acpi messages)
Oct 27 11:24:07 sphinx init: Handling slots-device-added event
Oct 27 11:24:07 sphinx init: last message repeated 30 times
Oct 27 11:24:07 sphinx init: vmware-tools pre-start process (1597) exited normally
Oct 27 11:24:07 sphinx init: vmware-tools state changed from pre-start to spawned
Oct 27 11:24:07 sphinx init: vmware-tools state changed from spawned to post-start
Oct 27 11:24:07 sphinx init: vmware-tools state changed from post-start to running
Oct 27 11:24:07 sphinx init: Handling started event
Oct 27 11:22:25 sphinx icinga: Warning: A system time change of 0d 0h 1m 42s (backwards in time) has been detected. Compensating...
Oct 27 11:22:25 sphinx dovecot: Fatal: Time just moved backwards by 102 seconds. This might cause a lot of problems, so I'll just kill myself now. http://wiki.dovecot.org/TimeMovedBackwards
I found a KB article on the vmware site about how to totally disable time sync, so I made those config changes and retested the scenario and it's "fixed" now. I don't really care I guess, since I use ntp to keep the VMs in sync, but I'd dearly like to know what the root cause is... Also, when the system is up and ntpd starts, it detects this restores the correct time.
Oct 27 11:24:07 sphinx init: Connection from private client
Oct 27 11:24:07 sphinx init: vmware-tools goal changed from stop to start
Oct 27 11:24:07 sphinx init: vmware-tools state changed from waiting to starting
Oct 27 11:24:07 sphinx init: Handling starting event
Oct 27 11:24:07 sphinx init: vmware-tools state changed from starting to pre-start
Oct 27 11:24:07 sphinx init: vmware-tools pre-start process (1597)
Oct 27 11:24:07 sphinx kernel: [ 35.984085] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
Oct 27 11:24:07 sphinx init: Handling module-device-added event
Oct 27 11:24:07 sphinx init: Handling slots-device-added event
Oct 27 11:24:07 sphinx kernel: [ 35.984324] acpiphp: Slot [32] registered
(snip a bunch more acpi messages)
Oct 27 11:24:07 sphinx init: Handling slots-device-added event
Oct 27 11:24:07 sphinx init: last message repeated 30 times
Oct 27 11:24:07 sphinx init: vmware-tools pre-start process (1597) exited normally
Oct 27 11:24:07 sphinx init: vmware-tools state changed from pre-start to spawned
Oct 27 11:24:07 sphinx init: vmware-tools state changed from spawned to post-start
Oct 27 11:24:07 sphinx init: vmware-tools state changed from post-start to running
Oct 27 11:24:07 sphinx init: Handling started event
Oct 27 11:22:25 sphinx icinga: Warning: A system time change of 0d 0h 1m 42s (backwards in time) has been detected. Compensating...
Oct 27 11:22:25 sphinx dovecot: Fatal: Time just moved backwards by 102 seconds. This might cause a lot of problems, so I'll just kill myself now. http://wiki.dovecot.org/TimeMovedBackwards
I found a KB article on the vmware site about how to totally disable time sync, so I made those config changes and retested the scenario and it's "fixed" now. I don't really care I guess, since I use ntp to keep the VMs in sync, but I'd dearly like to know what the root cause is... Also, when the system is up and ntpd starts, it detects this restores the correct time.