Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1431619

Summary: restarting vdsm during amend disk stuck in locked state forever
Product: [oVirt] ovirt-engine Reporter: Avihai <aefrat>
Component: BLL.StorageAssignee: Maor <mlipchuk>
Status: CLOSED DUPLICATE QA Contact: Raz Tamir <ratamir>
Severity: high Docs Contact:
Priority: unspecified    
Version: 4.1.1.4CC: bugs, tnisan
Target Milestone: ovirt-4.1.2Flags: rule-engine: ovirt-4.1+
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-04-05 08:47:59 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
engine & vdsm logs none

Description Avihai 2017-03-13 13:02:39 UTC 
Created attachment 1262437 [details]
engine & vdsm logs

Description of problem:
Testing vdsm restart during amend to disk we see disk is locked forever .

Version-Release number of selected component (if applicable):
ovirt-engine-setup-4.1.1.4-0.1.el7.noarch


How reproducible:
100%

Steps to Reproduce:
1. Create DC + cluster on v3
2. Create a VM with thin disk and create 5 snapshots
3. Upgrade cluster &DC to version 4
4. Amend the snapshot images to version 1.0 & kill vdsmd on SPM

Amend started :
2017-03-13 14:21:42,156+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-32) [disks_update_4b75ca3f-e89e-4ccd] EVENT_ID: USER_AMEND_IMAGE_START(1,328), Correlation ID: disks_update_4b75ca3f-e89e-4ccd, Job ID: 7b36632b-d67d-434b-b7e1-4e76521743e2, Call Stack: null, Custom Event ID: -1, Message: Started to amend vm_TestCase18337_REST_ISCS_1314183399_Disk1

Kill vdsm was done on 2017-03-13 14:21:46,211 - MainThread - art.ll_lib.hosts - INFO - kill VDSM pid: 21386 on host 10.35.80.63


Actual results:
Disk vm_TestCase18337_REST_ISCS_1314183399_Disk1  is locked forever.

Expected results:
Disk should not be locked after vdsm restart during amend 

Additional info:

In engine you see following errors :
2017-03-13 14:22:09,004+02 ERROR [org.ovirt.engine.core.bll.pm.FenceProxyLocator] (DefaultQuartzScheduler5) [47c317c5] Can not run fence action on host 'host_mixed_1', no suitable proxy host was found.
2017-03-13 14:22:09,309+02 ERROR [org.ovirt.engine.core.bll.StorageJobCallback] (DefaultQuartzScheduler10) [39025250] Command AmendVolume id: '59569ae6-a8a2-4990-a9b3-80538e5ff75b': failed to poll the command entity
2017-03-13 14:22:11,516+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler3) [53352434] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM command GetStoragePoolInfoVDS failed: Heartbeat exceeded
2017-03-13 14:22:11,517+02 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler3) [53352434] ERROR, org.ovirt.engine.core.vdsbroker.irsbroker.GetStoragePoolInfoVDSCommand, exception: VDSGenericException: VDSNetworkException: Heartbeat exceeded, log id: 3ec16644
2017-03-13 14:22:11,517+02 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler3) [53352434] Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: VDSGenericException: VDSNetworkException: Heartbeat exceeded
2017-03-13 14:22:23,955+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler3) [39025250] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM host_mixed_1 command HSMGetAllTasksStatusesVDS failed: Not SPM
2017-03-13 14:22:23,955+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler3) [39025250] Command 'HSMGetAllTasksStatusesVDSCommand(HostName = host_mixed_1, VdsIdVDSCommandParametersBase:{runAsync='true', hostId='552c7677-922b-4964-9446-12079565b3b3'})' execution failed: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM


VDSM errors seen :
2017-03-13 14:22:22,923+0200 ERROR (jsonrpc/2) [storage.TaskManager.Task] (Task='1c8b2687-0c88-4402-a6e3-206098990718') Unexpected error (task:870)
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 877, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/logUtils.py", line 52, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 2174, in getAllTasksStatuses
    allTasksStatus = self._pool.getAllTasksStatuses()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 77, in wrapper
    raise SecureError("Secured object is not in safe state")
SecureError: Secured object is not in safe state
Comment 1 Maor 2017-04-05 08:47:59 UTC 

*** This bug has been marked as a duplicate of bug 1432067 ***