[
https://issues.apache.org/jira/browse/CLOUDSTACK-7217?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14081521#comment-14081521
]
Prieur Leary commented on CLOUDSTACK-7217:
------------------------------------------
This is when the last VM tried to start.
2014-07-31 17:30:56,908 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Processing command: com.cloud.agent.api.StartCommand
2014-07-31 17:31:02,734 DEBUG [kvm.storage.KVMStoragePoolManager]
(agentRequest-Handler-2:null) Disconnecting disk
0f05b5b1-43da-42ff-92af-922bbf7d4554
2014-07-31 17:31:06,380 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Seq 14-4996743786567565373: { Ans: , MgmtId: 152663704217, via: 14, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answ$
2014-07-31 17:31:06,665 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Request:Seq 14-4996743786567565374: { Cmd , MgmtId: 152663704217, via: 14,
Ver: v1, Flags: 100011, [{"com.cloud.age$
2014-07-31 17:31:06,665 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Processing command: com.cloud.agent.api.StopCommand
2014-07-31 17:31:06,668 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: KVM, for vm: s-3893-VM,
continue
2014-07-31 17:31:06,670 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: LXC, for vm: s-3893-VM,
continue
2014-07-31 17:31:06,670 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find which hypervisor the vm used , then
use the default hypervisor
2014-07-31 17:31:06,672 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching n$
2014-07-31 17:31:06,674 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching n$
2014-07-31 17:31:06,676 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching n$
2014-07-31 17:31:06,676 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rul$
2014-07-31 17:31:06,858 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Execution is successful.
2014-07-31 17:31:06,859 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Try to stop the vm at first
2014-07-31 17:31:06,861 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) VM s-3893-VM doesn't exist, no need to stop it
2014-07-31 17:31:06,862 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Seq 14-4996743786567565374: { Ans: , MgmtId: 152663704217, via: 14, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Stop$
2014-07-31 17:31:11,401 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Processing command: com.cloud.agent.api.GetHostStatsCommand
2014-07-31 17:31:11,402 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep
Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle
2014-07-31 17:31:11,939 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2014-07-31 17:31:11,939 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing: /bin/bash -c freeMem=$(free|grep
cache:|awk '{print $4}');echo $freeMem
2014-07-31 17:31:11,945 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2014-07-31 17:31:11,945 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing: /bin/bash -c free|grep Mem:|awk
'{print $2}'
2014-07-31 17:31:11,950 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2014-07-31 17:31:27,051 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Found NFS storage pool d7e65e0e-9d21-3a24-ba56-45973c31dde7 in libvirt,
continuing
2014-07-31 17:31:27,051 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Executing:
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
10.30.0.155 -p /mnt/Primary201/Prima$
2014-07-31 17:31:27,068 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Execution is successful.
2014-07-31 17:31:27,072 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Found NFS storage pool cdad7fd2-36fe-37f3-bba2-04acb043ea78 in libvirt,
continuing
2014-07-31 17:31:27,072 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Executing:
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
10.30.0.5 -p /mnt/CS1/Primary -m /mn$
2014-07-31 17:31:27,086 DEBUG [kvm.resource.KVMHAMonitor] (Thread-20:null)
Execution is successful.
2014-07-31 17:31:27,442 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2014-07-31 17:31:27,595 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2014-07-31 17:31:27,679 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 14-18: { Cmd , MgmtId: -1, via: 14, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingRoutingWithNwGroupsComman$
2014-07-31 17:31:27,835 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
Received response: Seq 14-18: { Ans: , MgmtId: 152663704217, via: 14, Ver: v1,
Flags: 100010, [{"com.cloud.agent.api.PingA$
> Cannot launch VM after 4.4 Upgrade on KVM
> -----------------------------------------
>
> Key: CLOUDSTACK-7217
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7217
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: KVM, Management Server
> Affects Versions: 4.4.0
> Environment: CentOS 6
> Reporter: Prieur Leary
> Priority: Critical
>
> Cannot launch VM after 4.4 upgrade.
> Management server logs following:
> 2014-07-31 15:43:21,111 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053 ctx-1c0b8564) release
> cpu from host: 15, old used: 25500,reserved: 0, actual total$
> 2014-07-31 15:43:21,111 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053 ctx-1c0b8564) release
> mem from host: 15, old used: 37044092928,reserved: 0, total:$
> 2014-07-31 15:43:21,183 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053 ctx-1c0b8564)
> Invocation exception, caused by: com.cloud.exception.AgentUnavaila$
> 2014-07-31 15:43:21,183 INFO [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053 ctx-1c0b8564) Rethrow
> exception com.cloud.exception.AgentUnavailableException: R$
> 2014-07-31 15:43:21,183 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053) Done with run of VM
> work job: com.cloud.vm.VmWorkStart for VM 3783, job origin: 3$
> 2014-07-31 15:43:21,183 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053) Unable to complete
> AsyncJobVO {id:31053, userId: 1, accountId: 1, instanceType: n$
> com.cloud.exception.AgentUnavailableException: Resource [Host:15] is
> unreachable: Host 15: Unable to start instance due to Unable to get answer
> that is of class com.cloud.agent.api.StartAnswer
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1105)
> at
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
> at sun.reflect.GeneratedMethodAccessor296.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5335)
> at
> com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: 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.orchestrateStart(VirtualMachineManagerImpl.java:1019)
> ... 19 more
> 2014-07-31 15:43:21,185 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053) Complete async
> job-31053, jobStatus: FAILED, resultCode: 0, result: rO0ABXN$
> 2014-07-31 15:43:21,252 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-2:ctx-e03eec0e) VmStatsCollector is running...
> 2014-07-31 15:43:21,281 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Work-Job-Executor-157:ctx-089a5f26 job-30485/job-31053) Done executing
> com.cloud.vm.VmWorkStart for job-31053
> 2014-07-31 15:43:21,586 WARN [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-a3cfb728) Exception while trying to start secondary storage
> vm
> java.lang.RuntimeException: Job failed due to exception Resource [Host:15] is
> unreachable: Host 15: Unable to start instance due to Unable to get answer
> that is of class com.cloud.agent.api.StartA$
> at
> com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
--
This message was sent by Atlassian JIRA
(v6.2#6252)
