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

Shahar Havivi shaharh at redhat.com
Wed Feb 12 12:17:08 UTC 2014


Thanks Vojtech,
There is a bug (and a fix) here:
https://bugzilla.redhat.com/1063883

Shahar.

On 11.02.14 18:20, Vojtech Szocs wrote:
> 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).




More information about the Users mailing list