Bug 1787378 - MERGE_STATUS failed on VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52
Summary: MERGE_STATUS failed on VDSErrorException: Failed to MergeVDS, error = Merge f...
Keywords:
Status: CLOSED DUPLICATE of bug 1785939
Alias: None
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage
Version: 4.4.0
Hardware: x86_64
OS: Unspecified
unspecified
high
Target Milestone: ovirt-4.4.0
: ---
Assignee: Benny Zlotnik
QA Contact: Avihai
URL:
Whiteboard:
: 1788162 (view as bug list)
Depends On:
Blocks: 1690475
TreeView+ depends on / blocked
 
Reported: 2020-01-02 15:53 UTC by Shir Fishbain
Modified: 2020-03-17 12:05 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-01-13 15:48:05 UTC
oVirt Team: Storage
Embargoed:
pm-rhel: ovirt-4.4+


Attachments (Terms of Use)
Logs (2.22 MB, application/zip)
2020-01-02 15:59 UTC, Shir Fishbain
no flags Details

Description Shir Fishbain 2020-01-02 15:53:55 UTC
Description of problem:
After the steps below, when trying to delete the snapshot [step 7], it's failed on :
VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52 (Failed with error mergeErr and code 52)

Version-Release number of selected component (if applicable):
ovirt-engine-4.4.0-0.13.master.el7.noarch
vdsm-4.40.0-164.git38a19bb.el8ev.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Create a VM with 1 disk from Storage Domain.
2. Run the VM
3. Go to Storage->Disks and create a Direct LUN
4. Go to Compute->Virtual Machines->VM->Disks and hotplug the Direct LUN without changing any options.  (see below)
5. Hotplug another disk from the same Storage Domain as in [1].
6. Create a snapshot
7. Delete a snapshot 

Actual results:

Snapshot delete fails with these errors:

2020-01-02 17:24:27,532+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedExecutorService-commandCoordinator-Thread-1) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Failed in 'MergeVDS' method

2020-01-02 17:24:27,543+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedExecutorService-commandCoordinator-Thread-1) [b84f04f9-eef6-48b7-8b30-02059500a2f3] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_3 command MergeVDS failed: Merge failed

2020-01-02 17:24:27,545+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedExecutorService-commandCoordinator-Thread-1) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Command 'MergeVDSCommand(HostName = host_mixed_3, MergeVDSCommandParameters:{hostId='152a58c6-7669-4e35-8319-47a913f8fd1e', vmId='64786de1-eb34-4e0b-93b7-c42eb4ed48dd', storagePoolId='a7850294-595f-4921-9719-15aabbe0507e', storageDomainId='f7ddead6-316e-44e2-951c-0a43dcb70e0e', imageGroupId='7ee4334e-1f71-4c81-988f-4ea0225e31dc', imageId='845d44ec-7923-4a13-b706-af011f41a23e', baseImageId='0f7a611e-c80f-41c1-b09c-b08ed9600286', topImageId='845d44ec-7923-4a13-b706-af011f41a23e', bandwidth='0'})' execution failed: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Merge failed, code = 52

2020-01-02 17:24:27,546+02 ERROR [org.ovirt.engine.core.bll.MergeCommand] (EE-ManagedExecutorService-commandCoordinator-Thread-1) [b84f04f9-eef6-48b7-8b30-02059500a2f3] 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 deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.VdsHandler.handleVdsResult(VdsHandler.java:114)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2116)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.MergeCommand.executeCommand(MergeCommand.java:45)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1168)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1326)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2005)
	at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202)
	at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137)
	at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1386)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:420)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.executor.DefaultBackendActionExecutor.execute(DefaultBackendActionExecutor.java:13)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.Backend.runAction(Backend.java:451)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.Backend.runAction(Backend.java:697)
	at jdk.internal.reflect.GeneratedMethodAccessor556.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.as.ee.5.GA-redhat-00002//org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at org.jboss.as.weld.common.5.GA-redhat-00002//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:78)
	at org.jboss.as.weld.common.5.GA-redhat-00002//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:88)
	at org.jboss.as.weld.common.5.GA-redhat-00002//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
	at org.jboss.as.ee.5.GA-redhat-00002//org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13)
	at jdk.internal.reflect.GeneratedMethodAccessor75.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.as.ee.5.GA-redhat-00002//org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.5.GA-redhat-00002//org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ee.5.GA-redhat-00002//org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
	at org.jboss.as.ee.5.GA-redhat-00002//org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.5.GA-redhat-00002//org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
	at org.jboss.invocation.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.5.GA-redhat-00002//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:216)
	at org.jboss.as.ejb3.5.GA-redhat-00002//org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:418)
	at org.jboss.as.ejb3.5.GA-redhat-00002//org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:148)...

2020-01-02 17:24:28,231+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (EE-ManagedExecutorService-commandCoordinator-Thread-8) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand' return value 'StatusOnlyReturn [status=Status [code=52, message=Merge failed]]'

2020-01-02 17:24:30,978+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-37) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Command id: 'b2d28a95-ce35-4f7c-9637-e80e582f3fa6 failed child command status for step 'MERGE_STATUS'

2020-01-02 17:24:32,030+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-87) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Merging of snapshot '34d34d52-39c7-4d76-bbe2-95e8dff09ce6' images '0f7a611e-c80f-41c1-b09c-b08ed9600286'..'845d44ec-7923-4a13-b706-af011f41a23e' 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.

2020-01-02 17:24:32,036+02 ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-87) [b84f04f9-eef6-48b7-8b30-02059500a2f3] Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand' with failure.

2020-01-02 17:24:35,156+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-88) [b84f04f9-eef6-48b7-8b30-02059500a2f3] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Failed to delete snapshot 's1' for VM 'new_test_shir_2'.

Expected results:
Snapshot delete should succeed 

Additional info:
logs attached -  important comment: there is a difference between engine time and hosts time of 7 hours.

Comment 1 Shir Fishbain 2020-01-02 15:59:08 UTC
Created attachment 1649231 [details]
Logs

logs attached -  
Important comment: there is a difference between engine log time and hosts time of 7 hours.

Comment 2 Tal Nisan 2020-01-13 15:37:02 UTC
Scenario seems like a bit of overkill, my guess is that the minimal scenario to reproduce is more simple but Benny you might be able to get something from the logs

Comment 3 Tal Nisan 2020-01-13 15:38:17 UTC
*** Bug 1788162 has been marked as a duplicate of this bug. ***

Comment 4 Benny Zlotnik 2020-01-13 15:48:05 UTC
2020-01-02 10:02:43,477-0500 ERROR (jsonrpc/7) [virt.vm] (vmId='64786de1-eb34-4e0b-93b7-c42eb4ed48dd') Live merge failed (job: 7ed542ea-ba1e-4fe5-b1f6-07648bb6d815) (vm:5544)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/vdsm/virt/vm.py", line 5542, in merge
    bandwidth, flags)
  File "/usr/lib/python3.6/site-packages/vdsm/virt/virdomain.py", line 101, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/common/libvirtconnection.py", line 131, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/common/function.py", line 94, in wrapper
    return func(inst, *args, **kwargs)
  File "/usr/lib64/python3.6/site-packages/libvirt.py", line 728, in blockCommit
    if ret == -1: raise libvirtError ('virDomainBlockCommit() failed', dom=self)
libvirt.libvirtError: internal error: qemu block name 'json:{"backing": {"driver": "raw", "file": {"driver": "host_device", "filename": "/rhev/data-center/mnt/blockSD/f7ddead6-316e-44e2-951c-0a43dcb70e0e/images/9d317df9-b6af-4444-b68f-01fc0144159a/8b09a51d-0872-40e8-90ee-487dee2bfe8c"}}, "driver": "qcow2", "file": {"driver": "host_device", "filename": "/rhev/data-center/mnt/blockSD/f7ddead6-316e-44e2-951c-0a43dcb70e0e/images/9d317df9-b6af-4444-b68f-01fc0144159a/fe5eba60-691a-43ec-9551-bb0692d66af6"}}' doesn't match expected '/rhev/data-center/mnt/blockSD/f7ddead6-316e-44e2-951c-0a43dcb70e0e/images/9d317df9-b6af-4444-b68f-01fc0144159a/fe5eba60-691a-43ec-9551-bb0692d66af6'

A json provided where a string is expected, looks like qemu/libvirt mismatch, which looks like: bug 1785939. Closing as dupe

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


Note You need to log in before you can comment on or make changes to this bug.