Bug 1520546
| Summary: | LSM with continuous I/O to the VM failed and auto generated snapshot remains | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [oVirt] ovirt-engine | Reporter: | Raz Tamir <ratamir> | ||||
| Component: | BLL.Storage | Assignee: | Benny Zlotnik <bzlotnik> | ||||
| Status: | CLOSED DUPLICATE | QA Contact: | Elad <ebenahar> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 4.2.0 | CC: | bill.james, bugs, bzlotnik, ebenahar, frolland, ratamir, tnisan | ||||
| Target Milestone: | ovirt-4.3.4 | Keywords: | Automation | ||||
| Target Release: | --- | Flags: | rule-engine:
ovirt-4.3+
aoconnor: blocker- |
||||
| 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: | 2019-04-07 10:50:52 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: | |||||||
| Bug Depends On: | 1312909 | ||||||
| Bug Blocks: | |||||||
| Attachments: |
|
||||||
I sincerely doubt this is a regression. Raz, can you execute the same plan on an older build/version and attach logs from a successful run? Benny, other than (finally) implementing bug 1312909, is there anything we can do here? (In reply to Allon Mureinik from comment #1) > I sincerely doubt this is a regression. Raz, can you execute the same plan > on an older build/version and attach logs from a successful run? You are right Allon, It didn't pass on 4.1 too: engine.log: 2017-12-05 18:00:19,115+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] START, VmReplicateDiskFinishVDSCommand(HostName = host_mixed_3, VmReplicateDiskParameters:{runAsync='true', hostId='aed9971c-963e-4fd7-a652-a7839563d538', vmId='f724cc17-93ea-423c-86c6-5732253c25b4', storagePoolId='0ef229cd-a746-4a25-be21-39ffb68e1c5e', srcStorageDomainId='7d12be36-3538-4e59-94da-a1a6 edef01fb', targetStorageDomainId='13ecab19-539f-444b-a7a4-cd9b149791cb', imageGroupId='d7fb672f-0729-4d5c-b343-02c6417644d5', imageId='f645fb3b-f200-408f-922d-a18408f37cff'}), log id: 15a5685d 2017-12-05 18:00:19,314+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed in 'VmReplicateDiskFinishVDS' method 2017-12-05 18:00:19,327+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, C all Stack: null, Custom ID: null, Custom Event ID: -1, Message: VDSM host_mixed_3 command VmReplicateDiskFinishVDS failed: Resource unavailable 2017-12-05 18:00:19,327+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDi skFinishVDSCommand' return value 'StatusOnlyReturn [status=Status [code=40, message=Resource unavailable]]' 2017-12-05 18:00:19,327+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] HostName = host_mixed_3 2017-12-05 18:00:19,328+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'VmReplicateDiskFinishVDSCommand(HostName = host_mixed_3 , VmReplicateDiskParameters:{runAsync='true', hostId='aed9971c-963e-4fd7-a652-a7839563d538', vmId='f724cc17-93ea-423c-86c6-5732253c25b4', storagePoolId='0ef229cd-a746-4a25-be21-39ffb68e1c5e', srcStorageDomainId='7d12be36-3538-4e59-94da-a1 a6edef01fb', targetStorageDomainId='13ecab19-539f-444b-a7a4-cd9b149791cb', imageGroupId='d7fb672f-0729-4d5c-b343-02c6417644d5', imageId='f645fb3b-f200-408f-922d-a18408f37cff'})' execution failed: VDSGenericException: VDSErrorException: Fa iled to VmReplicateDiskFinishVDS, error = Resource unavailable, code = 40 2017-12-05 18:00:19,328+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] FINISH, VmReplicateDiskFinishVDSCommand, log id: 15a5685d 2017-12-05 18:00:19,347+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed VmReplicateDiskFinish (Disk 'd7fb672f-0729-4d5c-b343-02c6417644d5', VM 'f724cc17-93ea-423c-86c6-5732253c25b4') 2017-12-05 18:00:19,347+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'LiveMigrateDisk' id: '31e43ac6-a78a-4aee-81b5-3e483f2f506a' failed when attempting to perform the next operation, marking as FAILED '[fe6b9765-d444-4a7f-9480-7f14af5055ce, b2ee940d-032b-408f-a074-965db38a5f82]' 2017-12-05 18:00:19,347+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler4) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'LiveMigrateDisk' id: '31e43ac6-a78a-4aee-81b5-3e483f2f506a' child commands '[fe6b9765-d444-4a7f-9480-7f14af5055ce, b2ee940d-032b-408f-a074-965db38a5f82]' executions were completed, status 'FAILED' 2017-12-05 18:00:20,405+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Ending command 'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand' with failure. 2017-12-05 18:00:20,406+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed during live storage migration of disk 'd7fb672f-0729-4d5c-b343-02c6417 644d5' of vm 'f724cc17-93ea-423c-86c6-5732253c25b4', attempting to end replication before deleting the target disk 2017-12-05 18:00:20,406+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] START, VmReplicateDiskFinishVDSCommand(HostName = host_mixed_3, VmReplicateDiskParameters:{runAsync='true', hostId='aed9971c-963e-4fd7-a652-a7839563d538', vmId='f724cc17-93ea-423c-86c6-5732253c25b4', storagePoolId='0ef229cd-a746-4a25-be21-39ffb68e1c5e', srcStorageDomainId='7d12be36-3538-4e59-94da-a1a6 edef01fb', targetStorageDomainId='7d12be36-3538-4e59-94da-a1a6edef01fb', imageGroupId='d7fb672f-0729-4d5c-b343-02c6417644d5', imageId='f645fb3b-f200-408f-922d-a18408f37cff'}), log id: 4accae0f 2017-12-05 18:00:20,441+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed in 'VmReplicateDiskFinishVDS' method 2017-12-05 18:00:20,451+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, C all Stack: null, Custom ID: null, Custom Event ID: -1, Message: VDSM host_mixed_3 command VmReplicateDiskFinishVDS failed: Resource unavailable 2017-12-05 18:00:20,451+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDi skFinishVDSCommand' return value 'StatusOnlyReturn [status=Status [code=40, message=Resource unavailable]]' 2017-12-05 18:00:20,451+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] HostName = host_mixed_3 2017-12-05 18:00:20,451+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'VmReplicateDiskFinishVDSCommand(HostName = host_mixed_3 , VmReplicateDiskParameters:{runAsync='true', hostId='aed9971c-963e-4fd7-a652-a7839563d538', vmId='f724cc17-93ea-423c-86c6-5732253c25b4', storagePoolId='0ef229cd-a746-4a25-be21-39ffb68e1c5e', srcStorageDomainId='7d12be36-3538-4e59-94da-a1 a6edef01fb', targetStorageDomainId='7d12be36-3538-4e59-94da-a1a6edef01fb', imageGroupId='d7fb672f-0729-4d5c-b343-02c6417644d5', imageId='f645fb3b-f200-408f-922d-a18408f37cff'})' execution failed: VDSGenericException: VDSErrorException: Fa iled to VmReplicateDiskFinishVDS, error = Resource unavailable, code = 40 2017-12-05 18:00:20,451+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] FINISH, VmReplicateDiskFinishVDSCommand, log id: 4accae0f 2017-12-05 18:00:20,451+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Replication end of disk 'd7fb672f-0729-4d5c-b343-02c6417644d5' in vm 'f724cc1 7-93ea-423c-86c6-5732253c25b4' back to the source failed, skipping deletion of the target disk 2017-12-05 18:00:20,486+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler1) [8fc83505-f42b-45d5-bc55-c09f8284c787] EVENT_ID: USER_MOVED_DISK_FINISHED_FAILURE(2,011), Correlation ID: 8f c83505-f42b-45d5-bc55-c09f8284c787, Job ID: 961cddac-8338-4b67-89de-76759f732f85, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: User admin@internal-authz have failed to move disk test_Disk1 to domain iscsi_1. .... *** Remove snapshot starts *** 2017-12-05 18:00:27,272+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed in 'MergeVDS' method 2017-12-05 18:00:27,286+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: VDSM host_mixed_3 command MergeVDS failed: Merge failed 2017-12-05 18:00:27,287+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand' return value 'StatusOnlyReturn [status=Status [code=52, message=Merge failed]]' 2017-12-05 18:00:27,287+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] HostName = host_mixed_3 2017-12-05 18:00:27,287+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'MergeVDSCommand(HostName = host_mixed_3, MergeVDSCommandParameters:{runAsync='true', hostId='aed9971c-963e-4fd7-a652-a7839563d538', vmId='f724cc17-93ea-423c-86c6-5732253c25b4', storagePoolId='0ef229cd-a746-4a25-be21-39ffb68e1c5e', storageDomainId='7d12be36-3538-4e59-94da-a1a6edef01fb', imageGroupId='d7fb672f-0729-4d5c-b343-02c6417644d5', imageId='f645fb3b-f200-408f-922d-a18408f37cff', baseImageId='ad0ce530-8947-4ed8-8e58-ea9c6867784c', topImageId='f645fb3b-f200-408f-922d-a18408f37cff', bandwidth='0'})' execution failed: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 2017-12-05 18:00:27,287+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] FINISH, MergeVDSCommand, log id: 50efb8be 2017-12-05 18:00:27,287+02 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-5-thread-1) [8fc83505-f42b-45d5-bc55-c09f8284c787] Engine exception thrown while sending merge command: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed with error mergeErr and code 52) at org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:118) [bll.jar:] at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2166) [bll.jar:] at org.ovirt.engine.core.bll.MergeCommand.executeCommand(MergeCommand.java:45) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1251) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1391) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2055) [bll.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202) [utils.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137) [utils.jar:] .... 2017-12-05 18:00:31,140+02 ERROR [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-5-thread-2) [8fc83505-f42b-45d5-bc55-c09f8284c787] Failed to live merge, still in volume chain: [f645fb3b-f200-408f-922d-a18408f37cff, ad0ce530-8947-4ed8-8e58-ea9c6867784c] 2017-12-05 18:00:32,116+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler6) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command id: '9f2ccf33-ee4e-41fb-a798-9bd05fd2a046 failed child command status for step 'MERGE_STATUS' 2017-12-05 18:00:32,116+02 INFO [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback] (DefaultQuartzScheduler6) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'RemoveSnapshotSingleDiskLive' id: '9f2ccf33-ee4e-41fb-a798-9bd05fd2a046' child commands '[aa4e1a2d-6192-47f5-95f5-3f9fa2dfa0ce, 7f7404c2-5a46-4786-9e3c-950b5eef9761, c5aff60f-a542-4f39-a291-4e15fe76cb7e]' executions were completed, status 'FAILED' 2017-12-05 18:00:33,145+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler10) [8fc83505-f42b-45d5-bc55-c09f8284c787] Merging of snapshot '55adcd23-acc3-4894-988b-874276e6ffc4' images 'ad0ce530-8947-4ed8-8e58-ea9c6867784c'..'f645fb3b-f200-408f-922d-a18408f37cff' failed. Images have been marked illegal and can no longer be previewed or reverted to. Please retry Live Merge on the snapshot to complete the operation. 2017-12-05 18:00:33,164+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler10) [8fc83505-f42b-45d5-bc55-c09f8284c787] Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand' with failure. 2017-12-05 18:00:34,183+02 INFO [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler8) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'RemoveSnapshot' id: '7a16dd33-1012-42b8-abc2-d75f1d6e27d6' child commands '[9f2ccf33-ee4e-41fb-a798-9bd05fd2a046]' executions were completed, status 'FAILED' 2017-12-05 18:00:35,390+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (DefaultQuartzScheduler10) [8fc83505-f42b-45d5-bc55-c09f8284c787] Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand' with failure. 2017-12-05 18:00:35,521+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler10) [8fc83505-f42b-45d5-bc55-c09f8284c787] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Correlation ID: 8fc83505-f42b-45d5-bc55-c09f8284c787, Job ID: 993bf6f0-5482-4c7b-8932-e8cfa977c338, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: Failed to delete snapshot 'Auto-generated for Live Storage Migration' for VM 'test'. 2017-12-05 18:00:35,695+02 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler4) [50016382] Setting new tasks map. The map contains now 2 tasks 2017-12-05 18:00:35,791+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler10) [8fc83505-f42b-45d5-bc55-c09f8284c787] Command 'LiveMigrateVmDisks' id: 'a7a24454-675c-4cdb-8d77-d9a056c565fc' child commands '[88da3d27-fed3-4348-bd7f-97fb4e0a1bd0, 31e43ac6-a78a-4aee-81b5-3e483f2f506a, 7a16dd33-1012-42b8-abc2-d75f1d6e27d6]' executions were completed, status 'FAILED' 2017-12-05 18:00:37,217+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateVmDisksCommand] (DefaultQuartzScheduler9) [8fc83505-f42b-45d5-bc55-c09f8284c787] Ending command 'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateVmDisksCommand' with failure. vdsm.log (Remove Auto-generated snapshot fails): 2017-12-05 18:00:27,044+0200 INFO (jsonrpc/6) [virt.vm] (vmId='f724cc17-93ea-423c-86c6-5732253c25b4') Starting merge with jobUUID='90e3302f-59ab-4303-928f-05e7ebbb8e7d', original chain=ad0ce530-8947-4ed8-8e58-ea9c6867784c < f645fb3b-f200-408f-922d-a18408f37cff (top), disk='sda', base='sda[1]', top=None, bandwidth=0, flags=12 (vm:4943) 2017-12-05 18:00:27,145+0200 ERROR (jsonrpc/6) [virt.vm] (vmId='f724cc17-93ea-423c-86c6-5732253c25b4') Live merge failed (job: 90e3302f-59ab-4303-928f-05e7ebbb8e7d) (vm:4949) Traceback (most recent call last): File "/usr/share/vdsm/virt/vm.py", line 4947, in merge bandwidth, flags) File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 69, in f ret = attr(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 123, in wrapper ret = f(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 1006, in wrapper return func(inst, *args, **kwargs) File "/usr/lib64/python2.7/site-packages/libvirt.py", line 678, in blockCommit if ret == -1: raise libvirtError ('virDomainBlockCommit() failed', dom=self) libvirtError: block copy still active: disk 'sda' already in active block job So this is not a regression - should I open a bug for 4.1 too? (In reply to Raz Tamir from comment #3) > So this is not a regression - should I open a bug for 4.1 too? I don't think we need to of them - there definitely is a bug, and it definitely needs to be fixed. Once we have a fix, we can assess whether it's feasible/worth the effort of fixing in 4.1 too. Do we have plans to fix it in 4.2.z? In case not, please remove the blocker+ flag *** This bug has been marked as a duplicate of bug 1312909 *** *** Bug 1679355 has been marked as a duplicate of this bug. *** |
Created attachment 1362764 [details] engine and vdsm logs Description of problem: LSM with continuous I/O (dd) to the VM with 2 disks failed. I executed dd if=/dev/vda of=/dev/sda bs=8MB and started LSM of the second disk without the OS. /dev/vda is with OS. From engine.log: 2017-12-04 18:37:48,841+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] START, VmReplicateDiskFinishVDSCommand(HostName = host_mixed_1, VmReplicateDiskParameters:{hostId='20a94a01-73e4-431f-a796-cb2238512967', vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889', storagePoolId='480d7e0f-4587-41d7-a045-a0fd8a41b6af', srcStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', targetStorageDomainId='d2ae3fa6-8591-4845-b14e-ab1469ae9d32', imageGroupId='7de54695-ff9c-4aa2-986d-2acd5c3ae878', imageId='41bf5efd-0be5-4e24-8e18-f82a20fdae7c'}), log id: 6e85987c 2017-12-04 18:37:48,883+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Failed in 'VmReplicateDiskFinishVDS' method 2017-12-04 18:37:48,892+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command VmReplicateDiskFinishVDS failed: Resource unavailable 2017-12-04 18:37:48,892+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand' return value 'StatusOnlyReturn [status=Status [code=40, message=Resource unavailable]]' 2017-12-04 18:37:48,892+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] HostName = host_mixed_1 2017-12-04 18:37:48,893+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Command 'VmReplicateDiskFinishVDSCommand(HostName = host_mixed_1, VmReplicateDiskParameters:{hostId='20a94a01-73e4-431f-a796-cb2238512967', vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889', storagePoolId='480d7e0f-4587-41d7-a045-a0fd8a41b6af', srcStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', targetStorageDomainId='d2ae3fa6-8591-4845-b14e-ab1469ae9d32', imageGroupId='7de54695-ff9c-4aa2-986d-2acd5c3ae878', imageId='41bf5efd-0be5-4e24-8e18-f82a20fdae7c'})' execution failed: VDSGenericException: VDSErrorException: Failed to VmReplicateDiskFinishVDS, error = Resource unavailable, code = 40 2017-12-04 18:37:48,893+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] FINISH, VmReplicateDiskFinishVDSCommand, log id: 6e85987c 2017-12-04 18:37:48,903+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Failed VmReplicateDiskFinish (Disk '7de54695-ff9c-4aa2-986d-2acd5c3ae878', VM '2c9d5cc9-110f-40f4-88dc-348ed6b56889') 2017-12-04 18:37:48,904+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Command 'LiveMigrateDisk' id: '5b8afa1e-e2a8-4be6-a097-300382a361f9' failed when attempting to perform the next operation, marking as FAILED '[de95db67-4d4f-466c-92d5-9f6575014fdf, a30d4c51-5853-4246-850d-3120306e49f8, ec2090a7-8ceb-478e-bb36-1ed97178e35a]' 2017-12-04 18:37:48,904+02 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-13) [4c924332] Command 'LiveMigrateDisk' id: '5b8afa1e-e2a8-4be6-a097-300382a361f9' child commands '[de95db67-4d4f-466c-92d5-9f6575014fdf, a30d4c51-5853-4246-850d-3120306e49f8, ec2090a7-8ceb-478e-bb36-1ed97178e35a]' executions were completed, status 'FAILED' 2017-12-04 18:37:49,960+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Ending command 'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand' with failure. 2017-12-04 18:37:49,960+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Failed during live storage migration of disk '7de54695-ff9c-4aa2-986d-2acd5c3ae878' of vm '2c9d5cc9-110f-40f4-88dc-348ed6b56889', attempting to end replication before deleting the target disk 2017-12-04 18:37:49,964+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] START, VmReplicateDiskFinishVDSCommand(HostName = host_mixed_1, VmReplicateDiskParameters:{hostId='20a94a01-73e4-431f-a796-cb2238512967', vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889', storagePoolId='480d7e0f-4587-41d7-a045-a0fd8a41b6af', srcStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', targetStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', imageGroupId='7de54695-ff9c-4aa2-986d-2acd5c3ae878', imageId='41bf5efd-0be5-4e24-8e18-f82a20fdae7c'}), log id: 2d30d3a6 2017-12-04 18:37:50,055+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Failed in 'VmReplicateDiskFinishVDS' method 2017-12-04 18:37:50,064+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command VmReplicateDiskFinishVDS failed: Resource unavailable 2017-12-04 18:37:50,065+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand' return value 'StatusOnlyReturn [status=Status [code=40, message=Resource unavailable]]' 2017-12-04 18:37:50,065+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] HostName = host_mixed_1 2017-12-04 18:37:50,065+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Command 'VmReplicateDiskFinishVDSCommand(HostName = host_mixed_1, VmReplicateDiskParameters:{hostId='20a94a01-73e4-431f-a796-cb2238512967', vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889', storagePoolId='480d7e0f-4587-41d7-a045-a0fd8a41b6af', srcStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', targetStorageDomainId='f48d3452-24f6-4701-aafe-be1faa4d4ca4', imageGroupId='7de54695-ff9c-4aa2-986d-2acd5c3ae878', imageId='41bf5efd-0be5-4e24-8e18-f82a20fdae7c'})' execution failed: VDSGenericException: VDSErrorException: Failed to VmReplicateDiskFinishVDS, error = Resource unavailable, code = 40 2017-12-04 18:37:50,065+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] FINISH, VmReplicateDiskFinishVDSCommand, log id: 2d30d3a6 2017-12-04 18:37:50,065+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Replication end of disk '7de54695-ff9c-4aa2-986d-2acd5c3ae878' in vm '2c9d5cc9-110f-40f4-88dc-348ed6b56889' back to the source failed, skipping deletion of the target disk 2017-12-04 18:37:50,075+02 WARN [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Trying to release exclusive lock which does not exist, lock key: '2c9d5cc9-110f-40f4-88dc-348ed6b56889LIVE_STORAGE_MIGRATION' 2017-12-04 18:37:50,075+02 INFO [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] Lock freed to object 'EngineLock:{exclusiveLocks='[2c9d5cc9-110f-40f4-88dc-348ed6b56889=LIVE_STORAGE_MIGRATION]', sharedLocks=''}' 2017-12-04 18:37:50,150+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [4c924332] EVENT_ID: USER_MOVED_DISK_FINISHED_FAILURE(2,011), User admin@internal-authz have failed to move disk test_Disk1 to domain iscsi_1. vdsm.log: 2017-12-04 18:37:48,848+0200 INFO (jsonrpc/1) [api.virt] START diskReplicateFinish(srcDisk={'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'f48d3452-24f 6-4701-aafe-be1faa4d4ca4', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}, dstDisk={'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'd2ae3fa6-8591-484 5-b14e-ab1469ae9d32', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}) from=::ffff:10.35.161.127,59390, flow_id=4c924332 (api:46) 2017-12-04 18:37:48,869+0200 ERROR (jsonrpc/1) [virt.vm] (vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889') Replication job unfinished (drive: 'sda', srcDisk: {'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41 bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'f48d3452-24f6-4701-aafe-be1faa4d4ca4', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}, job: {'end': 2438529024L, 'bandwidth': 0L, 'type': 2, 'cur': 620560384L}) (vm:4421) 2017-12-04 18:37:48,878+0200 INFO (jsonrpc/1) [api.virt] FINISH diskReplicateFinish return={'status': {'message': 'Resource unavailable', 'code': 40}} from=::ffff:10.35.161.127,59390, flow_id=4c924332 (api:52) 2017-12-04 18:37:48,879+0200 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call VM.diskReplicateFinish failed (error 40) in 0.03 seconds (__init__:573) 2017-12-04 18:37:50,027+0200 INFO (jsonrpc/6) [api.virt] START diskReplicateFinish(srcDisk={'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'f48d3452-24f 6-4701-aafe-be1faa4d4ca4', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}, dstDisk={'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'f48d3452-24f6-470 1-aafe-be1faa4d4ca4', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}) from=::ffff:10.35.161.127,59390, flow_id=4c924332 (api:46) 2017-12-04 18:37:50,050+0200 ERROR (jsonrpc/6) [virt.vm] (vmId='2c9d5cc9-110f-40f4-88dc-348ed6b56889') Replication job unfinished (drive: 'sda', srcDisk: {'device': 'disk', 'poolID': '480d7e0f-4587-41d7-a045-a0fd8a41b6af', 'volumeID': '41 bf5efd-0be5-4e24-8e18-f82a20fdae7c', 'domainID': 'f48d3452-24f6-4701-aafe-be1faa4d4ca4', 'imageID': '7de54695-ff9c-4aa2-986d-2acd5c3ae878'}, job: {'end': 2474835968L, 'bandwidth': 0L, 'type': 2, 'cur': 648216576L}) (vm:4421) Version-Release number of selected component (if applicable): rhv-4.2.0-0.5.master.el7 vdsm-api-4.20.8-1.el7ev.noarch How reproducible: 100% Steps to Reproduce: 1. Create VM with OS disk + 1 more thin provision disk 2. Start the VM and execute #dd if=/dev/vda of=/dev/sda 2.1 /dev/vda disk with OS, /dev/sda 2nd thin disk 3. LSM the 2nd disk to different storage domain (I tested same type - iscsi) Actual results: LSM fails and the auto-generated snapshot remains Expected results: Additional info: