This is a multi-part message in MIME format. ------=_NextPart_000_00B5_01CD50A1.2C0D2C70 Content-Type: text/plain; charset="koi8-r" Content-Transfer-Encoding: 7bit Hi. I use a bunch of ovirt 3.1 beta and gluster storage. The virtual machine was created successfully, but will not start. In the logs: Vdsm.log: Thread-1426::DEBUG::2012-06-22 09:37:27,151::task::978::TaskManager.Task::(_decref) Task=`9a68c120-169f-4c0e-98e3-08e3bf5c66ab`::ref 0 aborting False Thread-1427::DEBUG::2012-06-22 09:37:27,162::BindingXMLRPC::160::vds::(wrapper) [10.1.20.2] Thread-1427::DEBUG::2012-06-22 09:37:27,163::task::588::TaskManager.Task::(_updateState) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::moving from state init -> state preparing Thread-1427::INFO::2012-06-22 09:37:27,163::logUtils::37::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='b1c7875a-964d-4633-8ea4-2b191d68c105', options=None) Thread-1427::DEBUG::2012-06-22 09:37:27,163::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.b1c7875a-964d-4633-8ea4-2b191d68c105`ReqID=`ca9b7715-1f0b-4 225-9717-d1179193c42e`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' Thread-1427::DEBUG::2012-06-22 09:37:27,164::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' for lock type 'shared' Thread-1427::DEBUG::2012-06-22 09:37:27,164::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' is free. Now locking as 'shared' (1 active user) Thread-1427::DEBUG::2012-06-22 09:37:27,164::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.b1c7875a-964d-4633-8ea4-2b191d68c105`ReqID=`ca9b7715-1f0b-4 225-9717-d1179193c42e`::Granted request Thread-1427::DEBUG::2012-06-22 09:37:27,164::task::817::TaskManager.Task::(resourceAcquired) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::_resourcesAcquired: Storage.b1c7875a-964d-4633-8ea4-2b191d68c105 (shared) Thread-1427::DEBUG::2012-06-22 09:37:27,165::task::978::TaskManager.Task::(_decref) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::ref 1 aborting False Thread-1427::INFO::2012-06-22 09:37:27,165::logUtils::39::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'name': 'gluster', 'version': '0', 'domains': '68aa0dc2-9cd1-4549-8008-30b1bae667db:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 0}, 'dominfo': {'68aa0dc2-9cd1-4549-8008-30b1bae667db': {'status': 'Active', 'diskfree': '27505983488', 'alerts': [], 'disktotal': '53579874304'}}} Thread-1427::DEBUG::2012-06-22 09:37:27,165::task::1172::TaskManager.Task::(prepare) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::finished: {'info': {'spm_id': 1, 'master_uuid': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'name': 'gluster', 'version': '0', 'domains': '68aa0dc2-9cd1-4549-8008-30b1bae667db:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 0}, 'dominfo': {'68aa0dc2-9cd1-4549-8008-30b1bae667db': {'status': 'Active', 'diskfree': '27505983488', 'alerts': [], 'disktotal': '53579874304'}}} Thread-1427::DEBUG::2012-06-22 09:37:27,166::task::588::TaskManager.Task::(_updateState) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::moving from state preparing -> state finished Thread-1427::DEBUG::2012-06-22 09:37:27,166::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105': < ResourceRef 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105', isValid: 'True' obj: 'None'>} Thread-1427::DEBUG::2012-06-22 09:37:27,166::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1427::DEBUG::2012-06-22 09:37:27,166::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' Thread-1427::DEBUG::2012-06-22 09:37:27,166::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' (0 active users) Thread-1427::DEBUG::2012-06-22 09:37:27,167::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' is free, finding out if anyone is waiting for it. Thread-1427::DEBUG::2012-06-22 09:37:27,167::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105', Clearing records. Thread-1427::DEBUG::2012-06-22 09:37:27,167::task::978::TaskManager.Task::(_decref) Task=`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::ref 0 aborting False Thread-1428::DEBUG::2012-06-22 09:37:27,476::BindingXMLRPC::872::vds::(wrapper) client [10.1.20.2]::call vmCreate with ({'custom': {}, 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'acpiEnable': 'true', 'emulatedMachine': 'pc', 'tabletEnable': 'true', 'vmId': '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': '9780f3aa-4c0e-44eb-bc94-7ebfb63fe2f3'}, {'index': '2', 'iface': 'ide', 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': '59b3e477-8ba9-4a09-ac4a-4d0da91708ce', 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'volumeID': 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'specParams': {}, 'readonly': 'false', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'optional': 'false', 'deviceId': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'poolID': 'b1c7875a-964d-4633-8ea4-2b191d68c105', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:01:14:00', 'network': 'ovirtmgmt', 'specParams': {}, 'deviceId': 'c580b531-2178-4a38-bb1e-971bf300bf8a', 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': '3df4e23d-85bd-41b3-a320-3a510a1c2e7f'}], 'smp': '1', 'vmType': 'kvm', 'timeOffset': '0', 'memSize': 512, 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '1', 'vmName': 'fgjh', 'display': 'vnc', 'transparentHugePages': 'true', 'nice': '0'},) {} flowID [60053096] Thread-1428::INFO::2012-06-22 09:37:27,477::API::603::vds::(_getNetworkIp) network None: using 0 Thread-1428::INFO::2012-06-22 09:37:27,477::API::229::vds::(create) vmContainerLock acquired by vm 92de99e5-067a-421b-a4b1-2a2b60e8894a Thread-1429::DEBUG::2012-06-22 09:37:27,479::vm::564::vm.Vm::(_startUnderlyingVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Start Thread-1428::DEBUG::2012-06-22 09:37:27,479::API::246::vds::(create) Total desktops after creation of 92de99e5-067a-421b-a4b1-2a2b60e8894a is 1 Thread-1428::DEBUG::2012-06-22 09:37:27,480::BindingXMLRPC::879::vds::(wrapper) return vmCreate with {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'pc', 'tabletEnable': 'true', 'pid': '0', 'timeOffset': '0', 'displayPort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custom': {}, 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'vmId': '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'transparentHugePages': 'true', 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': '9780f3aa-4c0e-44eb-bc94-7ebfb63fe2f3'}, {'index': '2', 'iface': 'ide', 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': '59b3e477-8ba9-4a09-ac4a-4d0da91708ce', 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'volumeID': 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'specParams': {}, 'readonly': 'false', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'optional': 'false', 'deviceId': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'poolID': 'b1c7875a-964d-4633-8ea4-2b191d68c105', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:01:14:00', 'network': 'ovirtmgmt', 'specParams': {}, 'deviceId': 'c580b531-2178-4a38-bb1e-971bf300bf8a', 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': '3df4e23d-85bd-41b3-a320-3a510a1c2e7f'}], 'smp': '1', 'vmType': 'kvm', 'memSize': 512, 'displayIp': '0', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '1', 'vmName': 'fgjh', 'display': 'vnc', 'nice': '0'}} Thread-1429::DEBUG::2012-06-22 09:37:27,481::vm::568::vm.Vm::(_startUnderlyingVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::_ongoingCreations acquired Thread-1429::INFO::2012-06-22 09:37:27,482::libvirtvm::1287::vm.Vm::(_run) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::VM wrapper has started Thread-1429::DEBUG::2012-06-22 09:37:27,482::task::588::TaskManager.Task::(_updateState) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::moving from state init -> state preparing Thread-1429::INFO::2012-06-22 09:37:27,482::logUtils::37::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='68aa0dc2-9cd1-4549-8008-30b1bae667db', spUUID='b1c7875a-964d-4633-8ea4-2b191d68c105', imgUUID='61180d3c-63ba-41ca-989a-8bd2acff4d7e', volUUID='eb866d5a-1319-4e32-b9f3-4de3ad3272fb', options=None) Thread-1429::DEBUG::2012-06-22 09:37:27,483::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=`2b25c825-b3b5-4 4f1-a41c-3e21dd2e716f`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' Thread-1429::DEBUG::2012-06-22 09:37:27,483::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' for lock type 'shared' Thread-1429::DEBUG::2012-06-22 09:37:27,483::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free. Now locking as 'shared' (1 active user) Thread-1429::DEBUG::2012-06-22 09:37:27,483::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=`2b25c825-b3b5-4 4f1-a41c-3e21dd2e716f`::Granted request Thread-1429::DEBUG::2012-06-22 09:37:27,484::task::817::TaskManager.Task::(resourceAcquired) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::_resourcesAcquired: Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db (shared) Thread-1429::DEBUG::2012-06-22 09:37:27,484::task::978::TaskManager.Task::(_decref) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::ref 1 aborting False Thread-1429::DEBUG::2012-06-22 09:37:27,485::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for eb866d5a-1319-4e32-b9f3-4de3ad3272fb Thread-1429::DEBUG::2012-06-22 09:37:27,487::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for eb866d5a-1319-4e32-b9f3-4de3ad3272fb Thread-1429::INFO::2012-06-22 09:37:27,488::logUtils::39::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737426432', 'apparentsize': '10737418240'} Thread-1429::DEBUG::2012-06-22 09:37:27,488::task::1172::TaskManager.Task::(prepare) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::finished: {'truesize': '10737426432', 'apparentsize': '10737418240'} Thread-1429::DEBUG::2012-06-22 09:37:27,489::task::588::TaskManager.Task::(_updateState) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::moving from state preparing -> state finished Thread-1429::DEBUG::2012-06-22 09:37:27,489::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db': < ResourceRef 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', isValid: 'True' obj: 'None'>} Thread-1429::DEBUG::2012-06-22 09:37:27,489::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1429::DEBUG::2012-06-22 09:37:27,489::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' Thread-1429::DEBUG::2012-06-22 09:37:27,489::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' (0 active users) Thread-1429::DEBUG::2012-06-22 09:37:27,490::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free, finding out if anyone is waiting for it. Thread-1429::DEBUG::2012-06-22 09:37:27,490::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', Clearing records. Thread-1429::DEBUG::2012-06-22 09:37:27,490::task::978::TaskManager.Task::(_decref) Task=`5922124f-6997-4a7f-a3a8-b4852afabe18`::ref 0 aborting False Thread-1429::INFO::2012-06-22 09:37:27,490::clientIF::279::vds::(prepareVolumePath) prepared volume path: Thread-1429::DEBUG::2012-06-22 09:37:27,490::task::588::TaskManager.Task::(_updateState) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::moving from state init -> state preparing Thread-1429::INFO::2012-06-22 09:37:27,491::logUtils::37::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='68aa0dc2-9cd1-4549-8008-30b1bae667db', spUUID='b1c7875a-964d-4633-8ea4-2b191d68c105', imgUUID='61180d3c-63ba-41ca-989a-8bd2acff4d7e', volUUID='eb866d5a-1319-4e32-b9f3-4de3ad3272fb') Thread-1429::DEBUG::2012-06-22 09:37:27,491::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=`95022af4-4bcc-4 503-81c6-767215c0cca5`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource' Thread-1429::DEBUG::2012-06-22 09:37:27,491::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' for lock type 'shared' Thread-1429::DEBUG::2012-06-22 09:37:27,491::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free. Now locking as 'shared' (1 active user) Thread-1429::DEBUG::2012-06-22 09:37:27,492::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=`95022af4-4bcc-4 503-81c6-767215c0cca5`::Granted request Thread-1429::DEBUG::2012-06-22 09:37:27,492::task::817::TaskManager.Task::(resourceAcquired) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::_resourcesAcquired: Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db (shared) Thread-1429::DEBUG::2012-06-22 09:37:27,492::task::978::TaskManager.Task::(_decref) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::ref 1 aborting False Thread-1429::DEBUG::2012-06-22 09:37:27,493::fileVolume::535::Storage.Volume::(validateVolumePath) validate path for eb866d5a-1319-4e32-b9f3-4de3ad3272fb Thread-1429::INFO::2012-06-22 09:37:27,496::image::357::Storage.Image::(getChain) sdUUID=68aa0dc2-9cd1-4549-8008-30b1bae667db imgUUID=61180d3c-63ba-41ca-989a-8bd2acff4d7e chain=[<storage.fileVolume.FileVolume instance at 0x7fe5d4540ef0>] Thread-1429::INFO::2012-06-22 09:37:27,497::logUtils::39::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'path': '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-8 008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4 e32-b9f3-4de3ad3272fb', 'chain': [{'path': '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-8 008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4 e32-b9f3-4de3ad3272fb', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'volumeID': 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': '61180d3c-63ba-41ca-989a-8bd2acff4d7e'}]} Thread-1429::DEBUG::2012-06-22 09:37:27,498::task::1172::TaskManager.Task::(prepare) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::finished: {'path': '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-8 008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4 e32-b9f3-4de3ad3272fb', 'chain': [{'path': '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-8 008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4 e32-b9f3-4de3ad3272fb', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'volumeID': 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': '61180d3c-63ba-41ca-989a-8bd2acff4d7e'}]} Thread-1429::DEBUG::2012-06-22 09:37:27,498::task::588::TaskManager.Task::(_updateState) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::moving from state preparing -> state finished Thread-1429::DEBUG::2012-06-22 09:37:27,498::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db': < ResourceRef 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', isValid: 'True' obj: 'None'>} Thread-1429::DEBUG::2012-06-22 09:37:27,498::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1429::DEBUG::2012-06-22 09:37:27,499::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' Thread-1429::DEBUG::2012-06-22 09:37:27,499::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' (0 active users) Thread-1429::DEBUG::2012-06-22 09:37:27,499::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free, finding out if anyone is waiting for it. Thread-1429::DEBUG::2012-06-22 09:37:27,499::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', Clearing records. Thread-1429::DEBUG::2012-06-22 09:37:27,500::task::978::TaskManager.Task::(_decref) Task=`9eba14b9-a037-4f59-bc90-97b5ce032503`::ref 0 aborting False Thread-1429::INFO::2012-06-22 09:37:27,500::clientIF::279::vds::(prepareVolumePath) prepared volume path: /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb Thread-1429::DEBUG::2012-06-22 09:37:27,507::libvirtvm::1340::vm.Vm::(_run) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::<?xml version="1.0" encoding="utf-8"?> <domain type="kvm"> <name>fgjh</name> <uuid>92de99e5-067a-421b-a4b1-2a2b60e8894a</uuid> <memory>524288</memory> <currentMemory>524288</currentMemory> <vcpu>1</vcpu> <devices> <channel type="unix"> <target name="com.redhat.rhevm.vdsm" type="virtio"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/fgjh.com.redhat.rhevm.vdsm"/> </channel> <input bus="usb" type="tablet"/> <graphics autoport="yes" keymap="en-us" listen="0" passwd="*****" passwdValidTo="1970-01-01T00:00:01" port="-1" type="vnc"/> <console type="pty"> <target port="0" type="virtio"/> </console> <video> <model heads="1" type="qxl" vram="65536"/> </video> <interface type="bridge"> <mac address="00:1a:4a:01:14:00"/> <model type="virtio"/> <source bridge="ovirtmgmt"/> </interface> <memballoon model="virtio"/> <disk device="cdrom" snapshot="no" type="file"> <source file=""/> <target bus="ide" dev="hdc"/> <readonly/> <serial></serial> </disk> <disk device="disk" snapshot="no" type="file"> <source file="/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4 549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1 319-4e32-b9f3-4de3ad3272fb"/> <target bus="virtio" dev="vda"/> <serial>61180d3c-63ba-41ca-989a-8bd2acff4d7e</serial> <boot order="1"/> <driver cache="none" error_policy="stop" io="threads" name="qemu" type="raw"/> </disk> </devices> <os> <type arch="x86_64" machine="pc">hvm</type> <smbios mode="sysinfo"/> </os> <sysinfo type="smbios"> <system> <entry name="manufacturer">Red Hat</entry> <entry name="product">RHEV Hypervisor</entry> <entry name="version">6.2-1.1</entry> <entry name="serial">068FD200-06AF-7318-06AF-73180A8F5201_00:1c:c4:74:94:f0</entry> <entry name="uuid">92de99e5-067a-421b-a4b1-2a2b60e8894a</entry> </system> </sysinfo> <clock adjustment="0" offset="variable"> <timer name="rtc" tickpolicy="catchup"/> </clock> <features> <acpi/> </features> <cpu match="exact"> <model>Conroe</model> <topology cores="1" sockets="1" threads="1"/> </cpu> </domain> Thread-1429::DEBUG::2012-06-22 09:37:28,084::vm::580::vm.Vm::(_startUnderlyingVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::_ongoingCreations released Thread-1429::ERROR::2012-06-22 09:37:28,084::vm::604::vm.Vm::(_startUnderlyingVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::The vm start process failed Traceback (most recent call last): File "/usr/share/vdsm/vm.py", line 570, in _startUnderlyingVm self._run() File "/usr/share/vdsm/libvirtvm.py", line 1366, in _run self._connection.createXML(domxml, flags), File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 82, in wrapper ret = f(*args, **kwargs) File "/usr/lib64/python2.6/site-packages/libvirt.py", line 2087, in createXML if ret is None:raise libvirtError('virDomainCreateXML() failed', conn=self) libvirtError: internal error Process exited while reading console log output: char device redirected to /dev/pts/1 qemu-kvm: -drive file=/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-45 49-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-13 19-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61 180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=th reads: could not open disk image /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb: Permission denied Thread-1429::DEBUG::2012-06-22 09:37:28,087::vm::920::vm.Vm::(setDownStatus) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Changed state to Down: internal error Process exited while reading console log output: char device redirected to /dev/pts/1 qemu-kvm: -drive file=/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-45 49-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-13 19-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61 180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=th reads: could not open disk image /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb: Permission denied Thread-1432::DEBUG::2012-06-22 09:37:28,354::BindingXMLRPC::872::vds::(wrapper) client [10.1.20.2]::call vmGetStats with ('92de99e5-067a-421b-a4b1-2a2b60e8894a',) {} Thread-1432::DEBUG::2012-06-22 09:37:28,354::BindingXMLRPC::879::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Down', 'hash': '0', 'exitMessage': 'internal error Process exited while reading console log output: char device redirected to /dev/pts/1\nqemu-kvm: -drive file=/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-45 49-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-13 19-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61 180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=th reads: could not open disk image /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb: Permission denied\n', 'vmId': '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'timeOffset': '0', 'exitCode': 1}]} Thread-1433::DEBUG::2012-06-22 09:37:28,366::BindingXMLRPC::872::vds::(wrapper) client [10.1.20.2]::call vmDestroy with ('92de99e5-067a-421b-a4b1-2a2b60e8894a',) {} Thread-1433::INFO::2012-06-22 09:37:28,366::API::319::vds::(destroy) vmContainerLock acquired by vm 92de99e5-067a-421b-a4b1-2a2b60e8894a Thread-1433::DEBUG::2012-06-22 09:37:28,366::libvirtvm::2088::vm.Vm::(destroy) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::destroy Called Thread-1433::INFO::2012-06-22 09:37:28,366::libvirtvm::2042::vm.Vm::(releaseVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Release VM resources Thread-1433::WARNING::2012-06-22 09:37:28,366::vm::328::vm.Vm::(_set_lastStatus) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::trying to set state to Powering down when already Down Thread-1433::DEBUG::2012-06-22 09:37:28,367::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/service ksmtuned retune' (cwd None) Thread-1433::DEBUG::2012-06-22 09:37:28,413::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0 Thread-1433::DEBUG::2012-06-22 09:37:28,414::task::588::TaskManager.Task::(_updateState) Task=`f042d1c3-5c18-4cb2-89d9-87d64a560922`::moving from state init -> state preparing Thread-1433::INFO::2012-06-22 09:37:28,415::logUtils::37::dispatcher::(wrapper) Run and protect: inappropriateDevices(thiefId='92de99e5-067a-421b-a4b1-2a2b60e8894a') Thread-1433::INFO::2012-06-22 09:37:28,418::logUtils::39::dispatcher::(wrapper) Run and protect: inappropriateDevices, Return response: None Thread-1433::DEBUG::2012-06-22 09:37:28,418::task::1172::TaskManager.Task::(prepare) Task=`f042d1c3-5c18-4cb2-89d9-87d64a560922`::finished: None Thread-1433::DEBUG::2012-06-22 09:37:28,418::task::588::TaskManager.Task::(_updateState) Task=`f042d1c3-5c18-4cb2-89d9-87d64a560922`::moving from state preparing -> state finished Thread-1433::DEBUG::2012-06-22 09:37:28,419::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-1433::DEBUG::2012-06-22 09:37:28,419::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1433::DEBUG::2012-06-22 09:37:28,419::task::978::TaskManager.Task::(_decref) Task=`f042d1c3-5c18-4cb2-89d9-87d64a560922`::ref 0 aborting False Thread-1433::DEBUG::2012-06-22 09:37:28,419::libvirtvm::2083::vm.Vm::(deleteVm) vmId=`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Total desktops after destroy of 92de99e5-067a-421b-a4b1-2a2b60e8894a is 0 Thread-1433::DEBUG::2012-06-22 09:37:28,420::BindingXMLRPC::879::vds::(wrapper) return vmDestroy with {'status': {'message': 'Machine destroyed', 'code': 0}} Thread-1434::DEBUG::2012-06-22 09:37:30,459::task::588::TaskManager.Task::(_updateState) Task=`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::moving from state init -> state preparing Thread-1434::INFO::2012-06-22 09:37:30,459::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-1434::INFO::2012-06-22 09:37:30,459::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'68aa0dc2-9cd1-4549-8008-30b1bae667db': {'delay': '0.0014181137085', 'lastCheck': 1340372243.5057499, 'code': 0, 'valid': True}} Thread-1434::DEBUG::2012-06-22 09:37:30,460::task::1172::TaskManager.Task::(prepare) Task=`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::finished: {'68aa0dc2-9cd1-4549-8008-30b1bae667db': {'delay': '0.0014181137085', 'lastCheck': 1340372243.5057499, 'code': 0, 'valid': True}} Thread-1434::DEBUG::2012-06-22 09:37:30,460::task::588::TaskManager.Task::(_updateState) Task=`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::moving from state preparing -> state finished Thread-1434::DEBUG::2012-06-22 09:37:30,460::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-1434::DEBUG::2012-06-22 09:37:30,460::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1434::DEBUG::2012-06-22 09:37:30,460::task::978::TaskManager.Task::(_decref) Task=`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::ref 0 aborting False ^C Error: libvirtError: internal error Process exited while reading console log output: char device redirected to /dev/pts/1 qemu-kvm: -drive file=/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-45 49-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-13 19-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61 180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=th reads: could not open disk image /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb: Permission denied [root@noc-3-synt mnt]# ls -lh /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb -rw-rw----. 1 vdsm kvm 10G Jun 22 09:28 /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549-80 08-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e 32-b9f3-4de3ad3272fb [root@noc-3-synt mnt]# ps -aux | grep /usr/share/vdsm/vdsm Warning: bad syntax, perhaps a bogus '-'? See /usr/share/doc/procps-3.2.8/FAQ root 2761 0.0 0.0 103280 804 pts/0 S+ 09:51 0:00 grep /usr/share/vdsm/vdsm vdsm 4480 0.0 0.0 9272 616 ? S< 09:07 0:00 /bin/bash -e /usr/share/vdsm/respawn --minlifetime 10 --daemon --masterpid /var/run/vdsm/respawn.pid /usr/share/vdsm/vdsm vdsm 4483 0.6 0.2 1411684 34800 ? S<l 09:07 0:17 /usr/bin/python /usr/share/vdsm/vdsm vdsm 5265 0.0 0.1 1387096 26880 ? S< 09:17 0:00 /usr/bin/python /usr/share/vdsm/vdsm vdsm 5266 0.0 0.1 1387096 26660 ? S< 09:17 0:00 /usr/bin/python /usr/share/vdsm/vdsm vdsm 5267 0.0 0.1 1387096 26660 ? S< 09:17 0:00 /usr/bin/python /usr/share/vdsm/vdsm vdsm 5269 0.0 0.1 1387096 26584 ? S< 09:17 0:00 /usr/bin/python /usr/share/vdsm/vdsm vdsm 5271 0.0 0.1 1387096 26584 ? S< 09:17 0:00 /usr/bin/python /usr/share/vdsm/vdsm :. ------=_NextPart_000_00B5_01CD50A1.2C0D2C70 Content-Type: text/html; charset="koi8-r" Content-Transfer-Encoding: quoted-printable <html xmlns:v=3D"urn:schemas-microsoft-com:vml" = xmlns:o=3D"urn:schemas-microsoft-com:office:office" = xmlns:w=3D"urn:schemas-microsoft-com:office:word" = xmlns:m=3D"http://schemas.microsoft.com/office/2004/12/omml" = xmlns=3D"http://www.w3.org/TR/REC-html40"><head> <META HTTP-EQUIV=3D"Content-Type" CONTENT=3D"text/html; = charset=3Dkoi8-r"> <meta name=3DGenerator content=3D"Microsoft Word 12 (filtered = medium)"><style><!-- /* Font Definitions */ @font-face {font-family:"Cambria Math"; panose-1:2 4 5 3 5 4 6 3 2 4;} @font-face {font-family:Calibri; panose-1:2 15 5 2 2 2 4 3 2 4;} /* Style Definitions */ p.MsoNormal, li.MsoNormal, div.MsoNormal {margin:0cm; margin-bottom:.0001pt; font-size:11.0pt; font-family:"Calibri","sans-serif";} a:link, span.MsoHyperlink {mso-style-priority:99; color:blue; text-decoration:underline;} a:visited, span.MsoHyperlinkFollowed {mso-style-priority:99; color:purple; text-decoration:underline;} span.EmailStyle17 {mso-style-type:personal-compose; font-family:"Calibri","sans-serif"; color:windowtext;} .MsoChpDefault {mso-style-type:export-only;} @page WordSection1 {size:612.0pt 792.0pt; margin:2.0cm 42.5pt 2.0cm 3.0cm;} div.WordSection1 {page:WordSection1;} --></style><!--[if gte mso 9]><xml> <o:shapedefaults v:ext=3D"edit" spidmax=3D"1026" /> </xml><![endif]--><!--[if gte mso 9]><xml> <o:shapelayout v:ext=3D"edit"> <o:idmap v:ext=3D"edit" data=3D"1" /> </o:shapelayout></xml><![endif]--></head><body lang=3DRU link=3Dblue = vlink=3Dpurple><div class=3DWordSection1><p class=3DMsoNormal><span = lang=3DEN-US>Hi.<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>I use a bunch of ovirt 3.1 beta and gluster storage. = <o:p></o:p></span></p><p class=3DMsoNormal><span lang=3DEN-US>The = virtual machine was created successfully, but will not = start.<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>In the logs:<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Vdsm.log:<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1426::DEBUG::2012-06-22 = 09:37:27,151::task::978::TaskManager.Task::(_decref) = Task=3D`9a68c120-169f-4c0e-98e3-08e3bf5c66ab`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,162::BindingXMLRPC::160::vds::(wrapper) = [10.1.20.2]<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,163::task::588::TaskManager.Task::(_updateState) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::moving from state init = -&gt; state preparing<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::INFO::2012-06-22 = 09:37:27,163::logUtils::37::dispatcher::(wrapper) Run and protect: = getStoragePoolInfo(spUUID=3D'b1c7875a-964d-4633-8ea4-2b191d68c105', = options=3DNone)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,163::resourceManager::175::ResourceManager.Request::(__init__) = ResName=3D`Storage.b1c7875a-964d-4633-8ea4-2b191d68c105`ReqID=3D`ca9b7715= -1f0b-4225-9717-d1179193c42e`::Request was made in = '/usr/share/vdsm/storage/resourceManager.py' line '485' at = 'registerResource'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,164::resourceManager::486::ResourceManager::(registerResource) = Trying to register resource = 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' for lock type = 'shared'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,164::resourceManager::528::ResourceManager::(registerResource) = Resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' is free. Now = locking as 'shared' (1 active user)<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,164::resourceManager::212::ResourceManager.Request::(grant) = ResName=3D`Storage.b1c7875a-964d-4633-8ea4-2b191d68c105`ReqID=3D`ca9b7715= -1f0b-4225-9717-d1179193c42e`::Granted request<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,164::task::817::TaskManager.Task::(resourceAcquired) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::_resourcesAcquired: = Storage.b1c7875a-964d-4633-8ea4-2b191d68c105 = (shared)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,165::task::978::TaskManager.Task::(_decref) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::ref 1 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::INFO::2012-06-22 = 09:37:27,165::logUtils::39::dispatcher::(wrapper) Run and protect: = getStoragePoolInfo, Return response: {'info': {'spm_id': 1, = 'master_uuid': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'name': = 'gluster', 'version': '0', 'domains': = '68aa0dc2-9cd1-4549-8008-30b1bae667db:Active', 'pool_status': = 'connected', 'isoprefix': '', 'type': 'SHAREDFS', 'master_ver': 1, = 'lver': 0}, 'dominfo': {'68aa0dc2-9cd1-4549-8008-30b1bae667db': = {'status': 'Active', 'diskfree': '27505983488', 'alerts': [], = 'disktotal': '53579874304'}}}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,165::task::1172::TaskManager.Task::(prepare) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::finished: {'info': = {'spm_id': 1, 'master_uuid': '68aa0dc2-9cd1-4549-8008-30b1bae667db', = 'name': 'gluster', 'version': '0', 'domains': = '68aa0dc2-9cd1-4549-8008-30b1bae667db:Active', 'pool_status': = 'connected', 'isoprefix': '', 'type': 'SHAREDFS', 'master_ver': 1, = 'lver': 0}, 'dominfo': {'68aa0dc2-9cd1-4549-8008-30b1bae667db': = {'status': 'Active', 'diskfree': '27505983488', 'alerts': [], = 'disktotal': '53579874304'}}}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::task::588::TaskManager.Task::(_updateState) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::moving from state = preparing -&gt; state finished<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources = {'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105': &lt; ResourceRef = 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105', isValid: 'True' obj: = 'None'&gt;}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::resourceManager::538::ResourceManager::(releaseResource) = Trying to release resource = 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105'<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::resourceManager::553::ResourceManager::(releaseResource) = Released resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' (0 = active users)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,167::resourceManager::558::ResourceManager::(releaseResource) = Resource 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105' is free, finding = out if anyone is waiting for it.<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,167::resourceManager::565::ResourceManager::(releaseResource) = No one is waiting for resource = 'Storage.b1c7875a-964d-4633-8ea4-2b191d68c105', Clearing = records.<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1427::DEBUG::2012-06-22 = 09:37:27,167::task::978::TaskManager.Task::(_decref) = Task=3D`662a52dd-f00d-4be1-941d-eac8ec6a70f6`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1428::DEBUG::2012-06-22 = 09:37:27,476::BindingXMLRPC::872::vds::(wrapper) client = [10.1.20.2]::call vmCreate with ({'custom': {}, 'keyboardLayout': = 'en-us', 'kvmEnable': 'true', 'acpiEnable': 'true', 'emulatedMachine': = 'pc', 'tabletEnable': 'true', 'vmId': = '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'devices': [{'device': 'qxl', = 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': = '9780f3aa-4c0e-44eb-bc94-7ebfb63fe2f3'}, {'index': '2', 'iface': 'ide', = 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': = '59b3e477-8ba9-4a09-ac4a-4d0da91708ce', 'device': 'cdrom', 'path': '', = 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', = 'bootOrder': '1', 'volumeID': 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', = 'imageID': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'specParams': {}, = 'readonly': 'false', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', = 'optional': 'false', 'deviceId': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', = 'poolID': 'b1c7875a-964d-4633-8ea4-2b191d68c105', 'device': 'disk', = 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, = {'nicModel': 'pv', 'macAddr': '00:1a:4a:01:14:00', 'network': = 'ovirtmgmt', 'specParams': {}, 'deviceId': = 'c580b531-2178-4a38-bb1e-971bf300bf8a', 'device': 'bridge', 'type': = 'interface'}, {'device': 'memballoon', 'specParams': {'model': = 'virtio'}, 'type': 'balloon', 'deviceId': = '3df4e23d-85bd-41b3-a320-3a510a1c2e7f'}], 'smp': '1', 'vmType': 'kvm', = 'timeOffset': '0', 'memSize': 512, 'spiceSslCipherSuite': 'DEFAULT', = 'cpuType': 'Conroe', 'spiceSecureChannels': = 'smain,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': = '1', 'vmName': 'fgjh', 'display': 'vnc', 'transparentHugePages': 'true', = 'nice': '0'},) {} flowID [60053096]<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1428::INFO::2012-06-22 = 09:37:27,477::API::603::vds::(_getNetworkIp) network None: using = 0<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1428::INFO::2012-06-22 = 09:37:27,477::API::229::vds::(create) vmContainerLock acquired by vm = 92de99e5-067a-421b-a4b1-2a2b60e8894a<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,479::vm::564::vm.Vm::(_startUnderlyingVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Start<o:p></o:p></span></p= 09:37:27,479::API::246::vds::(create) Total desktops after creation of = 92de99e5-067a-421b-a4b1-2a2b60e8894a is 1<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1428::DEBUG::2012-06-22 = 09:37:27,480::BindingXMLRPC::879::vds::(wrapper) return vmCreate with = {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': = 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'pc', = 'tabletEnable': 'true', 'pid': '0', 'timeOffset': '0', 'displayPort': = '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', = 'cpuType': 'Conroe', 'custom': {}, 'clientIp': '', 'nicModel': = 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'vmId': = '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'transparentHugePages': 'true', = 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': = 'video', 'deviceId': '9780f3aa-4c0e-44eb-bc94-7ebfb63fe2f3'}, {'index': = '2', 'iface': 'ide', 'specParams': {'path': ''}, 'readonly': 'true', = 'deviceId': '59b3e477-8ba9-4a09-ac4a-4d0da91708ce', 'device': 'cdrom', = 'path': '', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': = 'raw', 'bootOrder': '1', 'volumeID': = 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': = '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'specParams': {}, 'readonly': = 'false', 'domainID': '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'optional': = 'false', 'deviceId': '61180d3c-63ba-41ca-989a-8bd2acff4d7e', 'poolID': = 'b1c7875a-964d-4633-8ea4-2b191d68c105', 'device': 'disk', 'shared': = 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', = 'macAddr': '00:1a:4a:01:14:00', 'network': 'ovirtmgmt', 'specParams': = {}, 'deviceId': 'c580b531-2178-4a38-bb1e-971bf300bf8a', 'device': = 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specParams': = {'model': 'virtio'}, 'type': 'balloon', 'deviceId': = '3df4e23d-85bd-41b3-a320-3a510a1c2e7f'}], 'smp': '1', 'vmType': 'kvm', = 'memSize': 512, 'displayIp': '0', 'spiceSecureChannels': = 'smain,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': = '1', 'vmName': 'fgjh', 'display': 'vnc', 'nice': = '0'}}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,481::vm::568::vm.Vm::(_startUnderlyingVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::_ongoingCreations = acquired<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,482::libvirtvm::1287::vm.Vm::(_run) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::VM wrapper has = started<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,482::task::588::TaskManager.Task::(_updateState) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::moving from state init = -&gt; state preparing<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,482::logUtils::37::dispatcher::(wrapper) Run and protect: = getVolumeSize(sdUUID=3D'68aa0dc2-9cd1-4549-8008-30b1bae667db', = spUUID=3D'b1c7875a-964d-4633-8ea4-2b191d68c105', = imgUUID=3D'61180d3c-63ba-41ca-989a-8bd2acff4d7e', = volUUID=3D'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', = options=3DNone)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,483::resourceManager::175::ResourceManager.Request::(__init__) = ResName=3D`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=3D`2b25c825= -b3b5-44f1-a41c-3e21dd2e716f`::Request was made in = '/usr/share/vdsm/storage/resourceManager.py' line '485' at = 'registerResource'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,483::resourceManager::486::ResourceManager::(registerResource) = Trying to register resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' for lock type = 'shared'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,483::resourceManager::528::ResourceManager::(registerResource) = Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free. Now = locking as 'shared' (1 active user)<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,483::resourceManager::212::ResourceManager.Request::(grant) = ResName=3D`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=3D`2b25c825= -b3b5-44f1-a41c-3e21dd2e716f`::Granted request<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,484::task::817::TaskManager.Task::(resourceAcquired) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::_resourcesAcquired: = Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db = (shared)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,484::task::978::TaskManager.Task::(_decref) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::ref 1 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,485::fileVolume::535::Storage.Volume::(validateVolumePath) = validate path for = eb866d5a-1319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,487::fileVolume::535::Storage.Volume::(validateVolumePath) = validate path for = eb866d5a-1319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,488::logUtils::39::dispatcher::(wrapper) Run and protect: = getVolumeSize, Return response: {'truesize': '10737426432', = 'apparentsize': '10737418240'}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,488::task::1172::TaskManager.Task::(prepare) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::finished: {'truesize': = '10737426432', 'apparentsize': '10737418240'}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::task::588::TaskManager.Task::(_updateState) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::moving from state = preparing -&gt; state finished<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources = {'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db': &lt; ResourceRef = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', isValid: 'True' obj: = 'None'&gt;}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::resourceManager::538::ResourceManager::(releaseResource) = Trying to release resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db'<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::resourceManager::553::ResourceManager::(releaseResource) = Released resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' (0 = active users)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,490::resourceManager::558::ResourceManager::(releaseResource) = Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free, finding = out if anyone is waiting for it.<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,490::resourceManager::565::ResourceManager::(releaseResource) = No one is waiting for resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', Clearing = records.<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,490::task::978::TaskManager.Task::(_decref) = Task=3D`5922124f-6997-4a7f-a3a8-b4852afabe18`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,490::clientIF::279::vds::(prepareVolumePath) prepared volume = path:<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,490::task::588::TaskManager.Task::(_updateState) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::moving from state init = -&gt; state preparing<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,491::logUtils::37::dispatcher::(wrapper) Run and protect: = prepareImage(sdUUID=3D'68aa0dc2-9cd1-4549-8008-30b1bae667db', = spUUID=3D'b1c7875a-964d-4633-8ea4-2b191d68c105', = imgUUID=3D'61180d3c-63ba-41ca-989a-8bd2acff4d7e', = volUUID=3D'eb866d5a-1319-4e32-b9f3-4de3ad3272fb')<o:p></o:p></span></p><p= class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,491::resourceManager::175::ResourceManager.Request::(__init__) = ResName=3D`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=3D`95022af4= -4bcc-4503-81c6-767215c0cca5`::Request was made in = '/usr/share/vdsm/storage/resourceManager.py' line '485' at = 'registerResource'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,491::resourceManager::486::ResourceManager::(registerResource) = Trying to register resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' for lock type = 'shared'<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,491::resourceManager::528::ResourceManager::(registerResource) = Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free. Now = locking as 'shared' (1 active user)<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,492::resourceManager::212::ResourceManager.Request::(grant) = ResName=3D`Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db`ReqID=3D`95022af4= -4bcc-4503-81c6-767215c0cca5`::Granted request<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,492::task::817::TaskManager.Task::(resourceAcquired) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::_resourcesAcquired: = Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db = (shared)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,492::task::978::TaskManager.Task::(_decref) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::ref 1 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,493::fileVolume::535::Storage.Volume::(validateVolumePath) = validate path for = eb866d5a-1319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,496::image::357::Storage.Image::(getChain) = sdUUID=3D68aa0dc2-9cd1-4549-8008-30b1bae667db = imgUUID=3D61180d3c-63ba-41ca-989a-8bd2acff4d7e = chain=3D[&lt;storage.fileVolume.FileVolume instance at = 0x7fe5d4540ef0&gt;]<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,497::logUtils::39::dispatcher::(wrapper) Run and protect: = prepareImage, Return response: {'path': = '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-454= 9-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-= 1319-4e32-b9f3-4de3ad3272fb', 'chain': [{'path': = '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-454= 9-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-= 1319-4e32-b9f3-4de3ad3272fb', 'domainID': = '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'volumeID': = 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': = '61180d3c-63ba-41ca-989a-8bd2acff4d7e'}]}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,498::task::1172::TaskManager.Task::(prepare) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::finished: {'path': = '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-454= 9-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-= 1319-4e32-b9f3-4de3ad3272fb', 'chain': [{'path': = '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-454= 9-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-= 1319-4e32-b9f3-4de3ad3272fb', 'domainID': = '68aa0dc2-9cd1-4549-8008-30b1bae667db', 'volumeID': = 'eb866d5a-1319-4e32-b9f3-4de3ad3272fb', 'imageID': = '61180d3c-63ba-41ca-989a-8bd2acff4d7e'}]}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,498::task::588::TaskManager.Task::(_updateState) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::moving from state = preparing -&gt; state finished<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,498::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources = {'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db': &lt; ResourceRef = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', isValid: 'True' obj: = 'None'&gt;}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,498::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,499::resourceManager::538::ResourceManager::(releaseResource) = Trying to release resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db'<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,499::resourceManager::553::ResourceManager::(releaseResource) = Released resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' (0 = active users)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,499::resourceManager::558::ResourceManager::(releaseResource) = Resource 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db' is free, finding = out if anyone is waiting for it.<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,499::resourceManager::565::ResourceManager::(releaseResource) = No one is waiting for resource = 'Storage.68aa0dc2-9cd1-4549-8008-30b1bae667db', Clearing = records.<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,500::task::978::TaskManager.Task::(_decref) = Task=3D`9eba14b9-a037-4f59-bc90-97b5ce032503`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::INFO::2012-06-22 = 09:37:27,500::clientIF::279::vds::(prepareVolumePath) prepared volume = path: = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:27,507::libvirtvm::1340::vm.Vm::(_run) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::&lt;?xml = version=3D&quot;1.0&quot; = encoding=3D&quot;utf-8&quot;?&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>&lt;domain = type=3D&quot;kvm&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;name&gt;fgjh&lt;/name&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;uuid&gt;92de99e5-067a-421b-a4b1-2a2b60e8894a&lt;/uuid&gt;<o:p></o:p><= /span></p><p class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;memory&gt;524288&lt;/memory&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;currentMemory&gt;524288&lt;/currentMemory&gt;<o:p></o:p></span></p><p= class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;vcpu&gt;1&lt;/vcpu&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;devices&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;channel = type=3D&quot;unix&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;target name=3D&quot;com.redhat.rhevm.vdsm&quot; = type=3D&quot;virtio&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;source mode=3D&quot;bind&quot; = path=3D&quot;/var/lib/libvirt/qemu/channels/fgjh.com.redhat.rhevm.vdsm&qu= ot;/&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/channel&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;input = bus=3D&quot;usb&quot; = type=3D&quot;tablet&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;graphics = autoport=3D&quot;yes&quot; keymap=3D&quot;en-us&quot; = listen=3D&quot;0&quot; passwd=3D&quot;*****&quot; = passwdValidTo=3D&quot;1970-01-01T00:00:01&quot; port=3D&quot;-1&quot; = type=3D&quot;vnc&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;console = type=3D&quot;pty&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;target port=3D&quot;0&quot; = type=3D&quot;virtio&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/console&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;video&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;model heads=3D&quot;1&quot; type=3D&quot;qxl&quot; = vram=3D&quot;65536&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/video&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;interface = type=3D&quot;bridge&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;mac = address=3D&quot;00:1a:4a:01:14:00&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;model = type=3D&quot;virtio&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;source = bridge=3D&quot;ovirtmgmt&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/interface&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;memballoon model=3D&quot;virtio&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;disk = device=3D&quot;cdrom&quot; snapshot=3D&quot;no&quot; = type=3D&quot;file&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;source file=3D&quot;&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;target bus=3D&quot;ide&quot; = dev=3D&quot;hdc&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;readonly/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;serial&gt;&lt;/serial&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/disk&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;disk = device=3D&quot;disk&quot; snapshot=3D&quot;no&quot; = type=3D&quot;file&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;source = file=3D&quot;/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0= dc2-9cd1-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d= 7e/eb866d5a-1319-4e32-b9f3-4de3ad3272fb&quot;/&gt;<o:p></o:p></span></p><= p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;target bus=3D&quot;virtio&quot; = dev=3D&quot;vda&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A = &lt;serial&gt;61180d3c-63ba-41ca-989a-8bd2acff4d7e&lt;/serial&gt;<o:p></o= :p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;boot order=3D&quot;1&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;driver cache=3D&quot;none&quot; = error_policy=3D&quot;stop&quot; io=3D&quot;threads&quot; = name=3D&quot;qemu&quot; = type=3D&quot;raw&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/disk&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/devices&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A &lt;os&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;type = arch=3D&quot;x86_64&quot; = machine=3D&quot;pc&quot;&gt;hvm&lt;/type&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;smbios = mode=3D&quot;sysinfo&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/os&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A &lt;sysinfo = type=3D&quot;smbios&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;system&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;entry name=3D&quot;manufacturer&quot;&gt;Red = Hat&lt;/entry&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;entry name=3D&quot;product&quot;&gt;RHEV = Hypervisor&lt;/entry&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;entry = name=3D&quot;version&quot;&gt;6.2-1.1&lt;/entry&gt;<o:p></o:p></span></p>= <p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;entry = name=3D&quot;serial&quot;&gt;068FD200-06AF-7318-06AF-73180A8F5201_00:1c:c= 4:74:94:f0&lt;/entry&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A &lt;entry = name=3D&quot;uuid&quot;&gt;92de99e5-067a-421b-a4b1-2a2b60e8894a&lt;/entry= &gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;/system&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/sysinfo&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A &lt;clock adjustment=3D&quot;0&quot; = offset=3D&quot;variable&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;timer = name=3D&quot;rtc&quot; = tickpolicy=3D&quot;catchup&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/clock&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;features&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;acpi/&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/features&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A &lt;cpu = match=3D&quot;exact&quot;&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = &lt;model&gt;Conroe&lt;/model&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A &lt;topology = cores=3D&quot;1&quot; sockets=3D&quot;1&quot; = threads=3D&quot;1&quot;/&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A=9A=9A=9A=9A=9A=9A = &lt;/cpu&gt;<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>&lt;/domain&gt;<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:28,084::vm::580::vm.Vm::(_startUnderlyingVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::_ongoingCreations = released<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1429::ERROR::2012-06-22 = 09:37:28,084::vm::604::vm.Vm::(_startUnderlyingVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::The vm start process = failed<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Traceback (most recent call last):<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A File = &quot;/usr/share/vdsm/vm.py&quot;, line 570, in = _startUnderlyingVm<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A self._run()<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>=9A File = &quot;/usr/share/vdsm/libvirtvm.py&quot;, line 1366, in = _run<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A self._connection.createXML(domxml, = flags),<o:p></o:p></span></p><p class=3DMsoNormal><span lang=3DEN-US>=9A = File = &quot;/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py&quot;,= line 82, in wrapper<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A ret =3D f(*args, = **kwargs)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A File = &quot;/usr/lib64/python2.6/site-packages/libvirt.py&quot;, line 2087, in = createXML<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>=9A=9A=9A if ret is None:raise = libvirtError('virDomainCreateXML() failed', = conn=3Dself)<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>libvirtError: internal error Process exited while reading = console log output: char device redirected to = /dev/pts/1<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>qemu-kvm: -drive = file=3D/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9c= d1-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8= 66d5a-1319-4e32-b9f3-4de3ad3272fb,if=3Dnone,id=3Ddrive-virtio-disk0,forma= t=3Draw,serial=3D61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=3Dnone,werror= =3Dstop,rerror=3Dstop,aio=3Dthreads: could not open disk image = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb: Permission denied<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1429::DEBUG::2012-06-22 = 09:37:28,087::vm::920::vm.Vm::(setDownStatus) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Changed state to Down: = internal error Process exited while reading console log output: char = device redirected to /dev/pts/1<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>qemu-kvm: -drive = file=3D/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9c= d1-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8= 66d5a-1319-4e32-b9f3-4de3ad3272fb,if=3Dnone,id=3Ddrive-virtio-disk0,forma= t=3Draw,serial=3D61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=3Dnone,werror= =3Dstop,rerror=3Dstop,aio=3Dthreads: could not open disk image = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb: Permission denied<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1432::DEBUG::2012-06-22 = 09:37:28,354::BindingXMLRPC::872::vds::(wrapper) client = [10.1.20.2]::call vmGetStats with = ('92de99e5-067a-421b-a4b1-2a2b60e8894a',) {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1432::DEBUG::2012-06-22 = 09:37:28,354::BindingXMLRPC::879::vds::(wrapper) return vmGetStats with = {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': = 'Down', 'hash': '0', 'exitMessage': 'internal error Process exited while = reading console log output: char device redirected to = /dev/pts/1\nqemu-kvm: -drive = file=3D/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9c= d1-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8= 66d5a-1319-4e32-b9f3-4de3ad3272fb,if=3Dnone,id=3Ddrive-virtio-disk0,forma= t=3Draw,serial=3D61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=3Dnone,werror= =3Dstop,rerror=3Dstop,aio=3Dthreads: could not open disk image = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb: Permission denied\n', 'vmId': = '92de99e5-067a-421b-a4b1-2a2b60e8894a', 'timeOffset': '0', 'exitCode': = 1}]}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,366::BindingXMLRPC::872::vds::(wrapper) client = [10.1.20.2]::call vmDestroy with = ('92de99e5-067a-421b-a4b1-2a2b60e8894a',) {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::INFO::2012-06-22 = 09:37:28,366::API::319::vds::(destroy) vmContainerLock acquired by vm = 92de99e5-067a-421b-a4b1-2a2b60e8894a<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,366::libvirtvm::2088::vm.Vm::(destroy) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::destroy = Called<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::INFO::2012-06-22 = 09:37:28,366::libvirtvm::2042::vm.Vm::(releaseVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Release VM = resources<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::WARNING::2012-06-22 = 09:37:28,366::vm::328::vm.Vm::(_set_lastStatus) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::trying to set state to = Powering down when already Down<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,367::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo = -n /sbin/service ksmtuned retune' (cwd None)<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,413::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: = &lt;err&gt; =3D ''; &lt;rc&gt; =3D 0<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,414::task::588::TaskManager.Task::(_updateState) = Task=3D`f042d1c3-5c18-4cb2-89d9-87d64a560922`::moving from state init = -&gt; state preparing<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::INFO::2012-06-22 = 09:37:28,415::logUtils::37::dispatcher::(wrapper) Run and protect: = inappropriateDevices(thiefId=3D'92de99e5-067a-421b-a4b1-2a2b60e8894a')<o:= p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::INFO::2012-06-22 = 09:37:28,418::logUtils::39::dispatcher::(wrapper) Run and protect: = inappropriateDevices, Return response: None<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,418::task::1172::TaskManager.Task::(prepare) = Task=3D`f042d1c3-5c18-4cb2-89d9-87d64a560922`::finished: = None<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,418::task::588::TaskManager.Task::(_updateState) = Task=3D`f042d1c3-5c18-4cb2-89d9-87d64a560922`::moving from state = preparing -&gt; state finished<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::task::978::TaskManager.Task::(_decref) = Task=3D`f042d1c3-5c18-4cb2-89d9-87d64a560922`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::libvirtvm::2083::vm.Vm::(deleteVm) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::Total desktops after = destroy of 92de99e5-067a-421b-a4b1-2a2b60e8894a is = 0<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1433::DEBUG::2012-06-22 = 09:37:28,420::BindingXMLRPC::879::vds::(wrapper) return vmDestroy with = {'status': {'message': 'Machine destroyed', 'code': = 0}}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,459::task::588::TaskManager.Task::(_updateState) = Task=3D`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::moving from state init = -&gt; state preparing<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1434::INFO::2012-06-22 = 09:37:30,459::logUtils::37::dispatcher::(wrapper) Run and protect: = repoStats(options=3DNone)<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1434::INFO::2012-06-22 = 09:37:30,459::logUtils::39::dispatcher::(wrapper) Run and protect: = repoStats, Return response: {'68aa0dc2-9cd1-4549-8008-30b1bae667db': = {'delay': '0.0014181137085', 'lastCheck': 1340372243.5057499, 'code': 0, = 'valid': True}}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::task::1172::TaskManager.Task::(prepare) = Task=3D`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::finished: = {'68aa0dc2-9cd1-4549-8008-30b1bae667db': {'delay': '0.0014181137085', = 'lastCheck': 1340372243.5057499, 'code': 0, 'valid': = True}}<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::task::588::TaskManager.Task::(_updateState) = Task=3D`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::moving from state = preparing -&gt; state finished<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::task::978::TaskManager.Task::(_decref) = Task=3D`a479829e-33ba-4c9b-987a-bc61d8bf11d6`::ref 0 aborting = False<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>^C<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>Error:<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>libvirtError: internal error Process exited while reading = console log output: char device redirected to = /dev/pts/1<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>qemu-kvm: -drive = file=3D/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9c= d1-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8= 66d5a-1319-4e32-b9f3-4de3ad3272fb,if=3Dnone,id=3Ddrive-virtio-disk0,forma= t=3Draw,serial=3D61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=3Dnone,werror= =3Dstop,rerror=3Dstop,aio=3Dthreads: could not open disk image = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb: Permission denied<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>[root@noc-3-synt mnt]# ls -lh = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>-rw-rw----. 1 vdsm kvm 10G Jun 22 = 09:28 = /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4549= -8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1= 319-4e32-b9f3-4de3ad3272fb<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>[root@noc-3-synt mnt]# ps -aux | = grep /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>Warning: bad syntax, perhaps a = bogus '-'? See /usr/share/doc/procps-3.2.8/FAQ<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>root=9A=9A=9A=9A=9A 2761=9A 0.0=9A = 0.0 103280=9A=9A 804 pts/0=9A=9A=9A S+=9A=9A 09:51=9A=9A 0:00 grep = /usr/share/vdsm/vdsm<o:p></o:p></span></p><p class=3DMsoNormal><span = lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 4480=9A 0.0=9A 0.0=9A=9A 9272=9A=9A 616 = ?=9A=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:07=9A=9A 0:00 /bin/bash -e = /usr/share/vdsm/respawn --minlifetime 10 --daemon --masterpid = /var/run/vdsm/respawn.pid /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 4483=9A 0.6=9A = 0.2 1411684 34800 ?=9A=9A=9A=9A=9A=9A S&lt;l=9A 09:07=9A=9A 0:17 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 5265=9A 0.0=9A = 0.1 1387096 26880 ?=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 5266=9A 0.0=9A = 0.1 1387096 26660 ?=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 5267=9A 0.0=9A = 0.1 1387096 26660 ?=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A =9A=9A=9A5269=9A 0.0=9A = 0.1 1387096 26584 ?=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>vdsm=9A=9A=9A=9A=9A 5271=9A 0.0=9A = 0.1 1387096 26584 ?=9A=9A=9A=9A=9A=9A S&lt;=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US>&#8230;.<o:p></o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span lang=3DEN-US><o:p>&nbsp;</o:p></span></p><p = class=3DMsoNormal><span = lang=3DEN-US><o:p>&nbsp;</o:p></span></p></div></body></html> ------=_NextPart_000_00B5_01CD50A1.2C0D2C70--