Re: [Users] Error installing self hosted engine

------=_Part_594693_2003216810.1396362976018 Content-Type: multipart/alternative; boundary="----=_Part_594692_1360520117.1396362976018" ------=_Part_594692_1360520117.1396362976018 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Thank you. I have attached the logfiles (mom.log, supervdsm.log, vdsm.log). metadata.log is empty ------=_Part_594692_1360520117.1396362976018-- ------=_Part_594693_2003216810.1396362976018 Content-Type: text/x-log Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename=vdsm.log MainThread::INFO::2014-04-01 12:50:15,497::vdsm::119::vds::(run) (PID: 5366) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 12:50:15,498::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 12:50:15,499::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 12:50:15,504::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 12:50:15,994::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 12:50:16,020::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 12:50:16,020::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 12:50:16,211::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 12:50:16,212::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 12:50:16,216::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 12:50:16,217::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 12:50:16,217::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 12:50:16,218::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' storageRefresh::DEBUG::2014-04-01 12:50:16,218::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) MainThread::INFO::2014-04-01 12:50:16,220::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 12:50:16,235::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 12:50:16,240::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 12:50:16,254::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 12:50:16,255::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 12:50:16,257::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 12:50:16,273::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 12:50:16,274::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 12:50:16,302::task::595::TaskManager.Task::(_updateState) Task=`e024f2c2-4487-4115-869a-954a2d3eb26f`::moving from state init -> state preparing MainThread::INFO::2014-04-01 12:50:16,302::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x2d27fc8>>) MainThread::INFO::2014-04-01 12:50:16,303::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 12:50:16,303::task::1185::TaskManager.Task::(prepare) Task=`e024f2c2-4487-4115-869a-954a2d3eb26f`::finished: None MainThread::DEBUG::2014-04-01 12:50:16,303::task::595::TaskManager.Task::(_updateState) Task=`e024f2c2-4487-4115-869a-954a2d3eb26f`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 12:50:16,303::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 12:50:16,303::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 12:50:16,303::task::990::TaskManager.Task::(_decref) Task=`e024f2c2-4487-4115-869a-954a2d3eb26f`::ref 0 aborting False MainThread::INFO::2014-04-01 12:50:16,312::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 12:50:16,318::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 12:50:16,349::vmChannels::170::vds::(run) Starting VM channels listener thread. clientIFinit::DEBUG::2014-04-01 12:50:16,350::libvirtconnection::145::root::(get) trying to connect libvirt MainThread::WARNING::2014-04-01 12:50:16,363::clientIF::181::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. storageRefresh::DEBUG::2014-04-01 12:50:16,379::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:50:16,381::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,381::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,382::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,382::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,382::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,383::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,383::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 12:50:16,383::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,387::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 12:50:16,564::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:50:16,567::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,570::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,581::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 12:50:16,729::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:50:16,729::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,730::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 12:50:16,873::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:50:16,873::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:50:16,874::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 12:50:17,016::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:50:17,017::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 12:50:17,017::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 12:50:17,018::hsm::391::Storage.HSM::(storageRefresh) HSM is ready MainThread::DEBUG::2014-04-01 12:50:31,127::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 12:50:31,387::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 12:50:31,387::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 12:50:31,388::task::595::TaskManager.Task::(_updateState) Task=`a07b1802-4b0c-4e13-ba61-7a95b67c2c00`::moving from state init -> state preparing MainThread::INFO::2014-04-01 12:50:31,389::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 12:50:31,389::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped MainThread::INFO::2014-04-01 12:50:31,882::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 12:50:31,882::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 12:50:31,907::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 12:50:31,907::task::1185::TaskManager.Task::(prepare) Task=`a07b1802-4b0c-4e13-ba61-7a95b67c2c00`::finished: None MainThread::DEBUG::2014-04-01 12:50:31,907::task::595::TaskManager.Task::(_updateState) Task=`a07b1802-4b0c-4e13-ba61-7a95b67c2c00`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 12:50:31,907::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 12:50:31,908::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 12:50:31,908::task::990::TaskManager.Task::(_decref) Task=`a07b1802-4b0c-4e13-ba61-7a95b67c2c00`::ref 0 aborting False MainThread::INFO::2014-04-01 12:50:31,908::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 14 other threads... MainThread::INFO::2014-04-01 12:50:31,908::vdsm::129::vds::(run) <_MainThread(MainThread, started 140606334629632)> MainThread::INFO::2014-04-01 12:50:31,908::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 140606066681600)> MainThread::INFO::2014-04-01 12:50:31,908::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 140605820761856)> MainThread::INFO::2014-04-01 12:50:31,908::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 140605298550528)> MainThread::INFO::2014-04-01 12:50:31,909::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 12:50:31,909::vdsm::129::vds::(run) <MomThread(MOM, started 140605309040384)> MainThread::INFO::2014-04-01 12:50:31,909::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 140605789292288)> MainThread::INFO::2014-04-01 12:50:31,909::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 12:50:31,909::vdsm::129::vds::(run) <Listener(VM Channels Listener, started daemon 140604881237760)> MainThread::INFO::2014-04-01 12:50:31,909::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 140605350999808)> MainThread::INFO::2014-04-01 12:50:31,909::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 140606035212032)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 140606045701888)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 140606056191744)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 140605799782144)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 140605778802432)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 140605768312576)> MainThread::INFO::2014-04-01 12:50:31,910::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 140605810272000)> VM Channels Listener::INFO::2014-04-01 12:50:32,368::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 12:52:42,089::vdsm::119::vds::(run) (PID: 1954) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 12:52:42,093::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 12:52:42,093::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 12:52:42,105::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 12:52:42,618::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 12:52:42,650::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 12:52:42,650::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 12:52:42,844::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 12:52:42,844::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 12:52:42,848::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 12:52:42,849::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 12:52:42,849::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 12:52:42,850::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' storageRefresh::DEBUG::2014-04-01 12:52:42,850::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) MainThread::INFO::2014-04-01 12:52:42,852::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 12:52:43,018::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 12:52:43,021::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 12:52:43,088::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 12:52:43,088::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 12:52:43,089::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 12:52:43,157::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 12:52:43,158::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 12:52:43,225::task::595::TaskManager.Task::(_updateState) Task=`7c021db9-d327-4ca2-8f58-5ab2bd8dcf2f`::moving from state init -> state preparing MainThread::INFO::2014-04-01 12:52:43,225::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x11dc098>>) MainThread::INFO::2014-04-01 12:52:43,225::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 12:52:43,226::task::1185::TaskManager.Task::(prepare) Task=`7c021db9-d327-4ca2-8f58-5ab2bd8dcf2f`::finished: None MainThread::DEBUG::2014-04-01 12:52:43,226::task::595::TaskManager.Task::(_updateState) Task=`7c021db9-d327-4ca2-8f58-5ab2bd8dcf2f`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 12:52:43,226::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 12:52:43,226::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 12:52:43,227::task::990::TaskManager.Task::(_decref) Task=`7c021db9-d327-4ca2-8f58-5ab2bd8dcf2f`::ref 0 aborting False storageRefresh::DEBUG::2014-04-01 12:52:43,228::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:52:43,229::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,229::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,229::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,229::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,230::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,230::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,230::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 12:52:43,230::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,233::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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::INFO::2014-04-01 12:52:43,244::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 12:52:43,253::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 12:52:43,255::vmChannels::170::vds::(run) Starting VM channels listener thread. MainThread::WARNING::2014-04-01 12:52:43,396::clientIF::181::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. clientIFinit::DEBUG::2014-04-01 12:52:43,399::libvirtconnection::145::root::(get) trying to connect libvirt storageRefresh::DEBUG::2014-04-01 12:52:43,417::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:52:43,418::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,418::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,419::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 12:52:43,575::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:52:43,578::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,606::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 12:52:43,767::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:52:43,767::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 12:52:43,768::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 12:52:43,930::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 12:52:43,930::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 12:52:43,931::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 12:52:43,939::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-13::DEBUG::2014-04-01 12:55:50,786::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 12:55:50,929::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-14::DEBUG::2014-04-01 13:02:22,261::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-14::DEBUG::2014-04-01 13:02:22,285::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-15::DEBUG::2014-04-01 13:04:41,953::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-15::DEBUG::2014-04-01 13:04:41,955::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-16::DEBUG::2014-04-01 13:04:49,768::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-16::DEBUG::2014-04-01 13:04:49,777::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-17::DEBUG::2014-04-01 13:06:19,190::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-04-01 13:06:19,192::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} MainThread::DEBUG::2014-04-01 13:11:01,685::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 13:11:02,459::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 13:11:02,460::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 13:11:02,460::task::595::TaskManager.Task::(_updateState) Task=`45e391ef-1ad3-4a09-a344-988a3172b11e`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:11:02,461::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 13:11:02,462::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped VM Channels Listener::INFO::2014-04-01 13:11:02,601::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 13:11:02,971::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 13:11:02,971::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 13:11:02,971::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 13:11:02,971::task::1185::TaskManager.Task::(prepare) Task=`45e391ef-1ad3-4a09-a344-988a3172b11e`::finished: None MainThread::DEBUG::2014-04-01 13:11:02,971::task::595::TaskManager.Task::(_updateState) Task=`45e391ef-1ad3-4a09-a344-988a3172b11e`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:11:02,971::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:11:02,972::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:11:02,972::task::990::TaskManager.Task::(_decref) Task=`45e391ef-1ad3-4a09-a344-988a3172b11e`::ref 0 aborting False MainThread::INFO::2014-04-01 13:11:02,972::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 15 other threads... MainThread::INFO::2014-04-01 13:11:02,972::vdsm::129::vds::(run) <_MainThread(MainThread, started 139901802637056)> MainThread::INFO::2014-04-01 13:11:02,972::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 139901535491840)> MainThread::INFO::2014-04-01 13:11:02,972::vdsm::129::vds::(run) <GuestManager(GuestManager, started daemon 139900036839168)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 139901446125312)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 139901525001984)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 139901404165888)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 139900965873408)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 139901414655744)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 139901425145600)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 139900496111360)> MainThread::INFO::2014-04-01 13:11:02,973::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 139900976363264)> MainThread::INFO::2014-04-01 13:11:02,974::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 139900955383552)> MainThread::INFO::2014-04-01 13:11:02,974::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 139901393676032)> MainThread::INFO::2014-04-01 13:11:02,974::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 139901435635456)> MainThread::INFO::2014-04-01 13:11:02,974::vdsm::129::vds::(run) <HostMonitor(HostMonitor, started daemon 139900453762816)> MainThread::INFO::2014-04-01 13:11:02,974::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 13:11:02,974::vdsm::129::vds::(run) <MomThread(MOM, started 139900506601216)> MainThread::INFO::2014-04-01 13:11:10,078::vdsm::119::vds::(run) (PID: 3343) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 13:11:10,080::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 13:11:10,080::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 13:11:10,086::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 13:11:10,586::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 13:11:10,616::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 13:11:10,616::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 13:11:10,809::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 13:11:10,809::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 13:11:10,814::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 13:11:10,814::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 13:11:10,814::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 13:11:10,815::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' storageRefresh::DEBUG::2014-04-01 13:11:10,816::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) MainThread::INFO::2014-04-01 13:11:10,817::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 13:11:10,818::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:11:10,838::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 13:11:10,841::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:11:10,848::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 13:11:10,855::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 13:11:10,871::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:11:10,872::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 13:11:10,906::task::595::TaskManager.Task::(_updateState) Task=`1bb370e2-557f-4392-93f8-2120ebe30369`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:11:10,907::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x2c8bfc8>>) MainThread::INFO::2014-04-01 13:11:10,907::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 13:11:10,907::task::1185::TaskManager.Task::(prepare) Task=`1bb370e2-557f-4392-93f8-2120ebe30369`::finished: None MainThread::DEBUG::2014-04-01 13:11:10,907::task::595::TaskManager.Task::(_updateState) Task=`1bb370e2-557f-4392-93f8-2120ebe30369`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:11:10,908::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:11:10,908::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:11:10,908::task::990::TaskManager.Task::(_decref) Task=`1bb370e2-557f-4392-93f8-2120ebe30369`::ref 0 aborting False MainThread::INFO::2014-04-01 13:11:10,917::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 13:11:10,927::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 13:11:10,936::vmChannels::170::vds::(run) Starting VM channels listener thread. clientIFinit::DEBUG::2014-04-01 13:11:10,959::libvirtconnection::145::root::(get) trying to connect libvirt MainThread::WARNING::2014-04-01 13:11:10,979::clientIF::181::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. storageRefresh::DEBUG::2014-04-01 13:11:10,993::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:11:10,994::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,994::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,994::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,995::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,995::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,995::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,996::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:11:10,996::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:10,999::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:11:11,209::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:11:11,212::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:11,215::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:11,249::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:11:11,396::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:11:11,396::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:11,397::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:11:11,539::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:11:11,540::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:11:11,540::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:11:11,682::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:11:11,683::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 13:11:11,684::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 13:11:11,685::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-13::DEBUG::2014-04-01 13:11:22,955::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 13:11:23,031::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} MainThread::DEBUG::2014-04-01 13:13:29,535::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 13:13:30,050::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 13:13:30,050::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 13:13:30,051::task::595::TaskManager.Task::(_updateState) Task=`94e511a0-85eb-48d4-beae-cdd00fac1cbe`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:13:30,051::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 13:13:30,052::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped VM Channels Listener::INFO::2014-04-01 13:13:30,105::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 13:13:30,540::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 13:13:30,540::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 13:13:30,540::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 13:13:30,540::task::1185::TaskManager.Task::(prepare) Task=`94e511a0-85eb-48d4-beae-cdd00fac1cbe`::finished: None MainThread::DEBUG::2014-04-01 13:13:30,541::task::595::TaskManager.Task::(_updateState) Task=`94e511a0-85eb-48d4-beae-cdd00fac1cbe`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:13:30,541::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:13:30,541::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:13:30,541::task::990::TaskManager.Task::(_decref) Task=`94e511a0-85eb-48d4-beae-cdd00fac1cbe`::ref 0 aborting False MainThread::INFO::2014-04-01 13:13:30,541::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 15 other threads... MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <_MainThread(MainThread, started 140616788940544)> MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 140616522061568)> MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 140616423962368)> MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <GuestManager(GuestManager, started daemon 140615429867264)> MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <HostMonitor(HostMonitor, started daemon 140615440357120)> MainThread::INFO::2014-04-01 13:13:30,542::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <MomThread(MOM, started 140615484438272)> MainThread::INFO::2014-04-01 13:13:30,542::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 140616371513088)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 140616382002944)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 140615943710464)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 140616392492800)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 140615473948416)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 140615954200320)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 140616402982656)> MainThread::INFO::2014-04-01 13:13:30,543::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 140616413472512)> MainThread::INFO::2014-04-01 13:13:30,544::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 140616511571712)> MainThread::INFO::2014-04-01 13:13:30,544::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 140615933220608)> MainThread::INFO::2014-04-01 13:16:43,521::vdsm::119::vds::(run) (PID: 4430) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 13:16:43,522::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 13:16:43,523::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::DEBUG::2014-04-01 13:16:44,023::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 13:16:44,054::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 13:16:44,054::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 13:16:44,258::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 13:16:44,259::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 13:16:44,264::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 13:16:44,264::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 13:16:44,265::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 13:16:44,266::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' storageRefresh::DEBUG::2014-04-01 13:16:44,267::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) MainThread::INFO::2014-04-01 13:16:44,269::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 13:16:44,269::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:16:44,292::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 13:16:44,300::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:16:44,306::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 13:16:44,307::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 13:16:44,325::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:16:44,326::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 13:16:44,354::task::595::TaskManager.Task::(_updateState) Task=`a3b79013-b275-4de1-b015-9e11f01a74a5`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:16:44,354::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x20ee9e0>>) MainThread::INFO::2014-04-01 13:16:44,354::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 13:16:44,354::task::1185::TaskManager.Task::(prepare) Task=`a3b79013-b275-4de1-b015-9e11f01a74a5`::finished: None MainThread::DEBUG::2014-04-01 13:16:44,355::task::595::TaskManager.Task::(_updateState) Task=`a3b79013-b275-4de1-b015-9e11f01a74a5`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:16:44,355::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:16:44,355::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:16:44,355::task::990::TaskManager.Task::(_decref) Task=`a3b79013-b275-4de1-b015-9e11f01a74a5`::ref 0 aborting False MainThread::INFO::2014-04-01 13:16:44,367::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 13:16:44,377::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 13:16:44,381::vmChannels::170::vds::(run) Starting VM channels listener thread. clientIFinit::DEBUG::2014-04-01 13:16:44,399::libvirtconnection::145::root::(get) trying to connect libvirt MainThread::WARNING::2014-04-01 13:16:44,417::clientIF::181::vds::(_prepareBindings) Unable to load the json rpc server module. Please make sure it is installed. storageRefresh::DEBUG::2014-04-01 13:16:44,448::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:16:44,451::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,454::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,457::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,463::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,470::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,476::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,481::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:16:44,488::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,524::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:16:44,705::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:16:44,709::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,712::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,720::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:16:44,863::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:16:44,863::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:44,864::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:16:45,006::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:16:45,007::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:45,008::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:16:45,149::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:16:45,150::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:16:45,151::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-13::DEBUG::2014-04-01 13:16:45,271::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 13:16:45,344::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-14::DEBUG::2014-04-01 13:20:39,283::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-14::DEBUG::2014-04-01 13:20:39,297::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-15::DEBUG::2014-04-01 13:21:11,414::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-15::DEBUG::2014-04-01 13:21:11,423::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} MainThread::DEBUG::2014-04-01 13:22:10,217::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 13:22:10,439::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 13:22:10,439::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 13:22:10,440::task::595::TaskManager.Task::(_updateState) Task=`d46a208f-52dd-4136-9bcf-faa8cc47c55f`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:22:10,440::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 13:22:10,441::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped VM Channels Listener::INFO::2014-04-01 13:22:10,785::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 13:22:10,889::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 13:22:10,889::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 13:22:10,889::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 13:22:10,889::task::1185::TaskManager.Task::(prepare) Task=`d46a208f-52dd-4136-9bcf-faa8cc47c55f`::finished: None MainThread::DEBUG::2014-04-01 13:22:10,889::task::595::TaskManager.Task::(_updateState) Task=`d46a208f-52dd-4136-9bcf-faa8cc47c55f`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:22:10,890::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:22:10,890::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:22:10,890::task::990::TaskManager.Task::(_decref) Task=`d46a208f-52dd-4136-9bcf-faa8cc47c55f`::ref 0 aborting False MainThread::INFO::2014-04-01 13:22:10,890::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 15 other threads... MainThread::INFO::2014-04-01 13:22:10,890::vdsm::129::vds::(run) <_MainThread(MainThread, started 140406153848576)> MainThread::INFO::2014-04-01 13:22:10,890::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 140405886969600)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 140405165258496)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 140405624530688)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 140405582571264)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 140405593061120)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 140405603550976)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 140405614040832)> MainThread::INFO::2014-04-01 13:22:10,891::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 140405855500032)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 140405865989888)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 140405876479744)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 140405635020544)> MainThread::INFO::2014-04-01 13:22:10,892::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <MomThread(MOM, started 140405123299072)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 140405112809216)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <GuestManager(GuestManager, started daemon 140404659783424)> MainThread::INFO::2014-04-01 13:22:10,892::vdsm::129::vds::(run) <HostMonitor(HostMonitor, started daemon 140404670273280)> MainThread::INFO::2014-04-01 13:22:28,275::vdsm::119::vds::(run) (PID: 5891) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 13:22:28,283::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 13:22:28,283::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 13:22:28,289::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 13:22:28,786::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 13:22:28,809::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 13:22:28,809::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 13:22:29,015::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 13:22:29,016::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 13:22:29,020::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 13:22:29,021::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 13:22:29,021::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 13:22:29,022::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2014-04-01 13:22:29,024::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 13:22:29,024::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) storageRefresh::DEBUG::2014-04-01 13:22:29,044::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:22:29,048::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 13:22:29,055::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:22:29,062::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 13:22:29,063::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 13:22:29,080::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:22:29,081::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 13:22:29,114::task::595::TaskManager.Task::(_updateState) Task=`c687f922-eb71-4870-89f2-79997db11eb2`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:22:29,115::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x1b73fc8>>) MainThread::INFO::2014-04-01 13:22:29,115::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 13:22:29,115::task::1185::TaskManager.Task::(prepare) Task=`c687f922-eb71-4870-89f2-79997db11eb2`::finished: None MainThread::DEBUG::2014-04-01 13:22:29,115::task::595::TaskManager.Task::(_updateState) Task=`c687f922-eb71-4870-89f2-79997db11eb2`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:22:29,115::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:22:29,116::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:22:29,116::task::990::TaskManager.Task::(_decref) Task=`c687f922-eb71-4870-89f2-79997db11eb2`::ref 0 aborting False MainThread::INFO::2014-04-01 13:22:29,127::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 13:22:29,130::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. clientIFinit::DEBUG::2014-04-01 13:22:29,147::libvirtconnection::145::root::(get) trying to connect libvirt VM Channels Listener::INFO::2014-04-01 13:22:29,189::vmChannels::170::vds::(run) Starting VM channels listener thread. storageRefresh::DEBUG::2014-04-01 13:22:29,229::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:22:29,256::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,262::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,275::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,283::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,293::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,311::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,313::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:22:29,322::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,411::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:22:29,637::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:22:29,638::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,638::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,639::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:22:29,789::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:22:29,789::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,790::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:22:29,933::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:22:29,934::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:22:29,935::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) Thread-13::DEBUG::2014-04-01 13:22:30,032::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 13:22:30,032::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Recovering from crash or Initializing', 'code': 99}} storageRefresh::DEBUG::2014-04-01 13:22:30,078::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:22:30,079::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 13:22:30,079::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 13:22:30,079::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-14::DEBUG::2014-04-01 13:22:31,092::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-14::DEBUG::2014-04-01 13:22:31,166::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} MainThread::DEBUG::2014-04-01 13:43:11,588::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 13:43:12,407::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 13:43:12,407::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 13:43:12,408::task::595::TaskManager.Task::(_updateState) Task=`d71c704e-bf1f-4d6d-97c2-41a9f97087d3`::moving from state init -> state preparing MainThread::INFO::2014-04-01 13:43:12,408::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 13:43:12,410::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped VM Channels Listener::INFO::2014-04-01 13:43:12,529::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 13:43:12,872::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 13:43:12,872::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 13:43:12,872::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 13:43:12,873::task::1185::TaskManager.Task::(prepare) Task=`d71c704e-bf1f-4d6d-97c2-41a9f97087d3`::finished: None MainThread::DEBUG::2014-04-01 13:43:12,873::task::595::TaskManager.Task::(_updateState) Task=`d71c704e-bf1f-4d6d-97c2-41a9f97087d3`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 13:43:12,873::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 13:43:12,873::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 13:43:12,873::task::990::TaskManager.Task::(_decref) Task=`d71c704e-bf1f-4d6d-97c2-41a9f97087d3`::ref 0 aborting False MainThread::INFO::2014-04-01 13:43:12,873::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 15 other threads... MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <_MainThread(MainThread, started 140370161301248)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 140369894422272)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 140369329125120)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 140369756927744)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 140369883932416)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 140369318635264)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 140369788397312)> MainThread::INFO::2014-04-01 13:43:12,874::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 140369767417600)> MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <GuestManager(GuestManager, started daemon 140368848873216)> MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 140369308145408)> MainThread::INFO::2014-04-01 13:43:12,875::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <MomThread(MOM, started 140368859363072)> MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 140368368621312)> MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <HostMonitor(HostMonitor, started daemon 140368827893504)> MainThread::INFO::2014-04-01 13:43:12,875::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 140369798887168)> MainThread::INFO::2014-04-01 13:43:12,876::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 140369777907456)> MainThread::INFO::2014-04-01 13:43:12,876::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 140369746437888)> MainThread::INFO::2014-04-01 13:45:23,951::vdsm::119::vds::(run) (PID: 1960) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 13:45:23,962::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 13:45:23,962::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 13:45:23,976::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 13:45:24,512::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 13:45:24,567::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 13:45:24,567::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 13:45:24,765::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 13:45:24,766::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 13:45:24,770::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 13:45:24,771::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 13:45:24,771::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 13:45:24,772::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' storageRefresh::DEBUG::2014-04-01 13:45:24,772::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) MainThread::INFO::2014-04-01 13:45:24,774::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 13:45:24,775::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:45:24,946::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 13:45:24,950::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 13:45:24,982::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 13:45:25,011::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 13:45:25,071::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 13:45:25,072::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) storageRefresh::DEBUG::2014-04-01 13:45:25,153::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 13:45:25,153::task::595::TaskManager.Task::(_updateState) Task=`ce193c89-44a5-4e88-a22a-85954714c93f`::moving from state init -> state preparing storageRefresh::DEBUG::2014-04-01 13:45:25,154::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex MainThread::INFO::2014-04-01 13:45:25,161::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x2918098>>) storageRefresh::DEBUG::2014-04-01 13:45:25,162::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex MainThread::INFO::2014-04-01 13:45:25,162::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None storageRefresh::DEBUG::2014-04-01 13:45:25,162::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex MainThread::DEBUG::2014-04-01 13:45:25,163::task::1185::TaskManager.Task::(prepare) Task=`ce193c89-44a5-4e88-a22a-85954714c93f`::finished: None storageRefresh::DEBUG::2014-04-01 13:45:25,163::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex MainThread::DEBUG::2014-04-01 13:45:25,163::task::595::TaskManager.Task::(_updateState) Task=`ce193c89-44a5-4e88-a22a-85954714c93f`::moving from state preparing -> state finished storageRefresh::DEBUG::2014-04-01 13:45:25,164::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex MainThread::DEBUG::2014-04-01 13:45:25,164::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} storageRefresh::DEBUG::2014-04-01 13:45:25,164::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex MainThread::DEBUG::2014-04-01 13:45:25,165::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} storageRefresh::DEBUG::2014-04-01 13:45:25,165::misc::772::SamplingMethod::(__call__) Returning last result MainThread::DEBUG::2014-04-01 13:45:25,166::task::990::TaskManager.Task::(_decref) Task=`ce193c89-44a5-4e88-a22a-85954714c93f`::ref 0 aborting False storageRefresh::DEBUG::2014-04-01 13:45:25,166::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:45:25,170::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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::INFO::2014-04-01 13:45:25,181::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 13:45:25,191::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 13:45:25,194::vmChannels::170::vds::(run) Starting VM channels listener thread. clientIFinit::DEBUG::2014-04-01 13:45:25,305::libvirtconnection::145::root::(get) trying to connect libvirt storageRefresh::DEBUG::2014-04-01 13:45:25,372::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:45:25,406::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:45:25,422::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:45:25,431::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:45:25,619::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:45:25,622::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 13:45:25,629::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 13:45:25,803::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:45:25,804::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 13:45:25,804::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 13:45:25,968::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 13:45:25,969::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 13:45:25,970::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 13:45:25,978::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-13::DEBUG::2014-04-01 13:47:59,432::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 13:47:59,569::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-14::DEBUG::2014-04-01 13:49:32,208::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-14::DEBUG::2014-04-01 13:49:32,240::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-15::DEBUG::2014-04-01 13:51:17,857::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-15::DEBUG::2014-04-01 13:51:17,888::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-16::DEBUG::2014-04-01 13:57:54,486::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-16::DEBUG::2014-04-01 13:57:54,510::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-17::DEBUG::2014-04-01 14:02:37,349::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-04-01 14:02:37,360::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-18::DEBUG::2014-04-01 14:24:48,882::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-18::DEBUG::2014-04-01 14:24:48,931::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-19::DEBUG::2014-04-01 14:26:09,043::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-19::DEBUG::2014-04-01 14:26:09,067::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} MainThread::DEBUG::2014-04-01 14:26:18,534::vdsm::55::vds::(sigtermHandler) Received signal 15 MainThread::INFO::2014-04-01 14:26:19,015::vmChannels::183::vds::(stop) VM channels listener was stopped. MainThread::INFO::2014-04-01 14:26:19,015::momIF::84::MOM::(stop) Shutting down MOM MainThread::DEBUG::2014-04-01 14:26:19,016::task::595::TaskManager.Task::(_updateState) Task=`bba14d83-2a49-4970-8f76-2be58762768a`::moving from state init -> state preparing MainThread::INFO::2014-04-01 14:26:19,016::logUtils::44::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None) Thread-11::DEBUG::2014-04-01 14:26:19,051::storageServer::698::ConnectionMonitor::(_monitorConnections) Monitoring stopped VM Channels Listener::INFO::2014-04-01 14:26:19,075::vmChannels::178::vds::(run) VM channels listener thread has ended. MainThread::INFO::2014-04-01 14:26:19,527::domainMonitor::125::Storage.DomainMonitor::(close) Stopping domain monitors MainThread::DEBUG::2014-04-01 14:26:19,528::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks MainThread::INFO::2014-04-01 14:26:19,528::logUtils::47::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None MainThread::DEBUG::2014-04-01 14:26:19,528::task::1185::TaskManager.Task::(prepare) Task=`bba14d83-2a49-4970-8f76-2be58762768a`::finished: None MainThread::DEBUG::2014-04-01 14:26:19,528::task::595::TaskManager.Task::(_updateState) Task=`bba14d83-2a49-4970-8f76-2be58762768a`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 14:26:19,528::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 14:26:19,528::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 14:26:19,529::task::990::TaskManager.Task::(_decref) Task=`bba14d83-2a49-4970-8f76-2be58762768a`::ref 0 aborting False MainThread::INFO::2014-04-01 14:26:19,529::vdsm::125::vds::(run) VDSM main thread ended. Waiting for 15 other threads... MainThread::INFO::2014-04-01 14:26:19,529::vdsm::129::vds::(run) <_MainThread(MainThread, started 139946453554944)> MainThread::INFO::2014-04-01 14:26:19,529::vdsm::129::vds::(run) <Thread(libvirtEventLoop, started daemon 139946186409728)> MainThread::INFO::2014-04-01 14:26:19,529::vdsm::129::vds::(run) <WorkerThread(Thread-4, started daemon 139945939302144)> MainThread::INFO::2014-04-01 14:26:19,529::vdsm::129::vds::(run) <PolicyEngine(PolicyEngine, started daemon 139944530016000)> MainThread::INFO::2014-04-01 14:26:19,529::vdsm::129::vds::(run) <WorkerThread(Thread-9, started daemon 139945886852864)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-8, started daemon 139945897342720)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-7, started daemon 139945907832576)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-5, started daemon 139945928812288)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-10, started daemon 139945469540096)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <GuestManager(GuestManager, started daemon 139944980776704)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-3, started daemon 139946154940160)> MainThread::INFO::2014-04-01 14:26:19,530::vdsm::129::vds::(run) <WorkerThread(Thread-2, started daemon 139946165430016)> MainThread::INFO::2014-04-01 14:26:19,531::vdsm::129::vds::(run) <WorkerThread(Thread-1, started daemon 139946175919872)> MainThread::INFO::2014-04-01 14:26:19,531::momIF::84::MOM::(stop) Shutting down MOM MainThread::INFO::2014-04-01 14:26:19,531::vdsm::129::vds::(run) <MomThread(MOM, started 139945427580672)> MainThread::INFO::2014-04-01 14:26:19,531::vdsm::129::vds::(run) <HostMonitor(HostMonitor, started daemon 139945417090816)> MainThread::INFO::2014-04-01 14:26:19,531::vdsm::129::vds::(run) <WorkerThread(Thread-6, started daemon 139945918322432)> MainThread::INFO::2014-04-01 14:26:38,227::vdsm::119::vds::(run) (PID: 5104) I am the actual vdsm 4.14.6-0.el6 ovirt01.mydomain (2.6.32-431.11.2.el6.x86_64) MainThread::DEBUG::2014-04-01 14:26:38,228::resourceManager::421::ResourceManager::(registerNamespace) Registering namespace 'Storage' MainThread::DEBUG::2014-04-01 14:26:38,228::threadPool::35::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0 MainThread::WARNING::2014-04-01 14:26:38,233::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/mnt already exists MainThread::DEBUG::2014-04-01 14:26:38,781::supervdsm::77::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm MainThread::DEBUG::2014-04-01 14:26:38,817::multipath::142::Storage.Multipath::(isEnabled) Current revision of multipath.conf detected, preserving MainThread::DEBUG::2014-04-01 14:26:38,817::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None) MainThread::DEBUG::2014-04-01 14:26:38,999::hsm::423::Storage.Misc.excCmd::(__validateLvmLockingType) SUCCESS: <err> = ''; <rc> = 0 MainThread::DEBUG::2014-04-01 14:26:38,999::hsm::447::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center' MainThread::DEBUG::2014-04-01 14:26:39,003::hsm::479::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt'] MainThread::DEBUG::2014-04-01 14:26:39,003::hsm::480::Storage.HSM::(__cleanStorageRepository) Mount list: [] MainThread::DEBUG::2014-04-01 14:26:39,003::hsm::482::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers MainThread::DEBUG::2014-04-01 14:26:39,005::hsm::525::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center' MainThread::INFO::2014-04-01 14:26:39,007::dispatcher::97::Storage.Dispatcher::(__init__) Starting StorageDispatcher... storageRefresh::DEBUG::2014-04-01 14:26:39,007::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) storageRefresh::DEBUG::2014-04-01 14:26:39,060::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 14:26:39,075::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) storageRefresh::DEBUG::2014-04-01 14:26:39,075::misc::764::SamplingMethod::(__call__) Got in to sampling method storageRefresh::DEBUG::2014-04-01 14:26:39,078::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds storageRefresh::DEBUG::2014-04-01 14:26:39,078::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) storageRefresh::DEBUG::2014-04-01 14:26:39,118::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 14:26:39,119::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) MainThread::DEBUG::2014-04-01 14:26:39,159::task::595::TaskManager.Task::(_updateState) Task=`87e43e15-0963-43c4-be68-68466249fab0`::moving from state init -> state preparing MainThread::INFO::2014-04-01 14:26:39,161::logUtils::44::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback(callbackFunc=<bound method clientIF.contEIOVms of <clientIF.clientIF instance at 0x18c53f8>>) MainThread::INFO::2014-04-01 14:26:39,161::logUtils::47::dispatcher::(wrapper) Run and protect: registerDomainStateChangeCallback, Return response: None MainThread::DEBUG::2014-04-01 14:26:39,161::task::1185::TaskManager.Task::(prepare) Task=`87e43e15-0963-43c4-be68-68466249fab0`::finished: None MainThread::DEBUG::2014-04-01 14:26:39,161::task::595::TaskManager.Task::(_updateState) Task=`87e43e15-0963-43c4-be68-68466249fab0`::moving from state preparing -> state finished MainThread::DEBUG::2014-04-01 14:26:39,161::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} MainThread::DEBUG::2014-04-01 14:26:39,162::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} MainThread::DEBUG::2014-04-01 14:26:39,162::task::990::TaskManager.Task::(_decref) Task=`87e43e15-0963-43c4-be68-68466249fab0`::ref 0 aborting False MainThread::INFO::2014-04-01 14:26:39,172::momIF::47::MOM::(__init__) Starting up MOM MainThread::INFO::2014-04-01 14:26:39,188::vmChannels::187::vds::(settimeout) Setting channels' timeout to 30 seconds. VM Channels Listener::INFO::2014-04-01 14:26:39,190::vmChannels::170::vds::(run) Starting VM channels listener thread. clientIFinit::DEBUG::2014-04-01 14:26:39,233::libvirtconnection::145::root::(get) trying to connect libvirt storageRefresh::DEBUG::2014-04-01 14:26:39,235::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 14:26:39,236::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,241::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,241::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,242::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,242::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,242::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,243::misc::772::SamplingMethod::(__call__) Returning last result storageRefresh::DEBUG::2014-04-01 14:26:39,243::lvm::324::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,329::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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) storageRefresh::DEBUG::2014-04-01 14:26:39,547::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0 storageRefresh::DEBUG::2014-04-01 14:26:39,550::lvm::349::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,579::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,588::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 14:26:39,751::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 14:26:39,751::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,752::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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-13::DEBUG::2014-04-01 14:26:39,863::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-13::DEBUG::2014-04-01 14:26:39,863::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Recovering from crash or Initializing', 'code': 99}} storageRefresh::DEBUG::2014-04-01 14:26:39,913::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 14:26:39,914::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex storageRefresh::DEBUG::2014-04-01 14:26:39,915::lvm::295::Storage.Misc.excCmd::(cmd) '/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 obtain_device_list_from_udev=0 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,lv_count,pv_count,pv_name' (cwd None) storageRefresh::DEBUG::2014-04-01 14:26:40,055::lvm::295::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ' No volume groups found\n'; <rc> = 0 storageRefresh::DEBUG::2014-04-01 14:26:40,056::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex storageRefresh::WARNING::2014-04-01 14:26:40,057::fileUtils::167::Storage.fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists storageRefresh::DEBUG::2014-04-01 14:26:40,062::hsm::391::Storage.HSM::(storageRefresh) HSM is ready Thread-14::DEBUG::2014-04-01 14:26:40,924::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-14::DEBUG::2014-04-01 14:26:41,026::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-15::DEBUG::2014-04-01 14:48:06,601::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-15::DEBUG::2014-04-01 14:48:06,623::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-16::DEBUG::2014-04-01 14:51:28,992::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-16::DEBUG::2014-04-01 14:51:29,020::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-17::DEBUG::2014-04-01 15:04:55,803::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-17::DEBUG::2014-04-01 15:04:55,813::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-18::DEBUG::2014-04-01 15:07:59,091::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-18::DEBUG::2014-04-01 15:07:59,107::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-19::DEBUG::2014-04-01 15:10:26,674::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-19::DEBUG::2014-04-01 15:10:26,682::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-20::DEBUG::2014-04-01 15:22:09,047::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-20::DEBUG::2014-04-01 15:22:09,056::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-21::DEBUG::2014-04-01 15:22:32,925::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-21::DEBUG::2014-04-01 15:22:32,928::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} Thread-22::DEBUG::2014-04-01 15:30:32,100::BindingXMLRPC::1067::vds::(wrapper) client [127.0.0.1]::call getHardwareInfo with () {} Thread-22::DEBUG::2014-04-01 15:30:32,110::BindingXMLRPC::1074::vds::(wrapper) return getHardwareInfo with {'status': {'message': 'Done', 'code': 0}, 'info': {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'}} ------=_Part_594693_2003216810.1396362976018 Content-Type: text/x-log Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename=supervdsm.log MainThread::DEBUG::2014-04-01 12:50:10,809::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 12:50:12,851::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 12:50:12,851::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 12:50:12,873::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 12:50:12,873::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 12:50:12,873::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 12:50:12,874::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 12:50:12,874::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 12:50:12,880::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 12:50:12,880::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 12:50:16,019::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 12:50:16,020::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|PolicyEngine::DEBUG::2014-04-01 12:50:26,756::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 12:50:26,761::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainThread::DEBUG::2014-04-01 12:50:40,269::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 12:52:17,924::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 12:52:17,933::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 12:52:18,005::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 12:52:18,005::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 12:52:18,006::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 12:52:18,006::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 12:52:18,006::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 12:52:18,008::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 12:52:18,008::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 12:52:42,649::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 12:52:42,650::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|PolicyEngine::DEBUG::2014-04-01 12:52:53,805::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 12:52:53,806::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainProcess|Thread-13::DEBUG::2014-04-01 12:55:50,816::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-13::DEBUG::2014-04-01 12:55:50,928::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-14::DEBUG::2014-04-01 13:02:22,284::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-14::DEBUG::2014-04-01 13:02:22,285::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-15::DEBUG::2014-04-01 13:04:41,955::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-15::DEBUG::2014-04-01 13:04:41,955::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-16::DEBUG::2014-04-01 13:04:49,776::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-16::DEBUG::2014-04-01 13:04:49,777::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-17::DEBUG::2014-04-01 13:06:19,192::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-17::DEBUG::2014-04-01 13:06:19,192::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainThread::DEBUG::2014-04-01 13:11:01,435::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 13:11:07,331::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:11:07,332::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:11:07,352::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 13:11:07,353::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 13:11:07,353::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 13:11:07,353::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 13:11:07,353::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 13:11:07,357::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 13:11:07,358::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 13:11:10,614::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 13:11:10,615::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|PolicyEngine::DEBUG::2014-04-01 13:11:21,387::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:11:21,388::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainProcess|Thread-13::DEBUG::2014-04-01 13:11:22,959::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-13::DEBUG::2014-04-01 13:11:23,031::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainThread::DEBUG::2014-04-01 13:13:31,965::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 13:16:40,783::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:16:40,783::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:16:40,806::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 13:16:40,807::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 13:16:40,807::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 13:16:40,807::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 13:16:40,807::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 13:16:40,809::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 13:16:40,809::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 13:16:44,053::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 13:16:44,053::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|Thread-13::DEBUG::2014-04-01 13:16:45,279::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-13::DEBUG::2014-04-01 13:16:45,343::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:16:54,860::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:16:54,860::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainProcess|Thread-14::DEBUG::2014-04-01 13:20:39,297::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-14::DEBUG::2014-04-01 13:20:39,297::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-15::DEBUG::2014-04-01 13:21:11,423::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-15::DEBUG::2014-04-01 13:21:11,423::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainThread::DEBUG::2014-04-01 13:22:22,074::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 13:22:25,111::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:22:25,111::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:22:25,132::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 13:22:25,132::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 13:22:25,132::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 13:22:25,133::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 13:22:25,133::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 13:22:25,200::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 13:22:25,201::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 13:22:28,808::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 13:22:28,808::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|Thread-14::DEBUG::2014-04-01 13:22:31,095::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-14::DEBUG::2014-04-01 13:22:31,165::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:22:39,576::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:22:39,577::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainThread::DEBUG::2014-04-01 13:44:59,743::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:44:59,759::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 13:44:59,839::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 13:44:59,839::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 13:44:59,839::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 13:44:59,840::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 13:44:59,840::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 13:44:59,841::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 13:44:59,842::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 13:45:24,565::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 13:45:24,566::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|PolicyEngine::DEBUG::2014-04-01 13:45:35,830::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 13:45:35,837::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainProcess|Thread-13::DEBUG::2014-04-01 13:47:59,454::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-13::DEBUG::2014-04-01 13:47:59,568::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-14::DEBUG::2014-04-01 13:49:32,238::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-14::DEBUG::2014-04-01 13:49:32,240::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-15::DEBUG::2014-04-01 13:51:17,886::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-15::DEBUG::2014-04-01 13:51:17,888::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-16::DEBUG::2014-04-01 13:57:54,508::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-16::DEBUG::2014-04-01 13:57:54,510::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-17::DEBUG::2014-04-01 14:02:37,358::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-17::DEBUG::2014-04-01 14:02:37,359::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-18::DEBUG::2014-04-01 14:24:48,924::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-18::DEBUG::2014-04-01 14:24:48,931::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-19::DEBUG::2014-04-01 14:26:09,065::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-19::DEBUG::2014-04-01 14:26:09,066::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainThread::DEBUG::2014-04-01 14:26:29,970::supervdsmServer::424::SuperVdsm.Server::(main) Terminated normally MainThread::DEBUG::2014-04-01 14:26:34,549::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 14:26:34,550::netconfpersistence::134::root::(_getConfigs) Non-existing config set. MainThread::DEBUG::2014-04-01 14:26:34,633::supervdsmServer::384::SuperVdsm.Server::(main) Making sure I'm root - SuperVdsm MainThread::DEBUG::2014-04-01 14:26:34,635::supervdsmServer::393::SuperVdsm.Server::(main) Parsing cmd args MainThread::DEBUG::2014-04-01 14:26:34,635::supervdsmServer::396::SuperVdsm.Server::(main) Cleaning old socket /var/run/vdsm/svdsm.sock MainThread::DEBUG::2014-04-01 14:26:34,636::supervdsmServer::400::SuperVdsm.Server::(main) Setting up keep alive thread MainThread::DEBUG::2014-04-01 14:26:34,636::supervdsmServer::406::SuperVdsm.Server::(main) Creating remote object manager MainThread::DEBUG::2014-04-01 14:26:34,637::supervdsmServer::417::SuperVdsm.Server::(main) Started serving super vdsm object sourceRoute::DEBUG::2014-04-01 14:26:34,648::sourceRouteThread::56::root::(_subscribeToInotifyLoop) sourceRouteThread.subscribeToInotifyLoop started MainProcess::DEBUG::2014-04-01 14:26:38,816::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call readMultipathConf with () {} MainProcess::DEBUG::2014-04-01 14:26:38,816::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return readMultipathConf with ['# RHEV REVISION 1.0', '', 'defaults {', ' polling_interval 5', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', ' no_path_retry fail', ' user_friendly_names no', ' flush_on_last_del yes', ' fast_io_fail_tmo 5', ' dev_loss_tmo 30', ' max_fds 4096', '}', '', 'devices {', 'device {', ' vendor "HITACHI"', ' product "DF.*"', ' getuid_callout "/sbin/scsi_id --whitelisted --replace-whitespace --device=/dev/%n"', '}', 'device {', ' vendor "COMPELNT"', ' product "Compellent Vol"', ' no_path_retry fail', '}', '}'] MainProcess|Thread-14::DEBUG::2014-04-01 14:26:40,926::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-14::DEBUG::2014-04-01 14:26:41,025::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|PolicyEngine::DEBUG::2014-04-01 14:26:49,745::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call ksmTune with ({'run': 0},) {} MainProcess|PolicyEngine::DEBUG::2014-04-01 14:26:49,745::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return ksmTune with None MainProcess|Thread-15::DEBUG::2014-04-01 14:48:06,622::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-15::DEBUG::2014-04-01 14:48:06,622::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-16::DEBUG::2014-04-01 14:51:29,018::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-16::DEBUG::2014-04-01 14:51:29,019::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-17::DEBUG::2014-04-01 15:04:55,811::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-17::DEBUG::2014-04-01 15:04:55,812::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-18::DEBUG::2014-04-01 15:07:59,106::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-18::DEBUG::2014-04-01 15:07:59,106::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-19::DEBUG::2014-04-01 15:10:26,681::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-19::DEBUG::2014-04-01 15:10:26,682::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-20::DEBUG::2014-04-01 15:22:09,055::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-20::DEBUG::2014-04-01 15:22:09,055::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-21::DEBUG::2014-04-01 15:22:32,928::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-21::DEBUG::2014-04-01 15:22:32,928::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} MainProcess|Thread-22::DEBUG::2014-04-01 15:30:32,109::supervdsmServer::96::SuperVdsm.ServerCallback::(wrapper) call getHardwareInfo with () {} MainProcess|Thread-22::DEBUG::2014-04-01 15:30:32,109::supervdsmServer::103::SuperVdsm.ServerCallback::(wrapper) return getHardwareInfo with {'systemProductName': 'ProLiant DL380 G5', 'systemSerialNumber': 'CZC6451JFR', 'systemFamily': None, 'systemVersion': 'Not Specified', 'systemUUID': '435a4336-3435-435a-4336-3435314a4652', 'systemManufacturer': 'HP'} ------=_Part_594693_2003216810.1396362976018 Content-Type: text/x-log Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename=mom.log 2014-04-01 12:50:16,314 - mom - INFO - MOM starting 2014-04-01 12:50:16,401 - mom - INFO - hypervisor interface vdsm 2014-04-01 12:50:16,401 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 12:50:16,409 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 12:50:16,488 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 12:50:16,577 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 12:50:16,598 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 12:50:16,691 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 12:50:16,693 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 12:50:16,696 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 12:50:26,748 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 12:50:31,434 - mom.GuestManager - INFO - Guest Manager ending 2014-04-01 12:50:31,635 - mom.HostMonitor - INFO - Host Monitor ending 2014-04-01 12:50:31,712 - mom - ERROR - Thread 'HostMonitor' has exited 2014-04-01 12:52:43,250 - mom - INFO - MOM starting 2014-04-01 12:52:43,434 - mom - INFO - hypervisor interface vdsm 2014-04-01 12:52:43,444 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 12:52:43,464 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 12:52:43,528 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 12:52:43,551 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 12:52:43,644 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 12:52:43,742 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 12:52:43,742 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 12:52:43,750 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 12:52:53,802 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 13:11:10,919 - mom - INFO - MOM starting 2014-04-01 13:11:11,019 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 13:11:11,020 - mom - INFO - hypervisor interface vdsm 2014-04-01 13:11:11,028 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 13:11:11,080 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 13:11:11,112 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 13:11:11,186 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 13:11:11,309 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 13:11:11,310 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 13:11:11,314 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 13:11:21,366 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 13:13:31,180 - mom.GuestManager - INFO - Guest Manager ending 2014-04-01 13:13:31,458 - mom - ERROR - Thread 'GuestManager' has exited 2014-04-01 13:16:44,369 - mom - INFO - MOM starting 2014-04-01 13:16:44,431 - mom - INFO - hypervisor interface vdsm 2014-04-01 13:16:44,431 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 13:16:44,435 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 13:16:44,621 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 13:16:44,629 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 13:16:44,692 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 13:16:44,802 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 13:16:44,803 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 13:16:44,806 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 13:16:54,858 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 13:22:11,271 - mom.HostMonitor - INFO - Host Monitor ending 2014-04-01 13:22:29,129 - mom - INFO - MOM starting 2014-04-01 13:22:29,211 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 13:22:29,211 - mom - INFO - hypervisor interface vdsm 2014-04-01 13:22:29,323 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 13:22:29,340 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 13:22:29,370 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 13:22:29,401 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 13:22:29,525 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 13:22:29,525 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 13:22:29,527 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 13:22:39,575 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 13:43:13,362 - mom.PolicyEngine - INFO - Policy Engine ending 2014-04-01 13:45:25,188 - mom - INFO - MOM starting 2014-04-01 13:45:25,436 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 13:45:25,437 - mom - INFO - hypervisor interface vdsm 2014-04-01 13:45:25,507 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 13:45:25,533 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 13:45:25,558 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 13:45:25,596 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 13:45:25,752 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 13:45:25,754 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 13:45:25,762 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 13:45:35,814 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 2014-04-01 14:26:39,180 - mom - INFO - MOM starting 2014-04-01 14:26:39,307 - mom - INFO - hypervisor interface vdsm 2014-04-01 14:26:39,307 - mom.HostMonitor - INFO - Host Monitor starting 2014-04-01 14:26:39,395 - mom.HostMonitor - INFO - HostMonitor is ready 2014-04-01 14:26:39,463 - mom.GuestManager - INFO - Guest Manager starting 2014-04-01 14:26:39,482 - mom.Policy - INFO - Loaded policy '00-defines' 2014-04-01 14:26:39,527 - mom.Policy - INFO - Loaded policy '02-balloon' 2014-04-01 14:26:39,676 - mom.Policy - INFO - Loaded policy '03-ksm' 2014-04-01 14:26:39,677 - mom.PolicyEngine - INFO - Policy Engine starting 2014-04-01 14:26:39,690 - mom.RPCServer - INFO - RPC Server is disabled 2014-04-01 14:26:49,743 - mom.Controllers.KSM - INFO - Updating KSM configuration: pages_to_scan:0 run:0 sleep_millisecs:0 ------=_Part_594693_2003216810.1396362976018--