Re: [Users] [ovirt-test-day-2] Possible bug while testing vm-init-persistent feature

Hello, I think I found a possible bug while testing Shahar's vm-init-persistent feature, not sure if related to vm-init-persistent or Engine vs. vdsm RPC issue. Followed steps in [1,2] to install ovirt-engine on F19, then used it to setup another F19 node as host via WebAdmin GUI. [1] http://www.ovirt.org/OVirt_3.4_TestDay#Installation_notes [2] http://www.ovirt.org/OVirt_3.4.0_release_notes#SECOND_BETA_RELEASE On engine: # rpm -qa ovirt-engine* ovirt-engine-setup-base-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-webadmin-portal-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-websocket-proxy-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-dbscripts-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-setup-plugin-websocket-proxy-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-setup-plugin-ovirt-engine-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-tools-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-cli-3.4.0.3-1.fc19.noarch ovirt-engine-setup-plugin-ovirt-engine-common-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-setup-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-backend-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-setup-plugin-allinone-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-sdk-python-3.4.0.3-1.fc19.noarch ovirt-engine-restapi-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-lib-3.4.0-0.7.beta2.fc19.noarch ovirt-engine-userportal-3.4.0-0.7.beta2.fc19.noarch On host: # rpm -qa vdsm* vdsm-python-zombiereaper-4.14.2-0.fc19.noarch vdsm-xmlrpc-4.14.2-0.fc19.noarch vdsm-4.14.2-0.fc19.x86_64 vdsm-cli-4.14.2-0.fc19.noarch vdsm-python-4.14.2-0.fc19.x86_64 Using default 3.4 DataCenter/Cluster, created WinXP VM via WebAdmin GUI *without* Sysprep enabled. Trying to Run Once with WinXP ISO attached, I get: Error while executing action Run VM once: Network error during communication with the Host. Relevant log part attached as XmlRpcExtensionException-part.log Command org.ovirt.engine.core.bll.RunVmOnceCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: org.apache.xmlrpc.common.XmlRpcExtensionException: Null values aren't supported, if isEnabledForExtensions() == false (Failed with error VDS_NETWORK_ERROR and code 5022) Second try, created WinXP VM via WebAdmin GUI *with* Sysprep enabled. On Initial Run tab, checked "Configure Time Zone" and providing VM OS specific timezone override, whose value is different than in System tab's (general) "Time Zone" field. Trying to Run Once with Sysprep enabled & WinXP ISO attached, I get: Cannot run VM. VM is running. Relevant log part attached as VmIsRunning-part.log Command CreateVmVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=cd3722b0-3139-4d23-8ad4-f01875e85a63, vm=VM [winxp-foo]) execution failed. Exception: RuntimeException: java.lang.NullPointerException .. CanDoAction of action RunVmOnce failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_VM_IS_RUNNING Checking if VM is really running on host (it's not): # vdsClient -s 0 list table (no results) Full engine.log + vdsm.log attached. I can provide WebAdmin GUI link and more details if needed. It's possible that there's something wrong with my engine/host, but I'm clueless as how to fix above issues.. Thanks, Vojtech

2014-02-12 00:07:02,041 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] START, IsVmDuringInitiatingVDSCommand( vmId = cd3722b0-3139-4d23-8ad4-f01875e85a63), log id: 536a0258 2014-02-12 00:07:02,042 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 536a0258 2014-02-12 00:07:02,052 INFO [org.ovirt.engine.core.bll.RunVmOnceCommand] (ajp--127.0.0.1-8702-5) [1891c562] Running command: RunVmOnceCommand internal: false. Entities affected : ID: cd3722b0-3139-4d23-8ad4-f01875e85a63 Type: VM 2014-02-12 00:07:02,068 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-5) [1891c562] Running VM with attached cd en_windows_xp_professional_with_service_pack_3_x86_cd_vl_x14-73974.iso 2014-02-12 00:07:02,071 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] START, IsoPrefixVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, storagePoolId=00000002-0002-0002-0002-000000000002), log id: 160a4058 2014-02-12 00:07:02,080 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/10.34.63.204:_home_iso_shared/0c78b4d6-ba00-4d3e-9f9f-65c7d5899d71/images/11111111-1111-1111-1111-111111111111, log id: 160a4058 2014-02-12 00:07:02,090 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] START, CreateVmVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=cd3722b0-3139-4d23-8ad4-f01875e85a63, vm=VM [winxp-foo]), log id: 1106802f 2014-02-12 00:07:02,100 ERROR [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] Error in excuting CreateVmVDSCommand: java.lang.NullPointerException at org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand.initCreateVDSCommand(CreateVmVDSCommand.java:77) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand.executeVdsIdCommand(CreateVmVDSCommand.java:41) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VdsIdVDSCommandBase.executeVDSCommand(VdsIdVDSCommandBase.java:42) [vdsbroker.jar:] at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:56) [vdsbroker.jar:] at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:28) [dal.jar:] at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:399) [vdsbroker.jar:] at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:] at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.RunAsyncVdsCommand(VDSBrokerFrontendImpl.java:48) [bll.jar:] at org.ovirt.engine.core.bll.RunVmCommand.createVm(RunVmCommand.java:447) [bll.jar:] at org.ovirt.engine.core.bll.RunVmCommand.runVm(RunVmCommand.java:219) [bll.jar:] at org.ovirt.engine.core.bll.RunVmCommand.executeVmCommand(RunVmCommand.java:288) [bll.jar:] at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:89) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1123) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1208) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1884) [bll.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:174) [utils.jar:] at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:116) [utils.jar:] at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1228) [bll.jar:] at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:351) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:413) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:392) [bll.jar:] at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:350) [bll.jar:] at sun.reflect.GeneratedMethodAccessor96.invoke(Unknown Source) [:1.7.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.1.Final] at org.ovirt.engine.core.bll.interceptors.ThreadLocalSessionCleanerInterceptor.injectWebContextToThreadLocal(ThreadLocalSessionCleanerInterceptor.java:13) [bll.jar:] at sun.reflect.GeneratedMethodAccessor17.invoke(Unknown Source) [:1.7.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:123) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:36) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:211) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:363) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:194) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:173) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.1.Final] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.1.Final] at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.1.1.Final.jar:7.1.1.Final] at org.ovirt.engine.core.common.interfaces.BackendLocal$$$view9.runAction(Unknown Source) [common.jar:] at org.ovirt.engine.ui.frontend.server.gwt.GenericApiGWTServiceImpl.RunAction(GenericApiGWTServiceImpl.java:131) at sun.reflect.GeneratedMethodAccessor95.invoke(Unknown Source) [:1.7.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_51] at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_51] at com.google.gwt.rpc.server.RPC.invokeAndStreamResponse(RPC.java:196) at com.google.gwt.rpc.server.RpcServlet.processCall(RpcServlet.java:172) at com.google.gwt.rpc.server.RpcServlet.processPost(RpcServlet.java:233) at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62) at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) [jboss-servlet-3.0-api.jar:1.0.1.Final] at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-3.0-api.jar:1.0.1.Final] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.ovirt.engine.ui.frontend.server.gwt.GwtCachingFilter.doFilter(GwtCachingFilter.java:132) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.ovirt.engine.core.branding.BrandingFilter.doFilter(BrandingFilter.java:72) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.ovirt.engine.core.utils.servlet.LocaleFilter.doFilter(LocaleFilter.java:64) [utils.jar:] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.ovirt.engine.core.bll.AutomaticLoginFilter.doFilter(AutomaticLoginFilter.java:58) [bll.jar:] at org.ovirt.engine.core.bll.AutomaticLoginFilter.doFilter(AutomaticLoginFilter.java:49) [bll.jar:] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.ovirt.engine.core.authentication.AuthenticationFilter.doFilter(AuthenticationFilter.java:80) [common.jar:] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489) at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.jboss.web.rewrite.RewriteValve.invoke(RewriteValve.java:466) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505) at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:445) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:930) at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51] 2014-02-12 00:07:02,126 ERROR [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] Command CreateVmVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=cd3722b0-3139-4d23-8ad4-f01875e85a63, vm=VM [winxp-foo]) execution failed. Exception: RuntimeException: java.lang.NullPointerException 2014-02-12 00:07:02,127 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] FINISH, CreateVmVDSCommand, log id: 1106802f 2014-02-12 00:07:02,128 WARN [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-5) [1891c562] Failed to run VM winxp-foo: VdcBLLException: java.lang.RuntimeException: java.lang.NullPointerException (Failed with error ENGINE and code 5001) 2014-02-12 00:07:02,128 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-5) [1891c562] Trying to rerun VM winxp-foo 2014-02-12 00:07:02,133 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [1891c562] Correlation ID: 1891c562, Job ID: cc077985-9602-4357-b7b3-4d6c6984b10f, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM winxp-foo on Host f19-host-34beta2. 2014-02-12 00:07:02,142 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] START, IsVmDuringInitiatingVDSCommand( vmId = cd3722b0-3139-4d23-8ad4-f01875e85a63), log id: 1abacf15 2014-02-12 00:07:02,143 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [1891c562] FINISH, IsVmDuringInitiatingVDSCommand, return: true, log id: 1abacf15 2014-02-12 00:07:02,143 WARN [org.ovirt.engine.core.bll.RunVmOnceCommand] (ajp--127.0.0.1-8702-5) [1891c562] CanDoAction of action RunVmOnce failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_VM_IS_RUNNING 2014-02-12 00:07:02,147 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [1891c562] Correlation ID: 1891c562, Job ID: cc077985-9602-4357-b7b3-4d6c6984b10f, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM winxp-foo (User: admin).

2014-02-11 23:58:51,583 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] START, IsVmDuringInitiatingVDSCommand( vmId = 8cbc01e2-5e4e-4eec-8d07-880e51167e5e), log id: 447c45c5 2014-02-11 23:58:51,590 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 447c45c5 2014-02-11 23:58:51,607 INFO [org.ovirt.engine.core.bll.RunVmOnceCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] Running command: RunVmOnceCommand internal: false. Entities affected : ID: 8cbc01e2-5e4e-4eec-8d07-880e51167e5e Type: VM 2014-02-11 23:58:51,621 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] Running VM with attached cd en_windows_xp_professional_with_service_pack_3_x86_cd_vl_x14-73974.iso 2014-02-11 23:58:51,628 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] START, IsoPrefixVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, storagePoolId=00000002-0002-0002-0002-000000000002), log id: 23fb386d 2014-02-11 23:58:51,637 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/10.34.63.204:_home_iso_shared/0c78b4d6-ba00-4d3e-9f9f-65c7d5899d71/images/11111111-1111-1111-1111-111111111111, log id: 23fb386d 2014-02-11 23:58:51,647 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] START, CreateVmVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=8cbc01e2-5e4e-4eec-8d07-880e51167e5e, vm=VM [winxp-foo]), log id: 556e181c 2014-02-11 23:58:51,658 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] START, CreateVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=8cbc01e2-5e4e-4eec-8d07-880e51167e5e, vm=VM [winxp-foo]), log id: 26da2a9f 2014-02-11 23:58:51,673 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] Command CreateVDSCommand(HostName = f19-host-34beta2, HostId = 02a21a1a-47d6-4d90-8059-a69f0724feff, vmId=8cbc01e2-5e4e-4eec-8d07-880e51167e5e, vm=VM [winxp-foo]) execution failed. Exception: VDSNetworkException: org.apache.xmlrpc.common.XmlRpcExtensionException: Null values aren't supported, if isEnabledForExtensions() == false 2014-02-11 23:58:51,685 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] FINISH, CreateVDSCommand, log id: 26da2a9f 2014-02-11 23:58:51,689 ERROR [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] VDS::create Failed creating vm winxp-foo in vds = 02a21a1a-47d6-4d90-8059-a69f0724feff : f19-host-34beta2 error = org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: org.apache.xmlrpc.common.XmlRpcExtensionException: Null values aren't supported, if isEnabledForExtensions() == false 2014-02-11 23:58:51,697 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] FINISH, CreateVmVDSCommand, return: Down, log id: 556e181c 2014-02-11 23:58:51,701 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand] (ajp--127.0.0.1-8702-8) [d65a9c3] Command org.ovirt.engine.core.bll.RunVmOnceCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: org.apache.xmlrpc.common.XmlRpcExtensionException: Null values aren't supported, if isEnabledForExtensions() == false (Failed with error VDS_NETWORK_ERROR and code 5022) 2014-02-11 23:58:51,716 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-8) [d65a9c3] Correlation ID: d65a9c3, Job ID: d83c76cd-9d55-459c-93a6-96087caa1951, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM winxp-foo (User: admin).