Attachment 704126 Details for Bug 916981 – vdsm.log

vdsm.log

vdsm.log (text/x-log), 151.52 KB, created by Prasanth on 2013-03-01 10:46:58 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Prasanth

Created: 2013-03-01 10:46:58 UTC

Size: 151.52 KB

patch

obsolete

>MainThread::INFO::2013-03-01 15:41:47,018::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::DEBUG::2013-03-01 15:41:47,019::task::588::TaskManager.Task::(_updateState) Task=`c1b02437-6e32-4cde-8110-c55e5d5e839e`::moving from state init -> state preparing
>MainThread::INFO::2013-03-01 15:41:47,019::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2013-03-01 15:41:47,019::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2013-03-01 15:41:47,035::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2013-03-01 15:41:47,036::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2013-03-01 15:41:47,036::task::1172::TaskManager.Task::(prepare) Task=`c1b02437-6e32-4cde-8110-c55e5d5e839e`::finished: None
>MainThread::DEBUG::2013-03-01 15:41:47,037::task::588::TaskManager.Task::(_updateState) Task=`c1b02437-6e32-4cde-8110-c55e5d5e839e`::moving from state preparing -> state finished
>MainThread::DEBUG::2013-03-01 15:41:47,037::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2013-03-01 15:41:47,037::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2013-03-01 15:41:47,038::task::978::TaskManager.Task::(_decref) Task=`c1b02437-6e32-4cde-8110-c55e5d5e839e`::ref 0 aborting False
>MainThread::INFO::2013-03-01 15:41:47,038::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2013-03-01 15:41:47,039::vdsm::78::vds::(run) <_MainThread(MainThread, started 140481232369408)>
>MainThread::INFO::2013-03-01 15:41:47,039::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140481144768256)>
>MainThread::INFO::2013-03-01 15:41:47,039::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140480796948224)>
>MainThread::INFO::2013-03-01 15:41:47,040::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140481015138048)>
>MainThread::INFO::2013-03-01 15:41:47,040::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140480754988800)>
>MainThread::INFO::2013-03-01 15:41:47,041::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140480765478656)>
>MainThread::INFO::2013-03-01 15:41:47,041::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140481025627904)>
>MainThread::INFO::2013-03-01 15:41:47,041::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140480744498944)>
>MainThread::INFO::2013-03-01 15:41:47,042::vdsm::78::vds::(run) <KsmMonitorThread(KsmMonitor, started daemon 140480429934336)>
>MainThread::INFO::2013-03-01 15:41:47,042::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140480786458368)>
>MainThread::INFO::2013-03-01 15:41:47,042::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140481046607616)>
>MainThread::INFO::2013-03-01 15:41:47,043::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::INFO::2013-03-01 15:41:47,043::vdsm::78::vds::(run) <Listener(VM Channels Listener, started daemon 140480408954624)>
>MainThread::INFO::2013-03-01 15:41:47,044::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140480775968512)>
>MainThread::INFO::2013-03-01 15:41:47,044::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140481036117760)>
>MainThread::INFO::2013-03-01 15:44:20,342::vdsm::70::vds::(run) I am the actual vdsm 4.9-19
>MainThread::DEBUG::2013-03-01 15:44:20,733::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2013-03-01 15:44:20,734::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2013-03-01 15:44:20,738::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2013-03-01 15:44:20,757::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2013-03-01 15:44:20,779::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2013-03-01 15:44:20,780::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2013-03-01 15:44:20,780::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2013-03-01 15:44:20,781::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2013-03-01 15:44:20,792::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2013-03-01 15:44:20,793::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2013-03-01 15:44:20,797::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2013-03-01 15:44:20,797::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2013-03-01 15:44:20,797::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2013-03-01 15:44:20,800::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2013-03-01 15:44:20,802::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2013-03-01 15:44:20,805::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:20,806::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::DEBUG::2013-03-01 15:44:20,825::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf ksmd' (cwd None)
>Thread-12::DEBUG::2013-03-01 15:44:20,838::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2013-03-01 15:44:20,839::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:20,840::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:20,840::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::DEBUG::2013-03-01 15:44:20,860::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2013-03-01 15:44:20,861::ksm::40::vds::(__init__) starting ksm monitor thread, ksm pid is 29
>KsmMonitor::DEBUG::2013-03-01 15:44:20,866::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None)
>MainThread::INFO::2013-03-01 15:44:20,870::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds.
>VM Channels Listener::INFO::2013-03-01 15:44:20,878::vmChannels::127::vds::(run) Starting VM channels listener thread.
>Thread-12::DEBUG::2013-03-01 15:44:20,889::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2013-03-01 15:44:20,890::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:20,891::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2013-03-01 15:44:20,924::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2013-03-01 15:44:20,924::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2013-03-01 15:44:20,925::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2013-03-01 15:44:20,925::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2013-03-01 15:44:20,925::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2013-03-01 15:44:20,926::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>KsmMonitor::DEBUG::2013-03-01 15:44:20,945::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>KsmMonitor::DEBUG::2013-03-01 15:44:20,946::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service ksm start' (cwd None)
>Thread-12::DEBUG::2013-03-01 15:44:20,951::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2013-03-01 15:44:20,952::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2013-03-01 15:44:20,953::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2013-03-01 15:44:20,953::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py eb97205a-707b-41c2-aea7-1f97c7833cdf 2035' (cwd None)
>KsmMonitor::DEBUG::2013-03-01 15:44:21,001::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2013-03-01 15:44:21,183::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2013-03-01 15:44:21,184::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2013-03-01 15:44:21,184::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2013-03-01 15:44:21,185::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2013-03-01 15:44:21,185::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2013-03-01 15:44:21,186::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2013-03-01 15:44:21,187::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2013-03-01 15:44:22,961::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2013-03-01 15:44:22,970::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2013-03-01 15:44:22,973::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2013-03-01 15:44:22,976::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2013-03-01 15:44:24,979::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2013-03-01 15:44:24,992::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2013-03-01 15:44:24,993::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,993::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,994::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,994::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,995::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,995::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 15:44:24,996::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2013-03-01 15:44:24,996::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>Thread-14::DEBUG::2013-03-01 15:46:53,079::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-14::DEBUG::2013-03-01 15:46:53,263::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-14::DEBUG::2013-03-01 15:46:53,294::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-14::DEBUG::2013-03-01 15:46:53,295::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-14::DEBUG::2013-03-01 15:46:53,325::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-14::DEBUG::2013-03-01 15:46:53,326::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-14::DEBUG::2013-03-01 15:46:53,355::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 15:46:53,356::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-14::DEBUG::2013-03-01 15:46:53,384::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 15:46:53,385::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-14::DEBUG::2013-03-01 15:46:53,412::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 15:46:53,421::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}}
>Thread-15::DEBUG::2013-03-01 15:46:53,621::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-15::DEBUG::2013-03-01 15:46:53,665::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-15::DEBUG::2013-03-01 15:46:53,692::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-15::DEBUG::2013-03-01 15:46:53,693::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-15::DEBUG::2013-03-01 15:46:53,719::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-15::DEBUG::2013-03-01 15:46:53,720::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-15::DEBUG::2013-03-01 15:46:53,744::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 15:46:53,745::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-15::DEBUG::2013-03-01 15:46:53,771::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 15:46:53,772::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-15::DEBUG::2013-03-01 15:46:53,798::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 15:46:53,799::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-17::DEBUG::2013-03-01 15:46:57,106::task::588::TaskManager.Task::(_updateState) Task=`d631e446-0d44-458e-a130-2ecc428a55ff`::moving from state init -> state preparing
>Thread-17::INFO::2013-03-01 15:46:57,107::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-17::INFO::2013-03-01 15:46:57,107::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-17::DEBUG::2013-03-01 15:46:57,107::task::1172::TaskManager.Task::(prepare) Task=`d631e446-0d44-458e-a130-2ecc428a55ff`::finished: {}
>Thread-17::DEBUG::2013-03-01 15:46:57,108::task::588::TaskManager.Task::(_updateState) Task=`d631e446-0d44-458e-a130-2ecc428a55ff`::moving from state preparing -> state finished
>Thread-17::DEBUG::2013-03-01 15:46:57,108::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-17::DEBUG::2013-03-01 15:46:57,109::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-17::DEBUG::2013-03-01 15:46:57,110::task::978::TaskManager.Task::(_decref) Task=`d631e446-0d44-458e-a130-2ecc428a55ff`::ref 0 aborting False
>Thread-23::DEBUG::2013-03-01 15:47:12,318::task::588::TaskManager.Task::(_updateState) Task=`2e8c3b09-6009-4f45-ac25-e302a72ac50c`::moving from state init -> state preparing
>Thread-23::INFO::2013-03-01 15:47:12,319::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-23::INFO::2013-03-01 15:47:12,319::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-23::DEBUG::2013-03-01 15:47:12,320::task::1172::TaskManager.Task::(prepare) Task=`2e8c3b09-6009-4f45-ac25-e302a72ac50c`::finished: {}
>Thread-23::DEBUG::2013-03-01 15:47:12,320::task::588::TaskManager.Task::(_updateState) Task=`2e8c3b09-6009-4f45-ac25-e302a72ac50c`::moving from state preparing -> state finished
>Thread-23::DEBUG::2013-03-01 15:47:12,320::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-23::DEBUG::2013-03-01 15:47:12,321::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-23::DEBUG::2013-03-01 15:47:12,321::task::978::TaskManager.Task::(_decref) Task=`2e8c3b09-6009-4f45-ac25-e302a72ac50c`::ref 0 aborting False
>Thread-29::DEBUG::2013-03-01 15:47:27,519::task::588::TaskManager.Task::(_updateState) Task=`32953a33-3042-4e72-aef5-6d3dcfc30c26`::moving from state init -> state preparing
>Thread-29::INFO::2013-03-01 15:47:27,519::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-29::INFO::2013-03-01 15:47:27,520::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-29::DEBUG::2013-03-01 15:47:27,520::task::1172::TaskManager.Task::(prepare) Task=`32953a33-3042-4e72-aef5-6d3dcfc30c26`::finished: {}
>Thread-29::DEBUG::2013-03-01 15:47:27,521::task::588::TaskManager.Task::(_updateState) Task=`32953a33-3042-4e72-aef5-6d3dcfc30c26`::moving from state preparing -> state finished
>Thread-29::DEBUG::2013-03-01 15:47:27,521::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-29::DEBUG::2013-03-01 15:47:27,522::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-29::DEBUG::2013-03-01 15:47:27,522::task::978::TaskManager.Task::(_decref) Task=`32953a33-3042-4e72-aef5-6d3dcfc30c26`::ref 0 aborting False
>Thread-35::DEBUG::2013-03-01 15:47:42,732::task::588::TaskManager.Task::(_updateState) Task=`0d02e5ae-b1b1-45d0-b41f-2038e152472b`::moving from state init -> state preparing
>Thread-35::INFO::2013-03-01 15:47:42,732::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-35::INFO::2013-03-01 15:47:42,733::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-35::DEBUG::2013-03-01 15:47:42,733::task::1172::TaskManager.Task::(prepare) Task=`0d02e5ae-b1b1-45d0-b41f-2038e152472b`::finished: {}
>Thread-35::DEBUG::2013-03-01 15:47:42,734::task::588::TaskManager.Task::(_updateState) Task=`0d02e5ae-b1b1-45d0-b41f-2038e152472b`::moving from state preparing -> state finished
>Thread-35::DEBUG::2013-03-01 15:47:42,734::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-35::DEBUG::2013-03-01 15:47:42,734::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-35::DEBUG::2013-03-01 15:47:42,735::task::978::TaskManager.Task::(_decref) Task=`0d02e5ae-b1b1-45d0-b41f-2038e152472b`::ref 0 aborting False
>Thread-41::DEBUG::2013-03-01 15:47:57,937::task::588::TaskManager.Task::(_updateState) Task=`78e7f5f9-0911-43c8-8192-b8b78f6406da`::moving from state init -> state preparing
>Thread-41::INFO::2013-03-01 15:47:57,938::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-41::INFO::2013-03-01 15:47:57,938::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-41::DEBUG::2013-03-01 15:47:57,938::task::1172::TaskManager.Task::(prepare) Task=`78e7f5f9-0911-43c8-8192-b8b78f6406da`::finished: {}
>Thread-41::DEBUG::2013-03-01 15:47:57,939::task::588::TaskManager.Task::(_updateState) Task=`78e7f5f9-0911-43c8-8192-b8b78f6406da`::moving from state preparing -> state finished
>Thread-41::DEBUG::2013-03-01 15:47:57,939::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-41::DEBUG::2013-03-01 15:47:57,940::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-41::DEBUG::2013-03-01 15:47:57,940::task::978::TaskManager.Task::(_decref) Task=`78e7f5f9-0911-43c8-8192-b8b78f6406da`::ref 0 aborting False
>Thread-47::DEBUG::2013-03-01 15:48:13,131::task::588::TaskManager.Task::(_updateState) Task=`11864c87-d75d-4c0c-b889-096e8c9563a4`::moving from state init -> state preparing
>Thread-47::INFO::2013-03-01 15:48:13,132::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-47::INFO::2013-03-01 15:48:13,132::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-47::DEBUG::2013-03-01 15:48:13,133::task::1172::TaskManager.Task::(prepare) Task=`11864c87-d75d-4c0c-b889-096e8c9563a4`::finished: {}
>Thread-47::DEBUG::2013-03-01 15:48:13,133::task::588::TaskManager.Task::(_updateState) Task=`11864c87-d75d-4c0c-b889-096e8c9563a4`::moving from state preparing -> state finished
>Thread-47::DEBUG::2013-03-01 15:48:13,134::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-47::DEBUG::2013-03-01 15:48:13,134::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-47::DEBUG::2013-03-01 15:48:13,135::task::978::TaskManager.Task::(_decref) Task=`11864c87-d75d-4c0c-b889-096e8c9563a4`::ref 0 aborting False
>Thread-53::DEBUG::2013-03-01 15:48:28,344::task::588::TaskManager.Task::(_updateState) Task=`0610603c-6b54-4fab-9393-b1455a0d6924`::moving from state init -> state preparing
>Thread-53::INFO::2013-03-01 15:48:28,344::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-53::INFO::2013-03-01 15:48:28,345::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-53::DEBUG::2013-03-01 15:48:28,345::task::1172::TaskManager.Task::(prepare) Task=`0610603c-6b54-4fab-9393-b1455a0d6924`::finished: {}
>Thread-53::DEBUG::2013-03-01 15:48:28,346::task::588::TaskManager.Task::(_updateState) Task=`0610603c-6b54-4fab-9393-b1455a0d6924`::moving from state preparing -> state finished
>Thread-53::DEBUG::2013-03-01 15:48:28,346::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-53::DEBUG::2013-03-01 15:48:28,346::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-53::DEBUG::2013-03-01 15:48:28,347::task::978::TaskManager.Task::(_decref) Task=`0610603c-6b54-4fab-9393-b1455a0d6924`::ref 0 aborting False
>Thread-59::DEBUG::2013-03-01 15:48:43,548::task::588::TaskManager.Task::(_updateState) Task=`75f3db68-70de-4059-942c-67c0779ee70e`::moving from state init -> state preparing
>Thread-59::INFO::2013-03-01 15:48:43,548::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-59::INFO::2013-03-01 15:48:43,549::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-59::DEBUG::2013-03-01 15:48:43,549::task::1172::TaskManager.Task::(prepare) Task=`75f3db68-70de-4059-942c-67c0779ee70e`::finished: {}
>Thread-59::DEBUG::2013-03-01 15:48:43,550::task::588::TaskManager.Task::(_updateState) Task=`75f3db68-70de-4059-942c-67c0779ee70e`::moving from state preparing -> state finished
>Thread-59::DEBUG::2013-03-01 15:48:43,550::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-59::DEBUG::2013-03-01 15:48:43,551::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-59::DEBUG::2013-03-01 15:48:43,551::task::978::TaskManager.Task::(_decref) Task=`75f3db68-70de-4059-942c-67c0779ee70e`::ref 0 aborting False
>Thread-65::DEBUG::2013-03-01 15:48:58,748::task::588::TaskManager.Task::(_updateState) Task=`2bc3249e-0738-42bb-9fa2-2f0fffe977b6`::moving from state init -> state preparing
>Thread-65::INFO::2013-03-01 15:48:58,749::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-65::INFO::2013-03-01 15:48:58,749::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-65::DEBUG::2013-03-01 15:48:58,750::task::1172::TaskManager.Task::(prepare) Task=`2bc3249e-0738-42bb-9fa2-2f0fffe977b6`::finished: {}
>Thread-65::DEBUG::2013-03-01 15:48:58,750::task::588::TaskManager.Task::(_updateState) Task=`2bc3249e-0738-42bb-9fa2-2f0fffe977b6`::moving from state preparing -> state finished
>Thread-65::DEBUG::2013-03-01 15:48:58,750::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-65::DEBUG::2013-03-01 15:48:58,751::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-65::DEBUG::2013-03-01 15:48:58,751::task::978::TaskManager.Task::(_decref) Task=`2bc3249e-0738-42bb-9fa2-2f0fffe977b6`::ref 0 aborting False
>Thread-71::DEBUG::2013-03-01 15:49:14,005::task::588::TaskManager.Task::(_updateState) Task=`ddb51292-fd8b-442e-9ce8-b81de692dcd9`::moving from state init -> state preparing
>Thread-71::INFO::2013-03-01 15:49:14,005::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-71::INFO::2013-03-01 15:49:14,006::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-71::DEBUG::2013-03-01 15:49:14,006::task::1172::TaskManager.Task::(prepare) Task=`ddb51292-fd8b-442e-9ce8-b81de692dcd9`::finished: {}
>Thread-71::DEBUG::2013-03-01 15:49:14,007::task::588::TaskManager.Task::(_updateState) Task=`ddb51292-fd8b-442e-9ce8-b81de692dcd9`::moving from state preparing -> state finished
>Thread-71::DEBUG::2013-03-01 15:49:14,007::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-71::DEBUG::2013-03-01 15:49:14,008::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-71::DEBUG::2013-03-01 15:49:14,008::task::978::TaskManager.Task::(_decref) Task=`ddb51292-fd8b-442e-9ce8-b81de692dcd9`::ref 0 aborting False
>Thread-74::DEBUG::2013-03-01 15:49:17,394::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-74::DEBUG::2013-03-01 15:49:17,436::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-74::DEBUG::2013-03-01 15:49:17,462::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-74::DEBUG::2013-03-01 15:49:17,463::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-74::DEBUG::2013-03-01 15:49:17,487::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-74::DEBUG::2013-03-01 15:49:17,488::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-74::DEBUG::2013-03-01 15:49:17,513::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-74::DEBUG::2013-03-01 15:49:17,514::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-74::DEBUG::2013-03-01 15:49:17,538::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-74::DEBUG::2013-03-01 15:49:17,539::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-74::DEBUG::2013-03-01 15:49:17,566::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-74::DEBUG::2013-03-01 15:49:17,567::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-78::DEBUG::2013-03-01 15:49:29,212::task::588::TaskManager.Task::(_updateState) Task=`6d682646-9498-4117-8706-3a376aea167b`::moving from state init -> state preparing
>Thread-78::INFO::2013-03-01 15:49:29,212::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-78::INFO::2013-03-01 15:49:29,213::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-78::DEBUG::2013-03-01 15:49:29,213::task::1172::TaskManager.Task::(prepare) Task=`6d682646-9498-4117-8706-3a376aea167b`::finished: {}
>Thread-78::DEBUG::2013-03-01 15:49:29,214::task::588::TaskManager.Task::(_updateState) Task=`6d682646-9498-4117-8706-3a376aea167b`::moving from state preparing -> state finished
>Thread-78::DEBUG::2013-03-01 15:49:29,214::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-78::DEBUG::2013-03-01 15:49:29,214::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-78::DEBUG::2013-03-01 15:49:29,215::task::978::TaskManager.Task::(_decref) Task=`6d682646-9498-4117-8706-3a376aea167b`::ref 0 aborting False
>Thread-84::DEBUG::2013-03-01 15:49:44,426::task::588::TaskManager.Task::(_updateState) Task=`ab49c98c-a59d-48e0-8bdf-32542392815a`::moving from state init -> state preparing
>Thread-84::INFO::2013-03-01 15:49:44,427::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-84::INFO::2013-03-01 15:49:44,427::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-84::DEBUG::2013-03-01 15:49:44,428::task::1172::TaskManager.Task::(prepare) Task=`ab49c98c-a59d-48e0-8bdf-32542392815a`::finished: {}
>Thread-84::DEBUG::2013-03-01 15:49:44,428::task::588::TaskManager.Task::(_updateState) Task=`ab49c98c-a59d-48e0-8bdf-32542392815a`::moving from state preparing -> state finished
>Thread-84::DEBUG::2013-03-01 15:49:44,429::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-84::DEBUG::2013-03-01 15:49:44,429::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-84::DEBUG::2013-03-01 15:49:44,430::task::978::TaskManager.Task::(_decref) Task=`ab49c98c-a59d-48e0-8bdf-32542392815a`::ref 0 aborting False
>Thread-90::DEBUG::2013-03-01 15:49:59,630::task::588::TaskManager.Task::(_updateState) Task=`64b6697a-4d88-40f7-8e0a-8b3ee2c9fea0`::moving from state init -> state preparing
>Thread-90::INFO::2013-03-01 15:49:59,631::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-90::INFO::2013-03-01 15:49:59,631::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-90::DEBUG::2013-03-01 15:49:59,632::task::1172::TaskManager.Task::(prepare) Task=`64b6697a-4d88-40f7-8e0a-8b3ee2c9fea0`::finished: {}
>Thread-90::DEBUG::2013-03-01 15:49:59,632::task::588::TaskManager.Task::(_updateState) Task=`64b6697a-4d88-40f7-8e0a-8b3ee2c9fea0`::moving from state preparing -> state finished
>Thread-90::DEBUG::2013-03-01 15:49:59,632::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-90::DEBUG::2013-03-01 15:49:59,633::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-90::DEBUG::2013-03-01 15:49:59,633::task::978::TaskManager.Task::(_decref) Task=`64b6697a-4d88-40f7-8e0a-8b3ee2c9fea0`::ref 0 aborting False
>Thread-96::DEBUG::2013-03-01 15:50:14,835::task::588::TaskManager.Task::(_updateState) Task=`638a0b3a-4560-496b-9c98-1cd060d67894`::moving from state init -> state preparing
>Thread-96::INFO::2013-03-01 15:50:14,835::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-96::INFO::2013-03-01 15:50:14,835::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-96::DEBUG::2013-03-01 15:50:14,836::task::1172::TaskManager.Task::(prepare) Task=`638a0b3a-4560-496b-9c98-1cd060d67894`::finished: {}
>Thread-96::DEBUG::2013-03-01 15:50:14,836::task::588::TaskManager.Task::(_updateState) Task=`638a0b3a-4560-496b-9c98-1cd060d67894`::moving from state preparing -> state finished
>Thread-96::DEBUG::2013-03-01 15:50:14,837::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-96::DEBUG::2013-03-01 15:50:14,837::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-96::DEBUG::2013-03-01 15:50:14,838::task::978::TaskManager.Task::(_decref) Task=`638a0b3a-4560-496b-9c98-1cd060d67894`::ref 0 aborting False
>Thread-102::DEBUG::2013-03-01 15:50:30,042::task::588::TaskManager.Task::(_updateState) Task=`dbaaba0c-f933-4a3e-867b-c2564435ec0a`::moving from state init -> state preparing
>Thread-102::INFO::2013-03-01 15:50:30,043::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-102::INFO::2013-03-01 15:50:30,043::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-102::DEBUG::2013-03-01 15:50:30,044::task::1172::TaskManager.Task::(prepare) Task=`dbaaba0c-f933-4a3e-867b-c2564435ec0a`::finished: {}
>Thread-102::DEBUG::2013-03-01 15:50:30,044::task::588::TaskManager.Task::(_updateState) Task=`dbaaba0c-f933-4a3e-867b-c2564435ec0a`::moving from state preparing -> state finished
>Thread-102::DEBUG::2013-03-01 15:50:30,044::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-102::DEBUG::2013-03-01 15:50:30,045::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-102::DEBUG::2013-03-01 15:50:30,045::task::978::TaskManager.Task::(_decref) Task=`dbaaba0c-f933-4a3e-867b-c2564435ec0a`::ref 0 aborting False
>Thread-108::DEBUG::2013-03-01 15:50:45,253::task::588::TaskManager.Task::(_updateState) Task=`b6991e8e-1217-463a-ab71-540fbb34ea53`::moving from state init -> state preparing
>Thread-108::INFO::2013-03-01 15:50:45,254::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-108::INFO::2013-03-01 15:50:45,254::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-108::DEBUG::2013-03-01 15:50:45,255::task::1172::TaskManager.Task::(prepare) Task=`b6991e8e-1217-463a-ab71-540fbb34ea53`::finished: {}
>Thread-108::DEBUG::2013-03-01 15:50:45,255::task::588::TaskManager.Task::(_updateState) Task=`b6991e8e-1217-463a-ab71-540fbb34ea53`::moving from state preparing -> state finished
>Thread-108::DEBUG::2013-03-01 15:50:45,256::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-108::DEBUG::2013-03-01 15:50:45,256::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-108::DEBUG::2013-03-01 15:50:45,256::task::978::TaskManager.Task::(_decref) Task=`b6991e8e-1217-463a-ab71-540fbb34ea53`::ref 0 aborting False
>Thread-114::DEBUG::2013-03-01 15:51:00,468::task::588::TaskManager.Task::(_updateState) Task=`266590ae-4e4b-45e7-a694-d4d6d94ded6e`::moving from state init -> state preparing
>Thread-114::INFO::2013-03-01 15:51:00,468::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-114::INFO::2013-03-01 15:51:00,469::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-114::DEBUG::2013-03-01 15:51:00,469::task::1172::TaskManager.Task::(prepare) Task=`266590ae-4e4b-45e7-a694-d4d6d94ded6e`::finished: {}
>Thread-114::DEBUG::2013-03-01 15:51:00,470::task::588::TaskManager.Task::(_updateState) Task=`266590ae-4e4b-45e7-a694-d4d6d94ded6e`::moving from state preparing -> state finished
>Thread-114::DEBUG::2013-03-01 15:51:00,470::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-114::DEBUG::2013-03-01 15:51:00,470::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-114::DEBUG::2013-03-01 15:51:00,471::task::978::TaskManager.Task::(_decref) Task=`266590ae-4e4b-45e7-a694-d4d6d94ded6e`::ref 0 aborting False
>Thread-120::DEBUG::2013-03-01 15:51:15,672::task::588::TaskManager.Task::(_updateState) Task=`f26d421c-8796-415b-8311-a61655a3c75a`::moving from state init -> state preparing
>Thread-120::INFO::2013-03-01 15:51:15,672::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-120::INFO::2013-03-01 15:51:15,672::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-120::DEBUG::2013-03-01 15:51:15,673::task::1172::TaskManager.Task::(prepare) Task=`f26d421c-8796-415b-8311-a61655a3c75a`::finished: {}
>Thread-120::DEBUG::2013-03-01 15:51:15,673::task::588::TaskManager.Task::(_updateState) Task=`f26d421c-8796-415b-8311-a61655a3c75a`::moving from state preparing -> state finished
>Thread-120::DEBUG::2013-03-01 15:51:15,674::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-120::DEBUG::2013-03-01 15:51:15,674::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-120::DEBUG::2013-03-01 15:51:15,675::task::978::TaskManager.Task::(_decref) Task=`f26d421c-8796-415b-8311-a61655a3c75a`::ref 0 aborting False
>Thread-126::DEBUG::2013-03-01 15:51:30,879::task::588::TaskManager.Task::(_updateState) Task=`36da8cd9-6fac-4532-811e-bddca37916f7`::moving from state init -> state preparing
>Thread-126::INFO::2013-03-01 15:51:30,880::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-126::INFO::2013-03-01 15:51:30,880::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-126::DEBUG::2013-03-01 15:51:30,881::task::1172::TaskManager.Task::(prepare) Task=`36da8cd9-6fac-4532-811e-bddca37916f7`::finished: {}
>Thread-126::DEBUG::2013-03-01 15:51:30,881::task::588::TaskManager.Task::(_updateState) Task=`36da8cd9-6fac-4532-811e-bddca37916f7`::moving from state preparing -> state finished
>Thread-126::DEBUG::2013-03-01 15:51:30,881::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-126::DEBUG::2013-03-01 15:51:30,882::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-126::DEBUG::2013-03-01 15:51:30,882::task::978::TaskManager.Task::(_decref) Task=`36da8cd9-6fac-4532-811e-bddca37916f7`::ref 0 aborting False
>Thread-132::DEBUG::2013-03-01 15:51:46,100::task::588::TaskManager.Task::(_updateState) Task=`6ad8ccbe-cfbf-4b53-89b4-e1d2963083e9`::moving from state init -> state preparing
>Thread-132::INFO::2013-03-01 15:51:46,101::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-132::INFO::2013-03-01 15:51:46,101::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-132::DEBUG::2013-03-01 15:51:46,102::task::1172::TaskManager.Task::(prepare) Task=`6ad8ccbe-cfbf-4b53-89b4-e1d2963083e9`::finished: {}
>Thread-132::DEBUG::2013-03-01 15:51:46,102::task::588::TaskManager.Task::(_updateState) Task=`6ad8ccbe-cfbf-4b53-89b4-e1d2963083e9`::moving from state preparing -> state finished
>Thread-132::DEBUG::2013-03-01 15:51:46,103::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-132::DEBUG::2013-03-01 15:51:46,103::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-132::DEBUG::2013-03-01 15:51:46,103::task::978::TaskManager.Task::(_decref) Task=`6ad8ccbe-cfbf-4b53-89b4-e1d2963083e9`::ref 0 aborting False
>Thread-138::DEBUG::2013-03-01 15:52:01,305::task::588::TaskManager.Task::(_updateState) Task=`3771b18c-fa1a-4b82-b118-d6f94c2bcba4`::moving from state init -> state preparing
>Thread-138::INFO::2013-03-01 15:52:01,306::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-138::INFO::2013-03-01 15:52:01,306::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-138::DEBUG::2013-03-01 15:52:01,307::task::1172::TaskManager.Task::(prepare) Task=`3771b18c-fa1a-4b82-b118-d6f94c2bcba4`::finished: {}
>Thread-138::DEBUG::2013-03-01 15:52:01,307::task::588::TaskManager.Task::(_updateState) Task=`3771b18c-fa1a-4b82-b118-d6f94c2bcba4`::moving from state preparing -> state finished
>Thread-138::DEBUG::2013-03-01 15:52:01,308::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-138::DEBUG::2013-03-01 15:52:01,308::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-138::DEBUG::2013-03-01 15:52:01,309::task::978::TaskManager.Task::(_decref) Task=`3771b18c-fa1a-4b82-b118-d6f94c2bcba4`::ref 0 aborting False
>Thread-144::DEBUG::2013-03-01 15:52:16,518::task::588::TaskManager.Task::(_updateState) Task=`d64103f8-7759-4dc7-bc84-5f163484dba7`::moving from state init -> state preparing
>Thread-144::INFO::2013-03-01 15:52:16,518::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-144::INFO::2013-03-01 15:52:16,519::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-144::DEBUG::2013-03-01 15:52:16,519::task::1172::TaskManager.Task::(prepare) Task=`d64103f8-7759-4dc7-bc84-5f163484dba7`::finished: {}
>Thread-144::DEBUG::2013-03-01 15:52:16,519::task::588::TaskManager.Task::(_updateState) Task=`d64103f8-7759-4dc7-bc84-5f163484dba7`::moving from state preparing -> state finished
>Thread-144::DEBUG::2013-03-01 15:52:16,520::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-144::DEBUG::2013-03-01 15:52:16,520::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-144::DEBUG::2013-03-01 15:52:16,521::task::978::TaskManager.Task::(_decref) Task=`d64103f8-7759-4dc7-bc84-5f163484dba7`::ref 0 aborting False
>Thread-150::DEBUG::2013-03-01 15:52:31,725::task::588::TaskManager.Task::(_updateState) Task=`aba40fe4-6e22-42b3-aaa1-dd7a9839e6c4`::moving from state init -> state preparing
>Thread-150::INFO::2013-03-01 15:52:31,726::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-150::INFO::2013-03-01 15:52:31,726::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-150::DEBUG::2013-03-01 15:52:31,727::task::1172::TaskManager.Task::(prepare) Task=`aba40fe4-6e22-42b3-aaa1-dd7a9839e6c4`::finished: {}
>Thread-150::DEBUG::2013-03-01 15:52:31,727::task::588::TaskManager.Task::(_updateState) Task=`aba40fe4-6e22-42b3-aaa1-dd7a9839e6c4`::moving from state preparing -> state finished
>Thread-150::DEBUG::2013-03-01 15:52:31,728::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-150::DEBUG::2013-03-01 15:52:31,728::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-150::DEBUG::2013-03-01 15:52:31,728::task::978::TaskManager.Task::(_decref) Task=`aba40fe4-6e22-42b3-aaa1-dd7a9839e6c4`::ref 0 aborting False
>Thread-156::DEBUG::2013-03-01 15:52:46,939::task::588::TaskManager.Task::(_updateState) Task=`bf350edd-9fa1-4d03-9278-dd1c9a353b43`::moving from state init -> state preparing
>Thread-156::INFO::2013-03-01 15:52:46,939::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-156::INFO::2013-03-01 15:52:46,940::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-156::DEBUG::2013-03-01 15:52:46,940::task::1172::TaskManager.Task::(prepare) Task=`bf350edd-9fa1-4d03-9278-dd1c9a353b43`::finished: {}
>Thread-156::DEBUG::2013-03-01 15:52:46,941::task::588::TaskManager.Task::(_updateState) Task=`bf350edd-9fa1-4d03-9278-dd1c9a353b43`::moving from state preparing -> state finished
>Thread-156::DEBUG::2013-03-01 15:52:46,941::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-156::DEBUG::2013-03-01 15:52:46,942::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-156::DEBUG::2013-03-01 15:52:46,942::task::978::TaskManager.Task::(_decref) Task=`bf350edd-9fa1-4d03-9278-dd1c9a353b43`::ref 0 aborting False
>Thread-162::DEBUG::2013-03-01 15:53:02,149::task::588::TaskManager.Task::(_updateState) Task=`36fbb263-8fa7-4e0e-b179-94516a7c8f9d`::moving from state init -> state preparing
>Thread-162::INFO::2013-03-01 15:53:02,149::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-162::INFO::2013-03-01 15:53:02,150::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-162::DEBUG::2013-03-01 15:53:02,150::task::1172::TaskManager.Task::(prepare) Task=`36fbb263-8fa7-4e0e-b179-94516a7c8f9d`::finished: {}
>Thread-162::DEBUG::2013-03-01 15:53:02,151::task::588::TaskManager.Task::(_updateState) Task=`36fbb263-8fa7-4e0e-b179-94516a7c8f9d`::moving from state preparing -> state finished
>Thread-162::DEBUG::2013-03-01 15:53:02,151::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-162::DEBUG::2013-03-01 15:53:02,151::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-162::DEBUG::2013-03-01 15:53:02,152::task::978::TaskManager.Task::(_decref) Task=`36fbb263-8fa7-4e0e-b179-94516a7c8f9d`::ref 0 aborting False
>Thread-168::DEBUG::2013-03-01 15:53:17,358::task::588::TaskManager.Task::(_updateState) Task=`046b438b-6397-4b17-9b21-fa9796e52854`::moving from state init -> state preparing
>Thread-168::INFO::2013-03-01 15:53:17,358::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-168::INFO::2013-03-01 15:53:17,359::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-168::DEBUG::2013-03-01 15:53:17,359::task::1172::TaskManager.Task::(prepare) Task=`046b438b-6397-4b17-9b21-fa9796e52854`::finished: {}
>Thread-168::DEBUG::2013-03-01 15:53:17,359::task::588::TaskManager.Task::(_updateState) Task=`046b438b-6397-4b17-9b21-fa9796e52854`::moving from state preparing -> state finished
>Thread-168::DEBUG::2013-03-01 15:53:17,360::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-168::DEBUG::2013-03-01 15:53:17,360::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-168::DEBUG::2013-03-01 15:53:17,361::task::978::TaskManager.Task::(_decref) Task=`046b438b-6397-4b17-9b21-fa9796e52854`::ref 0 aborting False
>Thread-174::DEBUG::2013-03-01 15:53:32,562::task::588::TaskManager.Task::(_updateState) Task=`ac680e0a-d02c-4f4a-bed9-5b56b96a7914`::moving from state init -> state preparing
>Thread-174::INFO::2013-03-01 15:53:32,563::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-174::INFO::2013-03-01 15:53:32,564::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-174::DEBUG::2013-03-01 15:53:32,564::task::1172::TaskManager.Task::(prepare) Task=`ac680e0a-d02c-4f4a-bed9-5b56b96a7914`::finished: {}
>Thread-174::DEBUG::2013-03-01 15:53:32,564::task::588::TaskManager.Task::(_updateState) Task=`ac680e0a-d02c-4f4a-bed9-5b56b96a7914`::moving from state preparing -> state finished
>Thread-174::DEBUG::2013-03-01 15:53:32,565::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-174::DEBUG::2013-03-01 15:53:32,565::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-174::DEBUG::2013-03-01 15:53:32,566::task::978::TaskManager.Task::(_decref) Task=`ac680e0a-d02c-4f4a-bed9-5b56b96a7914`::ref 0 aborting False
>Thread-180::DEBUG::2013-03-01 15:53:47,764::task::588::TaskManager.Task::(_updateState) Task=`38f8a22b-3fbe-4c53-97ab-9ae681caf704`::moving from state init -> state preparing
>Thread-180::INFO::2013-03-01 15:53:47,765::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-180::INFO::2013-03-01 15:53:47,765::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-180::DEBUG::2013-03-01 15:53:47,766::task::1172::TaskManager.Task::(prepare) Task=`38f8a22b-3fbe-4c53-97ab-9ae681caf704`::finished: {}
>Thread-180::DEBUG::2013-03-01 15:53:47,766::task::588::TaskManager.Task::(_updateState) Task=`38f8a22b-3fbe-4c53-97ab-9ae681caf704`::moving from state preparing -> state finished
>Thread-180::DEBUG::2013-03-01 15:53:47,766::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-180::DEBUG::2013-03-01 15:53:47,767::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-180::DEBUG::2013-03-01 15:53:47,767::task::978::TaskManager.Task::(_decref) Task=`38f8a22b-3fbe-4c53-97ab-9ae681caf704`::ref 0 aborting False
>Thread-186::DEBUG::2013-03-01 15:54:02,967::task::588::TaskManager.Task::(_updateState) Task=`cf858b86-bab6-43c5-bc22-9950de7d621f`::moving from state init -> state preparing
>Thread-186::INFO::2013-03-01 15:54:02,968::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-186::INFO::2013-03-01 15:54:02,968::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-186::DEBUG::2013-03-01 15:54:02,969::task::1172::TaskManager.Task::(prepare) Task=`cf858b86-bab6-43c5-bc22-9950de7d621f`::finished: {}
>Thread-186::DEBUG::2013-03-01 15:54:02,969::task::588::TaskManager.Task::(_updateState) Task=`cf858b86-bab6-43c5-bc22-9950de7d621f`::moving from state preparing -> state finished
>Thread-186::DEBUG::2013-03-01 15:54:02,970::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-186::DEBUG::2013-03-01 15:54:02,970::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-186::DEBUG::2013-03-01 15:54:02,970::task::978::TaskManager.Task::(_decref) Task=`cf858b86-bab6-43c5-bc22-9950de7d621f`::ref 0 aborting False
>Thread-192::DEBUG::2013-03-01 15:54:17,373::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-192::DEBUG::2013-03-01 15:54:17,413::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-192::DEBUG::2013-03-01 15:54:17,438::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-192::DEBUG::2013-03-01 15:54:17,439::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-192::DEBUG::2013-03-01 15:54:17,465::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-192::DEBUG::2013-03-01 15:54:17,466::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-192::DEBUG::2013-03-01 15:54:17,491::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-192::DEBUG::2013-03-01 15:54:17,492::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-192::DEBUG::2013-03-01 15:54:17,517::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-192::DEBUG::2013-03-01 15:54:17,518::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-192::DEBUG::2013-03-01 15:54:17,545::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-192::DEBUG::2013-03-01 15:54:17,546::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-193::DEBUG::2013-03-01 15:54:18,175::task::588::TaskManager.Task::(_updateState) Task=`584635fe-5fd2-4909-a84f-3d8b56c38cbe`::moving from state init -> state preparing
>Thread-193::INFO::2013-03-01 15:54:18,175::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-193::INFO::2013-03-01 15:54:18,175::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-193::DEBUG::2013-03-01 15:54:18,176::task::1172::TaskManager.Task::(prepare) Task=`584635fe-5fd2-4909-a84f-3d8b56c38cbe`::finished: {}
>Thread-193::DEBUG::2013-03-01 15:54:18,176::task::588::TaskManager.Task::(_updateState) Task=`584635fe-5fd2-4909-a84f-3d8b56c38cbe`::moving from state preparing -> state finished
>Thread-193::DEBUG::2013-03-01 15:54:18,177::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-193::DEBUG::2013-03-01 15:54:18,177::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-193::DEBUG::2013-03-01 15:54:18,178::task::978::TaskManager.Task::(_decref) Task=`584635fe-5fd2-4909-a84f-3d8b56c38cbe`::ref 0 aborting False
>Thread-199::DEBUG::2013-03-01 15:54:33,373::task::588::TaskManager.Task::(_updateState) Task=`0a2063d6-79cc-4898-aba3-cf5d33b2f452`::moving from state init -> state preparing
>Thread-199::INFO::2013-03-01 15:54:33,374::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-199::INFO::2013-03-01 15:54:33,374::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-199::DEBUG::2013-03-01 15:54:33,375::task::1172::TaskManager.Task::(prepare) Task=`0a2063d6-79cc-4898-aba3-cf5d33b2f452`::finished: {}
>Thread-199::DEBUG::2013-03-01 15:54:33,375::task::588::TaskManager.Task::(_updateState) Task=`0a2063d6-79cc-4898-aba3-cf5d33b2f452`::moving from state preparing -> state finished
>Thread-199::DEBUG::2013-03-01 15:54:33,375::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-199::DEBUG::2013-03-01 15:54:33,376::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-199::DEBUG::2013-03-01 15:54:33,376::task::978::TaskManager.Task::(_decref) Task=`0a2063d6-79cc-4898-aba3-cf5d33b2f452`::ref 0 aborting False
>Thread-205::DEBUG::2013-03-01 15:54:48,581::task::588::TaskManager.Task::(_updateState) Task=`eab34703-48f8-419a-a73f-758f24497cc9`::moving from state init -> state preparing
>Thread-205::INFO::2013-03-01 15:54:48,582::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-205::INFO::2013-03-01 15:54:48,582::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-205::DEBUG::2013-03-01 15:54:48,583::task::1172::TaskManager.Task::(prepare) Task=`eab34703-48f8-419a-a73f-758f24497cc9`::finished: {}
>Thread-205::DEBUG::2013-03-01 15:54:48,583::task::588::TaskManager.Task::(_updateState) Task=`eab34703-48f8-419a-a73f-758f24497cc9`::moving from state preparing -> state finished
>Thread-205::DEBUG::2013-03-01 15:54:48,583::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-205::DEBUG::2013-03-01 15:54:48,584::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-205::DEBUG::2013-03-01 15:54:48,584::task::978::TaskManager.Task::(_decref) Task=`eab34703-48f8-419a-a73f-758f24497cc9`::ref 0 aborting False
>Thread-211::DEBUG::2013-03-01 15:55:03,783::task::588::TaskManager.Task::(_updateState) Task=`6be234ab-ee50-45f1-b293-3b76b71017e3`::moving from state init -> state preparing
>Thread-211::INFO::2013-03-01 15:55:03,784::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-211::INFO::2013-03-01 15:55:03,784::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-211::DEBUG::2013-03-01 15:55:03,785::task::1172::TaskManager.Task::(prepare) Task=`6be234ab-ee50-45f1-b293-3b76b71017e3`::finished: {}
>Thread-211::DEBUG::2013-03-01 15:55:03,785::task::588::TaskManager.Task::(_updateState) Task=`6be234ab-ee50-45f1-b293-3b76b71017e3`::moving from state preparing -> state finished
>Thread-211::DEBUG::2013-03-01 15:55:03,786::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-211::DEBUG::2013-03-01 15:55:03,786::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-211::DEBUG::2013-03-01 15:55:03,787::task::978::TaskManager.Task::(_decref) Task=`6be234ab-ee50-45f1-b293-3b76b71017e3`::ref 0 aborting False
>Thread-217::DEBUG::2013-03-01 15:55:18,981::task::588::TaskManager.Task::(_updateState) Task=`248c5b44-a3ec-4e98-957a-4e8df4c29ab7`::moving from state init -> state preparing
>Thread-217::INFO::2013-03-01 15:55:18,982::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-217::INFO::2013-03-01 15:55:18,982::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-217::DEBUG::2013-03-01 15:55:18,983::task::1172::TaskManager.Task::(prepare) Task=`248c5b44-a3ec-4e98-957a-4e8df4c29ab7`::finished: {}
>Thread-217::DEBUG::2013-03-01 15:55:18,983::task::588::TaskManager.Task::(_updateState) Task=`248c5b44-a3ec-4e98-957a-4e8df4c29ab7`::moving from state preparing -> state finished
>Thread-217::DEBUG::2013-03-01 15:55:18,983::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-217::DEBUG::2013-03-01 15:55:18,984::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-217::DEBUG::2013-03-01 15:55:18,984::task::978::TaskManager.Task::(_decref) Task=`248c5b44-a3ec-4e98-957a-4e8df4c29ab7`::ref 0 aborting False
>Thread-223::DEBUG::2013-03-01 15:55:34,171::task::588::TaskManager.Task::(_updateState) Task=`282e761a-5cf7-46cb-a8d1-b5a22c7d6388`::moving from state init -> state preparing
>Thread-223::INFO::2013-03-01 15:55:34,172::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-223::INFO::2013-03-01 15:55:34,172::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-223::DEBUG::2013-03-01 15:55:34,173::task::1172::TaskManager.Task::(prepare) Task=`282e761a-5cf7-46cb-a8d1-b5a22c7d6388`::finished: {}
>Thread-223::DEBUG::2013-03-01 15:55:34,173::task::588::TaskManager.Task::(_updateState) Task=`282e761a-5cf7-46cb-a8d1-b5a22c7d6388`::moving from state preparing -> state finished
>Thread-223::DEBUG::2013-03-01 15:55:34,174::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-223::DEBUG::2013-03-01 15:55:34,174::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-223::DEBUG::2013-03-01 15:55:34,174::task::978::TaskManager.Task::(_decref) Task=`282e761a-5cf7-46cb-a8d1-b5a22c7d6388`::ref 0 aborting False
>Thread-229::DEBUG::2013-03-01 15:55:49,358::task::588::TaskManager.Task::(_updateState) Task=`65f57523-8c3c-480b-8abf-fddee83aadeb`::moving from state init -> state preparing
>Thread-229::INFO::2013-03-01 15:55:49,359::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-229::INFO::2013-03-01 15:55:49,359::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-229::DEBUG::2013-03-01 15:55:49,360::task::1172::TaskManager.Task::(prepare) Task=`65f57523-8c3c-480b-8abf-fddee83aadeb`::finished: {}
>Thread-229::DEBUG::2013-03-01 15:55:49,360::task::588::TaskManager.Task::(_updateState) Task=`65f57523-8c3c-480b-8abf-fddee83aadeb`::moving from state preparing -> state finished
>Thread-229::DEBUG::2013-03-01 15:55:49,361::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-229::DEBUG::2013-03-01 15:55:49,361::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-229::DEBUG::2013-03-01 15:55:49,361::task::978::TaskManager.Task::(_decref) Task=`65f57523-8c3c-480b-8abf-fddee83aadeb`::ref 0 aborting False
>Thread-235::DEBUG::2013-03-01 15:56:04,555::task::588::TaskManager.Task::(_updateState) Task=`39904806-7332-4a23-b25b-4b984dc8395a`::moving from state init -> state preparing
>Thread-235::INFO::2013-03-01 15:56:04,556::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-235::INFO::2013-03-01 15:56:04,556::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-235::DEBUG::2013-03-01 15:56:04,556::task::1172::TaskManager.Task::(prepare) Task=`39904806-7332-4a23-b25b-4b984dc8395a`::finished: {}
>Thread-235::DEBUG::2013-03-01 15:56:04,557::task::588::TaskManager.Task::(_updateState) Task=`39904806-7332-4a23-b25b-4b984dc8395a`::moving from state preparing -> state finished
>Thread-235::DEBUG::2013-03-01 15:56:04,557::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-235::DEBUG::2013-03-01 15:56:04,558::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-235::DEBUG::2013-03-01 15:56:04,558::task::978::TaskManager.Task::(_decref) Task=`39904806-7332-4a23-b25b-4b984dc8395a`::ref 0 aborting False
>Thread-241::DEBUG::2013-03-01 15:56:19,762::task::588::TaskManager.Task::(_updateState) Task=`6af602f3-277c-4163-b2ef-c9c52b5ecbc8`::moving from state init -> state preparing
>Thread-241::INFO::2013-03-01 15:56:19,762::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-241::INFO::2013-03-01 15:56:19,763::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-241::DEBUG::2013-03-01 15:56:19,763::task::1172::TaskManager.Task::(prepare) Task=`6af602f3-277c-4163-b2ef-c9c52b5ecbc8`::finished: {}
>Thread-241::DEBUG::2013-03-01 15:56:19,764::task::588::TaskManager.Task::(_updateState) Task=`6af602f3-277c-4163-b2ef-c9c52b5ecbc8`::moving from state preparing -> state finished
>Thread-241::DEBUG::2013-03-01 15:56:19,764::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-241::DEBUG::2013-03-01 15:56:19,764::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-241::DEBUG::2013-03-01 15:56:19,765::task::978::TaskManager.Task::(_decref) Task=`6af602f3-277c-4163-b2ef-c9c52b5ecbc8`::ref 0 aborting False
>Thread-247::DEBUG::2013-03-01 15:56:34,968::task::588::TaskManager.Task::(_updateState) Task=`0ff39fbe-4878-4325-80f7-175666fd9339`::moving from state init -> state preparing
>Thread-247::INFO::2013-03-01 15:56:34,969::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-247::INFO::2013-03-01 15:56:34,969::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-247::DEBUG::2013-03-01 15:56:34,970::task::1172::TaskManager.Task::(prepare) Task=`0ff39fbe-4878-4325-80f7-175666fd9339`::finished: {}
>Thread-247::DEBUG::2013-03-01 15:56:34,970::task::588::TaskManager.Task::(_updateState) Task=`0ff39fbe-4878-4325-80f7-175666fd9339`::moving from state preparing -> state finished
>Thread-247::DEBUG::2013-03-01 15:56:34,971::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-247::DEBUG::2013-03-01 15:56:34,971::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-247::DEBUG::2013-03-01 15:56:34,972::task::978::TaskManager.Task::(_decref) Task=`0ff39fbe-4878-4325-80f7-175666fd9339`::ref 0 aborting False
>Thread-253::DEBUG::2013-03-01 15:56:50,163::task::588::TaskManager.Task::(_updateState) Task=`bb981200-b76c-4948-a2d5-96ace106133c`::moving from state init -> state preparing
>Thread-253::INFO::2013-03-01 15:56:50,164::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-253::INFO::2013-03-01 15:56:50,164::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-253::DEBUG::2013-03-01 15:56:50,165::task::1172::TaskManager.Task::(prepare) Task=`bb981200-b76c-4948-a2d5-96ace106133c`::finished: {}
>Thread-253::DEBUG::2013-03-01 15:56:50,165::task::588::TaskManager.Task::(_updateState) Task=`bb981200-b76c-4948-a2d5-96ace106133c`::moving from state preparing -> state finished
>Thread-253::DEBUG::2013-03-01 15:56:50,166::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-253::DEBUG::2013-03-01 15:56:50,166::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-253::DEBUG::2013-03-01 15:56:50,166::task::978::TaskManager.Task::(_decref) Task=`bb981200-b76c-4948-a2d5-96ace106133c`::ref 0 aborting False
>Thread-259::DEBUG::2013-03-01 15:57:05,359::task::588::TaskManager.Task::(_updateState) Task=`edf2a1fb-8274-4095-a0d6-68edadeb8e02`::moving from state init -> state preparing
>Thread-259::INFO::2013-03-01 15:57:05,360::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-259::INFO::2013-03-01 15:57:05,360::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-259::DEBUG::2013-03-01 15:57:05,361::task::1172::TaskManager.Task::(prepare) Task=`edf2a1fb-8274-4095-a0d6-68edadeb8e02`::finished: {}
>Thread-259::DEBUG::2013-03-01 15:57:05,361::task::588::TaskManager.Task::(_updateState) Task=`edf2a1fb-8274-4095-a0d6-68edadeb8e02`::moving from state preparing -> state finished
>Thread-259::DEBUG::2013-03-01 15:57:05,362::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-259::DEBUG::2013-03-01 15:57:05,362::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-259::DEBUG::2013-03-01 15:57:05,362::task::978::TaskManager.Task::(_decref) Task=`edf2a1fb-8274-4095-a0d6-68edadeb8e02`::ref 0 aborting False
>Thread-265::DEBUG::2013-03-01 15:57:20,566::task::588::TaskManager.Task::(_updateState) Task=`4679af63-97e1-4db8-a4ac-30dce90b15ec`::moving from state init -> state preparing
>Thread-265::INFO::2013-03-01 15:57:20,567::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-265::INFO::2013-03-01 15:57:20,567::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-265::DEBUG::2013-03-01 15:57:20,568::task::1172::TaskManager.Task::(prepare) Task=`4679af63-97e1-4db8-a4ac-30dce90b15ec`::finished: {}
>Thread-265::DEBUG::2013-03-01 15:57:20,568::task::588::TaskManager.Task::(_updateState) Task=`4679af63-97e1-4db8-a4ac-30dce90b15ec`::moving from state preparing -> state finished
>Thread-265::DEBUG::2013-03-01 15:57:20,568::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-265::DEBUG::2013-03-01 15:57:20,569::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-265::DEBUG::2013-03-01 15:57:20,569::task::978::TaskManager.Task::(_decref) Task=`4679af63-97e1-4db8-a4ac-30dce90b15ec`::ref 0 aborting False
>Thread-271::DEBUG::2013-03-01 15:57:35,774::task::588::TaskManager.Task::(_updateState) Task=`bd46ffc5-ced9-4735-941e-be4144c20350`::moving from state init -> state preparing
>Thread-271::INFO::2013-03-01 15:57:35,775::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-271::INFO::2013-03-01 15:57:35,775::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-271::DEBUG::2013-03-01 15:57:35,776::task::1172::TaskManager.Task::(prepare) Task=`bd46ffc5-ced9-4735-941e-be4144c20350`::finished: {}
>Thread-271::DEBUG::2013-03-01 15:57:35,776::task::588::TaskManager.Task::(_updateState) Task=`bd46ffc5-ced9-4735-941e-be4144c20350`::moving from state preparing -> state finished
>Thread-271::DEBUG::2013-03-01 15:57:35,776::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-271::DEBUG::2013-03-01 15:57:35,777::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-271::DEBUG::2013-03-01 15:57:35,777::task::978::TaskManager.Task::(_decref) Task=`bd46ffc5-ced9-4735-941e-be4144c20350`::ref 0 aborting False
>Thread-277::DEBUG::2013-03-01 15:57:50,973::task::588::TaskManager.Task::(_updateState) Task=`59adc8ef-64bb-4a40-9afb-17d8305026cd`::moving from state init -> state preparing
>Thread-277::INFO::2013-03-01 15:57:50,973::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-277::INFO::2013-03-01 15:57:50,974::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-277::DEBUG::2013-03-01 15:57:50,974::task::1172::TaskManager.Task::(prepare) Task=`59adc8ef-64bb-4a40-9afb-17d8305026cd`::finished: {}
>Thread-277::DEBUG::2013-03-01 15:57:50,975::task::588::TaskManager.Task::(_updateState) Task=`59adc8ef-64bb-4a40-9afb-17d8305026cd`::moving from state preparing -> state finished
>Thread-277::DEBUG::2013-03-01 15:57:50,975::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-277::DEBUG::2013-03-01 15:57:50,975::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-277::DEBUG::2013-03-01 15:57:50,976::task::978::TaskManager.Task::(_decref) Task=`59adc8ef-64bb-4a40-9afb-17d8305026cd`::ref 0 aborting False
>Thread-283::DEBUG::2013-03-01 15:58:06,172::task::588::TaskManager.Task::(_updateState) Task=`9ff82ad0-9ec6-439e-a612-90f3c6f053fd`::moving from state init -> state preparing
>Thread-283::INFO::2013-03-01 15:58:06,172::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-283::INFO::2013-03-01 15:58:06,173::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-283::DEBUG::2013-03-01 15:58:06,173::task::1172::TaskManager.Task::(prepare) Task=`9ff82ad0-9ec6-439e-a612-90f3c6f053fd`::finished: {}
>Thread-283::DEBUG::2013-03-01 15:58:06,174::task::588::TaskManager.Task::(_updateState) Task=`9ff82ad0-9ec6-439e-a612-90f3c6f053fd`::moving from state preparing -> state finished
>Thread-283::DEBUG::2013-03-01 15:58:06,174::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-283::DEBUG::2013-03-01 15:58:06,174::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-283::DEBUG::2013-03-01 15:58:06,175::task::978::TaskManager.Task::(_decref) Task=`9ff82ad0-9ec6-439e-a612-90f3c6f053fd`::ref 0 aborting False
>Thread-289::DEBUG::2013-03-01 15:58:21,366::task::588::TaskManager.Task::(_updateState) Task=`bf20692e-a52c-4638-9baf-463e2cb6aaad`::moving from state init -> state preparing
>Thread-289::INFO::2013-03-01 15:58:21,367::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-289::INFO::2013-03-01 15:58:21,367::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-289::DEBUG::2013-03-01 15:58:21,368::task::1172::TaskManager.Task::(prepare) Task=`bf20692e-a52c-4638-9baf-463e2cb6aaad`::finished: {}
>Thread-289::DEBUG::2013-03-01 15:58:21,368::task::588::TaskManager.Task::(_updateState) Task=`bf20692e-a52c-4638-9baf-463e2cb6aaad`::moving from state preparing -> state finished
>Thread-289::DEBUG::2013-03-01 15:58:21,368::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-289::DEBUG::2013-03-01 15:58:21,369::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-289::DEBUG::2013-03-01 15:58:21,369::task::978::TaskManager.Task::(_decref) Task=`bf20692e-a52c-4638-9baf-463e2cb6aaad`::ref 0 aborting False
>Thread-295::DEBUG::2013-03-01 15:58:36,566::task::588::TaskManager.Task::(_updateState) Task=`183348e4-085f-465f-83cf-3d7f9b1cec4a`::moving from state init -> state preparing
>Thread-295::INFO::2013-03-01 15:58:36,567::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-295::INFO::2013-03-01 15:58:36,567::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-295::DEBUG::2013-03-01 15:58:36,568::task::1172::TaskManager.Task::(prepare) Task=`183348e4-085f-465f-83cf-3d7f9b1cec4a`::finished: {}
>Thread-295::DEBUG::2013-03-01 15:58:36,568::task::588::TaskManager.Task::(_updateState) Task=`183348e4-085f-465f-83cf-3d7f9b1cec4a`::moving from state preparing -> state finished
>Thread-295::DEBUG::2013-03-01 15:58:36,568::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-295::DEBUG::2013-03-01 15:58:36,569::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-295::DEBUG::2013-03-01 15:58:36,569::task::978::TaskManager.Task::(_decref) Task=`183348e4-085f-465f-83cf-3d7f9b1cec4a`::ref 0 aborting False
>Thread-301::DEBUG::2013-03-01 15:58:51,763::task::588::TaskManager.Task::(_updateState) Task=`bb3b2fac-aa46-4b65-9a3c-68deb32b47d9`::moving from state init -> state preparing
>Thread-301::INFO::2013-03-01 15:58:51,764::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-301::INFO::2013-03-01 15:58:51,764::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-301::DEBUG::2013-03-01 15:58:51,764::task::1172::TaskManager.Task::(prepare) Task=`bb3b2fac-aa46-4b65-9a3c-68deb32b47d9`::finished: {}
>Thread-301::DEBUG::2013-03-01 15:58:51,765::task::588::TaskManager.Task::(_updateState) Task=`bb3b2fac-aa46-4b65-9a3c-68deb32b47d9`::moving from state preparing -> state finished
>Thread-301::DEBUG::2013-03-01 15:58:51,765::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-301::DEBUG::2013-03-01 15:58:51,766::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-301::DEBUG::2013-03-01 15:58:51,766::task::978::TaskManager.Task::(_decref) Task=`bb3b2fac-aa46-4b65-9a3c-68deb32b47d9`::ref 0 aborting False
>Thread-307::DEBUG::2013-03-01 15:59:06,963::task::588::TaskManager.Task::(_updateState) Task=`4c3042df-7ff7-4d3b-80be-d26af17f6760`::moving from state init -> state preparing
>Thread-307::INFO::2013-03-01 15:59:06,963::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-307::INFO::2013-03-01 15:59:06,963::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-307::DEBUG::2013-03-01 15:59:06,964::task::1172::TaskManager.Task::(prepare) Task=`4c3042df-7ff7-4d3b-80be-d26af17f6760`::finished: {}
>Thread-307::DEBUG::2013-03-01 15:59:06,964::task::588::TaskManager.Task::(_updateState) Task=`4c3042df-7ff7-4d3b-80be-d26af17f6760`::moving from state preparing -> state finished
>Thread-307::DEBUG::2013-03-01 15:59:06,965::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-307::DEBUG::2013-03-01 15:59:06,965::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-307::DEBUG::2013-03-01 15:59:06,966::task::978::TaskManager.Task::(_decref) Task=`4c3042df-7ff7-4d3b-80be-d26af17f6760`::ref 0 aborting False
>Thread-312::DEBUG::2013-03-01 15:59:17,365::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-312::DEBUG::2013-03-01 15:59:17,406::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-312::DEBUG::2013-03-01 15:59:17,431::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-312::DEBUG::2013-03-01 15:59:17,432::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-312::DEBUG::2013-03-01 15:59:17,458::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-312::DEBUG::2013-03-01 15:59:17,459::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-312::DEBUG::2013-03-01 15:59:17,483::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-312::DEBUG::2013-03-01 15:59:17,484::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-312::DEBUG::2013-03-01 15:59:17,509::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-312::DEBUG::2013-03-01 15:59:17,510::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-312::DEBUG::2013-03-01 15:59:17,537::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-312::DEBUG::2013-03-01 15:59:17,538::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-314::DEBUG::2013-03-01 15:59:22,172::task::588::TaskManager.Task::(_updateState) Task=`50ec89ec-1d5f-4b16-9f78-055aefb3cbf3`::moving from state init -> state preparing
>Thread-314::INFO::2013-03-01 15:59:22,172::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-314::INFO::2013-03-01 15:59:22,173::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-314::DEBUG::2013-03-01 15:59:22,173::task::1172::TaskManager.Task::(prepare) Task=`50ec89ec-1d5f-4b16-9f78-055aefb3cbf3`::finished: {}
>Thread-314::DEBUG::2013-03-01 15:59:22,174::task::588::TaskManager.Task::(_updateState) Task=`50ec89ec-1d5f-4b16-9f78-055aefb3cbf3`::moving from state preparing -> state finished
>Thread-314::DEBUG::2013-03-01 15:59:22,174::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-314::DEBUG::2013-03-01 15:59:22,174::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-314::DEBUG::2013-03-01 15:59:22,175::task::978::TaskManager.Task::(_decref) Task=`50ec89ec-1d5f-4b16-9f78-055aefb3cbf3`::ref 0 aborting False
>Thread-316::DEBUG::2013-03-01 15:59:25,262::task::588::TaskManager.Task::(_updateState) Task=`9292c6ab-501c-4cd4-957a-16bc29c21ad8`::moving from state init -> state preparing
>Thread-316::INFO::2013-03-01 15:59:25,262::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-316::INFO::2013-03-01 15:59:25,263::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-316::DEBUG::2013-03-01 15:59:25,263::task::1172::TaskManager.Task::(prepare) Task=`9292c6ab-501c-4cd4-957a-16bc29c21ad8`::finished: {}
>Thread-316::DEBUG::2013-03-01 15:59:25,263::task::588::TaskManager.Task::(_updateState) Task=`9292c6ab-501c-4cd4-957a-16bc29c21ad8`::moving from state preparing -> state finished
>Thread-316::DEBUG::2013-03-01 15:59:25,264::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-316::DEBUG::2013-03-01 15:59:25,264::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-316::DEBUG::2013-03-01 15:59:25,265::task::978::TaskManager.Task::(_decref) Task=`9292c6ab-501c-4cd4-957a-16bc29c21ad8`::ref 0 aborting False
>MainThread::INFO::2013-03-01 16:03:45,413::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::DEBUG::2013-03-01 16:03:45,414::task::588::TaskManager.Task::(_updateState) Task=`d52d9d96-7ffe-4e33-b580-8e04015ea10b`::moving from state init -> state preparing
>MainThread::INFO::2013-03-01 16:03:45,414::logUtils::37::dispatcher::(wrapper) Run and protect: prepareForShutdown(options=None)
>Thread-11::DEBUG::2013-03-01 16:03:45,415::storageServer::641::ConnectionMonitor::(_monitorConnections) Monitoring stopped
>MainThread::DEBUG::2013-03-01 16:03:45,430::taskManager::80::TaskManager::(prepareForShutdown) Request to stop all tasks
>MainThread::INFO::2013-03-01 16:03:45,430::logUtils::39::dispatcher::(wrapper) Run and protect: prepareForShutdown, Return response: None
>MainThread::DEBUG::2013-03-01 16:03:45,431::task::1172::TaskManager.Task::(prepare) Task=`d52d9d96-7ffe-4e33-b580-8e04015ea10b`::finished: None
>MainThread::DEBUG::2013-03-01 16:03:45,431::task::588::TaskManager.Task::(_updateState) Task=`d52d9d96-7ffe-4e33-b580-8e04015ea10b`::moving from state preparing -> state finished
>MainThread::DEBUG::2013-03-01 16:03:45,432::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>MainThread::DEBUG::2013-03-01 16:03:45,432::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>MainThread::DEBUG::2013-03-01 16:03:45,432::task::978::TaskManager.Task::(_decref) Task=`d52d9d96-7ffe-4e33-b580-8e04015ea10b`::ref 0 aborting False
>MainThread::INFO::2013-03-01 16:03:45,433::vdsm::75::vds::(run) VDSM main thread ended. Waiting for 13 other threads...
>MainThread::INFO::2013-03-01 16:03:45,433::vdsm::78::vds::(run) <_MainThread(MainThread, started 140313874425600)>
>MainThread::INFO::2013-03-01 16:03:45,434::vdsm::78::vds::(run) <Thread(libvirtEventLoop, started daemon 140313786824448)>
>MainThread::INFO::2013-03-01 16:03:45,434::vdsm::78::vds::(run) <WorkerThread(Thread-3, started daemon 140313669154560)>
>MainThread::INFO::2013-03-01 16:03:45,434::vmChannels::135::vds::(stop) VM channels listener was stopped.
>MainThread::INFO::2013-03-01 16:03:45,435::vdsm::78::vds::(run) <Listener(VM Channels Listener, stopped daemon 140313117046528)>
>MainThread::INFO::2013-03-01 16:03:45,435::vdsm::78::vds::(run) <WorkerThread(Thread-9, started daemon 140313261754112)>
>MainThread::INFO::2013-03-01 16:03:45,436::vdsm::78::vds::(run) <WorkerThread(Thread-10, started daemon 140313251264256)>
>MainThread::INFO::2013-03-01 16:03:45,436::vdsm::78::vds::(run) <WorkerThread(Thread-1, started daemon 140313690134272)>
>MainThread::INFO::2013-03-01 16:03:45,436::vdsm::78::vds::(run) <WorkerThread(Thread-7, started daemon 140313282733824)>
>MainThread::INFO::2013-03-01 16:03:45,437::vdsm::78::vds::(run) <WorkerThread(Thread-4, started daemon 140313658664704)>
>MainThread::INFO::2013-03-01 16:03:45,437::vdsm::78::vds::(run) <KsmMonitorThread(KsmMonitor, started daemon 140313138026240)>
>MainThread::INFO::2013-03-01 16:03:45,438::vdsm::78::vds::(run) <WorkerThread(Thread-6, started daemon 140313293223680)>
>MainThread::INFO::2013-03-01 16:03:45,438::vdsm::78::vds::(run) <WorkerThread(Thread-8, started daemon 140313272243968)>
>MainThread::INFO::2013-03-01 16:03:45,438::vdsm::78::vds::(run) <WorkerThread(Thread-5, started daemon 140313648174848)>
>MainThread::INFO::2013-03-01 16:03:45,439::vdsm::78::vds::(run) <WorkerThread(Thread-2, started daemon 140313679644416)>
>MainThread::INFO::2013-03-01 16:06:18,453::vdsm::70::vds::(run) I am the actual vdsm 4.9-19
>MainThread::DEBUG::2013-03-01 16:06:18,823::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'Storage'
>MainThread::DEBUG::2013-03-01 16:06:18,824::threadPool::45::Misc.ThreadPool::(__init__) Enter - numThreads: 10.0, waitTimeout: 3, maxTasks: 500.0
>MainThread::WARNING::2013-03-01 16:06:18,827::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/mnt already exists
>MainThread::DEBUG::2013-03-01 16:06:18,846::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /bin/cat /etc/multipath.conf' (cwd None)
>MainThread::DEBUG::2013-03-01 16:06:18,869::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2013-03-01 16:06:18,870::multipath::94::Storage.Multipath::(isEnabled) Manual override for multipath.conf detected - preserving current configuration
>MainThread::WARNING::2013-03-01 16:06:18,870::multipath::97::Storage.Multipath::(isEnabled) This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
>MainThread::DEBUG::2013-03-01 16:06:18,871::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm dumpconfig global/locking_type' (cwd None)
>MainThread::DEBUG::2013-03-01 16:06:18,883::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2013-03-01 16:06:18,884::hsm::407::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
>MainThread::DEBUG::2013-03-01 16:06:18,887::hsm::439::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
>MainThread::DEBUG::2013-03-01 16:06:18,888::hsm::440::Storage.HSM::(__cleanStorageRepository) Mount list: []
>MainThread::DEBUG::2013-03-01 16:06:18,888::hsm::442::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
>MainThread::DEBUG::2013-03-01 16:06:18,891::hsm::485::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
>MainThread::INFO::2013-03-01 16:06:18,893::dispatcher::95::Storage.Dispatcher::(__init__) Starting StorageDispatcher...
>Thread-12::DEBUG::2013-03-01 16:06:18,896::lvm::319::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:18,898::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm pvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,size,vg_name,vg_uuid,pe_start,pe_count,pe_alloc_count,mda_count,dev_size' (cwd None)
>MainThread::DEBUG::2013-03-01 16:06:18,912::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/pgrep -xf ksmd' (cwd None)
>Thread-12::DEBUG::2013-03-01 16:06:18,931::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2013-03-01 16:06:18,932::lvm::342::OperationMutex::(_reloadpvs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:18,932::lvm::352::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:18,933::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
>MainThread::DEBUG::2013-03-01 16:06:18,937::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::INFO::2013-03-01 16:06:18,938::ksm::40::vds::(__init__) starting ksm monitor thread, ksm pid is 29
>KsmMonitor::DEBUG::2013-03-01 16:06:18,941::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service ksmtuned start' (cwd None)
>MainThread::INFO::2013-03-01 16:06:18,948::vmChannels::139::vds::(settimeout) Setting channels' timeout to 30 seconds.
>VM Channels Listener::INFO::2013-03-01 16:06:18,956::vmChannels::127::vds::(run) Starting VM channels listener thread.
>Thread-12::DEBUG::2013-03-01 16:06:18,971::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2013-03-01 16:06:18,972::lvm::379::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:18,972::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags' (cwd None)
>Thread-12::DEBUG::2013-03-01 16:06:19,001::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
>Thread-12::DEBUG::2013-03-01 16:06:19,002::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
>Thread-12::DEBUG::2013-03-01 16:06:19,002::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2013-03-01 16:06:19,003::misc::1044::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
>Thread-12::DEBUG::2013-03-01 16:06:19,003::misc::1046::SamplingMethod::(__call__) Got in to sampling method
>Thread-12::DEBUG::2013-03-01 16:06:19,003::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
>KsmMonitor::DEBUG::2013-03-01 16:06:19,021::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>KsmMonitor::DEBUG::2013-03-01 16:06:19,022::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service ksm start' (cwd None)
>Thread-12::DEBUG::2013-03-01 16:06:19,027::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
>Thread-12::DEBUG::2013-03-01 16:06:19,028::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::DEBUG::2013-03-01 16:06:19,029::supervdsm::100::SuperVdsmProxy::(_start) Launching Super Vdsm
>Thread-12::DEBUG::2013-03-01 16:06:19,029::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/bin/python /usr/share/vdsm/supervdsmServer.py 6fc73ce7-dba6-42d7-bf9c-21735c859a4e 2039' (cwd None)
>KsmMonitor::DEBUG::2013-03-01 16:06:19,077::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>MainThread::DEBUG::2013-03-01 16:06:19,260::supervdsmServer::271::SuperVdsm.Server::(main) Making sure I'm root
>MainThread::DEBUG::2013-03-01 16:06:19,260::supervdsmServer::275::SuperVdsm.Server::(main) Parsing cmd args
>MainThread::DEBUG::2013-03-01 16:06:19,261::supervdsmServer::278::SuperVdsm.Server::(main) Creating PID file
>MainThread::DEBUG::2013-03-01 16:06:19,261::supervdsmServer::285::SuperVdsm.Server::(main) Cleaning old socket
>MainThread::DEBUG::2013-03-01 16:06:19,261::supervdsmServer::289::SuperVdsm.Server::(main) Setting up keep alive thread
>MainThread::DEBUG::2013-03-01 16:06:19,262::supervdsmServer::294::SuperVdsm.Server::(main) Creating remote object manager
>MainThread::DEBUG::2013-03-01 16:06:19,263::supervdsmServer::306::SuperVdsm.Server::(main) Started serving super vdsm object
>Thread-12::DEBUG::2013-03-01 16:06:21,037::supervdsm::153::SuperVdsmProxy::(_connect) Trying to connect to Super Vdsm
>MainProcess|Thread-12::DEBUG::2013-03-01 16:06:21,046::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host0/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2013-03-01 16:06:21,049::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/dd of=/sys/class/scsi_host/host1/scan' (cwd None)
>MainProcess|Thread-12::DEBUG::2013-03-01 16:06:21,051::iscsi::388::Storage.ISCSI::(forceIScsiScan) Performing SCSI scan, this will take up to 30 seconds
>Thread-12::DEBUG::2013-03-01 16:06:23,055::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
>Thread-12::DEBUG::2013-03-01 16:06:23,067::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-12::DEBUG::2013-03-01 16:06:23,068::lvm::460::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,069::lvm::462::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,069::lvm::472::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,069::lvm::474::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,070::lvm::493::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,070::lvm::495::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-12::DEBUG::2013-03-01 16:06:23,071::misc::1054::SamplingMethod::(__call__) Returning last result
>Thread-12::WARNING::2013-03-01 16:06:23,071::fileUtils::181::fileUtils::(createdir) Dir /rhev/data-center/hsm-tasks already exists
>Thread-14::DEBUG::2013-03-01 16:08:50,830::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-14::DEBUG::2013-03-01 16:08:51,011::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-14::DEBUG::2013-03-01 16:08:51,044::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-14::DEBUG::2013-03-01 16:08:51,045::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-14::DEBUG::2013-03-01 16:08:51,076::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-14::DEBUG::2013-03-01 16:08:51,077::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-14::DEBUG::2013-03-01 16:08:51,106::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 16:08:51,107::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-14::DEBUG::2013-03-01 16:08:51,135::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 16:08:51,136::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-14::DEBUG::2013-03-01 16:08:51,164::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-14::DEBUG::2013-03-01 16:08:51,173::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '0.0.0.0'}}
>Thread-15::DEBUG::2013-03-01 16:08:51,440::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-15::DEBUG::2013-03-01 16:08:51,480::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-15::DEBUG::2013-03-01 16:08:51,505::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-15::DEBUG::2013-03-01 16:08:51,506::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-15::DEBUG::2013-03-01 16:08:51,531::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-15::DEBUG::2013-03-01 16:08:51,532::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-15::DEBUG::2013-03-01 16:08:51,557::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 16:08:51,558::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-15::DEBUG::2013-03-01 16:08:51,583::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 16:08:51,584::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-15::DEBUG::2013-03-01 16:08:51,611::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-15::DEBUG::2013-03-01 16:08:51,612::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-18::DEBUG::2013-03-01 16:08:57,861::task::588::TaskManager.Task::(_updateState) Task=`41f58ad2-4d06-4fa0-9ca4-916c6e6ac010`::moving from state init -> state preparing
>Thread-18::INFO::2013-03-01 16:08:57,861::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-18::INFO::2013-03-01 16:08:57,862::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-18::DEBUG::2013-03-01 16:08:57,862::task::1172::TaskManager.Task::(prepare) Task=`41f58ad2-4d06-4fa0-9ca4-916c6e6ac010`::finished: {}
>Thread-18::DEBUG::2013-03-01 16:08:57,862::task::588::TaskManager.Task::(_updateState) Task=`41f58ad2-4d06-4fa0-9ca4-916c6e6ac010`::moving from state preparing -> state finished
>Thread-18::DEBUG::2013-03-01 16:08:57,863::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-18::DEBUG::2013-03-01 16:08:57,863::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-18::DEBUG::2013-03-01 16:08:57,863::task::978::TaskManager.Task::(_decref) Task=`41f58ad2-4d06-4fa0-9ca4-916c6e6ac010`::ref 0 aborting False
>Thread-24::DEBUG::2013-03-01 16:09:13,068::task::588::TaskManager.Task::(_updateState) Task=`b878758c-7331-47f3-a504-c85faf5d4e92`::moving from state init -> state preparing
>Thread-24::INFO::2013-03-01 16:09:13,068::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-24::INFO::2013-03-01 16:09:13,069::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-24::DEBUG::2013-03-01 16:09:13,069::task::1172::TaskManager.Task::(prepare) Task=`b878758c-7331-47f3-a504-c85faf5d4e92`::finished: {}
>Thread-24::DEBUG::2013-03-01 16:09:13,069::task::588::TaskManager.Task::(_updateState) Task=`b878758c-7331-47f3-a504-c85faf5d4e92`::moving from state preparing -> state finished
>Thread-24::DEBUG::2013-03-01 16:09:13,070::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-24::DEBUG::2013-03-01 16:09:13,070::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-24::DEBUG::2013-03-01 16:09:13,070::task::978::TaskManager.Task::(_decref) Task=`b878758c-7331-47f3-a504-c85faf5d4e92`::ref 0 aborting False
>Thread-27::DEBUG::2013-03-01 16:09:17,322::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-27::DEBUG::2013-03-01 16:09:17,362::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-27::DEBUG::2013-03-01 16:09:17,388::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-27::DEBUG::2013-03-01 16:09:17,389::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-27::DEBUG::2013-03-01 16:09:17,414::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-27::DEBUG::2013-03-01 16:09:17,415::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-27::DEBUG::2013-03-01 16:09:17,440::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-27::DEBUG::2013-03-01 16:09:17,441::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-27::DEBUG::2013-03-01 16:09:17,466::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-27::DEBUG::2013-03-01 16:09:17,467::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-27::DEBUG::2013-03-01 16:09:17,492::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-27::DEBUG::2013-03-01 16:09:17,493::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-31::DEBUG::2013-03-01 16:09:28,271::task::588::TaskManager.Task::(_updateState) Task=`b316a550-af0f-42b4-b6cf-c10d379c8ba7`::moving from state init -> state preparing
>Thread-31::INFO::2013-03-01 16:09:28,271::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-31::INFO::2013-03-01 16:09:28,271::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-31::DEBUG::2013-03-01 16:09:28,272::task::1172::TaskManager.Task::(prepare) Task=`b316a550-af0f-42b4-b6cf-c10d379c8ba7`::finished: {}
>Thread-31::DEBUG::2013-03-01 16:09:28,272::task::588::TaskManager.Task::(_updateState) Task=`b316a550-af0f-42b4-b6cf-c10d379c8ba7`::moving from state preparing -> state finished
>Thread-31::DEBUG::2013-03-01 16:09:28,273::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-31::DEBUG::2013-03-01 16:09:28,273::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-31::DEBUG::2013-03-01 16:09:28,273::task::978::TaskManager.Task::(_decref) Task=`b316a550-af0f-42b4-b6cf-c10d379c8ba7`::ref 0 aborting False
>Thread-37::DEBUG::2013-03-01 16:09:43,471::task::588::TaskManager.Task::(_updateState) Task=`93940d08-e3db-4995-a90d-21c8e0809bbf`::moving from state init -> state preparing
>Thread-37::INFO::2013-03-01 16:09:43,472::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-37::INFO::2013-03-01 16:09:43,472::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-37::DEBUG::2013-03-01 16:09:43,473::task::1172::TaskManager.Task::(prepare) Task=`93940d08-e3db-4995-a90d-21c8e0809bbf`::finished: {}
>Thread-37::DEBUG::2013-03-01 16:09:43,473::task::588::TaskManager.Task::(_updateState) Task=`93940d08-e3db-4995-a90d-21c8e0809bbf`::moving from state preparing -> state finished
>Thread-37::DEBUG::2013-03-01 16:09:43,473::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-37::DEBUG::2013-03-01 16:09:43,474::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-37::DEBUG::2013-03-01 16:09:43,474::task::978::TaskManager.Task::(_decref) Task=`93940d08-e3db-4995-a90d-21c8e0809bbf`::ref 0 aborting False
>Thread-43::DEBUG::2013-03-01 16:09:58,666::task::588::TaskManager.Task::(_updateState) Task=`76f02202-e4a4-4355-866e-2b3841b810bf`::moving from state init -> state preparing
>Thread-43::INFO::2013-03-01 16:09:58,667::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-43::INFO::2013-03-01 16:09:58,667::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-43::DEBUG::2013-03-01 16:09:58,667::task::1172::TaskManager.Task::(prepare) Task=`76f02202-e4a4-4355-866e-2b3841b810bf`::finished: {}
>Thread-43::DEBUG::2013-03-01 16:09:58,668::task::588::TaskManager.Task::(_updateState) Task=`76f02202-e4a4-4355-866e-2b3841b810bf`::moving from state preparing -> state finished
>Thread-43::DEBUG::2013-03-01 16:09:58,668::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-43::DEBUG::2013-03-01 16:09:58,668::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-43::DEBUG::2013-03-01 16:09:58,669::task::978::TaskManager.Task::(_decref) Task=`76f02202-e4a4-4355-866e-2b3841b810bf`::ref 0 aborting False
>Thread-49::DEBUG::2013-03-01 16:10:13,865::task::588::TaskManager.Task::(_updateState) Task=`9aaad248-54fc-419d-8961-e1190c2c750c`::moving from state init -> state preparing
>Thread-49::INFO::2013-03-01 16:10:13,865::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-49::INFO::2013-03-01 16:10:13,865::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-49::DEBUG::2013-03-01 16:10:13,866::task::1172::TaskManager.Task::(prepare) Task=`9aaad248-54fc-419d-8961-e1190c2c750c`::finished: {}
>Thread-49::DEBUG::2013-03-01 16:10:13,866::task::588::TaskManager.Task::(_updateState) Task=`9aaad248-54fc-419d-8961-e1190c2c750c`::moving from state preparing -> state finished
>Thread-49::DEBUG::2013-03-01 16:10:13,866::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-49::DEBUG::2013-03-01 16:10:13,867::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-49::DEBUG::2013-03-01 16:10:13,867::task::978::TaskManager.Task::(_decref) Task=`9aaad248-54fc-419d-8961-e1190c2c750c`::ref 0 aborting False
>Thread-55::DEBUG::2013-03-01 16:10:29,065::task::588::TaskManager.Task::(_updateState) Task=`584ccc45-43bd-441f-bce8-0a849ddaff6d`::moving from state init -> state preparing
>Thread-55::INFO::2013-03-01 16:10:29,066::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-55::INFO::2013-03-01 16:10:29,066::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-55::DEBUG::2013-03-01 16:10:29,067::task::1172::TaskManager.Task::(prepare) Task=`584ccc45-43bd-441f-bce8-0a849ddaff6d`::finished: {}
>Thread-55::DEBUG::2013-03-01 16:10:29,067::task::588::TaskManager.Task::(_updateState) Task=`584ccc45-43bd-441f-bce8-0a849ddaff6d`::moving from state preparing -> state finished
>Thread-55::DEBUG::2013-03-01 16:10:29,067::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-55::DEBUG::2013-03-01 16:10:29,068::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-55::DEBUG::2013-03-01 16:10:29,068::task::978::TaskManager.Task::(_decref) Task=`584ccc45-43bd-441f-bce8-0a849ddaff6d`::ref 0 aborting False
>Thread-61::DEBUG::2013-03-01 16:10:44,266::task::588::TaskManager.Task::(_updateState) Task=`3165196a-4289-45d9-9efb-69b83ae1218b`::moving from state init -> state preparing
>Thread-61::INFO::2013-03-01 16:10:44,266::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-61::INFO::2013-03-01 16:10:44,267::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-61::DEBUG::2013-03-01 16:10:44,267::task::1172::TaskManager.Task::(prepare) Task=`3165196a-4289-45d9-9efb-69b83ae1218b`::finished: {}
>Thread-61::DEBUG::2013-03-01 16:10:44,267::task::588::TaskManager.Task::(_updateState) Task=`3165196a-4289-45d9-9efb-69b83ae1218b`::moving from state preparing -> state finished
>Thread-61::DEBUG::2013-03-01 16:10:44,268::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-61::DEBUG::2013-03-01 16:10:44,268::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-61::DEBUG::2013-03-01 16:10:44,268::task::978::TaskManager.Task::(_decref) Task=`3165196a-4289-45d9-9efb-69b83ae1218b`::ref 0 aborting False
>Thread-67::DEBUG::2013-03-01 16:10:59,455::task::588::TaskManager.Task::(_updateState) Task=`f238eb17-da1a-456a-8650-0e80ec38f51f`::moving from state init -> state preparing
>Thread-67::INFO::2013-03-01 16:10:59,456::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-67::INFO::2013-03-01 16:10:59,456::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-67::DEBUG::2013-03-01 16:10:59,456::task::1172::TaskManager.Task::(prepare) Task=`f238eb17-da1a-456a-8650-0e80ec38f51f`::finished: {}
>Thread-67::DEBUG::2013-03-01 16:10:59,457::task::588::TaskManager.Task::(_updateState) Task=`f238eb17-da1a-456a-8650-0e80ec38f51f`::moving from state preparing -> state finished
>Thread-67::DEBUG::2013-03-01 16:10:59,457::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-67::DEBUG::2013-03-01 16:10:59,457::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-67::DEBUG::2013-03-01 16:10:59,458::task::978::TaskManager.Task::(_decref) Task=`f238eb17-da1a-456a-8650-0e80ec38f51f`::ref 0 aborting False
>Thread-73::DEBUG::2013-03-01 16:11:14,654::task::588::TaskManager.Task::(_updateState) Task=`cc5ad922-479b-4a10-aa68-4cf6d3630bc4`::moving from state init -> state preparing
>Thread-73::INFO::2013-03-01 16:11:14,654::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-73::INFO::2013-03-01 16:11:14,655::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-73::DEBUG::2013-03-01 16:11:14,655::task::1172::TaskManager.Task::(prepare) Task=`cc5ad922-479b-4a10-aa68-4cf6d3630bc4`::finished: {}
>Thread-73::DEBUG::2013-03-01 16:11:14,655::task::588::TaskManager.Task::(_updateState) Task=`cc5ad922-479b-4a10-aa68-4cf6d3630bc4`::moving from state preparing -> state finished
>Thread-73::DEBUG::2013-03-01 16:11:14,656::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-73::DEBUG::2013-03-01 16:11:14,656::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-73::DEBUG::2013-03-01 16:11:14,657::task::978::TaskManager.Task::(_decref) Task=`cc5ad922-479b-4a10-aa68-4cf6d3630bc4`::ref 0 aborting False
>Thread-79::DEBUG::2013-03-01 16:11:29,874::task::588::TaskManager.Task::(_updateState) Task=`4566791f-a267-4bc3-907b-444cda01645e`::moving from state init -> state preparing
>Thread-79::INFO::2013-03-01 16:11:29,875::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-79::INFO::2013-03-01 16:11:29,875::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-79::DEBUG::2013-03-01 16:11:29,875::task::1172::TaskManager.Task::(prepare) Task=`4566791f-a267-4bc3-907b-444cda01645e`::finished: {}
>Thread-79::DEBUG::2013-03-01 16:11:29,876::task::588::TaskManager.Task::(_updateState) Task=`4566791f-a267-4bc3-907b-444cda01645e`::moving from state preparing -> state finished
>Thread-79::DEBUG::2013-03-01 16:11:29,876::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-79::DEBUG::2013-03-01 16:11:29,876::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-79::DEBUG::2013-03-01 16:11:29,877::task::978::TaskManager.Task::(_decref) Task=`4566791f-a267-4bc3-907b-444cda01645e`::ref 0 aborting False
>Thread-85::DEBUG::2013-03-01 16:11:45,072::task::588::TaskManager.Task::(_updateState) Task=`49ab8453-d926-40d2-af4f-a4292e9460a2`::moving from state init -> state preparing
>Thread-85::INFO::2013-03-01 16:11:45,073::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-85::INFO::2013-03-01 16:11:45,073::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-85::DEBUG::2013-03-01 16:11:45,073::task::1172::TaskManager.Task::(prepare) Task=`49ab8453-d926-40d2-af4f-a4292e9460a2`::finished: {}
>Thread-85::DEBUG::2013-03-01 16:11:45,074::task::588::TaskManager.Task::(_updateState) Task=`49ab8453-d926-40d2-af4f-a4292e9460a2`::moving from state preparing -> state finished
>Thread-85::DEBUG::2013-03-01 16:11:45,074::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-85::DEBUG::2013-03-01 16:11:45,074::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-85::DEBUG::2013-03-01 16:11:45,075::task::978::TaskManager.Task::(_decref) Task=`49ab8453-d926-40d2-af4f-a4292e9460a2`::ref 0 aborting False
>Thread-91::DEBUG::2013-03-01 16:12:00,261::task::588::TaskManager.Task::(_updateState) Task=`ae2aa4c4-25d5-4524-a356-e224cea5b12c`::moving from state init -> state preparing
>Thread-91::INFO::2013-03-01 16:12:00,261::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-91::INFO::2013-03-01 16:12:00,262::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-91::DEBUG::2013-03-01 16:12:00,262::task::1172::TaskManager.Task::(prepare) Task=`ae2aa4c4-25d5-4524-a356-e224cea5b12c`::finished: {}
>Thread-91::DEBUG::2013-03-01 16:12:00,262::task::588::TaskManager.Task::(_updateState) Task=`ae2aa4c4-25d5-4524-a356-e224cea5b12c`::moving from state preparing -> state finished
>Thread-91::DEBUG::2013-03-01 16:12:00,263::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-91::DEBUG::2013-03-01 16:12:00,263::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-91::DEBUG::2013-03-01 16:12:00,263::task::978::TaskManager.Task::(_decref) Task=`ae2aa4c4-25d5-4524-a356-e224cea5b12c`::ref 0 aborting False
>Thread-97::DEBUG::2013-03-01 16:12:15,460::task::588::TaskManager.Task::(_updateState) Task=`ac38c111-0b45-4cb8-9928-62e795f5324e`::moving from state init -> state preparing
>Thread-97::INFO::2013-03-01 16:12:15,461::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-97::INFO::2013-03-01 16:12:15,461::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-97::DEBUG::2013-03-01 16:12:15,461::task::1172::TaskManager.Task::(prepare) Task=`ac38c111-0b45-4cb8-9928-62e795f5324e`::finished: {}
>Thread-97::DEBUG::2013-03-01 16:12:15,462::task::588::TaskManager.Task::(_updateState) Task=`ac38c111-0b45-4cb8-9928-62e795f5324e`::moving from state preparing -> state finished
>Thread-97::DEBUG::2013-03-01 16:12:15,462::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-97::DEBUG::2013-03-01 16:12:15,462::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-97::DEBUG::2013-03-01 16:12:15,463::task::978::TaskManager.Task::(_decref) Task=`ac38c111-0b45-4cb8-9928-62e795f5324e`::ref 0 aborting False
>Thread-103::DEBUG::2013-03-01 16:12:30,763::task::588::TaskManager.Task::(_updateState) Task=`f0a1f1a8-c6f8-406a-9d0e-4e9263fd1ace`::moving from state init -> state preparing
>Thread-103::INFO::2013-03-01 16:12:30,763::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-103::INFO::2013-03-01 16:12:30,764::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-103::DEBUG::2013-03-01 16:12:30,764::task::1172::TaskManager.Task::(prepare) Task=`f0a1f1a8-c6f8-406a-9d0e-4e9263fd1ace`::finished: {}
>Thread-103::DEBUG::2013-03-01 16:12:30,764::task::588::TaskManager.Task::(_updateState) Task=`f0a1f1a8-c6f8-406a-9d0e-4e9263fd1ace`::moving from state preparing -> state finished
>Thread-103::DEBUG::2013-03-01 16:12:30,765::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-103::DEBUG::2013-03-01 16:12:30,765::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-103::DEBUG::2013-03-01 16:12:30,765::task::978::TaskManager.Task::(_decref) Task=`f0a1f1a8-c6f8-406a-9d0e-4e9263fd1ace`::ref 0 aborting False
>Thread-109::DEBUG::2013-03-01 16:12:45,962::task::588::TaskManager.Task::(_updateState) Task=`e20c1e97-6afc-42a2-afc3-13199602538d`::moving from state init -> state preparing
>Thread-109::INFO::2013-03-01 16:12:45,963::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-109::INFO::2013-03-01 16:12:45,963::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-109::DEBUG::2013-03-01 16:12:45,963::task::1172::TaskManager.Task::(prepare) Task=`e20c1e97-6afc-42a2-afc3-13199602538d`::finished: {}
>Thread-109::DEBUG::2013-03-01 16:12:45,964::task::588::TaskManager.Task::(_updateState) Task=`e20c1e97-6afc-42a2-afc3-13199602538d`::moving from state preparing -> state finished
>Thread-109::DEBUG::2013-03-01 16:12:45,964::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-109::DEBUG::2013-03-01 16:12:45,964::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-109::DEBUG::2013-03-01 16:12:45,965::task::978::TaskManager.Task::(_decref) Task=`e20c1e97-6afc-42a2-afc3-13199602538d`::ref 0 aborting False
>Thread-115::DEBUG::2013-03-01 16:13:01,164::task::588::TaskManager.Task::(_updateState) Task=`75ac6aec-79b9-4ae4-bf2a-70acfc893e54`::moving from state init -> state preparing
>Thread-115::INFO::2013-03-01 16:13:01,164::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-115::INFO::2013-03-01 16:13:01,165::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-115::DEBUG::2013-03-01 16:13:01,165::task::1172::TaskManager.Task::(prepare) Task=`75ac6aec-79b9-4ae4-bf2a-70acfc893e54`::finished: {}
>Thread-115::DEBUG::2013-03-01 16:13:01,165::task::588::TaskManager.Task::(_updateState) Task=`75ac6aec-79b9-4ae4-bf2a-70acfc893e54`::moving from state preparing -> state finished
>Thread-115::DEBUG::2013-03-01 16:13:01,166::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-115::DEBUG::2013-03-01 16:13:01,166::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-115::DEBUG::2013-03-01 16:13:01,166::task::978::TaskManager.Task::(_decref) Task=`75ac6aec-79b9-4ae4-bf2a-70acfc893e54`::ref 0 aborting False
>Thread-121::DEBUG::2013-03-01 16:13:16,365::task::588::TaskManager.Task::(_updateState) Task=`0a1686d8-8bed-40c8-8dba-3f6225f77d51`::moving from state init -> state preparing
>Thread-121::INFO::2013-03-01 16:13:16,365::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-121::INFO::2013-03-01 16:13:16,366::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-121::DEBUG::2013-03-01 16:13:16,366::task::1172::TaskManager.Task::(prepare) Task=`0a1686d8-8bed-40c8-8dba-3f6225f77d51`::finished: {}
>Thread-121::DEBUG::2013-03-01 16:13:16,366::task::588::TaskManager.Task::(_updateState) Task=`0a1686d8-8bed-40c8-8dba-3f6225f77d51`::moving from state preparing -> state finished
>Thread-121::DEBUG::2013-03-01 16:13:16,367::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-121::DEBUG::2013-03-01 16:13:16,367::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-121::DEBUG::2013-03-01 16:13:16,367::task::978::TaskManager.Task::(_decref) Task=`0a1686d8-8bed-40c8-8dba-3f6225f77d51`::ref 0 aborting False
>Thread-127::DEBUG::2013-03-01 16:13:31,562::task::588::TaskManager.Task::(_updateState) Task=`50341533-829e-4785-b3b8-a76497673448`::moving from state init -> state preparing
>Thread-127::INFO::2013-03-01 16:13:31,563::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-127::INFO::2013-03-01 16:13:31,563::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-127::DEBUG::2013-03-01 16:13:31,563::task::1172::TaskManager.Task::(prepare) Task=`50341533-829e-4785-b3b8-a76497673448`::finished: {}
>Thread-127::DEBUG::2013-03-01 16:13:31,564::task::588::TaskManager.Task::(_updateState) Task=`50341533-829e-4785-b3b8-a76497673448`::moving from state preparing -> state finished
>Thread-127::DEBUG::2013-03-01 16:13:31,564::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-127::DEBUG::2013-03-01 16:13:31,564::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-127::DEBUG::2013-03-01 16:13:31,565::task::978::TaskManager.Task::(_decref) Task=`50341533-829e-4785-b3b8-a76497673448`::ref 0 aborting False
>Thread-133::DEBUG::2013-03-01 16:13:46,766::task::588::TaskManager.Task::(_updateState) Task=`4939b02e-47c8-4d04-867a-7ea3b27a3c59`::moving from state init -> state preparing
>Thread-133::INFO::2013-03-01 16:13:46,767::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-133::INFO::2013-03-01 16:13:46,767::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-133::DEBUG::2013-03-01 16:13:46,767::task::1172::TaskManager.Task::(prepare) Task=`4939b02e-47c8-4d04-867a-7ea3b27a3c59`::finished: {}
>Thread-133::DEBUG::2013-03-01 16:13:46,768::task::588::TaskManager.Task::(_updateState) Task=`4939b02e-47c8-4d04-867a-7ea3b27a3c59`::moving from state preparing -> state finished
>Thread-133::DEBUG::2013-03-01 16:13:46,768::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-133::DEBUG::2013-03-01 16:13:46,768::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-133::DEBUG::2013-03-01 16:13:46,769::task::978::TaskManager.Task::(_decref) Task=`4939b02e-47c8-4d04-867a-7ea3b27a3c59`::ref 0 aborting False
>Thread-139::DEBUG::2013-03-01 16:14:01,963::task::588::TaskManager.Task::(_updateState) Task=`a2cda26d-f7bf-4f83-a0dc-10f84576b607`::moving from state init -> state preparing
>Thread-139::INFO::2013-03-01 16:14:01,964::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-139::INFO::2013-03-01 16:14:01,964::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-139::DEBUG::2013-03-01 16:14:01,965::task::1172::TaskManager.Task::(prepare) Task=`a2cda26d-f7bf-4f83-a0dc-10f84576b607`::finished: {}
>Thread-139::DEBUG::2013-03-01 16:14:01,965::task::588::TaskManager.Task::(_updateState) Task=`a2cda26d-f7bf-4f83-a0dc-10f84576b607`::moving from state preparing -> state finished
>Thread-139::DEBUG::2013-03-01 16:14:01,965::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-139::DEBUG::2013-03-01 16:14:01,966::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-139::DEBUG::2013-03-01 16:14:01,966::task::978::TaskManager.Task::(_decref) Task=`a2cda26d-f7bf-4f83-a0dc-10f84576b607`::ref 0 aborting False
>Thread-145::DEBUG::2013-03-01 16:14:17,165::task::588::TaskManager.Task::(_updateState) Task=`cfd921c7-f4ac-49e0-8ec8-a2b45d9d946a`::moving from state init -> state preparing
>Thread-145::INFO::2013-03-01 16:14:17,165::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-145::INFO::2013-03-01 16:14:17,166::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-145::DEBUG::2013-03-01 16:14:17,166::task::1172::TaskManager.Task::(prepare) Task=`cfd921c7-f4ac-49e0-8ec8-a2b45d9d946a`::finished: {}
>Thread-145::DEBUG::2013-03-01 16:14:17,166::task::588::TaskManager.Task::(_updateState) Task=`cfd921c7-f4ac-49e0-8ec8-a2b45d9d946a`::moving from state preparing -> state finished
>Thread-145::DEBUG::2013-03-01 16:14:17,167::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-145::DEBUG::2013-03-01 16:14:17,167::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-145::DEBUG::2013-03-01 16:14:17,167::task::978::TaskManager.Task::(_decref) Task=`cfd921c7-f4ac-49e0-8ec8-a2b45d9d946a`::ref 0 aborting False
>Thread-147::DEBUG::2013-03-01 16:14:17,316::BindingXMLRPC::894::vds::(wrapper) client [10.70.36.27]::call getCapabilities with () {}
>Thread-147::DEBUG::2013-03-01 16:14:17,354::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-img-rhev' (cwd None)
>Thread-147::DEBUG::2013-03-01 16:14:17,379::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-147::DEBUG::2013-03-01 16:14:17,380::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" qemu-kvm-rhev' (cwd None)
>Thread-147::DEBUG::2013-03-01 16:14:17,405::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = ''; <rc> = 1
>Thread-147::DEBUG::2013-03-01 16:14:17,406::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" vdsm' (cwd None)
>Thread-147::DEBUG::2013-03-01 16:14:17,431::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-147::DEBUG::2013-03-01 16:14:17,432::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" spice-server' (cwd None)
>Thread-147::DEBUG::2013-03-01 16:14:17,457::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-147::DEBUG::2013-03-01 16:14:17,458::__init__::1164::Storage.Misc.excCmd::(_log) '/bin/rpm -q --qf "%{NAME}\t%{VERSION}\t%{RELEASE}\t%{BUILDTIME}\n" libvirt' (cwd None)
>Thread-147::DEBUG::2013-03-01 16:14:17,483::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
>Thread-147::DEBUG::2013-03-01 16:14:17,484::BindingXMLRPC::900::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060'}], 'FC': []}, 'packages2': {'kernel': {'release': '220.31.1.el6.x86_64', 'buildtime': 1357213214.0, 'version': '2.6.32'}, 'vdsm': {'release': '19.el6rhs', 'buildtime': '1361181586', 'version': '4.9.6'}, 'spice-server': {'release': '5.el6', 'buildtime': '1319663438', 'version': '0.8.2'}, 'libvirt': {'release': '21.el6_3.8', 'buildtime': '1357832405', 'version': '0.9.10'}}, 'cpuModel': 'Intel Xeon E312xx (Sandy Bridge)', 'hooks': {}, 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'rhevm': {'iface': 'rhevm', 'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'bridged': True, 'gateway': '10.70.37.254', 'ports': ['eth0']}}, 'bridges': {'rhevm': {'addr': '10.70.36.77', 'cfg': {'IPV6_AUTOCONF': 'yes', 'IPV6INIT': 'yes', 'DELAY': '0', 'NM_CONTROLLED': 'no', 'BOOTPROTO': 'dhcp', 'DEVICE': 'rhevm', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.254.0', 'stp': 'off', 'ports': ['eth0']}}, 'uuid': '20BCF5F7-1551-4155-A4A7-12C4580D2723', 'lastClientIface': 'rhevm', 'nics': {'eth0': {'addr': '', 'cfg': {'BRIDGE': 'rhevm', 'IPV6INIT': 'yes', 'NM_CONTROLLED': 'no', 'IPV6_AUTOCONF': 'yes', 'HWADDR': '00:1A:4A:46:24:9B', 'DEVICE': 'eth0', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:1A:4A:46:24:9B', 'speed': 0}}, 'software_revision': '19', 'management_ip': '', 'clusterLevels': ['3.0', '3.1'], 'cpuFlags': 'fpu,de,pse,tsc,msr,pae,mce,cx8,apic,mtrr,pge,mca,cmov,pat,pse36,clflush,mmx,fxsr,sse,sse2,syscall,nx,lm,constant_tsc,up,arch_perfmon,unfair_spinlock,pni,pclmulqdq,ssse3,cx16,sse4_1,sse4_2,x2apic,popcnt,aes,xsave,avx,hypervisor,lahf_lm,xsaveopt', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:1a69468e1060', 'netConfigDirty': 'False', 'memSize': '996', 'reservedMem': '321', 'bondings': {'bond4': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond0': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond1': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}, 'bond3': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'slaves': [], 'hwaddr': '00:00:00:00:00:00'}}, 'software_version': '4.9', 'cpuSpeed': '1999.999', 'cpuSockets': '1', 'vlans': {}, 'cpuCores': '1', 'kvmEnabled': 'false', 'guestOverhead': '65', 'supportedRHEVMs': ['3.0', '3.1'], 'version_name': 'Snow Man', 'emulatedMachines': [], 'operatingSystem': {'release': '6.2.0.3.el6', 'version': '6Server', 'name': 'RHEL'}, 'lastClient': '10.70.36.27'}}
>Thread-152::DEBUG::2013-03-01 16:14:32,377::task::588::TaskManager.Task::(_updateState) Task=`00903e77-7330-4019-a7bc-c6ed5d86043f`::moving from state init -> state preparing
>Thread-152::INFO::2013-03-01 16:14:32,378::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
>Thread-152::INFO::2013-03-01 16:14:32,378::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {}
>Thread-152::DEBUG::2013-03-01 16:14:32,379::task::1172::TaskManager.Task::(prepare) Task=`00903e77-7330-4019-a7bc-c6ed5d86043f`::finished: {}
>Thread-152::DEBUG::2013-03-01 16:14:32,379::task::588::TaskManager.Task::(_updateState) Task=`00903e77-7330-4019-a7bc-c6ed5d86043f`::moving from state preparing -> state finished
>Thread-152::DEBUG::2013-03-01 16:14:32,379::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-152::DEBUG::2013-03-01 16:14:32,380::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-152::DEBUG::2013-03-01 16:14:32,380::task::978::TaskManager.Task::(_decref) Task=`00903e77-7330-4019-a7bc-c6ed5d86043f`::ref 0 aborting False

Actions: View

Attachments on bug 916981: 704125 | 704126