Bug 1000824
| Summary: | Failed Migrate VM - NullPointerException | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Virtualization Manager | Reporter: | vvyazmin <vvyazmin> | ||||
| Component: | ovirt-engine | Assignee: | Arik <ahadas> | ||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Pavel Novotny <pnovotny> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | high | ||||||
| Version: | 3.3.0 | CC: | acathrow, iheim, lpeer, michal.skrivanek, pstehlik, Rhev-m-bugs, yeylon | ||||
| Target Milestone: | --- | Keywords: | Regression | ||||
| Target Release: | 3.3.0 | ||||||
| Hardware: | x86_64 | ||||||
| OS: | Linux | ||||||
| Whiteboard: | virt | ||||||
| Fixed In Version: | is19 | Doc Type: | Bug Fix | ||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | Type: | Bug | |||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Bug Depends On: | |||||||
| Bug Blocks: | 1026487 | ||||||
| Attachments: |
|
||||||
update: migration fails with the same error as in Bug 996146 im still looking at the NPE that follows We can make a fix that will, most probably, solve this one by adding null-check. but I think we should understand how is it possible to get the problematic null value. vvyazmin, can you please try to reproduce it again? I managed to reproduce it (in a hacked way though) - there was a race that the attached patch prevents (the trade-off is another access to the DB, but it is only to get the static part of the VM and only when the VM reach powerring up/up state which is not supposed to happen to frequently). Note though that the NPE is a side effect of the failed migration and not the other way around (the migration didn't fail because of it) so the classification of the bug (urgent priority and severity) is a too harsh. Verified in vdsm-4.13.0-0.3.beta1.el6ev.x86_64 (is19). qemu-kvm-rhev-0.12.1.2-2.408.el6.x86_64 sanlock-2.8-1.el6.x86_64 libvirt-0.10.2-29.el6.x86_64 VM migration completes successfully now, no errors in engine nor vdsm logs. Closing - RHEV 3.3 Released Closing - RHEV 3.3 Released Closing - RHEV 3.3 Released |
Created attachment 790122 [details] ## Logs rhevm, vdsm, libvirt, thread dump, superVdsm Failed Migrate VM - NullPointerException Version-Release number of selected component (if applicable): RHEVM 3.3 - IS11 environment: RHEVM: rhevm-3.3.0-0.16.master.el6ev.noarch PythonSDK: rhevm-sdk-python-3.3.0.11-1.el6ev.noarch VDSM: vdsm-4.12.0-72.git287bb7e.el6ev.x86_64 LIBVIRT: libvirt-0.10.2-18.el6_4.9.x86_64 QEMU & KVM: qemu-kvm-rhev-0.12.1.2-2.355.el6_4.5.x86_64 SANLOCK: sanlock-2.8-1.el6.x86_64 How reproducible: 100% Steps to Reproduce: Create iSCSI Data Center with 2 hosts Create VM Migrate VM Actual results: Failed Migrate VM - NullPointerException Expected results: Succeed Migrate VM Impact on user: Failed Migrate VM Workaround: none Additional info: /var/log/ovirt-engine/engine.log 2013-08-25 20:29:42,587 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-82) Rerun vm fca68c1d-bc4f-4a5e-9eb2-02b10f0fc2fa. Called fro m vds tigris01.scl.lab.tlv.redhat.com 2013-08-25 20:29:42,821 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) START, MigrateStatusVDSCommand(HostName = tigris01.scl.lab.t lv.redhat.com, HostId = 9576d8ca-4466-46e6-bebc-ccd922075ac6, vmId=fca68c1d-bc4f-4a5e-9eb2-02b10f0fc2fa), log id: 6658612a 2013-08-25 20:29:42,827 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) Failed in MigrateStatusVDS method 2013-08-25 20:29:42,827 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) Error code migrateErr and error message VDSGenericException: VDSErrorException: Failed to MigrateStatusVDS, error = Fatal error during migration 2013-08-25 20:29:42,827 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) Command org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateSta tusVDSCommand return value StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=12, mMessage=Fatal error during migration]] 2013-08-25 20:29:42,827 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) HostName = tigris01.scl.lab.tlv.redhat.com 2013-08-25 20:29:42,827 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) Command MigrateStatusVDS execution failed. Exception: VDSErr orException: VDSGenericException: VDSErrorException: Failed to MigrateStatusVDS, error = Fatal error during migration 2013-08-25 20:29:42,827 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-5-thread-36) FINISH, MigrateStatusVDSCommand, log id: 6658612a 2013-08-25 20:29:42,831 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-5-thread-36) Correlation ID: 55388c4f, Job ID: 12ef410d-97aa-4cc7-93f5 -6a7f05338906, Call Stack: null, Custom Event ID: -1, Message: Migration failed due to Error: Fatal error during migration. Trying to migrate to another Host (VM: vm-move-move, Source: tigris01.scl.lab.tlv.redhat.com, Destination: tigris02.scl.lab.tlv.redhat.com). 2013-08-25 20:29:42,921 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-82) ResourceManager::RerunFailedCommand: Error: EJBException: java.lang.NullPointerException, vds = 9576d8ca-4466-46e6-bebc-ccd922075ac6 : tigris01.scl.lab.tlv.redhat.com 2013-08-25 20:29:42,921 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-82) EJBException: java.lang.NullPointerException: javax.ejb.EJBException: java.lang.NullPointerException at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInNoTx(CMTTxInterceptor.java:191) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:237) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:374) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:218) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.ovirt.engine.core.common.businessentities.IVdsEventListener$$$view6.processOnVmPoweringUp(Unknown Source) at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.AfterRefreshTreatment(VdsUpdateRunTimeInfo.java:490) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsManager.OnTimer(VdsManager.java:259) [vdsbroker.jar:] at sun.reflect.GeneratedMethodAccessor12.invoke(Unknown Source) [:1.7.0_25] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_25] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_25] at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:] at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:] at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:] Caused by: java.lang.NullPointerException at org.ovirt.engine.core.bll.RunVmCommandBase.decreasePendingVms(RunVmCommandBase.java:280) [bll.jar:] at org.ovirt.engine.core.bll.RunVmCommandBase.onPowerringUp(RunVmCommandBase.java:334) [bll.jar:] at org.ovirt.engine.core.bll.VdsEventListener.processOnVmPoweringUp(VdsEventListener.java:220) [bll.jar:] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_25] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_25] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_25] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_25] at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final-redhat-2] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:235) [jboss-as-ejb3.jar:7.2.0.Final-redhat-8] ... 28 more 2013-08-25 20:29:42,982 WARN [org.ovirt.engine.core.bll.MigrateVmCommand] (pool-5-thread-36) CanDoAction of action MigrateVm failed. Reasons:VAR__ACTION__MIGRATE,VAR__TYPE__VM,VAR__ACTION__MIGRATE,VAR__TYPE__VM,VAR__ACTION__MIGRATE,VAR__TYPE__VM /var/log/vdsm/vdsm.log