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
