- Users - oVirt List Archives

[Users] Do not start the virtual machine (gluster storage and ovirt 3.1)
by зоррыч 25 Jun '12

25 Jun '12

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></style></head><body lang=3DRU link=3Dblue = vlink=3Dpurple><div class=3DWordSection1>Hi.<o:p></o:p>I use a bunch of ovirt 3.1 beta and gluster storage. = <o:p></o:p>The = virtual machine was created successfully, but will not = start.<o:p></o:p><o:p> </o:p>In the logs:<o:p></o:p>Vdsm.log:<o:p></o:p>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>Thread-1427::DEBUG::2012-06-22 = 09:37:27,162::BindingXMLRPC::160::vds::(wrapper) = [10.1.20.2]<o:p></o:p>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 = -> state preparing<o:p></o:p>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>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>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>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>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>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>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>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>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>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 -> state finished<o:p></o:p>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'>}<o:p></o:p>Thread-1427::DEBUG::2012-06-22 = 09:37:27,166::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p>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>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>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>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>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>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>Thread-1428::INFO::2012-06-22 = 09:37:27,477::API::603::vds::(_getNetworkIp) network None: using = 0<o:p></o:p>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>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></p= >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<o:p></o:p>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>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>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>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 = -> state preparing<o:p></o:p>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>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>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>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>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>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>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>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>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>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>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>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 -> state finished<o:p></o:p>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'>}<o:p></o:p>Thread-1429::DEBUG::2012-06-22 = 09:37:27,489::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p>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>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>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>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>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>Thread-1429::INFO::2012-06-22 = 09:37:27,490::clientIF::279::vds::(prepareVolumePath) prepared volume = path:<o:p></o:p>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 = -> state preparing<o:p></o:p>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><p= class=3DMsoNormal>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>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>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>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>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>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>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>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[<storage.fileVolume.FileVolume instance at = 0x7fe5d4540ef0>]<o:p></o:p>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>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>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 -> state finished<o:p></o:p>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'>}<o:p></o:p>Thread-1429::DEBUG::2012-06-22 = 09:37:27,498::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p>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>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>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>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>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>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>Thread-1429::DEBUG::2012-06-22 = 09:37:27,507::libvirtvm::1340::vm.Vm::(_run) = vmId=3D`92de99e5-067a-421b-a4b1-2a2b60e8894a`::<?xml = version=3D"1.0" = encoding=3D"utf-8"?><o:p></o:p><domain = type=3D"kvm"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = <name>fgjh</name><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = <uuid>92de99e5-067a-421b-a4b1-2a2b60e8894a</uuid><o:p></o:p><= /span>=9A=9A=9A=9A=9A=9A=9A = <memory>524288</memory><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = <currentMemory>524288</currentMemory><o:p></o:p><p= class=3DMsoNormal>=9A=9A=9A=9A=9A=9A=9A = <vcpu>1</vcpu><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = <devices><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <channel = type=3D"unix"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <target name=3D"com.redhat.rhevm.vdsm" = type=3D"virtio"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <source mode=3D"bind" = path=3D"/var/lib/libvirt/qemu/channels/fgjh.com.redhat.rhevm.vdsm&qu= ot;/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </channel><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <input = bus=3D"usb" = type=3D"tablet"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <graphics = autoport=3D"yes" keymap=3D"en-us" = listen=3D"0" passwd=3D"*****" = passwdValidTo=3D"1970-01-01T00:00:01" port=3D"-1" = type=3D"vnc"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <console = type=3D"pty"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <target port=3D"0" = type=3D"virtio"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </console><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = <video><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <model heads=3D"1" type=3D"qxl" = vram=3D"65536"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </video><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <interface = type=3D"bridge"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <mac = address=3D"00:1a:4a:01:14:00"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <model = type=3D"virtio"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <source = bridge=3D"ovirtmgmt"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </interface><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = <memballoon model=3D"virtio"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <disk = device=3D"cdrom" snapshot=3D"no" = type=3D"file"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <source file=3D""/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <target bus=3D"ide" = dev=3D"hdc"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <readonly/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <serial></serial><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </disk><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <disk = device=3D"disk" snapshot=3D"no" = type=3D"file"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <source = file=3D"/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"/><o:p></o:p><= p class=3DMsoNormal>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <target bus=3D"virtio" = dev=3D"vda"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A = <serial>61180d3c-63ba-41ca-989a-8bd2acff4d7e</serial><o:p></o= :p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <boot order=3D"1"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <driver cache=3D"none" = error_policy=3D"stop" io=3D"threads" = name=3D"qemu" = type=3D"raw"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </disk><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </devices><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A <os><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <type = arch=3D"x86_64" = machine=3D"pc">hvm</type><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <smbios = mode=3D"sysinfo"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </os><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A <sysinfo = type=3D"smbios"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = <system><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <entry name=3D"manufacturer">Red = Hat</entry><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <entry name=3D"product">RHEV = Hypervisor</entry><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <entry = name=3D"version">6.2-1.1</entry><o:p></o:p>= =9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <entry = name=3D"serial">068FD200-06AF-7318-06AF-73180A8F5201_00:1c:c= 4:74:94:f0</entry><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A= =9A=9A=9A <entry = name=3D"uuid">92de99e5-067a-421b-a4b1-2a2b60e8894a</entry= ><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = </system><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </sysinfo><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A <clock adjustment=3D"0" = offset=3D"variable"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <timer = name=3D"rtc" = tickpolicy=3D"catchup"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </clock><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = <features><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = <acpi/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </features><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A <cpu = match=3D"exact"><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A = <model>Conroe</model><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A=9A <topology = cores=3D"1" sockets=3D"1" = threads=3D"1"/><o:p></o:p>=9A=9A=9A=9A=9A=9A=9A = </cpu><o:p></o:p></domain><o:p></o:p><o:p> </o:p>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>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>Traceback (most recent call last):<o:p></o:p>=9A File = "/usr/share/vdsm/vm.py", line 570, in = _startUnderlyingVm<o:p></o:p>=9A=9A=9A self._run()<o:p></o:p>=9A File = "/usr/share/vdsm/libvirtvm.py", line 1366, in = _run<o:p></o:p>=9A=9A=9A self._connection.createXML(domxml, = flags),<o:p></o:p>=9A = File = "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py",= line 82, in wrapper<o:p></o:p>=9A=9A=9A ret =3D f(*args, = **kwargs)<o:p></o:p>=9A File = "/usr/lib64/python2.6/site-packages/libvirt.py", line 2087, in = createXML<o:p></o:p>=9A=9A=9A if ret is None:raise = libvirtError('virDomainCreateXML() failed', = conn=3Dself)<o:p></o:p>libvirtError: internal error Process exited while reading = console log output: char device redirected to = /dev/pts/1<o:p></o:p>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><o:p> </o:p>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>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><o:p> </o:p>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>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>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>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>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>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>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>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>Thread-1433::DEBUG::2012-06-22 = 09:37:28,413::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: = <err> =3D ''; <rc> =3D 0<o:p></o:p>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 = -> state preparing<o:p></o:p>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>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>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>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 -> state finished<o:p></o:p>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources {}<o:p></o:p>Thread-1433::DEBUG::2012-06-22 = 09:37:28,419::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p>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>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>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>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 = -> state preparing<o:p></o:p>Thread-1434::INFO::2012-06-22 = 09:37:30,459::logUtils::37::dispatcher::(wrapper) Run and protect: = repoStats(options=3DNone)<o:p></o:p>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>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>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 -> state finished<o:p></o:p>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::resourceManager::809::ResourceManager.Owner::(releaseAll) = Owner.releaseAll requests {} resources {}<o:p></o:p>Thread-1434::DEBUG::2012-06-22 = 09:37:30,460::resourceManager::844::ResourceManager.Owner::(cancelAll) = Owner.cancelAll requests {}<o:p></o:p>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>^C<o:p></o:p><o:p> </o:p>Error:<o:p></o:p>libvirtError: internal error Process exited while reading = console log output: char device redirected to = /dev/pts/1<o:p></o:p>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><o:p> </o:p>[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>-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><o:p> </o:p>[root@noc-3-synt mnt]# ps -aux | = grep /usr/share/vdsm/vdsm<o:p></o:p>Warning: bad syntax, perhaps a = bogus '-'? See /usr/share/doc/procps-3.2.8/FAQ<o:p></o:p>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>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<=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>vdsm=9A=9A=9A=9A=9A 4483=9A 0.6=9A = 0.2 1411684 34800 ?=9A=9A=9A=9A=9A=9A S<l=9A 09:07=9A=9A 0:17 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>vdsm=9A=9A=9A=9A=9A 5265=9A 0.0=9A = 0.1 1387096 26880 ?=9A=9A=9A=9A=9A=9A S<=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>vdsm=9A=9A=9A=9A=9A 5266=9A 0.0=9A = 0.1 1387096 26660 ?=9A=9A=9A=9A=9A=9A S<=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>vdsm=9A=9A=9A=9A=9A 5267=9A 0.0=9A = 0.1 1387096 26660 ?=9A=9A=9A=9A=9A=9A S<=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>vdsm=9A=9A =9A=9A=9A5269=9A 0.0=9A = 0.1 1387096 26584 ?=9A=9A=9A=9A=9A=9A S<=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>vdsm=9A=9A=9A=9A=9A 5271=9A 0.0=9A = 0.1 1387096 26584 ?=9A=9A=9A=9A=9A=9A S<=9A=9A 09:17=9A=9A 0:00 = /usr/bin/python /usr/share/vdsm/vdsm<o:p></o:p>….<o:p></o:p><o:p> </o:p><o:p> </o:p><o:p> </o:p></div></body></html> ------=_NextPart_000_00B5_01CD50A1.2C0D2C70--

2 3

[Users] host install failed (kernel version 3.4.3)
by зоррыч 25 Jun '12

25 Jun '12

This is a multipart message in MIME format. ------=_NextPart_000_0092_01CD50D6.DF9FD5F0 Content-Type: text/plain; charset="koi8-r" Content-Transfer-Encoding: 7bit Hi. I am trying to install the host kernel with version 3.4.3. an error: Unsupported kernel version: 0 Logs: [root@noc-3-synt tmp]# cat vds_bootstrap.372080.log Fri, 22 Jun 2012 16:08:20 DEBUG **** Start VDS Validation **** Fri, 22 Jun 2012 16:08:20 DEBUG Entered VdsValidation(subject = '10.1.20.7', random_num = '7d832636-a512-40ae-8e27-ecd24728b39a', rev_num = 'None', installVirtualizationService = 'False', installGlusterService = 'True') Fri, 22 Jun 2012 16:08:20 DEBUG Setting up Package Sacks Fri, 22 Jun 2012 16:08:20 DEBUG yumSearch: found vdsm entries: [<YumAvailablePackageSqlite : vdsm-4.10.0-0.58.gita6f4929.el6.x86_64 (0x1b42a10)>] Fri, 22 Jun 2012 16:08:20 DEBUG Host properly registered with RHN/Satellite. Fri, 22 Jun 2012 16:08:20 DEBUG <BSTRAP component='RHN_REGISTRATION' status='OK' message='Host properly registered with RHN/Satellite.'/> Fri, 22 Jun 2012 16:08:21 DEBUG yumSearchVersion: pkg vdsm-4.10.0-0.58.gita6f4929.el6.x86_64 starts with: vdsm-4.10 Fri, 22 Jun 2012 16:08:21 DEBUG Available VDSM matches requirements Fri, 22 Jun 2012 16:08:21 DEBUG <BSTRAP component='VDSM_MAJOR_VER' status='OK' message='Available VDSM matches requirements'/> Fri, 22 Jun 2012 16:08:21 DEBUG ['/bin/uname', '-r'] Fri, 22 Jun 2012 16:08:21 DEBUG 3.4.3 Fri, 22 Jun 2012 16:08:21 DEBUG Fri, 22 Jun 2012 16:08:21 DEBUG <BSTRAP component='OS' status='OK' type='RHEL6' message='Supported platform version'/> Fri, 22 Jun 2012 16:08:21 DEBUG <BSTRAP component='KERNEL' status='FAIL' version='0' message='Unsupported kernel version: 0. Minimal supported version: 150'/> Fri, 22 Jun 2012 16:08:21 ERROR osExplorer test failed Fri, 22 Jun 2012 16:08:21 DEBUG <BSTRAP component='RHEV_INSTALL' status='FAIL'/> Fri, 22 Jun 2012 16:08:21 DEBUG **** End VDS Validation **** [root@noc-3-synt tmp]# uname -r 3.4.3 ------=_NextPart_000_0092_01CD50D6.DF9FD5F0 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=3DContent-Type content=3D"text/html; charset=3Dkoi8-r"><meta = name=3DGenerator content=3D"Microsoft Word 14 (filtered = medium)"><style></style></head><body lang=3DRU link=3Dblue = vlink=3Dpurple><div class=3DWordSection1>Hi.<o:p></o:p>I am trying to install the host kernel with version = 3.4.3.<o:p></o:p>an = error:<o:p></o:p>Unsupported kernel version: 0<o:p></o:p>Logs:<o:p></o:p><o:p> </o:p>[root@noc-3-synt tmp]# cat = vds_bootstrap.372080.log<o:p></o:p>Fri, 22 Jun 2012 16:08:20 DEBUG=9A=9A=9A **** Start VDS = Validation ****<o:p></o:p>Fri, 22 Jun 2012 16:08:20 DEBUG=9A=9A=9A Entered = VdsValidation(subject =3D '10.1.20.7', random_num =3D = '7d832636-a512-40ae-8e27-ecd24728b39a', rev_num =3D 'None', = installVirtualizationService =3D 'False', installGlusterService =3D = 'True')<o:p></o:p>Fri, 22 Jun 2012 16:08:20 DEBUG=9A =9A=9ASetting up Package = Sacks<o:p></o:p>Fri, = 22 Jun 2012 16:08:20 DEBUG=9A=9A=9A yumSearch: found vdsm entries: = [<YumAvailablePackageSqlite : vdsm-4.10.0-0.58.gita6f4929.el6.x86_64 = (0x1b42a10)>]<o:p></o:p>Fri, 22 Jun 2012 16:08:20 DEBUG=9A=9A=9A Host properly = registered with RHN/Satellite.<o:p></o:p>Fri, 22 Jun 2012 16:08:20 = DEBUG=9A=9A=9A <BSTRAP component=3D'RHN_REGISTRATION' status=3D'OK' = message=3D'Host properly registered with = RHN/Satellite.'/><o:p></o:p>Fri, 22 Jun 2012 16:08:21 DEBUG=9A=9A=9A yumSearchVersion: = pkg vdsm-4.10.0-0.58.gita6f4929.el6.x86_64 starts with: = vdsm-4.10<o:p></o:p>Fri, 22 Jun 2012 16:08:21 DEBUG=9A=9A=9A Available VDSM = matches requirements<o:p></o:p>Fri, 22 Jun 2012 16:08:21 DEBUG=9A=9A=9A <BSTRAP = component=3D'VDSM_MAJOR_VER' status=3D'OK' message=3D'Available VDSM = matches requirements'/><o:p></o:p>Fri, 22 Jun 2012 16:08:21 = DEBUG=9A=9A=9A ['/bin/uname', '-r']<o:p></o:p>Fri, 22 Jun 2012 16:08:21 = DEBUG=9A=9A=9A 3.4.3<o:p></o:p><o:p> </o:p>Fri, 22 Jun 2012 16:08:21 DEBUG<o:p></o:p>Fri, 22 Jun 2012 16:08:21 = DEBUG=9A=9A=9A <BSTRAP component=3D'OS' status=3D'OK' type=3D'RHEL6' = message=3D'Supported platform version'/><o:p></o:p>Fri, 22 Jun 2012 16:08:21 = DEBUG=9A=9A=9A <BSTRAP component=3D'KERNEL' status=3D'FAIL' = version=3D'0' message=3D'Unsupported kernel version: 0. Minimal = supported version: 150'/><o:p></o:p>Fri, 22 Jun 2012 16:08:21 = ERROR=9A=9A=9A osExplorer test failed<o:p></o:p>Fri, 22 Jun 2012 16:08:21 = DEBUG=9A=9A=9A <BSTRAP component=3D'RHEV_INSTALL' = status=3D'FAIL'/><o:p></o:p>Fri, 22 Jun 2012 16:08:21 DEBUG=9A=9A=9A **** End VDS = Validation ****<o:p></o:p><o:p> </o:p>[root@noc-3-synt tmp]# uname -r<o:p></o:p>3.4.3<o:p></o:p></div></body></html> ------=_NextPart_000_0092_01CD50D6.DF9FD5F0--

3 3

[Users] Quantum support
by Rahul Upadhyaya 25 Jun '12

25 Jun '12

Hi Folks, According to your road-map, when shall quantum support be available for oVirt ? -- Regards, Rahul =======================================================

2 1

[Users] Getting a stream of errors inside engine.log
by Robert Middleswarth 25 Jun '12

25 Jun '12

Getting a log full of error messages like these. 2012-06-21 21:03:30,075 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-90) Failed to decryptData must start with zero 2012-06-21 21:03:46,235 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-18) Failed to decryptData must not be longer than 128 bytes What is causing this and what can I do to fix it? Thanks Robert

4 10

[Users] oVirt 3.1 and Glusterfs using NFS shares.
by Robert Middleswarth 24 Jun '12

24 Jun '12

It took me a while with lots of trail and error but I am pretty close to getting everything working but my latest error seems to be permission related. Very much like the error one gets with regular nfs and the share not owned by the correct uid/gid. But there doesn't seem to be a way to fix it. According to this doc http://www.gluster.org/community/documentation/index.php/Translators/featur… on the Gluster site you can set those but I don't see a way to set that inside the interface and the files I would need to change get over written but vdsm. Am I missing something really obvious? Has anyone actually been able to get ovirt and glusterfs running together. I feel like I am so close just missing one little piece of the puzzle. Thanks Robert

2 4

[Users] I am using the CentOS build from the 12th. I the engine is dieing with the following error.
by Robert Middleswarth 24 Jun '12

24 Jun '12

2012-06-17 05:21:24,682 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (ajp--0.0.0.0-8009-9) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 05:21:26,121 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-88) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 05:21:26,130 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand] (QuartzScheduler_Worker-88) XML RPC error in command GetCapabilitiesVDS ( Vds: ann100ovirt01 ), the error was: java.util.concurrent.ExecutionException: java.lang.reflect.InvocationTargetException, SocketException: Too many open files 2012-06-17 15:49:08,577 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-28) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 20:21:13,943 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-64) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 20:21:15,949 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-65) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 21:00:15,133 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-98) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 21:07:00,037 WARN [org.ovirt.engine.core.ServletUtils] (ajp--0.0.0.0-8009-5) File "/usr/share/vdsm-bootstrap/deployUtil.py is 47867 bytes long. Please reconsider using this servlet for files larger than 8192 bytes. 2012-06-17 21:07:00,115 WARN [org.ovirt.engine.core.ServletUtils] (ajp--0.0.0.0-8009-6) File "/usr/share/vdsm-bootstrap/vds_bootstrap.py is 33884 bytes long. Please reconsider using this servlet for files larger than 8192 bytes. 2012-06-17 21:32:10,686 WARN [org.ovirt.engine.core.ServletUtils] (ajp--0.0.0.0-8009-6) File "/usr/share/vdsm-bootstrap/deployUtil.py is 47867 bytes long. Please reconsider using this servlet for files larger than 8192 bytes. 2012-06-17 21:32:10,752 WARN [org.ovirt.engine.core.ServletUtils] (ajp--0.0.0.0-8009-1) File "/usr/share/vdsm-bootstrap/vds_bootstrap.py is 33884 bytes long. Please reconsider using this servlet for files larger than 8192 bytes. 2012-06-17 21:44:34,028 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand] (QuartzScheduler_Worker-23) XML RPC error in command ListVDS ( Vds: ann100ovirt01 ), the error was: java.util.concurrent.ExecutionException: java.lang.reflect.InvocationTargetException, SocketException: Too many open files 2012-06-17 21:44:36,034 ERROR [org.ovirt.engine.core.engineencryptutils.EncryptionUtils] (QuartzScheduler_Worker-26) Failed to decryptjava.io.FileNotFoundException: /etc/pki/ovirt-engine/.keystore (Too many open files) 2012-06-17 21:44:36,045 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand] (QuartzScheduler_Worker-26) XML RPC error in command GetCapabilitiesVDS ( Vds: ann100ovirt01 ), the error was: java.util.concurrent.ExecutionException: java.lang.reflect.InvocationTargetException, SocketException: Too many open files I restarted ovirt-engine and ran lsof -p 3557 I see hundreds of the same open file. java 3557 ovirt 839r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 840r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 841r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 842r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 843r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 844r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 845r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 846r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 847r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 848r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 849r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 850r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 851r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 852r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 853r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore java 3557 ovirt 854r REG 253,0 3230 7865608 /etc/pki/ovirt-engine/.keystore Is anyone else seeing this? Thanks Robert

4 10

[Users] VDSM ERROR
by Nathan Stratton 24 Jun '12

24 Jun '12

Fedora 17 RPMs, hosts complets install and reboots, but never connects back to engine. I just see thousands of the following in the logs: ---- MainThread::INFO::2012-06-21 13:07:26,304::vdsm::71::vds::(run) I am the actual vdsm 4.9-0 MainThread::ERROR::2012-06-21 13:07:26,656::vdsm::74::vds::(run) Traceback (most recent call last): File "/usr/share/vdsm/vdsm", line 72, in run serve_clients(log) File "/usr/share/vdsm/vdsm", line 40, in serve_clients cif = clientIF.clientIF(log) File "/usr/share/vdsm/clientIF.py", line 115, in __init__ self._createLibvirtNetworks() File "/usr/share/vdsm/clientIF.py", line 152, in _createLibvirtNetworks nf = netinfo.NetInfo() File "/usr/share/vdsm/netinfo.py", line 268, in __init__ _netinfo = get() File "/usr/share/vdsm/netinfo.py", line 215, in get for bridge in bridges() ]) KeyError: 'ovirtmgmt' MainThread::INFO::2012-06-21 13:07:26,657::vdsm::76::vds::(run) VDSM main thread ended. Waiting for 1 other threads... MainThread::INFO::2012-06-21 13:07:26,657::vdsm::79::vds::(run) <_MainThread(MainThread, started 140487047427904)> MainThread::INFO::2012-06-21 13:07:26,657::vdsm::79::vds::(run) <Thread(libvirtEventLoop, started daemon 140486974248704)> ---- ovirtmgmt is up and running: -bash-4.2# brctl show bridge name bridge id STP enabled interfaces ovirtmgmt 8000.a0369f0a15f8 no bond0 ><> Nathan Stratton nathan at robotics.net http://www.robotics.net

3 5

[Users] Setting up logical storage networks
by Trey Dockendorf 24 Jun '12

24 Jun '12

In ovirt-engine-3.1 I'm attempting to setup the base logical networks and have run into 2 major issues. The first is I'm only seeing a Gateway field for the management interface. When I went to create a network for VMs (on seperate subnet) I did not see a place to specify gateway (see img ovirt_network_missing_gateway.png). Right now my management port is on a 100mbps network and the bridged devices live on a 1Gbps network (net140 in cluster). Is there a reason the gateway would be missing? I've attached ovirt_networks.png that shows all the interfaces on my host. The second issue I'm having is creating a storage network. I created 2 logical networks , private0 and private1. I left the "VM Network" unchecked on both as my assumption was that dicates if they can be added to VMs. Since these are only for hosts to connect to the iSCSI I didn't think that was necessary. When I set the IP information (private_network0.png) and select Ok the save goes through but when I edit the interface again the information is gone and the file ifcfg-eth4 does not have IP information. This is what I looks like DEVICE=eth4 ONBOOT=yes BOOTPROTO=none HWADDR=00:1b:21:1d:33:f0 NM_CONTROLLED=no MTU=9000 I also attached image cluster_logical_networks.png that shows the all the logical networks on this cluster. So far my plan is to have a single public interface for VM traffic, then two for storage traffic, each going to a different switch. This setup is just an initial test but I'd hope to have it in production once I get some of these kinks worked out. Please let me know what information would be useful to debug this further. Thanks - Trey

5 11

[Users] Online snapshot
by Winfried de Heiden 23 Jun '12

23 Jun '12

Hi all, Using the latest RPM's from www.ovirt.org/releases/beta/fedora/17 creating an online snapshot still fails: /var/log/ovirt-engine/engine.log: 2012-06-22 14:27:59,378 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (ajp--0.0.0.0-8009-5) [29998947] Lock Acquired to object EngineLock [exclusiveLocks= key: 0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c value: VM 2012-06-22 14:27:59,520 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (ajp--0.0.0.0-8009-5) [29998947] Running command: CreateAllSnapshotsFromVmCommand internal: false. Entities affected : ID: 0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c Type: VM 2012-06-22 14:27:59,572 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (ajp--0.0.0.0-8009-5) [29998947] Lock freed to object EngineLock [exclusiveLocks= key: 0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c value: VM 2012-06-22 14:27:59,573 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (ajp--0.0.0.0-8009-5) [8c07d4d] Running command: CreateSnapshotCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage 2012-06-22 14:27:59,630 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--0.0.0.0-8009-5) [8c07d4d] START, CreateSnapshotVDSCommand(storagePoolId = 0c160f51-087d-4ddd-9faf-6c8157ad2557, ignoreFailoverLimit = false, compatabilityVersion = 3.1, storageDomainId = d9879dad-413a-4730-b86f-475b20b88e22, imageGroupId = 62b3d341-904c-4462-9a25-82b46b804729, imageSizeInBytes = 8589934592, volumeFormat = COW, newImageId = c5f61a27-a6f5-4383-b9b1-b75d0aae1c27, newImageDescription = , imageId = 133db385-effc-4243-a918-a6bcb2743172, sourceImageGroupId = 62b3d341-904c-4462-9a25-82b46b804729), log id: 75e8f256 2012-06-22 14:27:59,633 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--0.0.0.0-8009-5) [8c07d4d] -- CreateSnapshotVDSCommand::ExecuteIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2012-06-22 14:27:59,634 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--0.0.0.0-8009-5) [8c07d4d] -- createVolume parameters: 2012-06-22 14:27:59,746 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--0.0.0.0-8009-5) [8c07d4d] FINISH, CreateSnapshotVDSCommand, return: c5f61a27-a6f5-4383-b9b1-b75d0aae1c27, log id: 75e8f256 2012-06-22 14:27:59,779 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp--0.0.0.0-8009-5) [8c07d4d] AsyncTaskManager::AddTaskToManager: Adding task b742843e-77b9-4ddb-9ce4-1e813adece90 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2012-06-22 14:27:59,844 INFO [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp--0.0.0.0-8009-5) [8c07d4d] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c is CreateAllSnapshotsFromVm (determined by task b742843e-77b9-4ddb-9ce4-1e813adece90) 2012-06-22 14:28:01,621 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-55) SPMAsyncTask::PollTask: Polling task b742843e-77b9-4ddb-9ce4-1e813adece90 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2012-06-22 14:28:01,636 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-55) BaseAsyncTask::OnTaskEndSuccess: Task b742843e-77b9-4ddb-9ce4-1e813adece90 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2012-06-22 14:28:01,640 INFO [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-55) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c): calling EndAction for action type CreateAllSnapshotsFromVm. 2012-06-22 14:28:01,642 INFO [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-49) EntityAsyncTask::EndCommandAction [within thread]context: Attempting to EndAction CreateAllSnapshotsFromVm 2012-06-22 14:28:01,669 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (pool-3-thread-49) [29998947] Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand 2012-06-22 14:28:01,682 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (pool-3-thread-49) [29998947] START, SnapshotVDSCommand(vdsId = 231837e4-bc59-11e1-a700-93acb8917d03, vmId=0aa651e8-1260-4cd6-8e56-b27e3dc2ed0c), log id: edd5e8 2012-06-22 14:28:01,745 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [29998947] Failed in SnapshotVDS method 2012-06-22 14:28:01,746 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [29998947] Error code SNAPSHOT_FAILED and error message VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed 2012-06-22 14:28:01,748 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-3-thread-49) [29998947] Command org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand return value mMessage Snapshot failed 2012-06-22 14:28:01,749 ERROR [org.ovirt.engine.core.vdsbroker.VDSCommandBase] (pool-3-thread-49) [29998947] Command SnapshotVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed 2012-06-22 14:28:01,750 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (pool-3-thread-49) [29998947] FINISH, SnapshotVDSCommand, log id: edd5e8 2012-06-22 14:28:01,750 ERROR [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (pool-3-thread-49) [29998947] Wasnt able to live snpashot due to error: VdcBLLException: VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, rolling back. 2012-06-22 14:28:01,753 ERROR [org.ovirt.engine.core.bll.CreateSnapshotCommand] (pool-3-thread-49) [8c07d4d] Ending command with failure: org.ovirt.engine.core.bll.CreateSnapshotCommand 2012-06-22 14:28:02,228 INFO [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-49) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type CreateAllSnapshotsFromVm completed, handling the result. 2012-06-22 14:28:02,229 INFO [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-49) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type CreateAllSnapshotsFromVm hasn't succeeded, clearing tasks.

2 1

[Users] Sanlock issue when trying to start vm
by Dennis Jacobfeuerborn 22 Jun '12

22 Jun '12

Hi, after getting the 3.1 beta engine and a host set up I now get an error when trying to start a vm. Engine reports this: VM myvm is down. Exit message: internal error Failed to open socket to sanlock daemon: No such file or directory. On the node no sanlock daemon is running. When I try to start the service I get this: Jun 19 20:22:31 node systemd-sanlock[13607]: Starting sanlock: [ OK ] Jun 19 20:22:31 node sanlock[13621]: 2012-06-19 20:22:31+0200 910 [13621]: sanlock daemon started 2.3 aio 1 10 renew 20 80 host 93bea910-1d9d-4203-8333-beb3d7b92c10.node.local time 1340130151 Jun 19 20:22:31 node sanlock[13621]: 2012-06-19 20:22:31+0200 910 [13621]: set scheduler RR|RESET_ON_FORK priority 99 failed: Operation not permitted Jun 19 20:22:31 node sanlock[13621]: 2012-06-19 20:22:31+0200 910 [13621]: wdmd connect failed for watchdog handling Jun 19 20:22:31 node systemd[1]: sanlock.service: main process exited, code=exited, status=255 Jun 19 20:22:31 node systemd[1]: Unit sanlock.service entered failed state. I followed the SELinux and sanlock threads but I disabled SELinux on the node so that cannot be a reason for this to fail. Regards, Dennis

5 7