Attachment 648291 Details for Bug 878327 – Attaching vdsm log from the host

Attaching vdsm log from the host

vdsm.log (text/x-log), 135.24 KB, created by Shruti Sampat on 2012-11-20 06:33:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Shruti Sampat

Created: 2012-11-20 06:33:16 UTC

Size: 135.24 KB

patch

obsolete

>MainThread::INFO::2012-11-20 05:04:59,931::vdsm::70::vds::(run) I am the actual vdsm 4.9-14
>MainThread::DEBUG::2012-11-20 05:05:01,849::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 05:05:01,850::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::DEBUG::2012-11-20 05:05:01,895::multipath::109::Storage.Multipath::(isEnabled) multipath Defaulting to False
>MainThread::DEBUG::2012-11-20 05:05:01,895::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cp /tmp/tmpdjfqu0 /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,684::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 05:05:02,685::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath -F' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,697::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>MainThread::DEBUG::2012-11-20 05:05:02,698::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service multipathd restart' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,828::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 05:05:02,829::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,843::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 05:05:02,844::lvm::316::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-11-20 05:05:02,845::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,857::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 05:05:02,858::lvm::339::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-11-20 05:05:02,858::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-11-20 05:05:02,858::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,868::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>MainThread::DEBUG::2012-11-20 05:05:02,869::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-11-20 05:05:02,869::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:02,881::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>MainThread::INFO::2012-11-20 05:05:02,882::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>MainThread::DEBUG::2012-11-20 05:05:02,883::supervdsm::93::SuperVdsmProxy::(_killSupervdsm) Could not kill old Super Vdsm [Errno 2] No such file or directory: '/var/run/vdsm/svdsm.pid'
>MainThread::DEBUG::2012-11-20 05:05:02,883::supervdsm::81::SuperVdsmProxy::(_launchSupervdsm) Launching Super Vdsm
>MainThread::DEBUG::2012-11-20 05:05:02,883::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py fa21daa1-3047-41fb-903b-372b86839884 2308' (cwd None)
>Thread-12::DEBUG::2012-11-20 05:05:02,885::misc::1088::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 05:05:02,885::misc::1090::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 05:05:02,885::misc::1088::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 05:05:02,885::misc::1090::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 05:05:02,886::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 05:05:03,073::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 05:05:03,074::misc::1098::SamplingMethod::(__call__) Returning last result
>MainThread::DEBUG::2012-11-20 05:05:03,404::supervdsmServer::273::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 05:05:03,404::supervdsmServer::277::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 05:05:03,404::supervdsmServer::280::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 05:05:03,404::supervdsmServer::284::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 05:05:03,405::supervdsmServer::288::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 05:05:03,405::supervdsmServer::293::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 05:05:03,405::supervdsmServer::304::SuperVdsm.Server::(main) Started serving super vdsm object
>MainThread::DEBUG::2012-11-20 05:05:04,891::supervdsm::102::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainThread::DEBUG::2012-11-20 05:05:04,962::supervdsm::74::SuperVdsmProxy::(__init__) Connected to Super Vdsm
>MainThread::DEBUG::2012-11-20 05:05:04,965::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf ksmd' (cwd None)
>MainThread::DEBUG::2012-11-20 05:05:05,160::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 05:05:05,161::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds.
>VM Channels Listener::INFO::2012-11-20 05:05:05,163::vmChannels::127::vds::(run) Starting VM channels listener thread.
>Thread-12::DEBUG::2012-11-20 05:05:05,269::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 05:05:05,300::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 05:05:05,301::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,301::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,301::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,301::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,302::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,302::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 05:05:05,302::misc::1098::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 05:05:05,302::hsm::360::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>Thread-12::DEBUG::2012-11-20 05:05:05,303::hsm::392::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>Thread-12::DEBUG::2012-11-20 05:05:05,303::hsm::393::Storage.HSM::(__cleanStorageRepository) Mount list: []
>Thread-12::DEBUG::2012-11-20 05:05:05,304::hsm::395::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>Thread-12::DEBUG::2012-11-20 05:05:05,305::hsm::438::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 05:33:33,371::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::DEBUG::2012-11-20 05:33:33,372::task::588::TaskManager.Task::(_updateState) Task=`fb6139cf-ac63-4553-91b6-962c1f8d4f35`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 05:33:33,372::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 05:33:33,373::storageServer::610::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 05:33:33,379::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 05:33:33,380::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 05:33:33,380::task::1172::TaskManager.Task::(prepare) Task=`fb6139cf-ac63-4553-91b6-962c1f8d4f35`::finished: None
>MainThread::DEBUG::2012-11-20 05:33:33,380::task::588::TaskManager.Task::(_updateState) Task=`fb6139cf-ac63-4553-91b6-962c1f8d4f35`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 05:33:33,380::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 05:33:33,380::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 05:33:33,381::task::978::TaskManager.Task::(_decref) Task=`fb6139cf-ac63-4553-91b6-962c1f8d4f35`::ref 0 aborting False
>MainThread::INFO::2012-11-20 05:33:33,381::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 05:33:33,381::vdsm::78::vds::(run) <_MainThread(MainThread, started 140092344059648)>
>MainThread::INFO::2012-11-20 05:33:33,381::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140092119779072)>
>MainThread::INFO::2012-11-20 05:33:33,381::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140091590686464)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140092012676864)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140091601176320)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140092023166720)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140091991697152)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140091622156032)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140091632645888)>
>MainThread::INFO::2012-11-20 05:33:33,382::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140091611666176)>
>MainThread::INFO::2012-11-20 05:33:33,383::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::INFO::2012-11-20 05:33:33,383::vdsm::78::vds::(run) <Listener(VM Channels Listener, started daemon 140091456468736)>
>MainThread::INFO::2012-11-20 05:33:33,383::vdsm::78::vds::(run) <KsmMonitorThread(KsmMonitor, started daemon 140091477448448)>
>MainThread::INFO::2012-11-20 05:33:33,384::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140091981207296)>
>MainThread::INFO::2012-11-20 05:33:33,384::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140092002187008)>
>MainThread::INFO::2012-11-20 06:06:05,574::vdsm::70::vds::(run) I am the actual vdsm 4.9-14
>MainThread::DEBUG::2012-11-20 06:06:10,584::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:06:10,585::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::DEBUG::2012-11-20 06:06:10,772::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,085::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:06:11,086::multipath::101::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving
>MainThread::DEBUG::2012-11-20 06:06:11,086::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,100::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:06:11,101::lvm::316::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-11-20 06:06:11,101::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,113::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:06:11,113::lvm::339::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-11-20 06:06:11,114::lvm::349::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>MainThread::DEBUG::2012-11-20 06:06:11,114::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,127::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:06:11,127::lvm::376::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>MainThread::DEBUG::2012-11-20 06:06:11,128::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,141::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>MainThread::INFO::2012-11-20 06:06:11,142::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:06:11,144::misc::1088::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:06:11,144::misc::1090::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:06:11,145::misc::1088::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:06:11,145::misc::1090::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:06:11,145::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,146::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf ksmd' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:11,344::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:06:11,345::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds.
>VM Channels Listener::INFO::2012-11-20 06:06:11,346::vmChannels::127::vds::(run) Starting VM channels listener thread.
>Thread-12::DEBUG::2012-11-20 06:06:11,608::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:06:11,608::misc::1098::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:06:11,609::supervdsm::93::SuperVdsmProxy::(_killSupervdsm) Could not kill old Super Vdsm [Errno 2] No such file or directory: '/var/run/vdsm/svdsm.pid'
>Thread-12::DEBUG::2012-11-20 06:06:11,609::supervdsm::81::SuperVdsmProxy::(_launchSupervdsm) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:06:11,609::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 16662caf-43fd-450c-96ce-76f0f889bc80 2105' (cwd None)
>MainThread::DEBUG::2012-11-20 06:06:12,105::supervdsmServer::273::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:06:12,106::supervdsmServer::277::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:06:12,106::supervdsmServer::280::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:06:12,106::supervdsmServer::284::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:06:12,107::supervdsmServer::288::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:06:12,107::supervdsmServer::293::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:06:12,108::supervdsmServer::304::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:06:13,614::supervdsm::102::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:06:13,700::supervdsm::74::SuperVdsmProxy::(__init__) Connected to Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:06:14,005::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:06:14,063::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:06:14,063::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,064::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,064::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,064::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,064::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,064::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:06:14,065::misc::1098::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:06:14,065::hsm::360::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>Thread-12::DEBUG::2012-11-20 06:06:14,066::hsm::392::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>Thread-12::DEBUG::2012-11-20 06:06:14,066::hsm::393::Storage.HSM::(__cleanStorageRepository) Mount list: []
>Thread-12::DEBUG::2012-11-20 06:06:14,066::hsm::395::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>Thread-12::DEBUG::2012-11-20 06:06:14,096::hsm::438::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:06:56,637::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::DEBUG::2012-11-20 06:06:56,637::task::588::TaskManager.Task::(_updateState) Task=`1b7fb5e1-c978-4d73-89c7-08ec7fe154c5`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:06:56,637::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:06:56,638::storageServer::610::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:06:56,645::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:06:56,645::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:06:56,645::task::1172::TaskManager.Task::(prepare) Task=`1b7fb5e1-c978-4d73-89c7-08ec7fe154c5`::finished: None
>MainThread::DEBUG::2012-11-20 06:06:56,646::task::588::TaskManager.Task::(_updateState) Task=`1b7fb5e1-c978-4d73-89c7-08ec7fe154c5`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:06:56,646::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:06:56,646::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:06:56,646::task::978::TaskManager.Task::(_decref) Task=`1b7fb5e1-c978-4d73-89c7-08ec7fe154c5`::ref 0 aborting False
>MainThread::INFO::2012-11-20 06:06:56,646::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:06:56,646::vdsm::78::vds::(run) <_MainThread(MainThread, started 140040929265408)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140040704984832)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140040294364928)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140040644511488)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140040262895360)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140040655001344)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140040241915648)>
>MainThread::INFO::2012-11-20 06:06:56,647::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140040283875072)>
>MainThread::INFO::2012-11-20 06:06:56,648::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::INFO::2012-11-20 06:06:56,648::vdsm::78::vds::(run) <Listener(VM Channels Listener, started daemon 140039973480192)>
>MainThread::INFO::2012-11-20 06:06:56,648::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140040675981056)>
>MainThread::INFO::2012-11-20 06:06:56,648::vdsm::78::vds::(run) <KsmMonitorThread(KsmMonitor, started daemon 140039994459904)>
>MainThread::INFO::2012-11-20 06:06:56,648::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140040252405504)>
>MainThread::INFO::2012-11-20 06:06:56,648::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140040273385216)>
>MainThread::INFO::2012-11-20 06:06:56,649::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140040665491200)>
>MainThread::INFO::2012-11-20 06:19:26,412::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:29,274::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:29,275::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:29,300::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:29,352::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:30,051::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:30,052::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:30,052::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:30,052::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:30,063::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:30,063::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:30,065::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:30,065::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:30,065::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:30,123::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:30,125::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:30,127::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:30,129::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:30,137::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:30,138::task::588::TaskManager.Task::(_updateState) Task=`91d27908-e5ac-4e05-b197-1fe6b36786d7`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:30,138::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:30,138::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:30,148::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:30,148::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:30,149::task::1172::TaskManager.Task::(prepare) Task=`91d27908-e5ac-4e05-b197-1fe6b36786d7`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:30,149::task::588::TaskManager.Task::(_updateState) Task=`91d27908-e5ac-4e05-b197-1fe6b36786d7`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:30,149::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:30,149::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:30,149::task::978::TaskManager.Task::(_decref) Task=`91d27908-e5ac-4e05-b197-1fe6b36786d7`::ref 0 aborting False
>Thread-12::DEBUG::2012-11-20 06:19:30,156::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:30,274::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:30,274::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:30,274::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:30,149::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:30,277::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:30,277::vdsm::78::vds::(run) <_MainThread(MainThread, started 139773899421440)>
>MainThread::INFO::2012-11-20 06:19:30,277::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 139773673035520)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 139773360453376)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 139773641664256)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 139773370943232)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 139773035398912)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 139773381433088)>
>MainThread::INFO::2012-11-20 06:19:30,278::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 139773349963520)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 139773391922944)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <Thread(Thread-12, started 139773045888768)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 139773066868480)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 139773620684544)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 139773631174400)>
>MainThread::INFO::2012-11-20 06:19:30,279::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 139773402412800)>
>Thread-12::DEBUG::2012-11-20 06:19:30,288::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:30,288::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:30,288::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:30,300::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:30,300::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:30,300::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:30,301::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:30,301::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:30,301::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:30,563::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:30,563::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:30,564::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:30,564::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py ae65c760-a47a-4395-8063-fa4bdcd9169a 2169' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:31,051::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:31,052::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:31,052::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:31,052::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:31,052::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:31,053::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:31,053::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:32,568::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:32,604::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:32,606::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:32,608::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:34,610::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:34,661::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:34,661::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,662::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,662::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,662::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,663::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,663::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,663::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:34,664::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:34,717::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:34,851::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:34,851::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:34,853::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:34,860::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:34,872::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:34,872::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:34,872::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:34,873::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:34,883::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:34,883::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:34,885::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:34,885::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:34,885::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:34,887::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:34,888::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:34,890::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,890::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:34,899::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:34,900::task::588::TaskManager.Task::(_updateState) Task=`d6d77b05-209c-4124-85cf-d37e672d19dc`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:34,900::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:34,900::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:34,910::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:34,910::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:34,911::task::1172::TaskManager.Task::(prepare) Task=`d6d77b05-209c-4124-85cf-d37e672d19dc`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:34,911::task::588::TaskManager.Task::(_updateState) Task=`d6d77b05-209c-4124-85cf-d37e672d19dc`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:34,911::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:34,911::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:34,911::task::978::TaskManager.Task::(_decref) Task=`d6d77b05-209c-4124-85cf-d37e672d19dc`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:34,912::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:34,912::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:34,912::vdsm::78::vds::(run) <_MainThread(MainThread, started 140026002470656)>
>Thread-12::DEBUG::2012-11-20 06:19:34,915::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:34,916::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,916::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,916::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:19:34,912::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140025776084736)>
>MainThread::INFO::2012-11-20 06:19:34,919::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140025622673152)>
>MainThread::INFO::2012-11-20 06:19:34,919::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140025184380672)>
>MainThread::INFO::2012-11-20 06:19:34,919::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140025633163008)>
>MainThread::INFO::2012-11-20 06:19:34,919::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140025643652864)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140025612183296)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140025744713472)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140025664632576)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140025194870528)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140025142421248)>
>MainThread::INFO::2012-11-20 06:19:34,920::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140025173890816)>
>MainThread::INFO::2012-11-20 06:19:34,921::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140025654142720)>
>MainThread::INFO::2012-11-20 06:19:34,921::vdsm::78::vds::(run) <Thread(Thread-12, started 140025152911104)>
>Thread-12::DEBUG::2012-11-20 06:19:34,932::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:34,932::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:34,933::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:34,945::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:34,945::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:34,945::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:34,946::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:34,946::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:34,946::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:34,956::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:34,956::misc::1054::SamplingMethod::(__call__) Returning last result
>MainThread::INFO::2012-11-20 06:19:36,950::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:37,086::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:37,086::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:37,088::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:37,095::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:37,106::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:37,106::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:37,106::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:37,107::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:37,117::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:37,117::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:37,119::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:37,119::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:37,119::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:37,120::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:37,121::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:37,123::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:37,124::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:37,134::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:37,134::task::588::TaskManager.Task::(_updateState) Task=`2871d783-566f-48e1-b8b2-2d9d37f6a1fa`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:37,134::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:37,135::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:37,144::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:37,145::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:37,145::task::1172::TaskManager.Task::(prepare) Task=`2871d783-566f-48e1-b8b2-2d9d37f6a1fa`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:37,145::task::588::TaskManager.Task::(_updateState) Task=`2871d783-566f-48e1-b8b2-2d9d37f6a1fa`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:37,145::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:37,145::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:37,145::task::978::TaskManager.Task::(_decref) Task=`2871d783-566f-48e1-b8b2-2d9d37f6a1fa`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:37,146::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:37,146::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:37,146::vdsm::78::vds::(run) <_MainThread(MainThread, started 140019336926976)>
>Thread-12::DEBUG::2012-11-20 06:19:37,153::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:37,153::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:37,153::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:37,154::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:19:37,156::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140019110541056)>
>MainThread::INFO::2012-11-20 06:19:37,156::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140018576242432)>
>MainThread::INFO::2012-11-20 06:19:37,156::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140018607712000)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140018586732288)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140018473494272)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140018597222144)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140019010840320)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140018968880896)>
>MainThread::INFO::2012-11-20 06:19:37,157::vdsm::78::vds::(run) <Thread(Thread-12, started 140018483984128)>
>MainThread::INFO::2012-11-20 06:19:37,158::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140018618201856)>
>MainThread::INFO::2012-11-20 06:19:37,158::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140018989860608)>
>MainThread::INFO::2012-11-20 06:19:37,158::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140019000350464)>
>MainThread::INFO::2012-11-20 06:19:37,158::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140018979370752)>
>Thread-12::DEBUG::2012-11-20 06:19:37,169::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:37,169::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:37,169::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:37,180::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:37,180::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:37,180::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:37,181::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:37,181::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:37,181::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:37,193::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:37,193::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:37,194::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:37,194::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 3fadfea7-0696-444f-9a03-94a93df7a541 2315' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:37,306::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:37,307::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:37,307::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:37,307::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:37,307::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:37,308::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:37,308::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:39,198::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:39,205::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:39,208::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:39,211::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:41,214::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:41,228::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:41,228::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,229::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,229::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,229::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,230::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,230::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,230::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:41,231::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:41,283::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:41,421::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:41,422::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:41,423::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:41,430::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:41,442::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:41,442::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:41,442::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:41,443::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:41,453::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:41,453::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:41,455::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:41,455::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:41,455::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:41,456::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:41,457::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:41,459::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,460::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:41,468::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:41,469::task::588::TaskManager.Task::(_updateState) Task=`5955c631-2cd7-4ca0-b57f-1daea0bd2258`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:41,469::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:41,469::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:41,479::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:41,479::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:41,480::task::1172::TaskManager.Task::(prepare) Task=`5955c631-2cd7-4ca0-b57f-1daea0bd2258`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:41,480::task::588::TaskManager.Task::(_updateState) Task=`5955c631-2cd7-4ca0-b57f-1daea0bd2258`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:41,480::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:41,480::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:41,480::task::978::TaskManager.Task::(_decref) Task=`5955c631-2cd7-4ca0-b57f-1daea0bd2258`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:41,481::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:41,481::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:41,481::vdsm::78::vds::(run) <_MainThread(MainThread, started 140563663881984)>
>Thread-12::DEBUG::2012-11-20 06:19:41,484::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:41,484::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,485::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,485::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:19:41,481::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140563437496064)>
>MainThread::INFO::2012-11-20 06:19:41,488::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140562927707904)>
>MainThread::INFO::2012-11-20 06:19:41,488::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140562917218048)>
>MainThread::INFO::2012-11-20 06:19:41,488::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140562906728192)>
>MainThread::INFO::2012-11-20 06:19:41,488::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140563286251264)>
>MainThread::INFO::2012-11-20 06:19:41,488::vdsm::78::vds::(run) <Thread(Thread-12, started 140562885748480)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140563296741120)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140562938197760)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140563317720832)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140562736871168)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140563328210688)>
>MainThread::INFO::2012-11-20 06:19:41,489::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140563307230976)>
>MainThread::INFO::2012-11-20 06:19:41,490::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140563338700544)>
>Thread-12::DEBUG::2012-11-20 06:19:41,498::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:41,498::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:41,498::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:41,511::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:41,511::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:41,511::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:41,512::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:41,512::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:41,512::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:41,524::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:41,524::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:41,525::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:41,525::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 29d23096-7f4d-4739-b290-26849d2d2b49 2369' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:41,639::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:41,639::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:41,639::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:41,640::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:41,640::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:41,640::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:41,641::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:43,529::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:43,535::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:43,537::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:43,540::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:45,542::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:45,553::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:45,553::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,553::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,554::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,554::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,554::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,554::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,554::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:45,555::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:45,607::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:45,741::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:45,741::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:45,743::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:45,750::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:45,762::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:45,762::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:45,762::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:45,763::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:45,773::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:45,773::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:45,774::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:45,775::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:45,775::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:45,776::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:45,777::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:45,779::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,779::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:45,788::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:45,788::task::588::TaskManager.Task::(_updateState) Task=`6b816f3f-c57e-480f-aa85-6cd6e6303a89`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:45,789::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:45,789::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:45,799::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:45,799::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:45,799::task::1172::TaskManager.Task::(prepare) Task=`6b816f3f-c57e-480f-aa85-6cd6e6303a89`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:45,799::task::588::TaskManager.Task::(_updateState) Task=`6b816f3f-c57e-480f-aa85-6cd6e6303a89`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:45,799::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:45,800::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:45,800::task::978::TaskManager.Task::(_decref) Task=`6b816f3f-c57e-480f-aa85-6cd6e6303a89`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:45,800::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>Thread-12::DEBUG::2012-11-20 06:19:45,803::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:45,803::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,804::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,804::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:19:45,806::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:45,807::vdsm::78::vds::(run) <_MainThread(MainThread, started 140200190588672)>
>MainThread::INFO::2012-11-20 06:19:45,807::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140199964202752)>
>MainThread::INFO::2012-11-20 06:19:45,807::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140199434630912)>
>MainThread::INFO::2012-11-20 06:19:45,807::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140199466100480)>
>MainThread::INFO::2012-11-20 06:19:45,807::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140199445120768)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140199455610624)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140199865001728)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140199823042304)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140199476590336)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140199331882752)>
>MainThread::INFO::2012-11-20 06:19:45,808::vdsm::78::vds::(run) <Thread(Thread-12, started 140199342372608)>
>MainThread::INFO::2012-11-20 06:19:45,809::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140199844022016)>
>MainThread::INFO::2012-11-20 06:19:45,809::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140199854511872)>
>MainThread::INFO::2012-11-20 06:19:45,809::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140199833532160)>
>Thread-12::DEBUG::2012-11-20 06:19:45,817::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:45,817::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:45,817::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:45,828::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:45,828::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:45,828::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:45,829::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:45,829::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:45,829::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:45,841::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:45,841::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:45,842::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:45,842::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py eb10353b-e719-48cc-8bd1-92b998e825f8 2423' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:45,953::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:45,954::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:45,954::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:45,954::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:45,954::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:45,955::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:45,955::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:47,846::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:47,853::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:47,856::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:47,858::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:49,861::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:49,879::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:49,879::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,880::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,880::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,880::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,881::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,881::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:49,881::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:49,882::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:49,936::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:50,074::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:50,074::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:50,076::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:50,083::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:50,095::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:50,095::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:50,095::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:50,096::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:50,106::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:50,106::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:50,108::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:50,108::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:50,108::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:50,109::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:50,110::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:50,112::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:50,113::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:50,122::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:50,123::task::588::TaskManager.Task::(_updateState) Task=`23b026ed-6b94-4241-859f-dca921475d27`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:50,123::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:50,123::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:50,130::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:50,130::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:50,130::task::1172::TaskManager.Task::(prepare) Task=`23b026ed-6b94-4241-859f-dca921475d27`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:50,131::task::588::TaskManager.Task::(_updateState) Task=`23b026ed-6b94-4241-859f-dca921475d27`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:50,131::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:50,131::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:50,131::task::978::TaskManager.Task::(_decref) Task=`23b026ed-6b94-4241-859f-dca921475d27`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:50,131::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:50,135::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:50,135::vdsm::78::vds::(run) <_MainThread(MainThread, started 140199939626752)>
>MainThread::INFO::2012-11-20 06:19:50,135::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140199713240832)>
>MainThread::INFO::2012-11-20 06:19:50,135::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140199568848640)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140199197665024)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140199579338496)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140199176685312)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140199187175168)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140199558358784)>
>MainThread::INFO::2012-11-20 06:19:50,136::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140199006828288)>
>MainThread::INFO::2012-11-20 06:19:50,137::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140199600318208)>
>MainThread::INFO::2012-11-20 06:19:50,137::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140199610808064)>
>MainThread::INFO::2012-11-20 06:19:50,137::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140199208154880)>
>MainThread::INFO::2012-11-20 06:19:50,137::vdsm::78::vds::(run) <Thread(Thread-12, started 140199155705600)>
>MainThread::INFO::2012-11-20 06:19:50,137::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140199589828352)>
>Thread-12::DEBUG::2012-11-20 06:19:50,144::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:50,144::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:50,144::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:50,145::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:50,158::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:50,158::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:50,159::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:50,172::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:50,172::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:50,172::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:50,173::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:50,173::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:50,173::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:50,186::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:50,186::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:50,187::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:50,187::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py e6029b60-30d6-4f66-996d-c30a6ec7db64 2477' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:50,297::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:50,298::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:50,298::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:50,298::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:50,298::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:50,299::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:50,299::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:52,192::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:52,199::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:52,202::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:52,204::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:54,207::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:54,230::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:54,230::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,231::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,231::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,231::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,231::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,232::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,232::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:54,232::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:54,285::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:54,421::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:54,422::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:54,424::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:54,431::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:54,444::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:54,444::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:54,444::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:54,445::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:54,455::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:54,455::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:54,457::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:54,457::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:54,457::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:54,458::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:54,459::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:54,461::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,461::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:54,470::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:54,470::task::588::TaskManager.Task::(_updateState) Task=`079e7ab4-2c1c-4fb9-bc9e-4a4b47543aba`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:54,471::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:54,471::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:54,478::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:54,478::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:54,478::task::1172::TaskManager.Task::(prepare) Task=`079e7ab4-2c1c-4fb9-bc9e-4a4b47543aba`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:54,478::task::588::TaskManager.Task::(_updateState) Task=`079e7ab4-2c1c-4fb9-bc9e-4a4b47543aba`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:54,482::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:54,482::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:54,482::task::978::TaskManager.Task::(_decref) Task=`079e7ab4-2c1c-4fb9-bc9e-4a4b47543aba`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:54,482::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:54,483::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:54,483::vdsm::78::vds::(run) <_MainThread(MainThread, started 139677174036224)>
>MainThread::INFO::2012-11-20 06:19:54,483::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 139676947650304)>
>MainThread::INFO::2012-11-20 06:19:54,483::vdsm::78::vds::(run) <Thread(Thread-12, started 139676321036032)>
>MainThread::INFO::2012-11-20 06:19:54,483::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 139676790798080)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 139676822267648)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 139676801287936)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 139676342015744)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 139676780308224)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 139676916279040)>
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 139676832757504)>
>Thread-12::DEBUG::2012-11-20 06:19:54,487::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:54,488::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,488::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,488::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:19:54,484::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 139676352505600)>
>MainThread::INFO::2012-11-20 06:19:54,491::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 139676362995456)>
>MainThread::INFO::2012-11-20 06:19:54,491::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 139676310546176)>
>MainThread::INFO::2012-11-20 06:19:54,491::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 139676811777792)>
>Thread-12::DEBUG::2012-11-20 06:19:54,502::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:54,502::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:54,502::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:54,515::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:54,515::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:54,515::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:54,516::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:54,516::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:54,516::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:54,528::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:54,528::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:54,529::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:54,529::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py d47ed77c-3e19-48e3-a5b8-88c9cb9ed195 2531' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:54,640::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:54,640::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:54,640::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:54,641::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:54,641::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:54,641::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:54,642::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:19:56,533::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:56,540::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:56,543::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:19:56,544::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:19:58,547::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:58,559::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:58,559::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,560::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,560::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,560::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,561::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,561::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,561::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:19:58,562::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:19:58,614::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:19:58,754::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:19:58,755::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:19:58,757::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:19:58,764::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:58,776::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:19:58,776::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:19:58,776::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:19:58,777::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:58,787::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:19:58,787::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:19:58,789::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:19:58,789::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:19:58,789::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:19:58,790::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:19:58,791::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:19:58,793::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,794::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:19:58,803::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:19:58,803::task::588::TaskManager.Task::(_updateState) Task=`e7d2a389-9672-4a2e-ad1b-b7ffea52712f`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:19:58,804::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:19:58,804::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:19:58,811::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:19:58,811::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:19:58,811::task::1172::TaskManager.Task::(prepare) Task=`e7d2a389-9672-4a2e-ad1b-b7ffea52712f`::finished: None
>MainThread::DEBUG::2012-11-20 06:19:58,811::task::588::TaskManager.Task::(_updateState) Task=`e7d2a389-9672-4a2e-ad1b-b7ffea52712f`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:19:58,811::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:19:58,812::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:19:58,812::task::978::TaskManager.Task::(_decref) Task=`e7d2a389-9672-4a2e-ad1b-b7ffea52712f`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:19:58,812::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::78::vds::(run) <_MainThread(MainThread, started 139871711823616)>
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 139871485437696)>
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 139871339394816)>
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::78::vds::(run) <Thread(Thread-12, started 139870926251776)>
>MainThread::INFO::2012-11-20 06:19:58,816::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 139871349884672)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 139870947231488)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 139871360374528)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 139870978701056)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 139871328904960)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 139870777374464)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 139870968211200)>
>MainThread::INFO::2012-11-20 06:19:58,817::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 139871381354240)>
>MainThread::INFO::2012-11-20 06:19:58,818::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 139870957721344)>
>MainThread::INFO::2012-11-20 06:19:58,818::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 139871370864384)>
>Thread-12::DEBUG::2012-11-20 06:19:58,825::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:58,825::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,825::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,826::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:58,839::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:58,839::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:19:58,840::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:58,851::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:19:58,851::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:19:58,851::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:58,852::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:19:58,852::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:19:58,852::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:19:58,865::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:19:58,865::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:19:58,866::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:19:58,866::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 02acd521-9795-4c4c-9d09-2095b43e3215 2585' (cwd None)
>MainThread::DEBUG::2012-11-20 06:19:58,979::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:19:58,980::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:19:58,980::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:19:58,980::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:19:58,980::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:19:58,981::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:19:58,981::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:20:00,871::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:00,878::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:00,881::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:00,883::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:20:02,886::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:20:02,912::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:20:02,912::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,913::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,913::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,913::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,913::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,913::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:02,914::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:20:02,914::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>MainThread::INFO::2012-11-20 06:20:02,966::vdsm::70::vds::(run) I am the actual vdsm 4.9-32
>MainThread::DEBUG::2012-11-20 06:20:03,104::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2012-11-20 06:20:03,104::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2012-11-20 06:20:03,106::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2012-11-20 06:20:03,113::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2012-11-20 06:20:03,125::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2012-11-20 06:20:03,125::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2012-11-20 06:20:03,125::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2012-11-20 06:20:03,126::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2012-11-20 06:20:03,137::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2012-11-20 06:20:03,137::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2012-11-20 06:20:03,139::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2012-11-20 06:20:03,139::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2012-11-20 06:20:03,139::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2012-11-20 06:20:03,140::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2012-11-20 06:20:03,141::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2012-11-20 06:20:03,143::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:03,144::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::ERROR::2012-11-20 06:20:03,152::clientIF::102::vds::(__init__) failed to init clientIF, shutting down storage dispatcher
>MainThread::DEBUG::2012-11-20 06:20:03,152::task::588::TaskManager.Task::(_updateState) Task=`f7e839c0-af8e-4f40-bd72-324f296d855d`::moving from state init -> state preparing
>MainThread::INFO::2012-11-20 06:20:03,153::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2012-11-20 06:20:03,153::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2012-11-20 06:20:03,163::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2012-11-20 06:20:03,163::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2012-11-20 06:20:03,163::task::1172::TaskManager.Task::(prepare) Task=`f7e839c0-af8e-4f40-bd72-324f296d855d`::finished: None
>MainThread::DEBUG::2012-11-20 06:20:03,163::task::588::TaskManager.Task::(_updateState) Task=`f7e839c0-af8e-4f40-bd72-324f296d855d`::moving from state preparing -> state finished
>MainThread::DEBUG::2012-11-20 06:20:03,163::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2012-11-20 06:20:03,164::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2012-11-20 06:20:03,164::task::978::TaskManager.Task::(_decref) Task=`f7e839c0-af8e-4f40-bd72-324f296d855d`::ref 0 aborting False
>MainThread::ERROR::2012-11-20 06:20:03,164::vdsm::73::vds::(run) Exception raised
>Traceback (most recent call last):
>  File "/usr/share/vdsm/vdsm", line 71, in run
>    serve_clients(log)
>  File "/usr/share/vdsm/vdsm", line 39, in serve_clients
>    cif = clientIF.clientIF(log)
>  File "/usr/share/vdsm/clientIF.py", line 87, in __init__
>    caps.CpuTopology().cores())
>  File "/usr/share/vdsm/caps.py", line 87, in __init__
>    self._topology = _getCpuTopology(capabilities)
>  File "/usr/lib64/python2.6/site-packages/vdsm/utils.py", line 799, in __call__
>    value = self.func(*args)
>  File "/usr/share/vdsm/caps.py", line 115, in _getCpuTopology
>    'sockets': int(cpu.getElementsByTagName('topology')[0].
>IndexError: list index out of range
>Thread-12::DEBUG::2012-11-20 06:20:03,167::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:20:03,167::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:03,168::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:03,168::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::INFO::2012-11-20 06:20:03,167::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <_MainThread(MainThread, started 140659471955712)>
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140659245569792)>
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140658929022720)>
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140658939512576)>
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <HostStatsThread(Thread-13, started 140658603968256)>
>MainThread::INFO::2012-11-20 06:20:03,171::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140658950002432)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140658918532864)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140658960492288)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140658970982144)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140658635437824)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140659193218816)>
>MainThread::INFO::2012-11-20 06:20:03,172::vdsm::78::vds::(run) <Thread(Thread-12, started 140658614458112)>
>MainThread::INFO::2012-11-20 06:20:03,173::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140659203708672)>
>MainThread::INFO::2012-11-20 06:20:03,173::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140659214198528)>
>Thread-12::DEBUG::2012-11-20 06:20:03,181::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:20:03,181::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:03,181::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:20:03,192::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:20:03,192::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2012-11-20 06:20:03,192::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:20:03,193::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2012-11-20 06:20:03,193::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2012-11-20 06:20:03,193::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:20:03,205::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2012-11-20 06:20:03,205::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2012-11-20 06:20:03,206::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2012-11-20 06:20:03,206::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 129ac090-f252-465f-8e2c-c4833c946ca5 2641' (cwd None)
>MainThread::DEBUG::2012-11-20 06:20:03,320::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2012-11-20 06:20:03,320::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2012-11-20 06:20:03,320::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2012-11-20 06:20:03,320::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2012-11-20 06:20:03,321::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2012-11-20 06:20:03,321::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2012-11-20 06:20:03,322::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2012-11-20 06:20:05,210::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:05,216::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:05,217::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2012-11-20 06:20:05,219::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2012-11-20 06:20:07,222::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2012-11-20 06:20:07,235::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2012-11-20 06:20:07,235::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,236::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,236::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,236::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,236::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,236::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2012-11-20 06:20:07,237::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2012-11-20 06:20:07,237::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists

Actions: View

Attachments on bug 878327: 648291