You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cloudstack.apache.org by "Sailaja Mada (JIRA)" <ji...@apache.org> on 2013/02/26 12:42:12 UTC

[jira] [Created] (CLOUDSTACK-1400) System VM's are failed to start with KVM 6.3

Sailaja Mada created CLOUDSTACK-1400:
----------------------------------------

             Summary: System VM's are failed to start with KVM 6.3
                 Key: CLOUDSTACK-1400
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1400
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: KVM, Management Server
    Affects Versions: 4.1.0
            Reporter: Sailaja Mada
            Assignee: Sailaja Mada
            Priority: Blocker


Setup:  Advanced network Zone with KVM 6.3 host 

Observation:

System VM's are failed to start. 

snippet of the log from Agent:

2013-02-26 22:34:27,409 WARN  [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Failed to start domain: v-2-VM: Cannot get interface MTU on 'cloudbr1': No such device
2013-02-26 22:34:27,410 WARN  [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Exception
org.libvirt.LibvirtException: Cannot get interface MTU on 'cloudbr1': No such device
        at org.libvirt.ErrorHandler.processError(Unknown Source)
        at org.libvirt.Connect.processError(Unknown Source)
        at org.libvirt.Domain.processError(Unknown Source)
        at org.libvirt.Domain.create(Unknown Source)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.startDomain(LibvirtComputingResource.java:1035)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3084)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1160)
        at com.cloud.agent.Agent.processRequest(Agent.java:525)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        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-26 22:34:27,410 WARN  [cloud.agent.Agent] (agentRequest-Handler-1:null) Caught:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4211)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2980)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3104)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1160)
        at com.cloud.agent.Agent.processRequest(Agent.java:525)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        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-26 22:34:27,412 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Seq 1-1571815464:  { Ans: , MgmtId: 55487956346259, via: 1, Ver: v1, Flags: 110, [{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4211)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2980)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3104)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1160)\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-26 22:34:27,458 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Request:Seq 1-1571815465:  { Cmd , MgmtId: 55487956346259, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"s-17-VM","wait":0}}] }
2013-02-26 22:34:27,458 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.StopCommand
2013-02-26 22:34:27,477 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Try to stop the vm at first


MS log:

2013-02-26 17:08:34,400 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1571815480: Received:  { Ans: , MgmtId: 55487956346259, via: 1, Ver: v1, Flags: 110, { Answer, Answer } }
2013-02-26 17:08:34,402 ERROR [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Failed to start instance VM[SecondaryStorageVm|s-18-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:767)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:461)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:454)
        at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        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:37)
        at sun.reflect.GeneratedMethodAccessor27.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.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
        at $Proxy193.start(Unknown Source)
        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-26 17:08:34,429 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-18-VM] in Starting state
2013-02-26 17:08:34,430 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1571815483: Waiting for Seq 1571815481 Scheduling:  { Cmd , MgmtId: 55487956346259, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"s-18-VM","wait":0}}] }
2013-02-26 17:08:34,474 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END===  10.144.7.13 -- GET  command=listSystemVms&response=json&sessionkey=eaXEBOovp%2BhDALvkcKqyiBax%2FjA%3D&page=1&pageSize=20&listAll=true&_=1361878735567
2013-02-26 17:08:35,805 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA 1-7: Processing Seq 1-7:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"PingRoutingCommand":{"newStates":{"s-18-VM":"Stopped"},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] }

Agent ifconfig :

[root@kvm57 agent]# ifconfig
brem1-101 Link encap:Ethernet  HWaddr D4:AE:52:AD:E9:C7
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:582 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:29060 (28.3 KiB)  TX bytes:0 (0.0 b)

cloud0    Link encap:Ethernet  HWaddr 00:00:00:00:00:00
          inet addr:169.254.0.1  Bcast:169.254.255.255  Mask:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:0 (0.0 b)  TX bytes:0 (0.0 b)

cloudbr0  Link encap:Ethernet  HWaddr D4:AE:52:AD:E9:C7
          inet addr:10.102.192.57  Bcast:10.102.195.255  Mask:255.255.252.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:944645 errors:0 dropped:0 overruns:0 frame:0
          TX packets:513659 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:822676937 (784.5 MiB)  TX bytes:910640196 (868.4 MiB)

em1       Link encap:Ethernet  HWaddr D4:AE:52:AD:E9:C7
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:951464 errors:0 dropped:0 overruns:0 frame:0
          TX packets:960709 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:840198772 (801.2 MiB)  TX bytes:943988966 (900.2 MiB)
          Interrupt:16

em1.101   Link encap:Ethernet  HWaddr D4:AE:52:AD:E9:C7
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:585 errors:0 dropped:0 overruns:0 frame:0
          TX packets:22 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:29198 (28.5 KiB)  TX bytes:1452 (1.4 KiB)

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:91 errors:0 dropped:0 overruns:0 frame:0
          TX packets:91 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:8034 (7.8 KiB)  TX bytes:8034 (7.8 KiB)

virbr0    Link encap:Ethernet  HWaddr 52:54:00:78:62:A8
          inet addr:192.168.122.1  Bcast:192.168.122.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:0 (0.0 b)  TX bytes:0 (0.0 b)

[root@kvm57 agent]#




--
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