Bug 834882

Summary: ovirt-engine-backend [Direct Lun]: RemoveVm with direct lun will cause vm to get stuck in image lock and will not remove the disk
Product: Red Hat Enterprise Virtualization Manager Reporter: Dafna Ron <dron>
Component: ovirt-engineAssignee: Tal Nisan <tnisan>
Status: CLOSED CURRENTRELEASE QA Contact: Dafna Ron <dron>
Severity: high Docs Contact:
Priority: urgent    
Version: 3.1.0CC: abaron, acathrow, amureini, dyasny, hateya, iheim, lpeer, Rhev-m-bugs, yeylon, ykaul
Target Milestone: ---   
Target Release: 3.1.0   
Hardware: x86_64   
OS: Linux   
Whiteboard: storage
Fixed In Version: si7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-12-04 20:00:13 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
logs none

Description Dafna Ron 2012-06-24 14:09:42 UTC
Created attachment 594007 [details]
logs

Description of problem:

I tried removing a vm with direct lun. 
the vm gets stuck in image lock and disk is not removed. 
I can see that the command finished in backend log and in vdsm. 

Version-Release number of selected component (if applicable):

si6

How reproducible:

100%

Steps to Reproduce:
1. create a vm with direct lun
2. try to remove the vm
3.
  
Actual results:

the vm gets stuck in image lock and the disk is not removed

Expected results:

we should remove disk and vm

Additional info:full logs

please note that the command is also sent to vdsm and I can see that the action finished in vdsm (although there is no disconnect and all vdsm does is to remove OVF. 


backend: 

2012-06-24 15:39:12,052 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-45) [668839f1] Running command: RemoveVmCommand internal: false. Entities affected :  ID: 0ffa8e45-f64d-45f4-9df1-6d165c48f8d8 Type: VM
2012-06-24 15:39:12,058 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-45) [668839f1] START, SetVmStatusVDSCommand(vmId = 0ffa8e45-f64d-45f4-9df1-6d165c48f8d8, status = ImageLocked), log id: 6a1d97fd
2012-06-24 15:39:12,062 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-45) [668839f1] FINISH, SetVmStatusVDSCommand, log id: 6a1d97fd
2012-06-24 15:39:12,232 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-45) [668839f1] Lock freed to object EngineLock [exclusiveLocks= key: 0ffa8e45-f64d-45f4-9df1-6d165c48f8d8 value: VM
, sharedLocks= ]
2012-06-24 15:39:12,236 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand] (pool-3-thread-45) [668839f1] START, RemoveVMVDSCommand(storagePoolId = e62063ce-2ab1-4140-a67b-f8a51c034688, ignoreFailoverLimit = false, compa
tabilityVersion = null, storageDomainId = 00000000-0000-0000-0000-000000000000, vmGuid = 0ffa8e45-f64d-45f4-9df1-6d165c48f8d8), log id: 1e26f60b
2012-06-24 15:39:12,260 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand] (pool-3-thread-45) [668839f1] FINISH, RemoveVMVDSCommand, log id: 1e26f60b
2012-06-24 15:39:12,264 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (pool-3-thread-45) [fe35ba4] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 0ffa8e45-f64d-45f4-9df1-6d165c48f8d8 Type:
 VM


vdsm:

Thread-162445::INFO::2012-06-24 15:37:58,342::logUtils::37::dispatcher::(wrapper) Run and protect: removeVM(spUUID='e62063ce-2ab1-4140-a67b-f8a51c034688', vmUUID='0ffa8e45-f64d-45f4-9df1-6d165c48f8d8', sdUUID=None, options=None)
Thread-162445::DEBUG::2012-06-24 15:37:58,343::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.e62063ce-2ab1-4140-a67b-f8a51c034688`ReqID=`530963bd-b1c8-44bb-b6e6-c4ccbf9a675c`::Request was made in '/usr/share/
vdsm/storage/resourceManager.py' line '485' at 'registerResource'
Thread-162445::DEBUG::2012-06-24 15:37:58,343::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.e62063ce-2ab1-4140-a67b-f8a51c034688' for lock type 'shared'
Thread-162445::DEBUG::2012-06-24 15:37:58,344::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.e62063ce-2ab1-4140-a67b-f8a51c034688' is free. Now locking as 'shared' (1 active user)
Thread-162445::DEBUG::2012-06-24 15:37:58,345::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.e62063ce-2ab1-4140-a67b-f8a51c034688`ReqID=`530963bd-b1c8-44bb-b6e6-c4ccbf9a675c`::Granted request
Thread-162445::DEBUG::2012-06-24 15:37:58,345::task::817::TaskManager.Task::(resourceAcquired) Task=`f34f9904-64d2-40e4-a129-73fdcb2a1449`::_resourcesAcquired: Storage.e62063ce-2ab1-4140-a67b-f8a51c034688 (shared)
Thread-162445::DEBUG::2012-06-24 15:37:58,346::task::978::TaskManager.Task::(_decref) Task=`f34f9904-64d2-40e4-a129-73fdcb2a1449`::ref 1 aborting False
Thread-162445::INFO::2012-06-24 15:37:58,346::sp::1228::Storage.StoragePool::(removeVM) spUUID=e62063ce-2ab1-4140-a67b-f8a51c034688 vmUUID=0ffa8e45-f64d-45f4-9df1-6d165c48f8d8 sdUUID=None
Thread-162445::INFO::2012-06-24 15:37:58,347::logUtils::39::dispatcher::(wrapper) Run and protect: removeVM, Return response: None
Thread-162445::DEBUG::2012-06-24 15:37:58,348::task::1172::TaskManager.Task::(prepare) Task=`f34f9904-64d2-40e4-a129-73fdcb2a1449`::finished: None

Comment 1 Tal Nisan 2012-06-25 11:36:57 UTC
Fixed in si7

Comment 2 Dafna Ron 2012-07-01 15:32:05 UTC
verified on si8