Hi,

1)

What do you need exactly? Shutdown VM, edit disk, "extend size by" ---> error

2)

storage domain is up and running, but with lvm command, vg exists, lv does not exist

Powering up a machine, I also saw these lines in vdsm log:

Thread-22::DEBUG::2017-05-07 18:59:54,115::blockSD::596::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000411491 s, 10.0 MB/s\n'; <rc> = 0

Thread-300::DEBUG::2017-05-07 18:59:55,539::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

Thread-1101::DEBUG::2017-05-07 18:59:55,539::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

VM Channels Listener::INFO::2017-05-07 18:59:55,560::guestagent::180::vm.Vm::(_handleAPIVersion) vmId=`79cd29dc-bb6c-4f1f-ae38-54d6cac05489`::Guest API version changed from 3 to 1

VM Channels Listener::INFO::2017-05-07 18:59:55,865::guestagent::180::vm.Vm::(_handleAPIVersion) vmId=`d37b37e9-1dd7-4a90-8d8c-755743c714ad`::Guest API version changed from 2 to 1

VM Channels Listener::INFO::2017-05-07 18:59:57,414::guestagent::180::vm.Vm::(_handleAPIVersion) vmId=`8a034ac2-2646-4fe7-8fda-7c33affa8009`::Guest API version changed from 2 to 1

VM Channels Listener::INFO::2017-05-07 18:59:58,178::guestagent::180::vm.Vm::(_handleAPIVersion) vmId=`4d1dad66-4ada-445a-b5f6-c695220d6b19`::Guest API version changed from 3 to 1

Thread-272::DEBUG::2017-05-07 18:59:58,187::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

Thread-166::DEBUG::2017-05-07 18:59:58,539::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

Thread-18::DEBUG::2017-05-07 19:00:33,805::persistentDict::234::Storage.PersistentDict::(refresh) read lines (LvMetadataRW)=[]

Thread-18::DEBUG::2017-05-07 19:00:33,805::persistentDict::252::Storage.PersistentDict::(refresh) Empty metadata

Thread-18::DEBUG::2017-05-07 19:00:33,805::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with VGTagMetadataRW backend

Thread-18::DEBUG::2017-05-07 19:00:33,805::lvm::504::Storage.OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' got the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,806::lvm::506::Storage.OperationMutex::(_invalidatevgs) Operation 'lvm invalidate operation' released the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,806::lvm::514::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' got the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,806::lvm::526::Storage.OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' released the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,806::lvm::371::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,806::lvm::291::Storage.Misc.excCmd::(cmd) /usr/bin/sudo -n /sbin/lvm vgs --config ' devices { preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 obtain_device_list_from_udev=0 filter = [ '\''a|/dev/mapper/360060160a62134002818778f949de411|/dev/mapper/360060160a621340040652b7582f5e511|/dev/mapper/360060160a621340064b1034cbbfce511|/dev/mapper/360060160a6213400c4b39e80949de411|/dev/mapper/360060160a6213400cce46e40949de411|/dev/mapper/360060160a6213400e622de69949de411|/dev/mapper/360060160a6213400fa2d31acbbfce511|'\'', '\''r|.*|'\'' ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0 }  backup {  retain_min = 50  retain_days = 0 } ' --noheadings --units b --nosuffix --separator '|' --ignoreskippedcluster -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name 2c501858-bf8d-49a5-a42b-bca341b47827 (cwd None)

Thread-18::DEBUG::2017-05-07 19:00:33,962::lvm::291::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = '  WARNING: lvmetad is running but disabled. Restart lvmetad before enabling it!\n'; <rc> = 0

Thread-18::DEBUG::2017-05-07 19:00:33,962::lvm::416::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex

Thread-18::DEBUG::2017-05-07 19:00:33,963::persistentDict::234::Storage.PersistentDict::(refresh) read lines (VGTagMetadataRW)=['CLASS=Data', 'DESCRIPTION=BKP01', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'LOGBLKSIZE=512', 'PHYBLKSIZE=512', 'POOL_UUID=715d1ba2-eabe-48db-9aea-c28c30359808', u'PV0=pv:360060160a6213400c4b39e80949de411,uuid:Epqopf-zKvd-Um2q-lHO9-6jmE-7IyB-qvib1I,pestart:0,pecount:3997,mapoffset:0', u'PV1=pv:360060160a6213400cce46e40949de411,uuid:GD9AnB-2pin-Jbof-kxHI-Gsa2-308p-zeoZ3B,pestart:0,pecount:4477,mapoffset:3997', 'ROLE=Regular', 'SDUUID=2c501858-bf8d-49a5-a42b-bca341b47827', 'TYPE=FCP', 'VERSION=3', 'VGUUID=p9xQ2y-gOuF-nUQU-fKJP-skMF-9xaY-H7W2ym', '_SHA_CKSUM=237ce5cf1ccddf89565560f570afb6622c58c90e']

Thread-18::INFO::2017-05-07 19:00:33,963::sd::385::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 2c501858-bf8d-49a5-a42b-bca341b47827_imageNS already registered

Thread-18::INFO::2017-05-07 19:00:33,963::sd::393::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 2c501858-bf8d-49a5-a42b-bca341b47827_volumeNS already registered

Thread-18::INFO::2017-05-07 19:00:33,964::blockSD::448::Storage.StorageDomain::(_registerResourceNamespaces) Resource namespace 2c501858-bf8d-49a5-a42b-bca341b47827_lvmActivationNS already registered

Thread-18::DEBUG::2017-05-07 19:00:33,964::lvm::291::Storage.Misc.excCmd::(cmd) /usr/bin/sudo -n /sbin/lvm vgck --config ' devices { preferred_names = ["^/dev/mapper/"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 obtain_device_list_from_udev=0 filter = [ '\''a|/dev/mapper/360060160a6213400c4b39e80949de411|/dev/mapper/360060160a6213400cce46e40949de411|'\'', '\''r|.*|'\'' ] }  global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0 }  backup {  retain_min = 50  retain_days = 0 } ' 2c501858-bf8d-49a5-a42b-bca341b47827 (cwd None)

2017-05-07 14:36 GMT+02:00 Kevin Goldblatt <kgoldbla@redhat.com>:

Hi Stephano,

From the log I see that the image cannot be found. This would indicate that you have an issue on your host connected to the storage provider:

 

OneImageInfoReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=254, mMessage=Image path does not exist or cannot be accessed/created: (u'/rhev/data-center/mnt/blockSD/6a386652-629d-4045-835b-21d2f5c104aa/images/c5fb9190-d059-4d9b-af23-07618ff660ce',)]]

Please provide the following:

1. Provide the exact scenario you performed in the Update of the disk

2. Can you please check to see that the storage domain on which the disk resides is up and running,

3. If not then check whether the storage on the host is visible through the host

4. If all the above is working then please submit a bug through bugzilla and provide the engine, server and vdsm logs.

Regards,

Kevin

On Tue, May 2, 2017 at 11:10 PM, Stefano Bovina <bovy89@gmail.com> wrote:

Hi, while trying to update a VM disk, a failure was returned (forcing me to add a new disk)

Any advice on how to resolve this error?

Thanks

Installation info:

ovirt-release35-006-1.noarch

libgovirt-0.3.3-1.el7_2.1.x86_64

vdsm-4.16.30-0.el7.centos.x86_64

vdsm-xmlrpc-4.16.30-0.el7.centos.noarch

vdsm-yajsonrpc-4.16.30-0.el7.centos.noarch

vdsm-jsonrpc-4.16.30-0.el7.centos.noarch

vdsm-python-zombiereaper-4.16.30-0.el7.centos.noarch

vdsm-python-4.16.30-0.el7.centos.noarch

vdsm-cli-4.16.30-0.el7.centos.noarch

qemu-kvm-ev-2.3.0-29.1.el7.x86_64

qemu-kvm-common-ev-2.3.0-29.1.el7.x86_64

qemu-kvm-tools-ev-2.3.0-29.1.el7.x86_64

libvirt-client-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-storage-1.2.17-13.el7_2.3.x86_64

libvirt-python-1.2.17-2.el7.x86_64

libvirt-daemon-driver-nwfilter-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-nodedev-1.2.17-13.el7_2.3.x86_64

libvirt-lock-sanlock-1.2.17-13.el7_2.3.x86_64

libvirt-glib-0.1.9-1.el7.x86_64

libvirt-daemon-driver-network-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-lxc-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-interface-1.2.17-13.el7_2.3.x86_64

libvirt-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-config-network-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-secret-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-config-nwfilter-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-kvm-1.2.17-13.el7_2.3.x86_64

libvirt-daemon-driver-qemu-1.2.17-13.el7_2.3.x86_64

-------- engine.log

2017-05-02 09:48:26,505 INFO  [org.ovirt.engine.core.bll.UpdateVmDiskCommand] (ajp--127.0.0.1-8702-6) [c3d7125] Lock Acquired to object EngineLock [exclusiveLocks= key: 25c0bcc0-0d3d-4ddc-b103-24ed2ac5aa05 value: VM_DISK_BOOT

key: c5fb9190-d059-4d9b-af23-07618ff660ce value: DISK

, sharedLocks= key: 25c0bcc0-0d3d-4ddc-b103-24ed2ac5aa05 value: VM

]

2017-05-02 09:48:26,515 INFO  [org.ovirt.engine.core.bll.UpdateVmDiskCommand] (ajp--127.0.0.1-8702-6) [c3d7125] Running command: UpdateVmDiskCommand internal: false. Entities affected :  ID: c5fb9190-d059-4d9b-af23-07618ff660ce Type: DiskAction group EDIT_DISK_PROPERTIES with role type USER

2017-05-02 09:48:26,562 INFO  [org.ovirt.engine.core.bll.ExtendImageSizeCommand] (ajp--127.0.0.1-8702-6) [ae718d8] Running command: ExtendImageSizeCommand internal: true. Entities affected :  ID: c5fb9190-d059-4d9b-af23-07618ff660ce Type: DiskAction group EDIT_DISK_PROPERTIES with role type USER

2017-05-02 09:48:26,565 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ExtendImageSizeVDSCommand] (ajp--127.0.0.1-8702-6) [ae718d8] START, ExtendImageSizeVDSCommand( storagePoolId = 715d1ba2-eabe-48db-9aea-c28c30359808, ignoreFailoverLimit = false), log id: 52aac743

2017-05-02 09:48:26,604 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ExtendImageSizeVDSCommand] (ajp--127.0.0.1-8702-6) [ae718d8] FINISH, ExtendImageSizeVDSCommand, log id: 52aac743

2017-05-02 09:48:26,650 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (ajp--127.0.0.1-8702-6) [ae718d8] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command cb7958d9-6eae-44a9-891a-7fe088a79df8

2017-05-02 09:48:26,651 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-6) [ae718d8] CommandMultiAsyncTasks::AttachTask: Attaching task 769a4b18-182b-4048-bb34-a276a55ccbff to command cb7958d9-6eae-44a9-891a-7fe088a79df8.

2017-05-02 09:48:26,661 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (ajp--127.0.0.1-8702-6) [ae718d8] Adding task 769a4b18-182b-4048-bb34-a276a55ccbff (Parent Command UpdateVmDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..

2017-05-02 09:48:26,673 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [ae718d8] Correlation ID: c3d7125, Call Stack: null, Custom Event ID: -1, Message: VM sysinfo-73 sysinfo-73_Disk3 disk was updated by admin@internal.

2017-05-02 09:48:26,674 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (ajp--127.0.0.1-8702-6) [ae718d8] BaseAsyncTask::startPollingTask: Starting to poll task 769a4b18-182b-4048-bb34-a276a55ccbff.

2017-05-02 09:48:28,430 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-48) [36cd2f7] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now

2017-05-02 09:48:28,435 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-48) [36cd2f7] Failed in HSMGetAllTasksStatusesVDS method

2017-05-02 09:48:28,436 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-48) [36cd2f7] SPMAsyncTask::PollTask: Polling task 769a4b18-182b-4048-bb34-a276a55ccbff (Parent Command UpdateVmDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'cleanSuccess'.

2017-05-02 09:48:28,446 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-48) [36cd2f7] BaseAsyncTask::logEndTaskFailure: Task 769a4b18-182b-4048-bb34-a276a55ccbff (Parent Command UpdateVmDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended with failure:

-- Result: cleanSuccess

-- Message: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Could not acquire resource. Probably resource factory threw an exception.: (), code = 100,

-- Exception: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Could not acquire resource. Probably resource factory threw an exception.: (), code = 100

2017-05-02 09:48:28,448 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-48) [36cd2f7] CommandAsyncTask::endActionIfNecessary: Al

l tasks of command cb7958d9-6eae-44a9-891a-7fe088a79df8 has ended -> executing endAction

2017-05-02 09:48:28,449 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-48) [36cd2f7] CommandAsyncTask::endAction: Ending action

 for 1 tasks (command ID: cb7958d9-6eae-44a9-891a-7fe088a79df8): calling endAction .

2017-05-02 09:48:28,450 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) [36cd2f7] CommandAsyncTask::endCommandAction [within

 thread] context: Attempting to endAction UpdateVmDisk, executionIndex: 0

2017-05-02 09:48:28,501 ERROR [org.ovirt.engine.core.bll.UpdateVmDiskCommand] (org.ovirt.thread.pool-8-thread-6) [c3d7125] Ending command with failure: org.ovirt.engine

.core.bll.UpdateVmDiskCommand

2017-05-02 09:48:28,502 ERROR [org.ovirt.engine.core.bll.ExtendImageSizeCommand] (org.ovirt.thread.pool-8-thread-6) Ending command with failure: org.ovirt.engine.core.b

ll.ExtendImageSizeCommand

2017-05-02 09:48:28,504 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-6) START, GetImageInfoVDSCommand( stora

gePoolId = 715d1ba2-eabe-48db-9aea-c28c30359808, ignoreFailoverLimit = false, storageDomainId = 6a386652-629d-4045-835b-21d2f5c104aa, imageGroupId = c5fb9190-d059-4d9b-

af23-07618ff660ce, imageId = 562f5b50-1d1a-457c-8b5f-cd8020611550), log id: 674a2581

2017-05-02 09:48:28,511 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-6) IrsBroker::getImageInfo::Failed gett

ing image info imageId = 562f5b50-1d1a-457c-8b5f-cd8020611550 does not exist on domainName = VM01 , domainId = 6a386652-629d-4045-835b-21d2f5c104aa,  error code: ImagePathError, message: Image path does not exist or cannot be accessed/created: (u'/rhev/data-center/mnt/blockSD/6a386652-629d-4045-835b-21d2f5c104aa/images/c5fb9190-d059-4d9b-af23-07618ff660ce',)

2017-05-02 09:48:28,512 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-6) Command org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand return value 

 

OneImageInfoReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=254, mMessage=Image path does not exist or cannot be accessed/created: (u'/rhev/data-center/mnt/blockSD/6a386652-629d-4045-835b-21d2f5c104aa/images/c5fb9190-d059-4d9b-af23-07618ff660ce',)]]

2017-05-02 09:48:28,512 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-6) FINISH, GetImageInfoVDSCommand, log id: 674a2581

2017-05-02 09:48:28,533 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-6) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to extend size of the disk 'sysinfo-73_Disk3' to 20 GB, User: admin@internal.

2017-05-02 09:48:28,534 INFO  [org.ovirt.engine.core.bll.UpdateVmDiskCommand] (org.ovirt.thread.pool-8-thread-6) Lock freed to object EngineLock [exclusiveLocks= key: 25c0bcc0-0d3d-4ddc-b103-24ed2ac5aa05 value: VM_DISK_BOOT

key: c5fb9190-d059-4d9b-af23-07618ff660ce value: DISK

, sharedLocks= key: 25c0bcc0-0d3d-4ddc-b103-24ed2ac5aa05 value: VM

]

2017-05-02 09:48:28,541 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-6) Correlation ID: c3d7125, Call Stack: null, Custom Event ID: -1, Message: VM sysinfo-73 sysinfo-73_Disk3 disk was updated by admin@internal.

2017-05-02 09:48:28,541 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type UpdateVmDisk completed, handling the result.

2017-05-02 09:48:28,541 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type UpdateVmDisk succeeded, clearing tasks.

_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users