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