Thread-58849::DEBUG::2013-02-06 15:55:05,246::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' is free, finding out if anyone is waiting for it.

Thread-58849::DEBUG::2013-02-06 15:55:05,246::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2', Clearing records.

Thread-58849::DEBUG::2013-02-06 15:55:05,247::task::957::TaskManager.Task::(_decref) Task=`ad17c17b-b5ca-4135-b70f-503f388da8ee`::ref 0 aborting False

Thread-58853::DEBUG::2013-02-06 15:55:11,347::task::568::TaskManager.Task::(_updateState) Task=`e585ff1e-c2b5-4d3c-97c3-e7974679e16b`::moving from state init -> state preparing

Thread-58853::INFO::2013-02-06 15:55:11,347::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)

Thread-58853::INFO::2013-02-06 15:55:11,348::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0121810436249', 'lastCheck': '7.1', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.013571023941', 'lastCheck': '4.2', 'code': 0, 'valid': True}}

Thread-58853::DEBUG::2013-02-06 15:55:11,348::task::1151::TaskManager.Task::(prepare) Task=`e585ff1e-c2b5-4d3c-97c3-e7974679e16b`::finished: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0121810436249', 'lastCheck': '7.1', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.013571023941', 'lastCheck': '4.2', 'code': 0, 'valid': True}}

Thread-58853::DEBUG::2013-02-06 15:55:11,348::task::568::TaskManager.Task::(_updateState) Task=`e585ff1e-c2b5-4d3c-97c3-e7974679e16b`::moving from state preparing -> state finished

Thread-58853::DEBUG::2013-02-06 15:55:11,348::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}

Thread-58853::DEBUG::2013-02-06 15:55:11,349::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58853::DEBUG::2013-02-06 15:55:11,349::task::957::TaskManager.Task::(_decref) Task=`e585ff1e-c2b5-4d3c-97c3-e7974679e16b`::ref 0 aborting False

Thread-58856::DEBUG::2013-02-06 15:55:15,289::BindingXMLRPC::161::vds::(wrapper) [172.16.110.253]

Thread-58856::DEBUG::2013-02-06 15:55:15,290::task::568::TaskManager.Task::(_updateState) Task=`b1ecedb8-6265-47a2-a370-4144dd8d30d8`::moving from state init -> state preparing

Thread-58856::INFO::2013-02-06 15:55:15,290::logUtils::41::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='bd9a0b0d-63af-4420-be3a-9699a9b44ec2', options=None)

Thread-58856::INFO::2013-02-06 15:55:15,291::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}

Thread-58856::DEBUG::2013-02-06 15:55:15,291::task::1151::TaskManager.Task::(prepare) Task=`b1ecedb8-6265-47a2-a370-4144dd8d30d8`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}

Thread-58856::DEBUG::2013-02-06 15:55:15,291::task::568::TaskManager.Task::(_updateState) Task=`b1ecedb8-6265-47a2-a370-4144dd8d30d8`::moving from state preparing -> state finished

Thread-58856::DEBUG::2013-02-06 15:55:15,291::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}

Thread-58856::DEBUG::2013-02-06 15:55:15,292::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58856::DEBUG::2013-02-06 15:55:15,292::task::957::TaskManager.Task::(_decref) Task=`b1ecedb8-6265-47a2-a370-4144dd8d30d8`::ref 0 aborting False

Thread-58857::DEBUG::2013-02-06 15:55:15,295::BindingXMLRPC::161::vds::(wrapper) [172.16.110.253]

Thread-58857::DEBUG::2013-02-06 15:55:15,296::task::568::TaskManager.Task::(_updateState) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::moving from state init -> state preparing

Thread-58857::INFO::2013-02-06 15:55:15,296::logUtils::41::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='bd9a0b0d-63af-4420-be3a-9699a9b44ec2', options=None)

Thread-58857::DEBUG::2013-02-06 15:55:15,298::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2`ReqID=`73210a9d-5ac6-4f9a-9eca-0601cc029375`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'

Thread-58857::DEBUG::2013-02-06 15:55:15,298::resourceManager::504::ResourceManager::(registerResource) Trying to register resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' for lock type 'shared'

Thread-58857::DEBUG::2013-02-06 15:55:15,298::resourceManager::547::ResourceManager::(registerResource) Resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' is free. Now locking as 'shared' (1 active user)

Thread-58857::DEBUG::2013-02-06 15:55:15,299::resourceManager::227::ResourceManager.Request::(grant) ResName=`Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2`ReqID=`73210a9d-5ac6-4f9a-9eca-0601cc029375`::Granted request

Thread-58857::DEBUG::2013-02-06 15:55:15,299::task::794::TaskManager.Task::(resourceAcquired) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::_resourcesAcquired: Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2 (shared)

Thread-58857::DEBUG::2013-02-06 15:55:15,299::task::957::TaskManager.Task::(_decref) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::ref 1 aborting False

Thread-58857::INFO::2013-02-06 15:55:15,306::logUtils::44::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b', 'name': 'DC_NFS', 'version': '3', 'domains': 'bc8522d9-11b2-479a-8c67-1a25979e02ce:Active,beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/bd9a0b0d-63af-4420-be3a-9699a9b44ec2/bc8522d9-11b2-479a-8c67-1a25979e02ce/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver': 1, 'lver': 13}, 'dominfo': {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}}}

Thread-58857::DEBUG::2013-02-06 15:55:15,307::task::1151::TaskManager.Task::(prepare) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::finished: {'info': {'spm_id': 1, 'master_uuid': 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b', 'name': 'DC_NFS', 'version': '3', 'domains': 'bc8522d9-11b2-479a-8c67-1a25979e02ce:Active,beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/bd9a0b0d-63af-4420-be3a-9699a9b44ec2/bc8522d9-11b2-479a-8c67-1a25979e02ce/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver': 1, 'lver': 13}, 'dominfo': {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}}}

Thread-58857::DEBUG::2013-02-06 15:55:15,307::task::568::TaskManager.Task::(_updateState) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::moving from state preparing -> state finished

Thread-58857::DEBUG::2013-02-06 15:55:15,307::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2': < ResourceRef 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2', isValid: 'True' obj: 'None'>}

Thread-58857::DEBUG::2013-02-06 15:55:15,307::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58857::DEBUG::2013-02-06 15:55:15,308::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2'

Thread-58857::DEBUG::2013-02-06 15:55:15,308::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' (0 active users)

Thread-58857::DEBUG::2013-02-06 15:55:15,308::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' is free, finding out if anyone is waiting for it.

Thread-58857::DEBUG::2013-02-06 15:55:15,308::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2', Clearing records.

Thread-58857::DEBUG::2013-02-06 15:55:15,308::task::957::TaskManager.Task::(_decref) Task=`9d5ebb26-1e34-4b71-8a58-1abfdefb5c9f`::ref 0 aborting False

Thread-58861::DEBUG::2013-02-06 15:55:20,044::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call setupNetworks with ({'Internet': {'nic': 'p1p2', 'vlan': '100', 'STP': 'no', 'bridged': 'true'}}, {}, {'connectivityCheck': 'true', 'connectivityTimeout': 120}) {}

Thread-58862::DEBUG::2013-02-06 15:55:20,046::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58862::DEBUG::2013-02-06 15:55:20,047::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,084::configNetwork::1313::setupNetworks::(setupNetworks) Setting up network according to configuration: networks:{'Internet': {'nic': 'p1p2', 'vlan': '100', 'STP': 'no', 'bridged': 'true'}}, bondings:{}, options:{'connectivityCheck': 'true', 'connectivityTimeout': 120}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,084::configNetwork::1317::root::(setupNetworks) Validating configuration

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,116::configNetwork::1320::setupNetworks::(setupNetworks) Applying...

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,116::configNetwork::1325::setupNetworks::(setupNetworks) Removing network 'Internet'

MainProcess|Thread-58861::INFO::2013-02-06 15:55:20,147::configNetwork::1068::root::(delNetwork) Removing network Internet with vlan=None, bonding=None, nics=[],options={}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,179::configNetwork::257::root::(_atomicNetworkBackup) Backed up Internet

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,181::configNetwork::266::root::(_persistentNetworkBackup) backing up network Internet: <network>

  <name>vdsm-Internet</name>

  <uuid>4e3aa963-db5a-24bb-1af3-0c89e2b19797</uuid>

  <forward mode='bridge'/>

  <bridge name='Internet' />

</network>

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,214::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifdown Internet' (cwd None)

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,447::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,447::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/brctl delbr Internet' (cwd None)

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,466::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,466::configNetwork::303::root::(_atomicBackup) Backed up /etc/sysconfig/network-scripts/ifcfg-Internet

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,467::configNetwork::335::root::(_persistentBackup) backing up ifcfg-Internet: DEVICE=Internet

ONBOOT=yes

TYPE=Bridge

DELAY=0

NM_CONTROLLED=no

STP=no

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,467::configNetwork::179::root::(_removeFile) Removed file /etc/sysconfig/network-scripts/ifcfg-Internet

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,538::configNetwork::1365::setupNetworks::(setupNetworks) Adding network 'Internet'

Thread-58863::DEBUG::2013-02-06 15:55:20,552::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58863::DEBUG::2013-02-06 15:55:20,553::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,563::configNetwork::890::root::(addNetwork) validating network...

MainProcess|Thread-58861::INFO::2013-02-06 15:55:20,563::configNetwork::899::root::(addNetwork) Adding network Internet with vlan=100, bonding=None, nics=['p1p2'], bondingOptions=None, mtu=None, bridged=True, options={'STP': 'no', 'implicitBonding': True}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,563::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifdown p1p2' (cwd None)

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,799::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,799::configNetwork::335::root::(_persistentBackup) backing up ifcfg-Internet: # original file did not exist

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,804::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifdown Internet' (cwd None)

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,998::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,999::configNetwork::303::root::(_atomicBackup) Backed up /etc/sysconfig/network-scripts/ifcfg-p1p2.100

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:20,999::configNetwork::335::root::(_persistentBackup) backing up ifcfg-p1p2.100: DEVICE=p1p2.100

ONBOOT=yes

VLAN=yes

BRIDGE=Internet

NM_CONTROLLED=no

STP=no

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,045::configNetwork::303::root::(_atomicBackup) Backed up /etc/sysconfig/network-scripts/ifcfg-p1p2

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,045::configNetwork::335::root::(_persistentBackup) backing up ifcfg-p1p2: DEVICE=p1p2

ONBOOT=yes

HWADDR=00:25:b5:01:10:4f

NM_CONTROLLED=no

STP=no

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,046::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifup p1p2' (cwd None)

Thread-58864::DEBUG::2013-02-06 15:55:21,059::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58864::DEBUG::2013-02-06 15:55:21,059::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,362::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,363::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifup p1p2.100' (cwd None)

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,393::misc::84::Storage.Misc.excCmd::(<lambda>) FAILED: <err> = 'RTNETLINK answers: File exists\n'; <rc> = 1

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,393::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/sbin/ifup Internet' (cwd None)

Thread-58865::DEBUG::2013-02-06 15:55:21,530::task::568::TaskManager.Task::(_updateState) Task=`15165ba3-1960-4c64-8ead-1328f58d4a03`::moving from state init -> state preparing

Thread-58865::INFO::2013-02-06 15:55:21,530::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)

Thread-58865::INFO::2013-02-06 15:55:21,531::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0148069858551', 'lastCheck': '7.3', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.0123958587646', 'lastCheck': '4.4', 'code': 0, 'valid': True}}

Thread-58865::DEBUG::2013-02-06 15:55:21,531::task::1151::TaskManager.Task::(prepare) Task=`15165ba3-1960-4c64-8ead-1328f58d4a03`::finished: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0148069858551', 'lastCheck': '7.3', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.0123958587646', 'lastCheck': '4.4', 'code': 0, 'valid': True}}

Thread-58865::DEBUG::2013-02-06 15:55:21,532::task::568::TaskManager.Task::(_updateState) Task=`15165ba3-1960-4c64-8ead-1328f58d4a03`::moving from state preparing -> state finished

Thread-58865::DEBUG::2013-02-06 15:55:21,532::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}

Thread-58865::DEBUG::2013-02-06 15:55:21,532::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58865::DEBUG::2013-02-06 15:55:21,532::task::957::TaskManager.Task::(_decref) Task=`15165ba3-1960-4c64-8ead-1328f58d4a03`::ref 0 aborting False

Thread-58867::DEBUG::2013-02-06 15:55:21,565::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58867::DEBUG::2013-02-06 15:55:21,565::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,767::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = ''; <rc> = 0

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,768::configNetwork::266::root::(_persistentNetworkBackup) backing up network Internet: # original file did not exist

MainProcess|Thread-58861::DEBUG::2013-02-06 15:55:21,831::configNetwork::1370::setupNetworks::(setupNetworks) Checking connectivity...

Thread-58868::DEBUG::2013-02-06 15:55:22,071::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58868::DEBUG::2013-02-06 15:55:22,071::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

Thread-58869::DEBUG::2013-02-06 15:55:22,580::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call ping with () {}

Thread-58869::DEBUG::2013-02-06 15:55:22,582::BindingXMLRPC::920::vds::(wrapper) return ping with {'status': {'message': 'Done', 'code': 0}}

Thread-58861::DEBUG::2013-02-06 15:55:22,833::BindingXMLRPC::920::vds::(wrapper) return setupNetworks with {'status': {'message': 'Done', 'code': 0}}

Thread-58870::DEBUG::2013-02-06 15:55:23,090::BindingXMLRPC::913::vds::(wrapper) client [172.16.110.253]::call getCapabilities with () {}

Thread-58870::DEBUG::2013-02-06 15:55:23,135::BindingXMLRPC::920::vds::(wrapper) return getCapabilities with {'status': {'message': 'Done', 'code': 0}, 'info': {'HBAInventory': {'iSCSI': [{'InitiatorName': 'iqn.1994-05.com.redhat:6170ccb99a3b'}], 'FC': [{'wwpn': '20000025b5011c6f', 'wwnn': '20000025b501106f', 'model': 'Unknown - Unknown'}, {'wwpn': '20000025b5011def', 'wwnn': '20000025b501106f', 'model': 'Unknown - Unknown'}]}, 'packages2': {'kernel': {'release': '204.fc18.x86_64', 'buildtime': 1358955869.0, 'version': '3.7.4'}, 'spice-server': {'release': '3.fc18', 'buildtime': 1358784016L, 'version': '0.12.2'}, 'vdsm': {'release': '6.fc18', 'buildtime': 1359564723L, 'version': '4.10.3'}, 'qemu-kvm': {'release': '4.fc18', 'buildtime': 1358785726L, 'version': '1.2.2'}, 'libvirt': {'release': '3.fc18', 'buildtime': 1355788803L, 'version': '0.10.2.2'}, 'qemu-img': {'release': '4.fc18', 'buildtime': 1358785726L, 'version': '1.2.2'}, 'mom': {'release': '1.fc18', 'buildtime': 1349470214L, 'version': '0.3.0'}}, 'cpuModel': 'Intel(R) Xeon(R) CPU           E5649  @ 2.53GHz', 'hooks': {}, 'cpuSockets': '2', 'vmTypes': ['kvm'], 'supportedProtocols': ['2.2', '2.3'], 'networks': {'ovirtmgmt': {'netmask': '255.255.255.0', 'iface': u'p1p1', 'addr': '172.16.110.1', 'bridged': False, 'interface': u'p1p1', 'gateway': '172.16.110.253', 'mtu': '1500'}, 'Internet2': {'iface': 'Internet2', 'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': []}, 'Internet': {'iface': 'Internet', 'addr': '', 'cfg': {'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'Internet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'bridged': True, 'gateway': '0.0.0.0', 'ports': []}}, 'bridges': {'Internet2': {'addr': '', 'cfg': {}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'ports': []}, 'Internet': {'addr': '', 'cfg': {'DELAY': '0', 'NM_CONTROLLED': 'no', 'STP': 'no', 'DEVICE': 'Internet', 'TYPE': 'Bridge', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '', 'stp': 'off', 'ports': []}}, 'uuid': 'BC112A2C-517F-11E1-0001-0000000000EF', 'lastClientIface': 'p1p1', 'nics': {'p1p1': {'addr': '172.16.110.1', 'cfg': {'NM_CONTROLLED': 'no', 'IPADDR': '172.16.110.1', 'GATEWAY': '172.16.110.253', 'HWADDR': '00:25:b5:01:10:3f', 'NETMASK': '255.255.255.0', 'BOOTPROTO': 'none', 'DEVICE': 'p1p1', 'ONBOOT': 'yes'}, 'mtu': '1500', 'netmask': '255.255.255.0', 'hwaddr': '00:25:b5:01:10:3f', 'speed': 10000}, 'p1p2': {'addr': '', 'cfg': {'DEVICE': 'p1p2', 'HWADDR': '00:25:b5:01:10:4f', 'STP': 'no', 'ONBOOT': 'yes', 'NM_CONTROLLED': 'no'}, 'mtu': '1500', 'netmask': '', 'hwaddr': '00:25:b5:01:10:4f', 'speed': 10000}}, 'software_revision': '6', 'clusterLevels': ['3.0', '3.1', '3.2'], 'cpuFlags': u'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,pdpe1gb,rdtscp,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,nopl,xtopology,nonstop_tsc,aperfmperf,pni,pclmulqdq,dtes64,monitor,ds_cpl,vmx,smx,est,tm2,ssse3,cx16,xtpr,pdcm,pcid,dca,sse4_1,sse4_2,popcnt,aes,lahf_lm,ida,arat,dtherm,tpr_shadow,vnmi,flexpriority,ept,vpid,model_Nehalem,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_Westmere,model_n270', 'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:6170ccb99a3b', 'netConfigDirty': 'True', 'supportedENGINEs': ['3.0', '3.1'], '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'}}, 'software_version': '4.10', 'memSize': '48241', 'cpuSpeed': '1596.000', 'version_name': 'Snow Man', 'vlans': {}, 'cpuCores': '12', 'kvmEnabled': 'true', 'guestOverhead': '65', 'management_ip': '', 'cpuThreads': '24', 'emulatedMachines': [u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc', u'pc-1.2', u'none', u'pc', u'pc-1.1', u'pc-1.0', u'pc-0.15', u'pc-0.14', u'pc-0.13', u'pc-0.12', u'pc-0.11', u'pc-0.10', u'isapc'], 'operatingSystem': {'release': '1', 'version': '18', 'name': 'Fedora'}, 'lastClient': '172.16.110.253'}}

Thread-58872::DEBUG::2013-02-06 15:55:25,344::BindingXMLRPC::161::vds::(wrapper) [172.16.110.253]

Thread-58872::DEBUG::2013-02-06 15:55:25,344::task::568::TaskManager.Task::(_updateState) Task=`b0fe5766-2afd-4742-9e1c-3077ec20a379`::moving from state init -> state preparing

Thread-58872::INFO::2013-02-06 15:55:25,345::logUtils::41::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='bd9a0b0d-63af-4420-be3a-9699a9b44ec2', options=None)

Thread-58872::INFO::2013-02-06 15:55:25,345::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}

Thread-58872::DEBUG::2013-02-06 15:55:25,345::task::1151::TaskManager.Task::(prepare) Task=`b0fe5766-2afd-4742-9e1c-3077ec20a379`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 13}}

Thread-58872::DEBUG::2013-02-06 15:55:25,346::task::568::TaskManager.Task::(_updateState) Task=`b0fe5766-2afd-4742-9e1c-3077ec20a379`::moving from state preparing -> state finished

Thread-58872::DEBUG::2013-02-06 15:55:25,346::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}

Thread-58872::DEBUG::2013-02-06 15:55:25,346::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58872::DEBUG::2013-02-06 15:55:25,346::task::957::TaskManager.Task::(_decref) Task=`b0fe5766-2afd-4742-9e1c-3077ec20a379`::ref 0 aborting False

Thread-58873::DEBUG::2013-02-06 15:55:25,350::BindingXMLRPC::161::vds::(wrapper) [172.16.110.253]

Thread-58873::DEBUG::2013-02-06 15:55:25,350::task::568::TaskManager.Task::(_updateState) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::moving from state init -> state preparing

Thread-58873::INFO::2013-02-06 15:55:25,350::logUtils::41::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='bd9a0b0d-63af-4420-be3a-9699a9b44ec2', options=None)

Thread-58873::DEBUG::2013-02-06 15:55:25,350::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2`ReqID=`8293df3b-3019-41cf-8039-0be62b6b45f4`::Request was made in '/usr/share/

Thread-58873::DEBUG::2013-02-06 15:55:25,350::task::568::TaskManager.Task::(_updateState) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::moving from state init -> state preparing

Thread-58873::INFO::2013-02-06 15:55:25,350::logUtils::41::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='bd9a0b0d-63af-4420-be3a-9699a9b44ec2', options=None)

Thread-58873::DEBUG::2013-02-06 15:55:25,350::resourceManager::190::ResourceManager.Request::(__init__) ResName=`Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2`ReqID=`8293df3b-3019-41cf-8039-0be62b6b45f4`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at '__init__'

Thread-58873::DEBUG::2013-02-06 15:55:25,351::resourceManager::504::ResourceManager::(registerResource) Trying to register resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' for lock type 'shared'

Thread-58873::DEBUG::2013-02-06 15:55:25,351::resourceManager::547::ResourceManager::(registerResource) Resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' is free. Now locking as 'shared' (1 active user)

Thread-58873::DEBUG::2013-02-06 15:55:25,351::resourceManager::227::ResourceManager.Request::(grant) ResName=`Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2`ReqID=`8293df3b-3019-41cf-8039-0be62b6b45f4`::Granted request

Thread-58873::DEBUG::2013-02-06 15:55:25,351::task::794::TaskManager.Task::(resourceAcquired) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::_resourcesAcquired: Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2 (shared)

Thread-58873::DEBUG::2013-02-06 15:55:25,352::task::957::TaskManager.Task::(_decref) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::ref 1 aborting False

Thread-58873::INFO::2013-02-06 15:55:25,356::logUtils::44::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b', 'name': 'DC_NFS', 'version': '3', 'domains': 'bc8522d9-11b2-479a-8c67-1a25979e02ce:Active,beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/bd9a0b0d-63af-4420-be3a-9699a9b44ec2/bc8522d9-11b2-479a-8c67-1a25979e02ce/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver': 1, 'lver': 13}, 'dominfo': {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}}}

Thread-58873::DEBUG::2013-02-06 15:55:25,356::task::1151::TaskManager.Task::(prepare) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::finished: {'info': {'spm_id': 1, 'master_uuid': 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b', 'name': 'DC_NFS', 'version': '3', 'domains': 'bc8522d9-11b2-479a-8c67-1a25979e02ce:Active,beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/bd9a0b0d-63af-4420-be3a-9699a9b44ec2/bc8522d9-11b2-479a-8c67-1a25979e02ce/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver': 1, 'lver': 13}, 'dominfo': {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'status': 'Active', 'diskfree': '193252556800', 'alerts': [], 'disktotal': '216039161856'}}}

Thread-58873::DEBUG::2013-02-06 15:55:25,356::task::568::TaskManager.Task::(_updateState) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::moving from state preparing -> state finished

Thread-58873::DEBUG::2013-02-06 15:55:25,356::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2': < ResourceRef 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2', isValid: 'True' obj: 'None'>}

Thread-58873::DEBUG::2013-02-06 15:55:25,356::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58873::DEBUG::2013-02-06 15:55:25,357::resourceManager::557::ResourceManager::(releaseResource) Trying to release resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2'

Thread-58873::DEBUG::2013-02-06 15:55:25,357::resourceManager::573::ResourceManager::(releaseResource) Released resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' (0 active users)

Thread-58873::DEBUG::2013-02-06 15:55:25,357::resourceManager::578::ResourceManager::(releaseResource) Resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2' is free, finding out if anyone is waiting for it.

Thread-58873::DEBUG::2013-02-06 15:55:25,357::resourceManager::585::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd9a0b0d-63af-4420-be3a-9699a9b44ec2', Clearing records.

Thread-58873::DEBUG::2013-02-06 15:55:25,357::task::957::TaskManager.Task::(_decref) Task=`9d4bf3aa-a7a4-4a4b-baba-90598f9e9f7e`::ref 0 aborting False

Thread-58877::DEBUG::2013-02-06 15:55:31,718::task::568::TaskManager.Task::(_updateState) Task=`96caee84-372c-4e6d-bddf-cac8fcd533eb`::moving from state init -> state preparing

Thread-58877::INFO::2013-02-06 15:55:31,719::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None)

Thread-58877::INFO::2013-02-06 15:55:31,719::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0147500038147', 'lastCheck': '7.5', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.0138521194458', 'lastCheck': '4.5', 'code': 0, 'valid': True}}

Thread-58877::DEBUG::2013-02-06 15:55:31,719::task::1151::TaskManager.Task::(prepare) Task=`96caee84-372c-4e6d-bddf-cac8fcd533eb`::finished: {'bc8522d9-11b2-479a-8c67-1a25979e02ce': {'delay': '0.0147500038147', 'lastCheck': '7.5', 'code': 0, 'valid': True}, 'beee8b03-13b1-4ef4-9d29-f0f9ef47ec4b': {'delay': '0.0138521194458', 'lastCheck': '4.5', 'code': 0, 'valid': True}}

Thread-58877::DEBUG::2013-02-06 15:55:31,720::task::568::TaskManager.Task::(_updateState) Task=`96caee84-372c-4e6d-bddf-cac8fcd533eb`::moving from state preparing -> state finished

Thread-58877::DEBUG::2013-02-06 15:55:31,720::resourceManager::830::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}

Thread-58877::DEBUG::2013-02-06 15:55:31,720::resourceManager::864::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}

Thread-58877::DEBUG::2013-02-06 15:55:31,720::task::957::TaskManager.Task::(_decref) Task=`96caee84-372c-4e6d-bddf-cac8fcd533eb`::ref 0 aborting False

^C