[ovirt-users] Snapshot deletion failure

Marcelo Leandro marceloltmm at gmail.com
Wed Sep 28 08:07:49 EDT 2016 

Hello, I have the same problem but i use the ovirt version
4.0.4.4-1.el7.centos .

My logs.


Engine.log

2016-09-28 08:18:00,947 INFO
[org.ovirt.engine.core.vdsbroker.monitoring.VmJobsMonitoring]
(DefaultQuartzScheduler1) [7013b545] VM Job
[4dd2b885-2452-4520-b20a-928edea50836]: In progress (no change)
2016-09-28 08:18:08,010 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (default
task-54) [5a27e364] Lock Acquired to object
'EngineLock:{exclusiveLocks='[eb73a967-1908-46e9-9de2-9706bf29643a=<VM,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-09-28 08:18:09,169 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (default
task-54) [5a27e364] Running command: RemoveSnapshotCommand internal: false.
Entities affected :  ID: eb73a967-1908-46e9-9de2-9706bf29643a Type:
VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
2016-09-28 08:18:09,185 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (default
task-54) [5a27e364] Lock freed to object
'EngineLock:{exclusiveLocks='[eb73a967-1908-46e9-9de2-9706bf29643a=<VM,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-09-28 08:18:09,265 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(pool-7-thread-3) [354939e9] Running command:
RemoveSnapshotSingleDiskLiveCommand internal: true. Entities affected :
ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2016-09-28 08:18:09,302 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(default task-54) [] Correlation ID: 5a27e364, Job ID:
661f8f55-30c6-4735-bb0a-fdcd3ac4004a, Call Stack: null, Custom Event ID:
-1, Message: Snapshot 'Backup the VM' deletion for VM 'SRV-ActPrint' was
initiated by admin at internal.
2016-09-28 08:18:10,197 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler4) [354939e9] Executing Live Merge command step
'EXTEND'
2016-09-28 08:18:10,254 INFO
[org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-7) [57c94fc3]
Running command: MergeExtendCommand internal: true. Entities affected :
ID: 6e5cce71-3438-4045-9d54-607123e0557e Type: Storage
2016-09-28 08:18:10,255 INFO
[org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-7) [57c94fc3]
Refreshing volume c08d86ed-46f1-44bc-9476-0cc2c6aed367 on host
f22d87b9-4449-4a71-8529-58095dd81b6f
2016-09-28 08:18:10,275 INFO
[org.ovirt.engine.core.bll.RefreshVolumeCommand] (pool-7-thread-7)
[47625ba4] Running command: RefreshVolumeCommand internal: true.
2016-09-28 08:18:10,275 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.RefreshVolumeVDSCommand]
(pool-7-thread-7) [47625ba4] START, RefreshVolumeVDSCommand(HostName =
Host04, RefreshVolumeVDSCommandParameters:{runAsync='true',
hostId='f22d87b9-4449-4a71-8529-58095dd81b6f',
storagePoolId='77e24b20-9d21-4952-a089-3c5c592b4e6d',
storageDomainId='6e5cce71-3438-4045-9d54-607123e0557e',
imageGroupId='9fc0b2f6-d786-4a21-8f5c-b22b23df4aaa',
imageId='c08d86ed-46f1-44bc-9476-0cc2c6aed367'}), log id: 77b9ded4
2016-09-28 08:18:11,245 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler8) [354939e9] Command 'RemoveSnapshot' (id:
'18613dc9-d8c8-45c4-9fbe-a298e701ead5') waiting on child command id:
'fd866748-3211-4d48-9908-12eb6078a69e' type:'RemoveSnapshotSingleDiskLive'
to complete
2016-09-28 08:18:11,810 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.RefreshVolumeVDSCommand]
(pool-7-thread-7) [47625ba4] FINISH, RefreshVolumeVDSCommand, log id:
77b9ded4
2016-09-28 08:18:11,810 INFO
[org.ovirt.engine.core.bll.RefreshVolumeCommand] (pool-7-thread-7)
[47625ba4] Successfully refreshed volume
'c08d86ed-46f1-44bc-9476-0cc2c6aed367' on host
'f22d87b9-4449-4a71-8529-58095dd81b6f'
2016-09-28 08:18:12,267 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler10) [354939e9] Waiting on Live Merge command step
'EXTEND' to finalize
2016-09-28 08:18:14,294 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler9) [354939e9] Executing Live Merge command step
'MERGE'
2016-09-28 08:18:14,347 INFO  [org.ovirt.engine.core.bll.MergeCommand]
(pool-7-thread-2) [15ef379f] Running command: MergeCommand internal: true.
Entities affected :  ID: 6e5cce71-3438-4045-9d54-607123e0557e Type: Storage
2016-09-28 08:18:14,348 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] START, MergeVDSCommand(HostName = Host04,
MergeVDSCommandParameters:{runAsync='true',
hostId='f22d87b9-4449-4a71-8529-58095dd81b6f',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a',
storagePoolId='77e24b20-9d21-4952-a089-3c5c592b4e6d',
storageDomainId='6e5cce71-3438-4045-9d54-607123e0557e',
imageGroupId='9fc0b2f6-d786-4a21-8f5c-b22b23df4aaa',
imageId='95fefce5-7599-460f-b38c-377323659b52',
baseImageId='c08d86ed-46f1-44bc-9476-0cc2c6aed367',
topImageId='95fefce5-7599-460f-b38c-377323659b52', bandwidth='0'}), log id:
544f03ae
2016-09-28 08:18:15,335 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler8) [354939e9] Command 'RemoveSnapshot' (id:
'18613dc9-d8c8-45c4-9fbe-a298e701ead5') waiting on child command id:
'fd866748-3211-4d48-9908-12eb6078a69e' type:'RemoveSnapshotSingleDiskLive'
to complete
2016-09-28 08:18:15,625 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] Failed in 'MergeVDS' method
2016-09-28 08:18:15,628 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(pool-7-thread-2) [15ef379f] Correlation ID: null, Call Stack: null, Custom
Event ID: -1, Message: VDSM Host04 command failed: Merge failed
2016-09-28 08:18:15,628 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand' return value
'StatusOnlyReturnForXmlRpc [status=StatusForXmlRpc [code=52, message=Merge
failed]]'
2016-09-28 08:18:15,629 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] HostName = Host04
2016-09-28 08:18:15,629 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] Command 'MergeVDSCommand(HostName = Host04,
MergeVDSCommandParameters:{runAsync='true',
hostId='f22d87b9-4449-4a71-8529-58095dd81b6f',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a',
storagePoolId='77e24b20-9d21-4952-a089-3c5c592b4e6d',
storageDomainId='6e5cce71-3438-4045-9d54-607123e0557e',
imageGroupId='9fc0b2f6-d786-4a21-8f5c-b22b23df4aaa',
imageId='95fefce5-7599-460f-b38c-377323659b52',
baseImageId='c08d86ed-46f1-44bc-9476-0cc2c6aed367',
topImageId='95fefce5-7599-460f-b38c-377323659b52', bandwidth='0'})'
execution failed: VDSGenericException: VDSErrorException: Failed to
MergeVDS, error = Merge failed, code = 52
2016-09-28 08:18:15,629 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(pool-7-thread-2) [15ef379f] FINISH, MergeVDSCommand, log id: 544f03ae
2016-09-28 08:18:15,629 ERROR [org.ovirt.engine.core.bll.MergeCommand]
(pool-7-thread-2) [15ef379f] 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:114)
[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:2171)
[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:1305)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1447)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2075)
[bll.jar:]
        at
org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:204)
[utils.jar:]
        at
org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:139)
[utils.jar:]
        at
org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:107)
[utils.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1490)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:398)
[bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:493)
[bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:729)
[bll.jar:]
        at sun.reflect.GeneratedMethodAccessor675.invoke(Unknown Source)
[:1.8.0_101]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.8.0_101]
        at java.lang.reflect.Method.invoke(Method.java:498)
[rt.jar:1.8.0_101]
        at
org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:70)
[wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:80)
[wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93)
[wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
        at
org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13)
[bll.jar:]
        at sun.reflect.GeneratedMethodAccessor140.invoke(Unknown Source)
[:1.8.0_101]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.8.0_101]
        at java.lang.reflect.Method.invoke(Method.java:498)
[rt.jar:1.8.0_101]
        at
org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
        at
org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
[weld-core-impl-2.3.2.Final.jar:2.3.2.Final]
        at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83)
[wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
[wildfly-ee-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:263)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:374)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:243)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
[wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
        at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
        at
org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
        at
org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
        at
org.ovirt.engine.core.bll.interfaces.BackendCommandObjectsHandler$$$view3.runAction(Unknown
Source) [bll.jar:]
        at
org.ovirt.engine.core.bll.tasks.CommandExecutor.executeCommand(CommandExecutor.java:57)
[bll.jar:]
        at
org.ovirt.engine.core.bll.tasks.CommandExecutor.lambda$executeAsyncCommand$0(CommandExecutor.java:46)
[bll.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[rt.jar:1.8.0_101]
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[rt.jar:1.8.0_101]
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[rt.jar:1.8.0_101]
        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101]
2016-09-28 08:18:16,038 INFO
[org.ovirt.engine.core.vdsbroker.monitoring.VmJobsMonitoring]
(DefaultQuartzScheduler10) [354939e9] VM Job
[4dd2b885-2452-4520-b20a-928edea50836]: In progress (no change)
2016-09-28 08:18:16,341 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler6) [354939e9] Waiting on Live Merge command step
'MERGE' to complete
2016-09-28 08:18:16,351 INFO
[org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler6)
[15ef379f] Merge command (jobId = null) has completed for images
'c08d86ed-46f1-44bc-9476-0cc2c6aed367'..'95fefce5-7599-460f-b38c-377323659b52'
2016-09-28 08:18:18,372 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler6) [354939e9] Executing Live Merge command step
'MERGE_STATUS'
2016-09-28 08:18:18,418 INFO
[org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-1) [42d41e81]
Running command: MergeStatusCommand internal: true. Entities affected :
ID: 6e5cce71-3438-4045-9d54-607123e0557e Type: Storage
2016-09-28 08:18:18,506 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand]
(pool-7-thread-1) [42d41e81] START, FullListVDSCommand(HostName = Host04,
FullListVDSCommandParameters:{runAsync='true',
hostId='f22d87b9-4449-4a71-8529-58095dd81b6f',
vds='Host[Host04,f22d87b9-4449-4a71-8529-58095dd81b6f]',
vmIds='[eb73a967-1908-46e9-9de2-9706bf29643a]'}), log id: 62d7ca75
2016-09-28 08:18:19,528 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand]
(pool-7-thread-1) [42d41e81] FINISH, FullListVDSCommand, return:
[{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0,
afterMigrationStatus=, vmId=eb73a967-1908-46e9-9de2-9706bf29643a,
memGuaranteedSize=1740, transparentHugePages=true, displaySecurePort=5907,
timeOffset=-7088, cpuType=Nehalem, smp=2,
guestNumaNodes=[Ljava.lang.Object;@1f96e8d8, hypervEnable=true,
custom={device_66bcfc2f-fca9-4890-8bf5-74095d059da9device_de626997-b95c-45be-81f2-b2de374b5f8adevice_0faaec88-ceff-467b-85fd-6f131cfae9fadevice_ad363387-214a-4435-ab86-486feeea6ad3=VmDevice:{id='VmDeviceId:{deviceId='ad363387-214a-4435-ab86-486feeea6ad3',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a'}', device='spicevmc',
type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0,
controller=0, type=virtio-serial, port=3}', managed='false',
plugged='true', readOnly='false', deviceAlias='channel2',
customProperties='[]', snapshotId='null', logicalName='null',
usingScsiReservation='false', hostDevice='null'},
device_66bcfc2f-fca9-4890-8bf5-74095d059da9=VmDevice:{id='VmDeviceId:{deviceId='66bcfc2f-fca9-4890-8bf5-74095d059da9',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a'}', device='ide',
type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01,
bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false',
plugged='true', readOnly='false', deviceAlias='ide', customProperties='[]',
snapshotId='null', logicalName='null', usingScsiReservation='false',
hostDevice='null'},
device_66bcfc2f-fca9-4890-8bf5-74095d059da9device_de626997-b95c-45be-81f2-b2de374b5f8a=VmDevice:{id='VmDeviceId:{deviceId='de626997-b95c-45be-81f2-b2de374b5f8a',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a'}', device='unix',
type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0,
controller=0, type=virtio-serial, port=1}', managed='false',
plugged='true', readOnly='false', deviceAlias='channel0',
customProperties='[]', snapshotId='null', logicalName='null',
usingScsiReservation='false', hostDevice='null'},
device_66bcfc2f-fca9-4890-8bf5-74095d059da9device_de626997-b95c-45be-81f2-b2de374b5f8adevice_0faaec88-ceff-467b-85fd-6f131cfae9fa=VmDevice:{id='VmDeviceId:{deviceId='0faaec88-ceff-467b-85fd-6f131cfae9fa',
vmId='eb73a967-1908-46e9-9de2-9706bf29643a'}', device='unix',
type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0,
controller=0, type=virtio-serial, port=2}', managed='false',
plugged='true', readOnly='false', deviceAlias='channel1',
customProperties='[]', snapshotId='null', logicalName='null',
usingScsiReservation='false', hostDevice='null'}}, vmType=kvm,
smpThreadsPerCore=1, memSize=1740, smpCoresPerSocket=2,
vmName=SRV-ActPrint, nice=0, status=Up, maxMemSize=4194304,
bootMenuEnable=false, guestDiskMapping={}, pid=14894,
displayIp=192.168.144.104, displayPort=-1, smartcardEnable=false,
maxMemSlots=16, nicModel=rtl8139,pv, kvmEnable=true,
displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@1c3c34e6,
maxVCpus=32, clientIp=, statusTime=7115868520, display=qxl}], log id:
62d7ca75
2016-09-28 08:18:19,538 ERROR
[org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-1) [42d41e81]
Failed to live merge, still in volume chain:
[c08d86ed-46f1-44bc-9476-0cc2c6aed367, 95fefce5-7599-460f-b38c-377323659b52]
2016-09-28 08:18:20,422 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler9) [354939e9] Failed child command status for step
'MERGE_STATUS'
2016-09-28 08:18:21,449 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(DefaultQuartzScheduler8) [354939e9] Merging of snapshot
'275c0570-32b6-4d50-9529-b2428f6a8a0b' images
'c08d86ed-46f1-44bc-9476-0cc2c6aed367'..'95fefce5-7599-460f-b38c-377323659b52'
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.
2016-09-28 08:18:21,459 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler8) [354939e9] Command 'RemoveSnapshot' id:
'18613dc9-d8c8-45c4-9fbe-a298e701ead5' child commands
'[fd866748-3211-4d48-9908-12eb6078a69e]' executions were completed, status
'FAILED'
2016-09-28 08:18:22,564 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
(DefaultQuartzScheduler10) [354939e9] Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand' with failure.
2016-09-28 08:18:22,634 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(DefaultQuartzScheduler10) [354939e9] Correlation ID: 5a27e364, Job ID:
661f8f55-30c6-4735-bb0a-fdcd3ac4004a, Call Stack: null, Custom Event ID:
-1, Message: Failed to delete snapshot 'Backup the VM' for VM
'SRV-ActPrint'.


 Vdsm.log
periodic/5740::DEBUG::2016-09-28
08:01:31,574::vm::4519::virt.vm::(queryBlockJobs)
vmId=`eb73a967-1908-46e9-9de2-9706bf29643a`::Still waiting for block job
4dd2b885-2452-4520-b20a-928edea50836 to be synchronized
....
jsonrpc.Executor/5::ERROR::2016-09-28
08:33:04,783::vm::4427::virt.vm::(trackBlockJob)
vmId=`eb73a967-1908-46e9-9de2-9706bf29643a`::Cannot add block job
50a359bd-097d-4c07-a7ae-5f4a9db23b81.  A block job with id
4dd2b885-2452-4520-b20a-928edea50836 already exists for image
9fc0b2f6-d786-4a21-8f5c-b22b23df4aaa
jsonrpc.Executor/5::ERROR::2016-09-28
08:33:04,784::vm::4600::virt.vm::(merge)
vmId=`eb73a967-1908-46e9-9de2-9706bf29643a`::A block job is already active
on this disk


Thanks.

Marcelo Leandro

2016-06-24 12:49 GMT-03:00 Nicolás <nicolas at devels.es>:

> Done, you can find it in [1]. Feel free to add/modify anything you
> consider inaccurate.
>
> Thank you.
>
>  [1]: https://bugzilla.redhat.com/show_bug.cgi?id=1349950
>
> El 24/06/16 a las 12:39, Nir Soffer escribió:
>
> On Fri, Jun 24, 2016 at 11:39 AM, Vinzenz Feenstra <vfeenstr at redhat.com>
>> wrote:
>>
>>> On Jun 24, 2016, at 9:10 AM, nicolas at devels.es wrote:
>>>>
>>>> Hi,
>>>>
>>>> We're trying to delete an auto-generated live snapshot that has been
>>>> created after migrating an online VM's storage to a different domain. oVirt
>>>> version is 3.6.6 and VDSM version is 4.17.28. Most relevant log lines are:
>>>>
>>>>     2016-06-24 07:50:36,252 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
>>>> (pool-7-thread-10) [799a22e3] Failed in 'MergeVDS' method
>>>>     2016-06-24 07:50:36,256 ERROR [org.ovirt.engine.core.dal.dbb
>>>> roker.auditloghandling.AuditLogDirector] (pool-7-thread-10) [799a22e3]
>>>> Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM
>>>> host2.domain.com command failed: Merge failed
>>>>     2016-06-24 07:50:36,256 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
>>>> (pool-7-thread-10) [799a22e3] Command 'MergeVDSCommand(HostName =
>>>> host2.domain.com, MergeVDSCommandParameters:{runAsync='true',
>>>> hostId='c31dca1a-e5bc-43f6-940f-6397e3ddbee4',
>>>> vmId='7083832a-a1a2-42b7-961f-2e9c0dcd7e18',
>>>> storagePoolId='fa155d43-4e68-486f-9f9d-ae3e3916cc4f',
>>>> storageDomainId='9339780c-3667-4fef-aa13-9bec08957c5f',
>>>> imageGroupId='65a0b0d4-5c96-4dd9-a31b-4d08e40a46a5',
>>>> imageId='9eec9e8f-38db-4abf-b1c4-92fa9383f8b1',
>>>> baseImageId='568b2f77-0ddf-4349-a45c-36fcb0edecb6',
>>>> topImageId='9eec9e8f-38db-4abf-b1c4-92fa9383f8b1', bandwidth='0'})'
>>>> execution failed: VDSGenericException: VDSErrorException: Failed to
>>>> MergeVDS, error = Merge failed, code = 52
>>>>     2016-06-24 07:50:36,256 ERROR [org.ovirt.engine.core.bll.MergeCommand]
>>>> (pool-7-thread-10) [799a22e3] 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)
>>>>
>>>> I'm attaching relevant logs (both for ovirt-engine and SPM's vdsm).
>>>>
>>>> What could be the reason for this error?
>>>>
>>> @Nir,
>>>
>>> that looks like some issue in VDSM please have a look
>>>
>>> jsonrpc.Executor/3::ERROR::2016-06-24 07:50:36,216::vm::4955::virt.vm::(merge)
>>> vmId=`7083832a-a1a2-42b7-961f-2e9c0dcd7e18`::Live merge failed (job:
>>> 3ea68e36-6d99-4af9-a54e-4c5b06df6a0f)
>>> Traceback (most recent call last):
>>>    File "/usr/share/vdsm/virt/vm.py", line 4951, in merge
>>>      flags)
>>>    File "/usr/share/vdsm/virt/virdomain.py", line 68, in f
>>>      ret = attr(*args, **kwargs)
>>>    File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py",
>>> line 124, in wrapper
>>>      ret = f(*args, **kwargs)
>>>    File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 1313, in
>>> wrapper
>>>      return func(inst, *args, **kwargs)
>>>    File "/usr/lib64/python2.7/site-packages/libvirt.py", line 668, in
>>> blockCommit
>>>      if ret == -1: raise libvirtError ('virDomainBlockCommit() failed',
>>> dom=self)
>>> libvirtError: block copy still active: disk 'vda' already in active
>>> block job
>>>
>> This means there was a previous attempt to merge, and the block job
>> did not complete yet.
>>
>> Engine should detect that there is an active block job and wait until
>> it completes.
>>
>> This is probably engine bug, please file a bug and attach complete vdsm
>> and
>> engine logs.
>>
>> Ala, can you look at this?
>>
>> Nir
>>
>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20160928/1ba8dda9/attachment-0001.html>

More information about the Users mailing list