[Users] Use Filer for NFS storage

Mon Apr 16 10:39:04 UTC 2012

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 at 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.
> >