incubator-cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Marcus Sorensen (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-1269) Failed to start CPVM java.lang.NullPointerException Unable to start SSVM
Date Fri, 15 Feb 2013 14:53:13 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-1269?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13579221#comment-13579221
] 

Marcus Sorensen commented on CLOUDSTACK-1269:
---------------------------------------------

What I'm asking is that you look on the agent host when the state is in
starting and do a 'virsh list'. Very often the VM is actually running but
not ping able yet, which means we can gather info on it.

Do you have a /var/lib/cloud? A /usr/share/cloud? What is the cloud users
home directory set to? Please check both mgmt server and kvm host. I just
want to ensure this is a fresh install because we have seen issues with
upgrades if they have the old setup.

There have been lots of emails about the agent logging. Please rename
log4j-cloud.xml  in /etc/cloudstack/agent to log4j.xml and restart the
agent.


                
> Failed to start CPVM java.lang.NullPointerException   Unable to start SSVM
> --------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-1269
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1269
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Management Server
>    Affects Versions: 4.1.0
>         Environment: MS   rhel6.3         10.223.195.114    build   CloudStack-non-OSS-23-rhel6.3.tar.gz
> host rhel6.3 kvm  10.223.51.2        build   CloudStack-non-OSS-23-rhel6.3.tar.gz
> 1. host  installation: 
> build  CloudStack-non-OSS-23-rhel6.3.tar.gz  contains old version qemu-img-0.12.1.2-3.209.el6.4.x86_64
> Due to 4.1 packaging, build does not have  new qemu-img and qemu-kvm for testing kvm
6.3 snapshot
> manually replace qemu-img-0.12.1.2-3.209.el6.4.x86_64  with  qemu-img-0.12.1.2-3.295.el6.4.x86_64
> manually install   qemu-kvm-0.12.1.2-3.295.el6.4.x86_64
> as part of above , had to remove  libvirt-0.9.10-21.el6.x86_64, download libvirt-0.9.10-21.el6.x86_64
> Here are some rpms that was reinstalled:
>    1975468          Feb 13 20:56        libvirt-0.9.10-21.el6.x86_64.rpm
>    1361029          Feb 13 20:32        qemu-img-0.12.1.2-3.295.el6.10.x86_64.rpm
>  10878235          Feb 13 20:33        qemu-kvm-0.12.1.2-3.295.el6.10.x86_64.rpm
>      375800          Feb 13 22:16        xnba-kvm-1.0.3-7.x86_64.rpm
> 2.  create advance zone isolation mode.  
>     CPVM unable to start          SSVM    CPVM
>            Reporter: angeline shen
>            Assignee: Fang Wang
>            Priority: Blocker
>             Fix For: 4.1.0
>
>         Attachments: management-server.log.gz, management-server.log.gz, Screenshot-CloudStack
- Mozilla Firefox.png, Screenshot-CloudStack - Mozilla Firefox.png
>
>
> 2013-02-13 17:10:25,656 DEBUG [agent.transport.Request] (AgentManager-Handler-12:null)
Seq 1-1481768980: Processing:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110,
[{"Answer":{"result":false,"details":"java.lang.Nul
> lPointerException\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(Libvirt
> ComputingResource.java:2983)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtCompu
> tingResource.java:1163)\n\tat com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.
> ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}},{"Answer":{"result":false,"
> details":"Stopped by previous failure","wait":0}}] }
> 2013-02-13 17:10:25,657 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1481768980:
Received:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110, { Answer, Answer }
}
> 2013-02-13 17:10:25,657 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-12:null)
Seq 1-1481768981: Sending now.  is current sequence.
> 2013-02-13 17:10:25,662 ERROR [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null)
Failed to start instance VM[SecondaryStorageVm|s-1-VM]
> com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is of class
com.cloud.agent.api.StartAnswer
>         at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:777)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:466)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:459)
>         at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
>         at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
>         at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
>         at com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:43)
>         at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:616)
>         at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
>         at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
>         at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>         at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>         at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
>         at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:264)
>         at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:689)
>         at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
>         at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
>         at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
>         at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
>         at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
>         at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
>         at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> 2013-02-13 17:10:25,667 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null)
Cleaning up resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting state
> 2013-02-13 17:10:25,668 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1481768983:
Waiting for Seq 1481768981 Scheduling:  { Cmd , MgmtId: 6809771312912, via: 1, Ver: v1, Flags:
100111, [{"StopCommand":{"isProxy":false,
> "vmName":"s-1-VM","wait":0}}] }
> 2013-02-13 17:10:35,133 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===
 10.216.133.70 -- POST  command=createAccount&response=json&sessionkey=ZPNnO6ZVMdSYISIfi%2FUga%2FM9H9A%3D
> 2013-02-13 17:10:35,154 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-10:null)
Access granted to Acct[2-admin] to Domain:2/d1/ by DomainChecker
> 2013-02-13 17:10:35,161 DEBUG [network.security.SecurityGroupManagerImpl] (catalina-exec-10:null)
Created security group 
> 2013-02-13 17:10:35,133 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===
 10.216.133.70 -- POST  command=createAccount&response=json&sessionkey=ZPNnO6ZVMdSYISIfi%2FUga%2FM9H9A%3D
> 2013-02-13 17:10:35,154 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-10:null)
Access granted to Acct[2-admin] to Domain:2/d1/ by DomainChecker
> 2013-02-13 17:10:35,161 DEBUG [network.security.SecurityGroupManagerImpl] (catalina-exec-10:null)
Created security group com.cloud.network.security.SecurityGroupVO$$EnhancerByCGLIB$$53628a27@753f827a
for account id=4
> 2013-02-13 17:10:35,163 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-10:null)
Creating user: d1domain, accountId: 4 timezone:America/Los_Angeles
> 2013-02-13 17:10:35,324 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===
 10.216.133.70 -- POST  command=createAccount&response=json&sessionkey=ZPNnO6ZVMdSYISIfi%2FUga%2FM9H9A%3D
> 2013-02-13 17:10:36,326 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null)
Seq 1-1481768981: Processing:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110,
[{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}},{"Answer":{"result":false,"details":"Stopped
by previous failure","wait":0}}] }
> 2013-02-13 17:10:36,326 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-13:null)
Seq 1-1481768983: Sending now.  is current sequence.
> 2013-02-13 17:10:36,326 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1481768981:
Received:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110, { Answer, Answer }
}
> 2013-02-13 17:10:36,339 ERROR [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null)
Failed to start instance VM[ConsoleProxy|v-2-VM]
> com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is of class
com.cloud.agent.api.StartAnswer
>         at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:777)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:466)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:459)
>         at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
>         at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
>         at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
>         at com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(TransactionContextBuilder.java:43)
>         at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:616)
>         at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
>         at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
>         at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>         at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>         at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:630)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1960)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:174)
>         at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
>         at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
>         at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
>         at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> 2013-02-13 17:10:36,343 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null)
Cleaning up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
> 2013-02-13 17:10:36,344 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1481768984:
Waiting for Seq 1481768983 Scheduling:  { Cmd , MgmtId: 6809771312912, via: 1, Ver: v1, Flags:
100111, [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] }
> 2013-02-13 17:10:36,395 DEBUG [agent.transport.Request] (AgentManager-Handler-14:null)
Seq 1-1481768983: Processing:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
> 2013-02-13 17:10:36,395 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-14:null)
Seq 1-1481768984: Sending now.  is current sequence.
> 2013-02-13 17:10:36,395 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1481768983:
Received:  { Ans: , MgmtId: 6809771312912, via: 1, Ver: v1, Flags: 110, { StopAnswer } }

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message