On Sun, Apr 15, 2012 at 01:05:52PM -0700, Christian Hernandez wrote:
Scolling up I found these "initIRS" errors in the logs
*MainThread::INFO::2012-04-13 17:18:30,965::vdsm::78::vds::(run)
<Thread(Thread-11, started daemon 140487776270080)>*
*MainThread::INFO::2012-04-13 17:18:30,965::vdsm::78::vds::(run)
<WorkerThread(Thread-5, started daemon 140488178923264)>*
*MainThread::INFO::2012-04-13 17:18:30,965::vdsm::78::vds::(run)
<KsmMonitorThread(KsmMonitor, started daemon 140487755290368)>*
*MainThread::INFO::2012-04-13 17:18:30,966::vdsm::78::vds::(run)
<WorkerThread(Thread-4, started daemon 140488530888448)>*
*MainThread::INFO::2012-04-13 17:18:30,966::vmChannels::135::vds::(stop) VM
channels listener was stopped.*
*MainThread::INFO::2012-04-13 17:18:30,966::vdsm::78::vds::(run)
<Listener(VM Channels Listener, started daemon 140487734310656)>*
*MainThread::INFO::2012-04-13 17:18:30,966::vdsm::78::vds::(run)
<WorkerThread(Thread-3, started daemon 140488541378304)>*
*MainThread::INFO::2012-04-13 17:18:30,966::vdsm::78::vds::(run)
<WorkerThread(Thread-2, started daemon 140488551868160)>*
*MainThread::INFO::2012-04-13 17:18:32,475::vdsm::70::vds::(run) I am the
actual vdsm 4.9-0*
*MainThread::DEBUG::2012-04-13
17:18:32,688::resourceManager::379::ResourceManager::(registerNamespace)
Registering namespace 'Storage'*
*MainThread::DEBUG::2012-04-13
17:18:32,688::threadPool::45::Misc.ThreadPool::(__init__) Enter -
numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0*
*MainThread::DEBUG::2012-04-13
17:18:32,708::multipath::109::Storage.Multipath::(isEnabled) multipath
Defaulting to False*
*MainThread::DEBUG::2012-04-13
17:18:32,709::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n
/bin/cp /tmp/tmpXnjmr1 /etc/multipath.conf' (cwd None)*
*MainThread::DEBUG::2012-04-13
17:18:32,761::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> =
'sudo: sorry, you must have a tty to run sudo\n'; <rc> = 1*
Vdsm's evil /etc/sudoers.d/vdsm file has
Defaults:vdsm !requiretty
which should allow vdsm running sudo with no tty.
I suspect that you have an overriding config in your /etc/sudoers** or
that you somehow got that file removed. Could you check if that's that?
*MainThread::ERROR::2012-04-13
17:18:32,762::clientIF::162::vds::(_initIRS)
Error initializing IRS*
*Traceback (most recent call last):*
* File "/usr/share/vdsm/clientIF.py", line 160, in _initIRS*
* self.irs = Dispatcher(HSM())*
* File "/usr/share/vdsm/storage/hsm.py", line 294, in __init__*
* multipath.setupMultipath()*
* File "/usr/share/vdsm/storage/multipath.py", line 125, in setupMultipath*
* raise se.MultipathSetupError()*
*MultipathSetupError: Failed to setup multipath: ()*
*MainThread::DEBUG::2012-04-13
17:18:32,766::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep
-xf ksmd' (cwd None)*
*MainThread::DEBUG::2012-04-13
17:18:32,779::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
*MainThread::INFO::2012-04-13
17:18:32,780::vmChannels::139::vds::(settimeout) Setting channels' timeout
to 30 seconds.*
*VM Channels Listener::INFO::2012-04-13
17:18:32,782::vmChannels::127::vds::(run) Starting VM channels listener
thread.*
*Thread-13::DEBUG::2012-04-13
17:18:33,521::BindingXMLRPC::869::vds::(wrapper) client
[192.168.11.236]::call getCapabilities with () {}*
*Thread-13::WARNING::2012-04-13
17:18:33,616::utils::688::root::(getHostUUID) Could not find host UUID.*
*Thread-13::DEBUG::2012-04-13
17:18:33,643::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf
"%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm' (cwd None)*
*Thread-13::DEBUG::2012-04-13
17:18:33,667::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
*Thread-13::DEBUG::2012-04-13
17:18:33,667::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf
"%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img' (cwd None)*
*Thread-13::DEBUG::2012-04-13
17:18:33,690::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
*Thread-13::DEBUG::2012-04-13
17:18:33,690::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf
"%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)*
*Thread-13::DEBUG::2012-04-13
17:18:33,711::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
*Thread-13::DEBUG::2012-04-13
17:18:33,711::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf
"%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd
None)*
*Thread-13::DEBUG::2012-04-13
17:18:33,732::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
*Thread-13::DEBUG::2012-04-13
17:18:33,733::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf
"%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)*
*Thread-13::DEBUG::2012-04-13
17:18:33,754::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> =
''; <rc> = 0*
On Sun, Apr 15, 2012 at 6:57 AM, Dan Kenigsberg <danken(a)redhat.com> wrote:
> On Fri, Apr 13, 2012 at 12:26:39PM -0700, Christian Hernandez wrote:
> > Here is the log from the Host
> >
> >
> > *Thread-1821::DEBUG::2012-04-13
> > 12:18:52,200::BindingXMLRPC::167::vds::(wrapper) [192.168.11.236]
> > Thread-1821::ERROR::2012-04-13
> > 12:18:52,200::BindingXMLRPC::171::vds::(wrapper) Unexpected exception
> > Traceback (most recent call last):
> > File "/usr/share/vdsm/BindingXMLRPC.py", line 169, in wrapper
> > return f(*args, **kwargs)
> > File "/usr/share/vdsm/BindingXMLRPC.py", line 571, in
> > poolValidateStorageServerConnection
> > return pool.validateStorageServerConnection(domType, conList)
> > File "/usr/share/vdsm/API.py", line 897, in
> > validateStorageServerConnection
> > return self._irs.validateStorageServerConnection(domainType,
> > AttributeError: 'NoneType' object has no attribute
> > 'validateStorageServerConnection'
> > Thread-1822::DEBUG::2012-04-13
> > 12:18:52,333::BindingXMLRPC::167::vds::(wrapper) [192.168.11.236]
> > Thread-1822::ERROR::2012-04-13
> > 12:18:52,334::BindingXMLRPC::171::vds::(wrapper) Unexpected exception
> > Traceback (most recent call last):
> > File "/usr/share/vdsm/BindingXMLRPC.py", line 169, in wrapper
> > return f(*args, **kwargs)
> > File "/usr/share/vdsm/BindingXMLRPC.py", line 491, in
> > poolDisconnectStorageServer
> > return pool.disconnectStorageServer(domType, conList)
> > File "/usr/share/vdsm/API.py", line 823, in
disconnectStorageServer
> > return self._irs.disconnectStorageServer(domainType, self._UUID,
> > AttributeError: 'NoneType' object has no attribute
> 'disconnectStorageServer'
>
> It seems like the interesting traceback should be further up - I
> suppose self._irs failed initialization and kept its original None
> value. Please scroll up and try to find out why this failed on Vdsm
> startup.
>
> We have a FIXME in vdsm so that we report such failures better:
>
> vdsm/BindingXMLRPC.py: # XXX: Need another way to check if IRS init was
> okay
>
> Adam, could you take a further look into this?
>
> Regards,
> Dan.
>