Return-Path: X-Original-To: apmail-incubator-cloudstack-dev-archive@minotaur.apache.org Delivered-To: apmail-incubator-cloudstack-dev-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 63BB4D750 for ; Tue, 26 Feb 2013 15:16:15 +0000 (UTC) Received: (qmail 72992 invoked by uid 500); 26 Feb 2013 15:16:14 -0000 Delivered-To: apmail-incubator-cloudstack-dev-archive@incubator.apache.org Received: (qmail 72706 invoked by uid 500); 26 Feb 2013 15:16:14 -0000 Mailing-List: contact cloudstack-dev-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: cloudstack-dev@incubator.apache.org Delivered-To: mailing list cloudstack-dev@incubator.apache.org Received: (qmail 72663 invoked by uid 99); 26 Feb 2013 15:16:13 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 26 Feb 2013 15:16:13 +0000 Date: Tue, 26 Feb 2013 15:16:13 +0000 (UTC) From: "Marcus Sorensen (JIRA)" To: cloudstack-dev@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-1400) System VM's are failed to start with KVM 6.3 MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-1400?page=3Dcom.atla= ssian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId= =3D13587186#comment-13587186 ]=20 Marcus Sorensen commented on CLOUDSTACK-1400: --------------------------------------------- Please see CLOUDSTACK-1078, CLOUDSTCK1269, and close this if it turns out t= o be the same issue. =20 > System VM's are failed to start with KVM 6.3 > -------------------------------------------- > > Key: CLOUDSTACK-1400 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-140= 0 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > Components: KVM, Management Server > Affects Versions: 4.1.0 > Reporter: Sailaja Mada > Assignee: Sailaja Mada > Priority: Blocker > Attachments: agent.log, management-server.log > > > Setup: Advanced network Zone with KVM 6.3 host=20 > Observation: > System VM's are failed to start.=20 > snippet of the log from Agent: > 2013-02-26 22:34:27,409 WARN [kvm.resource.LibvirtComputingResource] (ag= entRequest-Handler-1:null) Failed to start domain: v-2-VM: Cannot get inter= face MTU on 'cloudbr1': No such device > 2013-02-26 22:34:27,410 WARN [kvm.resource.LibvirtComputingResource] (ag= entRequest-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.sta= rtDomain(LibvirtComputingResource.java:1035) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cute(LibvirtComputingResource.java:3084) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cuteRequest(LibvirtComputingResource.java:1160) > at com.cloud.agent.Agent.processRequest(Agent.java:525) > at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:85= 2) > at com.cloud.utils.nio.Task.run(Task.java:83) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.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.cle= anupVMNetworks(LibvirtComputingResource.java:4211) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.han= dleVmStartFailure(LibvirtComputingResource.java:2980) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cute(LibvirtComputingResource.java:3104) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cuteRequest(LibvirtComputingResource.java:1160) > at com.cloud.agent.Agent.processRequest(Agent.java:525) > at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:85= 2) > at com.cloud.utils.nio.Task.run(Task.java:83) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.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.NullPointerExc= eption\n\tat com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cle= anupVMNetworks(LibvirtComputingResource.java:4211)\n\tat com.cloud.hypervis= or.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComput= ingResource.java:2980)\n\tat com.cloud.hypervisor.kvm.resource.LibvirtCompu= tingResource.execute(LibvirtComputingResource.java:3104)\n\tat com.cloud.hy= pervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComput= ingResource.java:1160)\n\tat com.cloud.agent.Agent.processRequest(Agent.jav= a:525)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:85= 2)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.util.concurr= ent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat java.u= til.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, V= er: 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] (ag= entRequest-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:nul= l) Seq 1-1571815480: Received: { Ans: , MgmtId: 55487956346259, via: 1, Ve= r: v1, Flags: 110, { Answer, Answer } } > 2013-02-26 17:08:34,402 ERROR [cloud.vm.VirtualMachineManagerImpl] (secst= orage-1:null) Failed to start instance VM[SecondaryStorageVm|s-18-VM] > com.cloud.utils.exception.CloudRuntimeException: Unable to get answer tha= t is of class com.cloud.agent.api.StartAnswer > at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMac= hineManagerImpl.java:767) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineMan= agerImpl.java:461) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineMan= agerImpl.java:454) > at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:616) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingR= eflection(AopUtils.java:319) > at org.springframework.aop.framework.ReflectiveMethodInvocation.i= nvokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:150) > at org.springframework.aop.aspectj.MethodInvocationProceedingJoin= Point.proceed(MethodInvocationProceedingJoinPoint.java:80) > at com.cloud.utils.db.TransactionContextBuilder.AroundAnyMethod(T= ransactionContextBuilder.java:37) > at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:616) > at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAd= viceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) > at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAd= viceMethod(AbstractAspectJAdvice.java:610) > at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(Asp= ectJAroundAdvice.java:65) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.interceptor.ExposeInvocationIntercepto= r.invoke(ExposeInvocationInterceptor.java:90) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(Jd= kDynamicAopProxy.java:202) > at $Proxy193.start(Unknown Source) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startS= ecStorageVm(SecondaryStorageManagerImpl.java:264) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocC= apacity(SecondaryStorageManagerImpl.java:689) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expand= Pool(SecondaryStorageManagerImpl.java:1300) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPo= ol(PremiumSecondaryStorageManagerImpl.java:121) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPo= ol(PremiumSecondaryStorageManagerImpl.java:52) > at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.= java:104) > at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanne= r.java:33) > at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScann= er.java:81) > at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.jav= a:72) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.= java:471) > at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTa= sk.java:351) > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:17= 8) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutu= reTask.access$201(ScheduledThreadPoolExecutor.java:165) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutu= reTask.run(ScheduledThreadPoolExecutor.java:267) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-02-26 17:08:34,429 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secst= orage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-18-V= M] in Starting state > 2013-02-26 17:08:34,430 DEBUG [agent.transport.Request] (secstorage-1:nul= l) 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:nul= l) =3D=3D=3DEND=3D=3D=3D 10.144.7.13 -- GET command=3DlistSystemVms&respo= nse=3Djson&sessionkey=3DeaXEBOovp%2BhDALvkcKqyiBax%2FjA%3D&page=3D1&pageSiz= e=3D20&listAll=3Dtrue&_=3D1361878735567 > 2013-02-26 17:08:35,805 DEBUG [agent.manager.AgentManagerImpl] (AgentMana= ger-Handler-12:null) SeqA 1-7: Processing Seq 1-7: { Cmd , MgmtId: -1, via= : 1, Ver: v1, Flags: 11, [{"PingRoutingCommand":{"newStates":{"s-18-VM":"St= opped"},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routin= g","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.25= 5.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 administrato= rs For more information on JIRA, see: http://www.atlassian.com/software/jira