CloudStack
  1. CloudStack
  2. CLOUDSTACK-1269

Failed to start CPVM java.lang.NullPointerException Unable to start SSVM

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Blocker Blocker
    • Resolution: Won't Fix
    • Affects Version/s: 4.1.0
    • Fix Version/s: 4.1.0
    • Component/s: Management Server
    • Security Level: Public (Anyone can view this level - this is the default.)
    • Labels:
      None
    • Environment:

      Description

      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 }

      }

      1. agent.log
        56 kB
        angeline shen
      2. management-server.log.gz
        556 kB
        angeline shen
      3. management-server.log.gz
        1.78 MB
        angeline shen
      4. Screenshot-CloudStack - Mozilla Firefox.png
        105 kB
        angeline shen
      5. Screenshot-CloudStack - Mozilla Firefox.png
        105 kB
        angeline shen

        Activity

        Hide
        angeline shen added a comment -

        Verified with host agent changes

        Show
        angeline shen added a comment - Verified with host agent changes
        Hide
        Sudha Ponnaganti added a comment -

        Based on Marcus' explanation and Rayees testing, looks like this can be closed. Angie - Pl close this defect as "Not A Defect"

        thanks
        /sudha

        Show
        Sudha Ponnaganti added a comment - Based on Marcus' explanation and Rayees testing, looks like this can be closed. Angie - Pl close this defect as "Not A Defect" thanks /sudha
        Hide
        Rayees Namathponnan added a comment - - edited

        I faced similar issue then I added private.network.device=cloudbr0 in /etc/cloudstack/agent/agent.properties , this issue is resolved

        Now I am facing another issue with ssvm; defect https://issues.apache.org/jira/browse/CLOUDSTACK-1326 created

        Show
        Rayees Namathponnan added a comment - - edited I faced similar issue then I added private.network.device=cloudbr0 in /etc/cloudstack/agent/agent.properties , this issue is resolved Now I am facing another issue with ssvm; defect https://issues.apache.org/jira/browse/CLOUDSTACK-1326 created
        Hide
        Marcus Sorensen added a comment -

        Your question: Why is agent looking for cloudbr1?

        http://incubator.apache.org/cloudstack/docs/en-US/Apache_CloudStack/4.0.0-incubating/html-single/Installation_Guide/index.html

        "In order to forward traffic to your instances you will need at least two bridges: public and private.
        By default these bridges are called cloudbr0 and cloudbr1, but you do have to make sure they are available on each hypervisor. The most important factor is that you keep the configuration consistent on all your hypervisors."

        and

        "The goal is to have two bridges called 'cloudbr0' and 'cloudbr1' after this section. This should be used as a guideline only. The exact configuration will depend on your network layout."

        If you aren't going to have a cloudbr1, you need to configure the system otherwise by adding a traffic label that would put the private traffic on cloudbr0. Either in the agent via 'private.network.device=', or in the management server via traffic label prior to adding the host so it will write the private.network.device entry for you.

        Show
        Marcus Sorensen added a comment - Your question: Why is agent looking for cloudbr1? http://incubator.apache.org/cloudstack/docs/en-US/Apache_CloudStack/4.0.0-incubating/html-single/Installation_Guide/index.html "In order to forward traffic to your instances you will need at least two bridges: public and private. By default these bridges are called cloudbr0 and cloudbr1, but you do have to make sure they are available on each hypervisor. The most important factor is that you keep the configuration consistent on all your hypervisors." and "The goal is to have two bridges called 'cloudbr0' and 'cloudbr1' after this section. This should be used as a guideline only. The exact configuration will depend on your network layout." If you aren't going to have a cloudbr1, you need to configure the system otherwise by adding a traffic label that would put the private traffic on cloudbr0. Either in the agent via 'private.network.device=', or in the management server via traffic label prior to adding the host so it will write the private.network.device entry for you.
        Hide
        angeline shen added a comment -

        On host 10.223.58.194 After rename /etc/cloudstack/agent/log4j-cloud.xml to log4j.xml, /var/log/cloudstack/agent/agent.log was generated.

        attached agent.log to bug.

        In the error below :

        Exception org.libvirt.LibvirtException: Cannot get interface MTU on 'cloudbr1': No such device

        There is no cloudbr1 on host, only cloudbr0:
        [root@Rack3Host15 agent]# ip route
        10.223.58.192/26 dev cloudbr0 proto kernel scope link src 10.223.58.194
        192.168.122.0/24 dev virbr0 proto kernel scope link src 192.168.122.1
        169.254.0.0/16 dev cloud0 proto kernel scope link src 169.254.0.1
        default via 10.223.58.193 dev cloudbr0

        Why is agent looking for cloudbr1?

        2013-02-15 16:43:41,127 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Failed to start domain: s-833-VM: Cannot get interface MTU on 'cloudbr1': No such device
        2013-02-15 16:43:41,129 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4: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:1038)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:43:41,132 WARN [cloud.agent.Agent] (agentRequest-Handler-4:null) Caught:
        java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:43:51,842 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Failed to start domain: v-2-VM: Cannot get interface MTU on 'cloudbr1': No such device
        2013-02-15 16:43:51,843 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5: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:1038)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:43:51,843 WARN [cloud.agent.Agent] (agentRequest-Handler-5:null) Caught:
        java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:43:51,843 WARN [cloud.agent.Agent] (agentRequest-Handler-5:null) Caught:
        java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:44:10,477 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Failed to start domain: s-833-VM: Cannot get interface MTU on 'cloudbr1': No such device
        2013-02-15 16:44:10,478 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4: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:1038)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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-15 16:44:15,500 WARN [cloud.agent.Agent] (agentRequest-Handler-4:null) Caught:
        java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163)
        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)

        Show
        angeline shen added a comment - On host 10.223.58.194 After rename /etc/cloudstack/agent/log4j-cloud.xml to log4j.xml, /var/log/cloudstack/agent/agent.log was generated. attached agent.log to bug. In the error below : Exception org.libvirt.LibvirtException: Cannot get interface MTU on 'cloudbr1': No such device There is no cloudbr1 on host, only cloudbr0: [root@Rack3Host15 agent] # ip route 10.223.58.192/26 dev cloudbr0 proto kernel scope link src 10.223.58.194 192.168.122.0/24 dev virbr0 proto kernel scope link src 192.168.122.1 169.254.0.0/16 dev cloud0 proto kernel scope link src 169.254.0.1 default via 10.223.58.193 dev cloudbr0 Why is agent looking for cloudbr1? 2013-02-15 16:43:41,127 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Failed to start domain: s-833-VM: Cannot get interface MTU on 'cloudbr1': No such device 2013-02-15 16:43:41,129 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4: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:1038) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:43:41,132 WARN [cloud.agent.Agent] (agentRequest-Handler-4:null) Caught: java.lang.NullPointerException at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:43:51,842 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Failed to start domain: v-2-VM: Cannot get interface MTU on 'cloudbr1': No such device 2013-02-15 16:43:51,843 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5: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:1038) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:43:51,843 WARN [cloud.agent.Agent] (agentRequest-Handler-5:null) Caught: java.lang.NullPointerException at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:43:51,843 WARN [cloud.agent.Agent] (agentRequest-Handler-5:null) Caught: java.lang.NullPointerException at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:44:10,477 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Failed to start domain: s-833-VM: Cannot get interface MTU on 'cloudbr1': No such device 2013-02-15 16:44:10,478 WARN [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4: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:1038) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3087) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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-15 16:44:15,500 WARN [cloud.agent.Agent] (agentRequest-Handler-4:null) Caught: java.lang.NullPointerException at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.cleanupVMNetworks(LibvirtComputingResource.java:4214) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.handleVmStartFailure(LibvirtComputingResource.java:2983) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3107) at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1163) 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)
        Hide
        Fang Wang added a comment -

        This bug is not related to the new rpm package I built. The problem exists on the older existing rpm packages, for this 4.1 build.
        Please reassign.

        Show
        Fang Wang added a comment - This bug is not related to the new rpm package I built. The problem exists on the older existing rpm packages, for this 4.1 build. Please reassign.
        Hide
        Marcus Sorensen added a comment -

        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.

        Show
        Marcus Sorensen added a comment - 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.
        Hide
        angeline shen added a comment -

        As shown from the attached screen shots, CPVM and SSVM remain in starting state and never go to running state.
        Cannot locate any agent.log file on the host. In Cloudplatform, /var/log/cloud/agent/agent.log is generated on host.
        Investigating why there is no /var/log/cloudstack/agent/agent.log or anything similar in ASF 4.1

        Show
        angeline shen added a comment - As shown from the attached screen shots, CPVM and SSVM remain in starting state and never go to running state. Cannot locate any agent.log file on the host. In Cloudplatform, /var/log/cloud/agent/agent.log is generated on host. Investigating why there is no /var/log/cloudstack/agent/agent.log or anything similar in ASF 4.1
        Hide
        Marcus Sorensen added a comment -

        Were you able to determine if the VM is starting? The error saying that it
        won't start doesn't tell you of the VM is actually started, just that it
        cannot be logged into via ssh. If it is starting it would be useful to see
        an XML dump of the VM config, and what is on the video console. Have we
        determined that this tar contains recent 4.1 code? Do we have the agent
        logs? They're the most important.

        Show
        Marcus Sorensen added a comment - Were you able to determine if the VM is starting? The error saying that it won't start doesn't tell you of the VM is actually started, just that it cannot be logged into via ssh. If it is starting it would be useful to see an XML dump of the VM config, and what is on the video console. Have we determined that this tar contains recent 4.1 code? Do we have the agent logs? They're the most important.
        Hide
        angeline shen added a comment -

        Same problem reproduced with two older qemu rpm packages:

        qemu-img-0.12.1.2-2.295.el6.10.x86_64.rpm
        qemu-kvm-0.12.1.2-2.295.el6.10.x86_64.rpm

        MS 10.223.195.113 rhel6.3 build CloudStack-non-OSS-23-rhel6.3.tar.gz
        host 10.223.58.194 rhel6.3 build CloudStack-non-OSS-23-rhel6.3.tar.gz

        create zone results in CPVM SSVM not coming up

        MS log:

        2013-02-14 17:36:35,335 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1647706282: Processing: { Ans: , MgmtId: 6655051826959, 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-14 17:36:35,335 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 1-1647706283: Sending now. is current sequence.
        2013-02-14 17:36:35,336 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1647706282: Received: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 110,

        { Answer, Answer }

        }
        2013-02-14 17:36:35,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-14 17:36:35,344 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Cleaning up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
        2013-02-14 17:36:35,345 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1647706284: Waiting for Seq 1647706283 Scheduling: { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] }
        2013-02-14 17:36:35,392 DEBUG [agent.transport.Request] (AgentManager-Handler-11:null) Seq 1-1647706283: Processing: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }

        Show
        angeline shen added a comment - Same problem reproduced with two older qemu rpm packages: qemu-img-0.12.1.2-2.295.el6.10.x86_64.rpm qemu-kvm-0.12.1.2-2.295.el6.10.x86_64.rpm MS 10.223.195.113 rhel6.3 build CloudStack-non-OSS-23-rhel6.3.tar.gz host 10.223.58.194 rhel6.3 build CloudStack-non-OSS-23-rhel6.3.tar.gz create zone results in CPVM SSVM not coming up MS log: 2013-02-14 17:36:35,335 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1647706282: Processing: { Ans: , MgmtId: 6655051826959, 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-14 17:36:35,335 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 1-1647706283: Sending now. is current sequence. 2013-02-14 17:36:35,336 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1647706282: Received: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 110, { Answer, Answer } } 2013-02-14 17:36:35,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-14 17:36:35,344 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Cleaning up resources for the vm VM [ConsoleProxy|v-2-VM] in Starting state 2013-02-14 17:36:35,345 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1647706284: Waiting for Seq 1647706283 Scheduling: { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] } 2013-02-14 17:36:35,392 DEBUG [agent.transport.Request] (AgentManager-Handler-11:null) Seq 1-1647706283: Processing: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
        Hide
        Marcus Sorensen added a comment -

        angeline, there is no need for qemu-kvm package to have the kvm kernel module on your system. However, the qemu-kvm package may configure a modprobe file somewhere that automatically loads it.

        Fang, I replied to your other email about agent logging:

        Move /etc/cloudstack/agent/log4j-cloud.xml to
        /etc/cloudstack/agent/log4j.xml. If you don't have an /etc/cloudstack,
        but only /etc/cloud, you should build new 4.1 RPMs and install them.

        Show
        Marcus Sorensen added a comment - angeline, there is no need for qemu-kvm package to have the kvm kernel module on your system. However, the qemu-kvm package may configure a modprobe file somewhere that automatically loads it. Fang, I replied to your other email about agent logging: Move /etc/cloudstack/agent/log4j-cloud.xml to /etc/cloudstack/agent/log4j.xml. If you don't have an /etc/cloudstack, but only /etc/cloud, you should build new 4.1 RPMs and install them.
        Hide
        Fang Wang added a comment -

        Marcus, do you know where I can locate the agent.log on the host?
        I can only find the setup.log, and I check the log4j-cloud.xml, it has the agent.log, but it does not seem to use the xml.
        I want to look at the agent.log on the host to debug the issue

        Show
        Fang Wang added a comment - Marcus, do you know where I can locate the agent.log on the host? I can only find the setup.log, and I check the log4j-cloud.xml, it has the agent.log, but it does not seem to use the xml. I want to look at the agent.log on the host to debug the issue
        Hide
        angeline shen added a comment -

        Thank you Marcus. This confirms KVM host needs some version of qemu-kvm... rpm installed before being
        able to be added to Cloudstack setup.

        I was trying to test if the generic build exhibits CPVM SSVM problem. However , generic build does not contain
        qemu-kvm rpm required to be present on the KVM host. So could not even add host to setup.

        Show
        angeline shen added a comment - Thank you Marcus. This confirms KVM host needs some version of qemu-kvm... rpm installed before being able to be added to Cloudstack setup. I was trying to test if the generic build exhibits CPVM SSVM problem. However , generic build does not contain qemu-kvm rpm required to be present on the KVM host. So could not even add host to setup.
        Hide
        Marcus Sorensen added a comment -

        Q: Marcus: which ASF 4.1 build have you been debugging with which does not exhibit SSVM CPVM problem?

        I don't know anything about ASF 4.1 builds, I just test/develop against HEAD on the 4.1 branch, the latest.

        Q: Does KVM host requires qemu-kvm rpm?

        I think the cloudstack-agent rpm requires it, but otherwise as long as you have the binary for it to call it should work. Do you see them starting via 'virsh list', but they just are never accessible via network?

        This is interesting: 2013-02-14 13:22:35,130 DEBUG [kvm.discoverer.KvmServerDiscoverer] (catalina-exec-8:null) It's not a KVM enabled machine
        It looks like your KVM host does not have kvm kernel modules, either not loaded or no hardware support for virtualization. I'm sorry, i thought you had a running host you could deploy SSVM and CPVM to.

        Show
        Marcus Sorensen added a comment - Q: Marcus: which ASF 4.1 build have you been debugging with which does not exhibit SSVM CPVM problem? I don't know anything about ASF 4.1 builds, I just test/develop against HEAD on the 4.1 branch, the latest. Q: Does KVM host requires qemu-kvm rpm? I think the cloudstack-agent rpm requires it, but otherwise as long as you have the binary for it to call it should work. Do you see them starting via 'virsh list', but they just are never accessible via network? This is interesting: 2013-02-14 13:22:35,130 DEBUG [kvm.discoverer.KvmServerDiscoverer] (catalina-exec-8:null) It's not a KVM enabled machine It looks like your KVM host does not have kvm kernel modules, either not loaded or no hardware support for virtualization. I'm sorry, i thought you had a running host you could deploy SSVM and CPVM to.
        Hide
        angeline shen added a comment -

        1. I am testing kvm 6.3 snapshot feature in ASF 4.1. This feature requires two rpms provided by developer Fang Wang:
        qemu-img-0.12.1.2-3.295.el6.10.x86_64
        qemu-kvm-0.12.1.2-3.295.el6.10.x86_64

        Due to 4.1 packaging issues, prior to CloudStack-non-OSS-23-rhel6.3.tar.gz, build that included the above two modules were unable to install successfully. Pradeep.soundararajan@citrix.com built CloudStack-non-OSS-23-rhel6.3.tar.gz which includes old version of rpm qemu-img-0.12.1.2-3.209.el6.4.x86_64
        .
        The key is This build installs successfully on MS and host centos 6.3. Then I manually replaced old qemu-img with Fang's qemu-img plus add qemu-kvm. At least this installation works. However SSVM CPVM fail to
        come up .

        I just installed CloudStack-non-OSS-23-rhel6.3.tar.gz on MS 10.223.195.113 and host 10.223.58.194
        but on the host I did not replace Fang's two new rpms. During zone creation, add host failed. This is same problem I filed bug https://issues.apache.org/jira/browse/CLOUDSTACK-1204

        Does KVM host requires qemu-kvm rpm?

        Marcus: which ASF 4.1 build have you been debugging with which does not exhibit SSVM CPVM problem?

        MS 10.223.195.113 MS log re: add host failure:

        2013-02-14 13:22:28,540 INFO [cloud.resource.ResourceManagerImpl] (catalina-exec-8:null) Trying to add a new host at http://10.223.58.194 in data center 1
        2013-02-14 13:22:28,878 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm
        2013-02-14 13:22:31,026 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm
        2013-02-14 13:22:33,078 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm
        2013-02-14 13:22:35,130 DEBUG [kvm.discoverer.KvmServerDiscoverer] (catalina-exec-8:null) It's not a KVM enabled machine
        2013-02-14 13:22:35,133 WARN [cloud.resource.ResourceManagerImpl] (catalina-exec-8:null) Unable to find the server resources at http://10.223.58.194
        2013-02-14 13:22:35,136 INFO [utils.exception.CSExceptionErrorCode] (catalina-exec-8:null) Could not find exception: com.cloud.exception.DiscoveryException in error code list for exceptions
        2013-02-14 13:22:35,139 WARN [admin.host.AddHostCmd] (catalina-exec-8:null) Exception:
        com.cloud.exception.DiscoveryException: Unable to add the host
        at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:857)
        at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:609)
        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 org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143)
        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 com.cloud.utils.db.TransactionContextBuilder.invoke(TransactionContextBuilder.java:60)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:159)
        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.api.ApiServer.queueCommand(ApiServer.java:492)
        at com.cloud.api.ApiServer.handleRequest(ApiServer.java:341)
        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 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.api.ApiServlet.processRequest(ApiServlet.java:302)
        at com.cloud.api.ApiServlet.doPost(ApiServlet.java:71)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
        at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
        at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:721)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2268)
        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-14 13:22:35,143 INFO [cloud.api.ApiServer] (catalina-exec-8:null) Unable to add the host
        2013-02-14 13:22:35,144 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END=== 10.216.133.70 – POST command=addHost&response=json&sessionkey=bdDBniCLfN0K3dhGdr88PvfIq6U%3D
        2013-02-14 13:22:43,427 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Skip capacity scan due to there is no Primary Storage UPintenance mode
        2013-02-14 13:22:45,254 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.

        Show
        angeline shen added a comment - 1. I am testing kvm 6.3 snapshot feature in ASF 4.1. This feature requires two rpms provided by developer Fang Wang: qemu-img-0.12.1.2-3.295.el6.10.x86_64 qemu-kvm-0.12.1.2-3.295.el6.10.x86_64 Due to 4.1 packaging issues, prior to CloudStack-non-OSS-23-rhel6.3.tar.gz, build that included the above two modules were unable to install successfully. Pradeep.soundararajan@citrix.com built CloudStack-non-OSS-23-rhel6.3.tar.gz which includes old version of rpm qemu-img-0.12.1.2-3.209.el6.4.x86_64 . The key is This build installs successfully on MS and host centos 6.3. Then I manually replaced old qemu-img with Fang's qemu-img plus add qemu-kvm. At least this installation works. However SSVM CPVM fail to come up . I just installed CloudStack-non-OSS-23-rhel6.3.tar.gz on MS 10.223.195.113 and host 10.223.58.194 but on the host I did not replace Fang's two new rpms. During zone creation, add host failed. This is same problem I filed bug https://issues.apache.org/jira/browse/CLOUDSTACK-1204 Does KVM host requires qemu-kvm rpm? Marcus: which ASF 4.1 build have you been debugging with which does not exhibit SSVM CPVM problem? MS 10.223.195.113 MS log re: add host failure: 2013-02-14 13:22:28,540 INFO [cloud.resource.ResourceManagerImpl] (catalina-exec-8:null) Trying to add a new host at http://10.223.58.194 in data center 1 2013-02-14 13:22:28,878 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm 2013-02-14 13:22:31,026 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm 2013-02-14 13:22:33,078 DEBUG [utils.ssh.SSHCmdHelper] (catalina-exec-8:null) Executing cmd: lsmod|grep kvm 2013-02-14 13:22:35,130 DEBUG [kvm.discoverer.KvmServerDiscoverer] (catalina-exec-8:null) It's not a KVM enabled machine 2013-02-14 13:22:35,133 WARN [cloud.resource.ResourceManagerImpl] (catalina-exec-8:null) Unable to find the server resources at http://10.223.58.194 2013-02-14 13:22:35,136 INFO [utils.exception.CSExceptionErrorCode] (catalina-exec-8:null) Could not find exception: com.cloud.exception.DiscoveryException in error code list for exceptions 2013-02-14 13:22:35,139 WARN [admin.host.AddHostCmd] (catalina-exec-8:null) Exception: com.cloud.exception.DiscoveryException: Unable to add the host at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:857) at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:609) 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 org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:143) 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 com.cloud.utils.db.TransactionContextBuilder.invoke(TransactionContextBuilder.java:60) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:159) 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.api.ApiServer.queueCommand(ApiServer.java:492) at com.cloud.api.ApiServer.handleRequest(ApiServer.java:341) 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 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.api.ApiServlet.processRequest(ApiServlet.java:302) at com.cloud.api.ApiServlet.doPost(ApiServlet.java:71) at javax.servlet.http.HttpServlet.service(HttpServlet.java:637) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:721) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2268) 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-14 13:22:35,143 INFO [cloud.api.ApiServer] (catalina-exec-8:null) Unable to add the host 2013-02-14 13:22:35,144 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END=== 10.216.133.70 – POST command=addHost&response=json&sessionkey=bdDBniCLfN0K3dhGdr88PvfIq6U%3D 2013-02-14 13:22:43,427 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Skip capacity scan due to there is no Primary Storage UPintenance mode 2013-02-14 13:22:45,254 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
        Hide
        Marcus Sorensen added a comment -

        I mean debugging the 4.1 branch, not seeing an issue like this.

        Show
        Marcus Sorensen added a comment - I mean debugging the 4.1 branch, not seeing an issue like this.
        Hide
        Marcus Sorensen added a comment -

        I am using the 4.1 branch from git. There is no 4.1.0 yet. I don't know what CloudStack-non-OSS-23-rhel6.3.tar.gz is or where it came from, but there are a lot of issues with 4.1 basic functionality over the last day or two that have been fixed in git branch 4.1

        Show
        Marcus Sorensen added a comment - I am using the 4.1 branch from git. There is no 4.1.0 yet. I don't know what CloudStack-non-OSS-23-rhel6.3.tar.gz is or where it came from, but there are a lot of issues with 4.1 basic functionality over the last day or two that have been fixed in git branch 4.1
        Hide
        Fang Wang added a comment -

        Do you have a bug number for the issue you are debugging with VR and CP starting?

        Show
        Fang Wang added a comment - Do you have a bug number for the issue you are debugging with VR and CP starting?
        Hide
        Fang Wang added a comment -

        Marcus, you are using 4.1.0, right?
        I look at the log, and it does not seem to be caused by the special qemu-kvm patch. I suspect it is a general
        issue with 4.1.0
        Thanks

        Show
        Fang Wang added a comment - Marcus, you are using 4.1.0, right? I look at the log, and it does not seem to be caused by the special qemu-kvm patch. I suspect it is a general issue with 4.1.0 Thanks
        Hide
        Marcus Sorensen added a comment -

        Should this bug be targeting 4.1? Sounds like it's used for testing KVM snapshots according to the 'Environment' section, and requires custom qemu? I've otherwise installed 4.1 from git and have been debugging it for the past few days with virtual routers and consoleproxy starting.

        Show
        Marcus Sorensen added a comment - Should this bug be targeting 4.1? Sounds like it's used for testing KVM snapshots according to the 'Environment' section, and requires custom qemu? I've otherwise installed 4.1 from git and have been debugging it for the past few days with virtual routers and consoleproxy starting.
        Hide
        angeline shen added a comment -

        http://jenkins-ccp.citrix.com/view/ASF-Builds/ First group titled: ASF-build-4.1-nonoss-rhel63: build # 23 using 4.1.0
        Pradeep made this build with an older qemu-img version so that it will at least install successfully.
        Rayees also encountered same problem . His build also use 4.1.0

        Show
        angeline shen added a comment - http://jenkins-ccp.citrix.com/view/ASF-Builds/ First group titled: ASF-build-4.1-nonoss-rhel63: build # 23 using 4.1.0 Pradeep made this build with an older qemu-img version so that it will at least install successfully. Rayees also encountered same problem . His build also use 4.1.0
        Hide
        Fang Wang added a comment -

        which MS version youy are using? master or 4.x?

        Show
        Fang Wang added a comment - which MS version youy are using? master or 4.x?

          People

          • Assignee:
            Rohit Yadav
            Reporter:
            angeline shen
          • Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development