[ OST Failure Report ] [ oVirt Master (ovirt-engine) ] [ 19-03-2018 ] [002_bootstrap.add_instance_type ]

Hi, We have a failure in test 002_bootstrap.add_instance_type. There seem to be a NullPointerException on template type which is causing this failure. The same change that was reported at the last failure is reported as the root cause for this failure as well, but I am not sure how it would cause this failure. Can you please check? *Link and headline of suspected patches: reported as failed: * *core: fix removal of vm-host device - https://gerrit.ovirt.org/#/c/89145/ <https://gerrit.ovirt.org/#/c/89145/>* *reported as root cause: * *core: USB in osinfo configuration depends on chipset - https://gerrit.ovirt.org/#/c/88777/ <https://gerrit.ovirt.org/#/c/88777/>* *Link to Job:http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6431 <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6431>Link to all logs:http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6431/a... <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/6431/artifa... error snippet from the log: <error>2018-03-19 04:59:01,040-04 INFO [org.ovirt.engine.core.bll.AddVmTemplateCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Lock Acquired to object 'EngineLock:{exclusiveLocks='[99a9dfb3-9a13-4595-a795-693493e722be=TEMPLATE, myinstancetype=TEMPLATE_NAME]', sharedLocks='[]'}'2018-03-19 04:59:01,087-04 INFO [org.ovirt.engine.core.bll.AddVmTemplateCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Running command: AddVmTemplateCommand internal: false. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: SystemAction group CREATE_TEMPLATE with role type USER2018-03-19 04:59:01,139-04 INFO [org.ovirt.engine.core.bll.storage.disk.CreateAllTemplateDisksCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Running command: CreateAllTemplateDisksCommand internal: true.2018-03-19 04:59:01,205-04 INFO [org.ovirt.engine.core.utils.transaction.TransactionSupport] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] transaction rolled back2018-03-19 04:59:01,205-04 ERROR [org.ovirt.engine.core.bll.AddVmTemplateCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Command 'org.ovirt.engine.core.bll.AddVmTemplateCommand' failed: null2018-03-19 04:59:01,205-04 ERROR [org.ovirt.engine.core.bll.AddVmTemplateCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Exception: java.lang.NullPointerException at org.ovirt.engine.core.bll.utils.EmulatedMachineUtils.getEffective(EmulatedMachineUtils.java:30) [bll.jar:] at org.ovirt.engine.core.bll.utils.EmulatedMachineUtils.getEffectiveChipset(EmulatedMachineUtils.java:21) [bll.jar:] at org.ovirt.engine.core.bll.utils.VmDeviceUtils.updateUsbSlots(VmDeviceUtils.java:744) [bll.jar:] at org.ovirt.engine.core.bll.utils.VmDeviceUtils.copyVmDevices(VmDeviceUtils.java:1519) [bll.jar:] at org.ovirt.engine.core.bll.utils.VmDeviceUtils.copyVmDevices(VmDeviceUtils.java:1565) [bll.jar:] at org.ovirt.engine.core.bll.AddVmTemplateCommand.lambda$executeCommand$4(AddVmTemplateCommand.java:362) [bll.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:202) [utils.jar:] at org.ovirt.engine.core.bll.AddVmTemplateCommand.executeCommand(AddVmTemplateCommand.java:345) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1133) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1286) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1935) [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:1346) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:400) [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:468) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:450) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:403) [bll.jar:] at sun.reflect.GeneratedMethodAccessor149.invoke(Unknown Source) [:1.8.0_161] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161] 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.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:92) [wildfly-weld-ejb-11.0.0.Final.jar:11.0.0.Final] at org.jboss.weld.interceptor.proxy.WeldInvocationContext.interceptorChainCompleted(WeldInvocationContext.java:98) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:117) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12) [common.jar:] at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source) [:1.8.0_161] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161] at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.WeldInvocationContext.invokeNext(WeldInvocationContext.java:83) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:115) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.weld.bean.InterceptorImpl.intercept(InterceptorImpl.java:108) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final] at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:82) [wildfly-weld-ejb-11.0.0.Final.jar:11.0.0.Final] at org.jboss.as.weld.interceptors.EjbComponentInterceptorSupport.delegateInterception(EjbComponentInterceptorSupport.java:60) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:76) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:88) at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101) 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.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509) at org.ovirt.engine.core.bll.interceptors.CorrelationIdTrackerInterceptor.aroundInvoke(CorrelationIdTrackerInterceptor.java:13) [bll.jar:] at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source) [:1.8.0_161] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161] at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161] at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptor.java:89) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422):* *End of error: * at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1508) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:326) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_161] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_161] at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_161] 2018-03-19 04:59:01,234-04 DEBUG [org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Compiled stored procedure. Call string is [{call get_entity_snapshot_by_command_id(?)}] 2018-03-19 04:59:01,234-04 DEBUG [org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimpleJdbcCall] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] SqlCall for procedure [get_entity_snapshot_by_command_id] compiled 2018-03-19 04:59:01,239-04 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Command [id=a7a51354-ae84-4109-a55e-b27558afbf2a]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.VmTemplate; snapshot: 99a9dfb3-9a13-4595-a795-693493e722be. 2018-03-19 04:59:01,278-04 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] EVENT_ID: USER_ADD_VM_TEMPLATE_FAILURE(36), Failed creating Template myinstancetype. 2018-03-19 04:59:01,295-04 INFO [org.ovirt.engine.core.bll.AddVmTemplateCommand] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] Lock freed to object 'EngineLock:{exclusiveLocks='[99a9dfb3-9a13-4595-a795-693493e722be=TEMPLATE, myinstancetype=TEMPLATE_NAME]', sharedLocks='[]'}' 2018-03-19 04:59:01,295-04 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (default task-5) [5a890b17-51ec-4398-8d64-82cc71939e6e] method: runAction, params: [AddVmTemplate, AddVmTemplateParameters:{commandId='a7a51354-ae84-4109-a55e-b27558afbf2a', user='admin', commandType='AddVmTemplate'}], timeElapsed: 301ms 2018-03-19 04:59:01,301-04 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-5) [] Operation Failed: [Internal Engine Error] 2018-03-19 04:59:01,547-04 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [5a890b17-51ec-4398-8d64-82cc71939e6e] Command 'AddVmTemplate' id: 'a7a51354-ae84-4109-a55e-b27558afbf2a' execution didn't complete, not proceeding to perform the next operation 2018-03-19 04:59:01,547-04 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [5a890b17-51ec-4398-8d64-82cc71939e6e] Command 'AddVmTemplate' id: 'a7a51354-ae84-4109-a55e-b27558afbf2a' child commands '[8484f4d2-9ddf-48bd-9877-7c99ef555255]' executions were completed, status 'FAILED' 2018-03-19 04:59:01,581-04 INFO [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [db5dd3dd-8b48-4647-a02d-723fcd6a7dda] Command 'ImportRepoImage' (id: 'a6475141-53ef-4ecd-bc17-ee8eae168dc7') waiting on child command id: '528fde29-9b5b-4a90-b62a-606fac3cd6a6' type:'DownloadImage' to complete 2018-03-19 04:59:02,363-04 DEBUG [org.ovirt.otopi.dialog.MachineDialogParser] (VdsDeploy) [665e1c35] Got: ***L:INFO Yum install: 349/515: gdisk-0.8.6-5.el7.x86_64 2018-03-19 04:59:02,364-04 DEBUG [org.ovirt.otopi.dialog.MachineDialogParser] (VdsDeploy) [665e1c35] nextEvent: Log INFO Yum install: 349/515: gdisk-0.8.6-5.el7.x86_64 2018-03-19 04:59:02,570-04 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (VdsDeploy) [665e1c35] EVENT_ID: VDS_INSTALL_IN_PROGRESS(509), Installing Host lago-basic-suite-master-host-1. Yum install: 349/515: gdisk-0.8.6-5.el7.x86_64. 2018-03-19 04:59:02,666-04 ERROR [org.ovirt.engine.core.bll.AddVmTemplateCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-86) [5a890b17-51ec-4398-8d64-82cc71939e6e] Ending command 'org.ovirt.engine.core.bll.AddVmTemplateCommand' with failure. *</error>*