[ovirt-users] Snapshot deletion failure

Ala Hino ahino at redhat.com
Wed Sep 28 08:19:09 EDT 2016


Hi Marcelo,

This error indicates that the image you are trying to delete doesn't exist.
When do you get this error? When running Live Merge or Live Storage
Migration (LSM)?

Please note that we fixed in LSM area where the VM went down while we tried
to delete the auto-generated snapshot. See
https://bugzilla.redhat.com/1368203 .

-Ala

On Wed, Sep 28, 2016 at 3:07 PM, Marcelo Leandro <marceloltmm at gmail.com>
wrote:

> 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.ManagedReferenceMethodIntercep
> tor.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.ManagedReferenceLifecycleMetho
> dInterceptor.processInvocation(ManagedReferenceLifecycleMetho
> dInterceptor.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.AbstractEJBRequestScopeActivat
> ionInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
> [weld-core-impl-2.3.2.Final.jar:2.3.2.Final]
>         at org.jboss.as.weld.ejb.EjbRequestScopeActivationInter
> ceptor.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.PrivilegedWithCombinerIntercep
> tor.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/1485eb3f/attachment-0001.html>


More information about the Users mailing list