1484070 – Hyper Convergence - Live Storage Migration fails

Bug 1484070 - Hyper Convergence - Live Storage Migration fails

Summary: Hyper Convergence - Live Storage Migration fails

Keywords:
Status:	CLOSED DUPLICATE of bug 1481688
Alias:	None
Product:	ovirt-engine
Classification:	oVirt
Component:	BLL.Storage
Sub Component:
Version:	4.1.5.2
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	high
Target Milestone:	ovirt-4.1.7
Target Release:	---
Assignee:	Denis Chaplygin
QA Contact:	Raz Tamir
Docs Contact:
URL:
Whiteboard:	Hyper Convergence
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2017-08-22 15:26 UTC by Kevin Alon Goldblatt
Modified:	2017-09-14 12:48 UTC (History)
CC List:	5 users (show)
Fixed In Version:
Clone Of:
Environment:
Last Closed:	2017-09-14 12:48:14 UTC
oVirt Team:	Gluster
Embargoed:
Dependent Products:
Flags:	rule-engine: ovirt-4.1+

Attachments	(Terms of Use)
vdsm, server, engine logs (937.77 KB, application/x-gzip) 2017-08-22 15:29 UTC, Kevin Alon Goldblatt	no flags	Details
View All

Description Kevin Alon Goldblatt 2017-08-22 15:26:15 UTC

Description of problem:
Live Migration fails on Dalton - Hyper Convergence

Version-Release number of selected component (if applicable):
ovirt-engine-4.1.5.2-0.1.el7.noarch
rhevm-4.1.5.2-0.1.el7.noarch
vdsm-4.19.26-1.el7ev.x86_64

How reproducible:
100%

Steps to Reproduce:
1.On Dalton Hyper Converged system start VM with Local gluster and regular nfs and block disks
2.Start Move operation >>>>> Fails with 
3.

Actual results:
Live Migration fails with NullPointerException

Expected results:
Should work

Additional info:
Engine Log:
-----------------
2017-08-22 17:30:14,293+03 INFO  [org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand] (default task-3) [626927d7-86d0-4798-985c-0083f289c8db] Running command: MoveDisksCommand internal: false. Entities affe
cted :  ID: e034e39c-9546-44f7-979d-5a7b1e796de5 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 6e27b527-e40b-445f-a1ff-ceb2859321ff Type: DiskAction group CONFIGURE_DISK_STORAGE with ro
le type USER,  ID: 00000000-0000-0000-0000-000000000000 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 5b1e3011-28a8-4e2a-9d6f-2cb71b4e2e58 Type: DiskAction group CONFIGURE_DISK_STORAGE 
with role type USER,  ID: c389f077-5ac8-4db5-9202-b0321ed1f798 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER
2017-08-22 17:30:14,304+03 ERROR [org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand] (default task-3) [626927d7-86d0-4798-985c-0083f289c8db] Command 'org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand
' failed: null
2017-08-22 17:30:14,304+03 ERROR [org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand] (default task-3) [626927d7-86d0-4798-985c-0083f289c8db] Exception: java.lang.NullPointerException
        at org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand.createVmDiskParamsMap(MoveDisksCommand.java:154) [bll.jar:]
        at org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand.updateParameters(MoveDisksCommand.java:119) [bll.jar:]
        at org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand.executeCommand(MoveDisksCommand.java:50) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1251) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1391) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:2055) [bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:137) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105) [utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1451) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:397) [bll.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendActionExecutor.execute(DefaultBackendActionExecutor.java:13) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:511) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:493) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:446) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor297.invoke(Unknown Source) [:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        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-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:80) [wildfly-weld-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93) [wildfly-weld-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        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.GeneratedMethodAccessor81.invoke(Unknown Source) [:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        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-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        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-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:263) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:374) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:243) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        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.jar:2.3.3.Final-redhat-1]
        at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83) [wildfly-weld-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66) [wildfly-ejb3-7.0.7.GA-redhat-3.jar:7.0.7.GA-redhat-3]
        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:632)
        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:198)
        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.common.interfaces.BackendLocal$$$view2.runAction(Unknown Source) [common.jar:]
        at org.ovirt.engine.ui.frontend.server.gwt.GenericApiGWTServiceImpl.runAction(GenericApiGWTServiceImpl.java:171)
        at sun.reflect.GeneratedMethodAccessor341.invoke(Unknown Source) [:1.8.0_131]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_131]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_131]
        at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:265)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:305)
        at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) [jboss-servlet-api_3.1_spec.jar:1.0.0.Final-redhat-1]
        at org.ovirt.engine.ui.frontend.server.gwt.GenericApiGWTServiceImpl.service(GenericApiGWTServiceImpl.java:77)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [jboss-servlet-api_3.1_spec.jar:1.0.0.Final-redhat-1]
        at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
        at org.ovirt.engine.core.utils.servlet.HeaderFilter.doFilter(HeaderFilter.java:94) [utils.jar:]
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.ovirt.engine.ui.frontend.server.gwt.GwtCachingFilter.doFilter(GwtCachingFilter.java:132)
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.ovirt.engine.core.branding.BrandingFilter.doFilter(BrandingFilter.java:73) [branding.jar:]
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at org.ovirt.engine.core.utils.servlet.LocaleFilter.doFilter(LocaleFilter.java:66) [utils.jar:]
        at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
        at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
        at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
        at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
        at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
        at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)
        at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:51)
        at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
        at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
        at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59)
        at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
        at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
        at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
        at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
        at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
  at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
        at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:285)
        at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:264)
        at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
        at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:175)
        at io.undertow.server.Connectors.executeRootHandler(Connectors.java:246)
        at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:802)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
        at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]

2017-08-22 17:30:14,341+03 ERROR [org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand] (default task-3) [626927d7-86d0-4798-985c-0083f289c8db] Transaction rolled-back for command 'org.ovirt.engine.core.bll.storage.disk.MoveDisksCommand'.
2017-08-22 17:31:54,145+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-15) [ff1a681f-d397-4b2f-90ab-57c5e35cb58a] EVENT_ID: REFRESH_REPOSITORY_IMAGE_LIST_SUCCEEDED(998), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Refresh image list succeeded for domain(s): ISO_DOMAIN (All file type)
2017-08-22 17:36:54,668+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-12) [25eb298c-77ce-4fb4-93d5-a98074680805] EVENT_ID: REFRESH_REPOSITORY_IMAGE_LIST_SUCCEEDED(998), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Refresh image list succeeded for domain(s): ISO_DOMAIN (All file type)
2017-08-22 17:41:55,639+03 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-6) [b158d9f4-73bc-420e-9679-e92457e7c65c] EVENT_ID: REFRESH_REPOSITORY_IMAGE_LIST_SUCCEEDED(998), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Refresh image list succeeded for domain(s): ISO_DOMAIN (All file type)
2017-08-22 17:43:23,244+03 INFO  [org.ovirt.engine.core.bll.EngineBackupAwarenessManager] (DefaultQuartzScheduler9) [6c44eaad] Backup check started.
2017-08-22 17:43:23,260+03 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler9) [6c44eaad] EVENT_ID: ENGINE_NO_FULL_BACKUP(9,022), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: There is no full backup available, please run engine-backup to prevent data loss in case of corruption.
2017-08-22 17:43:23,261+03 INFO  [org.ovirt.engine.core.bll.EngineBackupAwarenessManager] (DefaultQuartzScheduler9) [6c44eaad] Backup check completed.
2017-08-22 17:45:13,821+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (DefaultQuartzScheduler7) [714607cd] Attempting to update VMs/Templates Ovf.
2017-08-22 17:45:13,833+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Before acquiring and wait lock 'EngineLock:{exclusiveLocks='[3758631a-0de0-4c0f-a080-ed96a39790b4=OVF_UPDATE]', sharedLocks=''}'
2017-08-22 17:45:13,833+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Lock-wait acquired to object 'EngineLock:{exclusiveLocks='[3758631a-0de0-4c0f-a080-ed96a39790b4=OVF_UPDATE]', sharedLocks=''}'
2017-08-22 17:45:13,836+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected :  ID: 3758631a-0de0-4c0f-a080-ed96a39790b4 Type: StoragePool
2017-08-22 17:45:13,847+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Attempting to update VM OVFs in Data Center 'dc1'
2017-08-22 17:45:14,257+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Successfully updated VM OVFs in Data Center 'dc1'
2017-08-22 17:45:14,257+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Attempting to update template OVFs in Data Center 'dc1'
2017-08-22 17:45:14,260+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Successfully updated templates OVFs in Data Center 'dc1'
2017-08-22 17:45:14,260+03 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler7) [7fb2cbaa] Attempting to remove unneeded template/vm OVFs in Data Center 'dc1'

Comment 1 Kevin Alon Goldblatt 2017-08-22 15:29:32 UTC

Created attachment 1316681 [details]
vdsm, server, engine logs

Added logs

Comment 2 Yaniv Kaul 2017-08-23 08:12:57 UTC

1. Are you live migrating or live storage migrating? The description says the former but it looks like the latter?
2. Have you tested it without Gluster on the local Gluster?
3. Please refrain from using the term 'Dalton'.
4. What does it mean 'regular nfs and block disks' ?
5. Can I see the test plan (please send it via email) for this?

Comment 5 Allon Mureinik 2017-08-29 08:48:25 UTC

At the very least, this bug depends on bug 1481688. Chances are, however, it's just a duplicate of it.
Moving to Gluster to triage.

Comment 6 Sahina Bose 2017-08-30 06:19:33 UTC

(In reply to Allon Mureinik from comment #5)
> At the very least, this bug depends on bug 1481688. Chances are, however,
> it's just a duplicate of it.
> Moving to Gluster to triage.

From the engine logs, the NPE occurs even before the command is sent to vdsm:

DiskImage diskImage = diskImageDao.get(moveDiskParameters.getImageId());
Map<Boolean, List<VM>> allVmsForDisk = vmDao.getForDisk(diskImage.getId(), false); --> diskImage is null

Where was the disk image - source storage domain was gluster/nfs/iSCSI?

Comment 7 Kevin Alon Goldblatt 2017-08-31 08:35:55 UTC

(In reply to Sahina Bose from comment #6)
> (In reply to Allon Mureinik from comment #5)
> > At the very least, this bug depends on bug 1481688. Chances are, however,
> > it's just a duplicate of it.
> > Moving to Gluster to triage.
> 
> From the engine logs, the NPE occurs even before the command is sent to vdsm:
> 
> DiskImage diskImage = diskImageDao.get(moveDiskParameters.getImageId());
> Map<Boolean, List<VM>> allVmsForDisk = vmDao.getForDisk(diskImage.getId(),
> false); --> diskImage is null
> 
> Where was the disk image - source storage domain was gluster/nfs/iSCSI?

block to gluster
gluster to block
block to nfs
nfs to block
nfs to gluster

Comment 8 RamaKasturi 2017-08-31 09:25:44 UTC

Hi,

  I have tested LSM with both source and target domains to be glusterfs with libgfapi enabled and i see that it fails with following errors in engine and vdsm logs.

engine.log:
==================================

2017-08-31 01:50:00,390-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-28) [b9830c2e-c16a-485f-b91b-45058698f0aa] CommandAsyncTa
sk::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '3c1e7646-5a69-49cb-862f-2ee431fd2961'
2017-08-31 01:50:01,879-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand] (DefaultQuartzScheduler8) [7097b76a] FINISH, GlusterServersListVDSCom
mand, return: [10.70.36.78/23:CONNECTED, 10.70.36.76:CONNECTED, 10.70.36.77:CONNECTED], log id: 62ba0d5f
2017-08-31 01:50:01,891-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler8) [7097b76a] START, GlusterVolumesListVDSComm
and(HostName = yarrow.lab.eng.blr.redhat.com, GlusterVolumesListVDSParameters:{runAsync='true', hostId='11972b68-a720-4236-bde0-3c066ceff3b6'}), log id: 2ddaf087
2017-08-31 01:50:02,095-04 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler4) [b9830c2e-c16a-485f-b91b-45058698f0aa] Command 'L
iveMigrateVmDisks' (id: '7a857239-50a8-412a-922d-09228065bcda') waiting on child command id: '1b57116f-ba8f-40a9-b0d9-df4f4bfec93f' type:'LiveMigrateDisk' to complete
2017-08-31 01:50:03,116-04 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa]
 START, VmReplicateDiskStartVDSCommand(HostName = zod.lab.eng.blr.redhat.com, VmReplicateDiskParameters:{runAsync='true', hostId='6a90a343-10e4-4c5c-afc7-e5477594d2b6', vmId
='b6da275e-649b-470d-ac32-89738faa3be5', storagePoolId='59a5429a-0236-034c-00d4-000000000250', srcStorageDomainId='d58a1d51-da25-454e-9edd-9754e419d668', targetStorageDomain
Id='1e67ccf5-8331-4e69-a0f6-c5ed58381217', imageGroupId='908c0355-ceb8-41c8-a644-5a551040d914', imageId='209455eb-4b82-417e-97ea-d0bab2fce721'}), log id: 59c08196
2017-08-31 01:50:03,147-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler8) [7097b76a] FINISH, GlusterVolumesListVDSCom
mand, return: {9eae9600-7185-4fbb-a42c-bbe9c6eb86ea=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@9669622b, 0763bd54-ea1c-4707-8abb-3d80d62df20f=
org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7aaadd95, 0dccff81-2ffa-4876-b4c3-15930fab2c65=org.ovirt.engine.core.common.businessentities.gluste
r.GlusterVolumeEntity@844a93e1}, log id: 2ddaf087
2017-08-31 01:50:04,367-04 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Failed in 'VmReplicateDiskStartVDS' method
2017-08-31 01:50:04,377-04 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM zod.lab.eng.blr.redhat.com command VmReplicateDiskStartVDS failed: Drive replication error
2017-08-31 01:50:04,377-04 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand' return value 'StatusOnlyReturn [status=Status [code=55, message=Drive replication error]]'
2017-08-31 01:50:04,377-04 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] HostName = zod.lab.eng.blr.redhat.com
2017-08-31 01:50:04,377-04 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Command 'VmReplicateDiskStartVDSCommand(HostName = zod.lab.eng.blr.redhat.com, VmReplicateDiskParameters:{runAsync='true', hostId='6a90a343-10e4-4c5c-afc7-e5477594d2b6', vmId='b6da275e-649b-470d-ac32-89738faa3be5', storagePoolId='59a5429a-0236-034c-00d4-000000000250', srcStorageDomainId='d58a1d51-da25-454e-9edd-9754e419d668', targetStorageDomainId='1e67ccf5-8331-4e69-a0f6-c5ed58381217', imageGroupId='908c0355-ceb8-41c8-a644-5a551040d914', imageId='209455eb-4b82-417e-97ea-d0bab2fce721'})' execution failed: VDSGenericException: VDSErrorException: Failed to VmReplicateDiskStartVDS, error = Drive replication error, code = 55
2017-08-31 01:50:04,377-04 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] FINISH, VmReplicateDiskStartVDSCommand, log id: 59c08196
2017-08-31 01:50:04,377-04 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Failed VmReplicateDiskStart (Disk '908c0355-ceb8-41c8-a644-5a551040d914' , VM 'b6da275e-649b-470d-ac32-89738faa3be5')
2017-08-31 01:50:04,378-04 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Command 'LiveMigrateDisk' id: '1b57116f-ba8f-40a9-b0d9-df4f4bfec93f' failed when attempting to perform the next operation, marking as FAILED '[3c1e7646-5a69-49cb-862f-2ee431fd2961]'
2017-08-31 01:50:04,378-04 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler10) [b9830c2e-c16a-485f-b91b-45058698f0aa] Command 'LiveMigrateDisk' id: '1b57116f-ba8f-40a9-b0d9-df4f4bfec93f' child commands '[3c1e7646-5a69-49cb-862f-2ee431fd2961]' executions were completed, status 'FAILED'
2017-08-31 01:50:05,400-04 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler7) [b9830c2e-c16a-485f-b91b-45058698f0aa] Ending command 'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand' with failure.
2017-08-31 01:50:05,400-04 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (DefaultQuartzScheduler7) [b9830c2e-c16a-485f-b91b-45058698f0aa] Failed durin

vdsm.log file:
==================================================
fce721', 'volumeChain': [{'domainID': u'1e67ccf5-8331-4e69-a0f6-c5ed58381217', 'leaseOffset': 0, 'path': u'data/1e67ccf5-8331-4e69-a0f6-c5ed58381217/images/908c0355-ceb8-41c
8-a644-5a551040d914/209455eb-4b82-417e-97ea-d0bab2fce721', 'volumeID': u'209455eb-4b82-417e-97ea-d0bab2fce721', 'leasePath': u'/rhev/data-center/mnt/glusterSD/10.70.36.78:_d
ata/1e67ccf5-8331-4e69-a0f6-c5ed58381217/images/908c0355-ceb8-41c8-a644-5a551040d914/209455eb-4b82-417e-97ea-d0bab2fce721.lease', 'imageID': u'908c0355-ceb8-41c8-a644-5a5510
40d914'}, {'domainID': u'1e67ccf5-8331-4e69-a0f6-c5ed58381217', 'leaseOffset': 0, 'path': u'data/1e67ccf5-8331-4e69-a0f6-c5ed58381217/images/908c0355-ceb8-41c8-a644-5a551040
d914/f2380cbb-1e16-452e-b597-2066c979cbc2', 'volumeID': u'f2380cbb-1e16-452e-b597-2066c979cbc2', 'leasePath': u'/rhev/data-center/mnt/glusterSD/10.70.36.78:_data/1e67ccf5-83
31-4e69-a0f6-c5ed58381217/images/908c0355-ceb8-41c8-a644-5a551040d914/f2380cbb-1e16-452e-b597-2066c979cbc2.lease', 'imageID': u'908c0355-ceb8-41c8-a644-5a551040d914'}]} (vm:
3739)
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/vm.py", line 3727, in diskReplicateStart
    if utils.isBlockDevice(replica['path']):
  File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 96, in isBlockDevice
    return stat.S_ISBLK(os.stat(path).st_mode)
OSError: [Errno 2] No such file or directory: '/data/1e67ccf5-8331-4e69-a0f6-c5ed58381217/images/908c0355-ceb8-41c8-a644-5a551040d914/209455eb-4b82-417e-97ea-d0bab2fce721'
2017-08-31 11:20:03,486+0530 INFO  (jsonrpc/2) [vdsm.api] FINISH diskReplicateStart return={'status': {'message': 'Drive replication error', 'code': 55}} from=::ffff:10.70.3
4.124,42020, flow_id=b9830c2e-c16a-485f-b91b-45058698f0aa (api:52)
2017-08-31 11:20:03,487+0530 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call VM.diskReplicateStart failed (error 55) in 0.37 seconds (__init__:539)
2017-08-31 11:20:03,710+0530 INFO  (Reactor thread) [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:53150 (protocoldetector:72)
2017-08-31 11:20:03,719+0530 INFO  (Reactor thread) [ProtocolDetector.Detector] Detected protocol stomp from ::1:53150 (protocoldetector:127)

Tested migrating disk from one storage domain to another using glusterfs with libgfapi enabled when the vm is offline and i see that it works fine.

Comment 9 RamaKasturi 2017-08-31 12:07:24 UTC

Engine and vdsm logs can be found in the link below:
============================================================

http://rhsqe-repo.lab.eng.blr.redhat.com/sosreports/HC/1484070/

Comment 10 Yaniv Kaul 2017-09-05 09:55:29 UTC

Dup of bug 1481688 ?

Comment 11 RamaKasturi 2017-09-06 05:58:51 UTC


(In reply to Yaniv Kaul from comment #10)
> Dup of bug 1481688 ?

Hi Yaniv,

    yes i think. This bug a is a dup of 1481688. I will update my comments in the other bug and i think this can be closed as duplicate.

Thanks
kasturi

Comment 12 Yaniv Kaul 2017-09-14 12:48:14 UTC


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

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