Re: [ovirt-users] Snapshot deletion failure

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@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(a)devels.es&gt;: > 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(a)redhat.com&gt; >> wrote: >> >>> On Jun 24, 2016, at 9:10 AM, nicolas(a)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(a)ovirt.org > http://lists.ovirt.org/mailman/listinfo/users >