Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1690159

Summary: NPE in LibvirtVmXmlBuilder
Product: [oVirt] ovirt-engine Reporter: Simone Tiraboschi <stirabos>
Component: BLL.VirtAssignee: Tomasz Barański <tbaransk>
Status: CLOSED CURRENTRELEASE QA Contact: Liran Rotenberg <lrotenbe>
Severity: high Docs Contact:
Priority: urgent    
Version: 4.3.0CC: bugs, michal.skrivanek, rbarry, smelamud, tbaransk
Target Milestone: ovirt-4.3.3Flags: pm-rhel: ovirt-4.3+
pm-rhel: blocker+
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ovirt-engine-4.3.3.1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-04-16 13:58:33 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Virt RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Simone Tiraboschi 2019-03-18 22:14:06 UTC
Description of problem:
The engine is raising a NPE trying to build the OVF_STORE content.

2019-03-16 22:38:41,827-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] Attempting to update VMs/Templates Ovf.
2019-03-16 22:38:41,831-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Before acquiring and wait lock 'EngineLock:{exclusiveLocks='[c1f47590-485b-11e9-8f3b-5452c0a8c863=OVF_UPDATE]', sharedLocks=''}'
2019-03-16 22:38:41,831-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Lock-wait acquired to object 'EngineLock:{exclusiveLocks='[c1f47590-485b-11e9-8f3b-5452c0a8c863=OVF_UPDATE]', sharedLocks=''}'
2019-03-16 22:38:41,833-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected :  ID: c1f47590-485b-11e9-8f3b-5452c0a8c863 Type: StoragePool
2019-03-16 22:38:41,845-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Attempting to update VM OVFs in Data Center 'Default'
2019-03-16 22:38:41,930-04 WARN  [org.ovirt.engine.core.vdsbroker.builder.vminfo.VmInfoBuildUtils] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] No host NUMA nodes found for vm HostedEngine (9d1ed4dd-b7a0-48f9-b3cc-1bc959e5193c)
2019-03-16 22:38:41,934-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Command 'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand' failed: null
2019-03-16 22:38:41,934-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Exception: java.lang.NullPointerException
	at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.writeGraphics(LibvirtVmXmlBuilder.java:1625) [vdsbroker.jar:]
	at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.writeDevices(LibvirtVmXmlBuilder.java:1006) [vdsbroker.jar:]
	at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.buildCreateVm(LibvirtVmXmlBuilder.java:262) [vdsbroker.jar:]
	at org.ovirt.engine.core.utils.ovf.OvfManager.generateEngineXml(OvfManager.java:221) [bll.jar:]
	at org.ovirt.engine.core.utils.ovf.OvfManager.exportVm(OvfManager.java:70) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.OvfUpdateProcessHelper.generateVmMetadata(OvfUpdateProcessHelper.java:155) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.OvfUpdateProcessHelper.buildMetadataDictionaryForVm(OvfUpdateProcessHelper.java:80) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand.populateVmsMetadataForOvfUpdate(ProcessOvfUpdateForStoragePoolCommand.java:364) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand.updateOvfForVmsOfStoragePool(ProcessOvfUpdateForStoragePoolCommand.java:187) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand.executeCommand(ProcessOvfUpdateForStoragePoolCommand.java:121) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1157) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1315) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1964) [bll.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:164) [utils.jar:]
	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:103) [utils.jar:]
	at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1375) [bll.jar:]
	at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:419) [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:450) [bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:432) [bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:377) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor519.invoke(Unknown Source) [:1.8.0_201]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_201]
	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_201]
	at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:79)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:89)
	at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:102)
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45) [wildfly-ee-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
	at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:216) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:418) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:148) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
	at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81) [weld-ejb-3.0.5.Final.jar:3.0.5.Final]
	at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [wildfly-ejb3-15.0.1.Final.jar:15.0.1.Final]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
	at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:618)
	at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
	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.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
	at org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view2.runInternalAction(Unknown Source) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor518.invoke(Unknown Source) [:1.8.0_201]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_201]
	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_201]
	at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:410) [weld-core-impl-3.0.5.Final.jar:3.0.5.Final]
	at org.jboss.weld.module.ejb.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:134) [weld-ejb-3.0.5.Final.jar:3.0.5.Final]
	at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-impl-3.0.5.Final.jar:3.0.5.Final]
	at org.jboss.weld.module.ejb.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:68) [weld-ejb-3.0.5.Final.jar:3.0.5.Final]
	at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:106) [weld-core-impl-3.0.5.Final.jar:3.0.5.Final]
	at org.ovirt.engine.core.bll.BackendCommandObjectsHandler$BackendInternal$BackendLocal$2049259618$Proxy$_$$_Weld$EnterpriseProxy$.runInternalAction(Unknown Source) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater.performOvfUpdateForStoragePool(OvfDataUpdater.java:65) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater.updateOvfData(OvfDataUpdater.java:85) [bll.jar:]
	at org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater.ovfUpdate(OvfDataUpdater.java:72) [bll.jar:]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_201]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [rt.jar:1.8.0_201]
	at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383) [javax.enterprise.concurrent-1.0.jar:]
	at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534) [javax.enterprise.concurrent-1.0.jar:]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_201]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_201]
	at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_201]
	at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250) [javax.enterprise.concurrent-1.0.jar:]
	at org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)

2019-03-16 22:38:41,942-04 INFO  [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Lock freed to object 'EngineLock:{exclusiveLocks='[c1f47590-485b-11e9-8f3b-5452c0a8c863=OVF_UPDATE]', sharedLocks=''}'
2019-03-16 22:38:41,942-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Exception while trying to update or remove VMs/Templates ovf in Data Center 'Default'.
2019-03-16 22:38:41,942-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.OvfDataUpdater] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Data Center '{}' domains list for OVF update returned as NULL


Version-Release number of selected component (if applicable):
4.3

How reproducible:
100% in OST, see:
https://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-master/1149/artifact/exported-artifacts/test_logs/he-basic-suite-master/post-suite-sigterm/lago-he-basic-suite-master-host-0/_var_log/ovirt-hosted-engine-setup/engine-logs-2019-03-17T02%3A39%3A11Z/ovirt-engine/engine.log

Steps to Reproduce:
1. deploy hosted-engine
2.
3.

Actual results:
2019-03-16 22:38:41,934-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Command 'org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand' failed: null
2019-03-16 22:38:41,934-04 ERROR [org.ovirt.engine.core.bll.storage.ovfstore.ProcessOvfUpdateForStoragePoolCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [5c41ec26] Exception: java.lang.NullPointerException
	at org.ovirt.engine.core.vdsbroker.builder.vminfo.LibvirtVmXmlBuilder.writeGraphics(LibvirtVmXmlBuilder.java:1625) [vdsbroker.jar:]

Expected results:
the engine successfully creates the OVF_STORE content

Additional info:
It breaks hosted-engine deployment

Comment 1 Ryan Barry 2019-03-19 00:49:37 UTC
This looks like https://bugzilla.redhat.com/show_bug.cgi?id=1644748 again

Shmuel, did some recent change in OVA handling break again?

Comment 2 Michal Skrivanek 2019-03-19 04:50:14 UTC
I would rather suspect Cirrus removal. Simone, who is upgrading HE VM definition during cluster upgrade? The code responsible for updating normal VMs is skipping over HE VM, so unless it’s taken care of aomewhere else then the HE VM becomes invalid. Or is it a fresh install? In that case it still makes sense to check/update the definition to match 4.3

Comment 3 Michal Skrivanek 2019-03-19 04:55:24 UTC
Ah, no, sorry, I misread the line. It’s rather the fips mode setting which assume there is a host already. It doesn’t have to be the case. Tomasz, this needs to be fixed differently

Comment 4 Michal Skrivanek 2019-03-19 05:14:19 UTC
This is likely causing NPE for all VMs during periodic OVF sync, and also blocking export of VMs

Comment 5 Liran Rotenberg 2019-04-02 08:59:19 UTC
Verified on:
ovirt-engine-4.3.3.1-0.1.el7.noarch

Steps:
1. Deploy hosted-engine
2. Search for errors in the logs related to ProcessOvfUpdateForStoragePoolCommand

Results:
Deployment passed, there are no errors related to ProcessOvfUpdateForStoragePoolCommand.

Comment 6 Sandro Bonazzola 2019-04-16 13:58:33 UTC
This bugzilla is included in oVirt 4.3.3 release, published on April 16th 2019.

Since the problem described in this bug report should be
resolved in oVirt 4.3.3 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.