[Users] Do not start the virtual machine (gluster storage and ovirt 3.1)
зоррыч
zorro at megatrone.ru
Mon Jun 25 11:39:46 UTC 2012
I'm sorry.
Disabled SElinux
And the error disappeared.
Thank you!
-----Original Message-----
From: users-bounces at ovirt.org [mailto:users-bounces at ovirt.org] On Behalf Of зоррыч
Sent: Monday, June 25, 2012 3:20 PM
To: 'Itamar Heim'
Cc: users at ovirt.org
Subject: Re: [Users] Do not start the virtual machine (gluster storage and ovirt 3.1)
In an attachment
-----Original Message-----
From: Itamar Heim [mailto:iheim at redhat.com]
Sent: Saturday, June 23, 2012 4:46 PM
To: зоррыч
Cc: users at ovirt.org
Subject: Re: [Users] Do not start the virtual machine (gluster storage and ovirt 3.1)
On 06/22/2012 05:02 PM, зоррыч wrote:
> 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-4225-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-4225-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-44f1-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-44f1-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-4503-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-4503-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-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8
> 66d5a-1319-4e32-b9f3-4de3ad3272fb',
> 'chain': [{'path':
> '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-
> 4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8
> 66d5a-1319-4e32-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-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8
> 66d5a-1319-4e32-b9f3-4de3ad3272fb',
> 'chain': [{'path':
> '/rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-
> 4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb8
> 66d5a-1319-4e32-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-4
> 549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb86
> 6d5a-1319-4e32-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-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7
> e/eb866d5a-1319-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-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=threads:
> 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-1319-4e32-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-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=threads:
> 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-1319-4e32-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-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=threads:
> 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-1319-4e32-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-4549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb866d5a-1319-4e32-b9f3-4de3ad3272fb,if=none,id=drive-virtio-disk0,format=raw,serial=61180d3c-63ba-41ca-989a-8bd2acff4d7e,cache=none,werror=stop,rerror=stop,aio=threads:
> 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-1319-4e32-b9f3-4de3ad3272fb:
> Permission denied
>
> [root at noc-3-synt mnt]# ls -lh
> /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4
> 549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb86
> 6d5a-1319-4e32-b9f3-4de3ad3272fb
>
> -rw-rw----. 1 vdsm kvm 10G Jun 22 09:28
> /rhev/data-center/b1c7875a-964d-4633-8ea4-2b191d68c105/68aa0dc2-9cd1-4
> 549-8008-30b1bae667db/images/61180d3c-63ba-41ca-989a-8bd2acff4d7e/eb86
> 6d5a-1319-4e32-b9f3-4de3ad3272fb
>
> [root at 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
>
> ….
>
>
>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
can you please attach the libvirt log?
More information about the Users
mailing list