[ovirt-users] Snapshot deletion failure
Marcelo Leandro
marceloltmm at gmail.com
Wed Sep 28 12:29:20 UTC 2016
Hi Ala,
When running Live Merge.
I create the live snapshot and when I try delete snapshot and has this
error.
I saw the bug https://bugzilla.redhat.com/1368203 , but I not move the disk
to another domain.
Thanks.
Marcelo Leandro
2016-09-28 9:19 GMT-03:00 Ala Hino <ahino at redhat.com>:
> 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.vdsbrok
>> er.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.sna
>> pshots.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.dbb
>> roker.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.sna
>> pshots.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.vdsbrok
>> er.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.Con
>> currentChildCommandsExecutionCallback] (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.vdsbrok
>> er.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.sna
>> pshots.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.sna
>> pshots.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.Con
>> currentChildCommandsExecutionCallback] (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.dbb
>> roker.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.runVdsComman
>> d(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.executeActionInTransac
>> tionScope(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.e
>> xecuteInNewTransaction(TransactionSupport.java:204) [utils.jar:]
>> at org.ovirt.engine.core.utils.transaction.TransactionSupport.e
>> xecuteInRequired(TransactionSupport.java:139) [utils.jar:]
>> at org.ovirt.engine.core.utils.transaction.TransactionSupport.e
>> xecuteInScope(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(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InterceptorContext$Invocation.proceed(
>> InterceptorContext.java:437)
>> at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInte
>> rception(Jsr299BindingsInterceptor.java:70)
>> [wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInte
>> rception(Jsr299BindingsInterceptor.java:80)
>> [wildfly-weld-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvoc
>> ation(Jsr299BindingsInterceptor.java:93) [wildfly-weld-10.0.0.Final.jar
>> :10.0.0.Final]
>> at org.jboss.as.ee.component.interceptors.UserInterceptorFactor
>> y$1.processInvocation(UserInterceptorFactory.java:63)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InterceptorContext$Invocation.proceed(
>> InterceptorContext.java:437)
>> at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerI
>> nterceptor.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.ManagedReferenceLifecycleMethodInt
>> erceptor.processInvocation(ManagedReferenceLifecycleMethodIn
>> terceptor.java:89)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeI
>> nterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
>> [wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InterceptorContext$Invocation.proceed(
>> InterceptorContext.java:437)
>> at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationIntercep
>> tor.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(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.proc
>> essInvocation(ConcurrentContextInterceptor.java:45)
>> [wildfly-ee-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InitialInterceptor.processInvocation(In
>> itialInterceptor.java:21)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.ChainedInterceptor.processInvocation(Ch
>> ainedInterceptor.java:61)
>> at org.jboss.as.ee.component.interceptors.ComponentDispatcherIn
>> terceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.component.singleton.SingletonComponentInst
>> anceAssociationInterceptor.processInvocation(SingletonCompon
>> entInstanceAssociationInterceptor.java:53) [wildfly-ejb3-10.0.0.Final.jar
>> :10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.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(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.component.interceptors.CurrentInvocationCo
>> ntextInterceptor.processInvocation(CurrentInvoc
>> ationContextInterceptor.java:41) [wildfly-ejb3-10.0.0.Final.jar
>> :10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterc
>> eptor.processInvocation(WaitTimeInterceptor.java:43)
>> [wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.security.SecurityContextInterceptor.proces
>> sInvocation(SecurityContextInterceptor.java:100)
>> [wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptor
>> Factory$1.processInvocation(ShutDownInterceptorFactory.java:64)
>> [wildfly-ejb3-10.0.0.Final.jar:10.0.0.Final]
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.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(InterceptorC
>> ontext.java:340)
>> at org.jboss.as.ee.component.NamespaceContextInterceptor.proces
>> sInvocation(NamespaceContextInterceptor.java:50)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.ContextClassLoaderInterceptor.processIn
>> vocation(ContextClassLoaderInterceptor.java:64)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InterceptorContext.run(InterceptorConte
>> xt.java:356)
>> at org.wildfly.security.manager.WildFlySecurityManager.doChecke
>> d(WildFlySecurityManager.java:636)
>> at org.jboss.invocation.AccessCheckingInterceptor.processInvoca
>> tion(AccessCheckingInterceptor.java:61)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.InterceptorContext.run(InterceptorConte
>> xt.java:356)
>> at org.jboss.invocation.PrivilegedWithCombinerInterceptor.
>> processInvocation(PrivilegedWithCombinerInterceptor.java:80)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.ChainedInterceptor.processInvocation(Ch
>> ainedInterceptor.java:61)
>> at org.jboss.as.ee.component.ViewService$View.invoke(ViewServic
>> e.java:195)
>> at org.jboss.as.ee.component.ViewDescription$1.processInvocatio
>> n(ViewDescription.java:185)
>> at org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>> ontext.java:340)
>> at org.jboss.invocation.ChainedInterceptor.processInvocation(Ch
>> ainedInterceptor.java:61)
>> at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(Prox
>> yInvocationHandler.java:73)
>> at org.ovirt.engine.core.bll.interfaces.BackendCommandObjectsHa
>> ndler$$$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$execu
>> teAsyncCommand$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.vdsbrok
>> er.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.sna
>> pshots.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-0cc2c
>> 6aed367'..'95fefce5-7599-460f-b38c-377323659b52'
>> 2016-09-28 08:18:18,372 INFO [org.ovirt.engine.core.bll.sna
>> pshots.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.vdsbrok
>> er.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.vdsbrok
>> er.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-4
>> 890-8bf5-74095d059da9device_de626997-b95c-45be-81f2-b2de374b
>> 5f8adevice_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-377323
>> 659b52]
>> 2016-09-28 08:18:20,422 ERROR [org.ovirt.engine.core.bll.sna
>> pshots.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler9)
>> [354939e9] Failed child command status for step 'MERGE_STATUS'
>> 2016-09-28 08:18:21,449 ERROR [org.ovirt.engine.core.bll.sna
>> pshots.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.Con
>> currentChildCommandsExecutionCallback] (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.dbb
>> roker.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/554df62e/attachment-0001.html>
More information about the Users
mailing list