On Wed, Jan 16, 2013 at 01:19:47AM +0100, Gianluca Cecchi wrote:
On Wed, Jan 16, 2013 at 12:08 AM, Dan Kenigsberg wrote:
My question regarded a simple node-only reboot. I wonder if vdsm fails to start ALWAYS, or that this is an even more complex glitch.
Just done another reboot and the same problem. It seems vdsmd doesn't start at all
[root@f18ovn03 ~]# sudo systemctl status vdsmd.service vdsmd.service - Virtual Desktop Server Manager Loaded: loaded (/usr/lib/systemd/system/vdsmd.service; enabled) Active: inactive (dead) CGroup: name=systemd:/system/vdsmd.service
Under /var/log/vdsm I see vdsm.log with timestamp of when I stopped the system: MainThread::INFO::2013-01-16 00:45:57,716::vdsm::95::vds::(run) VDSM main thread ended. Waiting for 16 other threads... MainThread::INFO::2013-01-16 00:45:57,716::vdsm::99::vds::(run) <Thread(libvirtEventLoop, started daemon 140084926744320)> MainThread::INFO::2013-01-16 00:45:57,716::vdsm::99::vds::(run) <WorkerThread(Thread-5, started daemon 140084753970944)> MainThread::INFO::2013-01-16 00:45:57,716::vdsm::99::vds::(run) <HostMonitor(HostMonitor, started daemon 140083713799936)> MainThread::INFO::2013-01-16 00:45:57,716::vdsm::99::vds::(run) <WorkerThread(Thread-7, started daemon 140084737185536)> MainThread::INFO::2013-01-16 00:45:57,717::momIF::65::MOM::(stop) Shutting down MOM MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <MomThread(MOM, started 140084200314624)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-4, started daemon 140084762363648)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-10, started daemon 140084233885440)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-9, started daemon 140084242278144)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-1, started daemon 140084787541760)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-3, started daemon 140084770756352)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <WorkerThread(Thread-8, started daemon 140084250670848)> MainThread::INFO::2013-01-16 00:45:57,717::vdsm::99::vds::(run) <_MainThread(MainThread, started 140085026416448)> MainThread::INFO::2013-01-16 00:45:57,718::vdsm::99::vds::(run) <GuestManager(GuestManager, started daemon 140083688621824)> MainThread::INFO::2013-01-16 00:45:57,718::vdsm::99::vds::(run) <PolicyEngine(PolicyEngine, started daemon 140083680229120)> MainThread::INFO::2013-01-16 00:45:57,718::vdsm::99::vds::(run) <WorkerThread(Thread-2, started daemon 140084779149056)> MainThread::INFO::2013-01-16 00:45:57,718::vdsm::99::vds::(run) <WorkerThread(Thread-6, started daemon 140084745578240)> MainThread::INFO::2013-01-16 00:45:57,718::vmChannels::136::vds::(stop) VM channels listener was stopped. MainThread::INFO::2013-01-16 00:45:57,718::vdsm::99::vds::(run) <Listener(VM Channels Listener, started daemon 140083705407232)>
If then I manually start it root@f18ovn03 vdsm]# systemctl start vdsmd.service [root@f18ovn03 vdsm]# echo $? 0 [root@f18ovn03 vdsm]# systemctl status vdsmd.service vdsmd.service - Virtual Desktop Server Manager Loaded: loaded (/usr/lib/systemd/system/vdsmd.service; enabled) Active: active (running) since Wed, 2013-01-16 01:09:44 CET; 10s ago Process: 2483 ExecStart=/lib/systemd/systemd-vdsmd start (code=exited, status=0/SUCCESS) Main PID: 2770 (respawn) CGroup: name=systemd:/system/vdsmd.service ├ 2770 /bin/bash -e /usr/share/vdsm/respawn --minlifetime 10 --daemon --masterpid /var/run/vdsm/respawn.p... ├ 2773 /usr/bin/python /usr/share/vdsm/vdsm ├ 2791 /usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 75cc5638-f5c7-4431-bcbe-4a0cd8... └ 2792 /usr/bin/python /usr/share/vdsm/supervdsmServer.py 75cc5638-f5c7-4431-bcbe-4a0cd817a0e4 2773 /var/...
Jan 16 01:09:44 f18ovn03.ceda.polimi.it systemd-vdsmd[2483]: [27B blob data] Jan 16 01:09:44 f18ovn03.ceda.polimi.it systemd[1]: Started Virtual Desktop Server Manager. Jan 16 01:09:45 f18ovn03.ceda.polimi.it python[2773]: DIGEST-MD5 client step 2 Jan 16 01:09:45 f18ovn03.ceda.polimi.it python[2773]: DIGEST-MD5 client step 2 Jan 16 01:09:45 f18ovn03.ceda.polimi.it python[2773]: DIGEST-MD5 client step 3 Jan 16 01:09:45 f18ovn03.ceda.polimi.it vdsm[2773]: vdsm fileUtils WARNING Dir /rhev/data-center/mnt already exists Jan 16 01:09:48 f18ovn03.ceda.polimi.it vdsm[2773]: vdsm Storage.LVM WARNING lvm pvs failed: 5 [' NQRb0Q-3C0k-3RRo-1LZZ...T01'] Jan 16 01:09:48 f18ovn03.ceda.polimi.it vdsm[2773]: vdsm Storage.LVM WARNING lvm vgs failed: 5 [' x3XSZx-avUC-0NNI-w5K4...T01'] Jan 16 01:09:48 f18ovn03.ceda.polimi.it vdsm[2773]: vdsm vds WARNING Unable to load the json rpc server module. Please m...lled. Jan 16 01:09:51 f18ovn03.ceda.polimi.it vdsm[2773]: vdsm fileUtils WARNING Dir /rhev/data-center/hsm-tasks already exists
Tried also to run anable again systemctl enable vdsmd.service and reboot but same behaviour. In notice that the same is true for ntpd service, configured as enabled but not started. When I manually start vdsmd, also ntpd starts, as it is in the required chain for vdsmd... strange Can it depend on delay on network/bridges initialization?
It might be it - but there must be more clues in the logs. I'd like to see both vdsm.log and /var/log/message of boottime. journalctl may have stories to tell, too. If you can manually zap ntpd off of vdsmd.service and reboot, it could eliminate one usual suspect. Would you?
when the service has not manually started by me yet, the output of systemctl show vdsmd.service
Id=vdsmd.service Names=vdsmd.service Requires=multipathd.service libvirtd.service ntpd.service systemd-journald.socket basic.target