You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "sadhu suresh (JIRA)" <ji...@apache.org> on 2014/01/02 09:49:50 UTC
[jira] [Updated] (CLOUDSTACK-5713) kvm:NPE when agentmanager tries
to update the destroyed vm state during vmsync
[ https://issues.apache.org/jira/browse/CLOUDSTACK-5713?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
sadhu suresh updated CLOUDSTACK-5713:
-------------------------------------
Description:
env:4.3,kvm
steps:
1. create a advanced zone and add a host
2. deploy 2 vms
3. from host destroy the vm
4. check the vm state in Cloudstack
actual result:
during vm sync ,agent manager throws NULLpointer exception and due to this it fail to update the vm state.
VM":{"state":"PowerOn","host":"centos62"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":3,"wait":0}}] }
2014-01-02 08:56:14,614 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
2014-01-02 08:56:14,615 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
2014-01-02 08:56:14,672 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM does not require investigation so I'm marking it as Stopped: VM[User|vm2]
2014-01-02 08:56:14,673 WARN [o.a.c.alerts] (AgentManager-Handler-13:null) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: VM (name: vm2, id: 7) stopped unexpectedly on host id:3, availability zone id:1, pod id:1
2014-01-02 08:56:14,786 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM is not HA enabled so we're done.
2014-01-02 08:56:14,825 WARN [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) Caught:
java.lang.NullPointerException
at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1268)
at com.cloud.ha.HighAvailabilityManagerImpl.scheduleRestart(HighAvailabilityManagerImpl.java:346)
at com.cloud.vm.VirtualMachineManagerImpl.compareState(VirtualMachineManagerImpl.java:2719)
at com.cloud.vm.VirtualMachineManagerImpl.deltaHostSync(VirtualMachineManagerImpl.java:2325)
at com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:2855)
at com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:292)
at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.processRequest(AgentManagerImpl.java:1184)
at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.doTask(AgentManagerImpl.java:1270)
at com.cloud.agent.manager.ClusteredAgentManagerImpl$ClusteredAgentHandler.doTask(ClusteredAgentManagerImpl.java:677)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2014-01-02 08:56:14,827 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 3-196: Sending Seq 3-196: { Ans: , MgmtId: 7020459589851, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.Answer":{"result":false,"wait":0}}] }
2014-01-02 08:56:15,657 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Processing Seq 4-1523: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2014-01-02 08:56:15,755 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Sending Seq 4-1523: { Ans: , MgmtId: 7020459589851, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
virsh # destroy i-2-7-VM
Domain i-2-7-VM destroyed
virsh # list
Id Name State
----------------------------------------------------
1 s-4-VM running
2 v-3-VM running
3 r-6-VM running
but on cloudstack it still shows as running.
mysql> select * from vm_instance where id=7\G;
*************************** 1. row ***************************
id: 7
name: vm2
uuid: ff79a39f-0309-47c9-be1a-62b7f9223943
instance_name: i-2-7-VM
state: Running
vm_template_id: 4
guest_os_id: 112
private_mac_address: 02:00:52:5d:00:03
private_ip_address: 10.1.1.240
pod_id: 1
data_center_id: 1
host_id: 3
last_host_id: 3
proxy_id: NULL
proxy_assign_time: NULL
vnc_password: U8wzZMnrqJ/JXjGSV5QeStfk3S6tTpeN
ha_enabled: 0
limit_cpu_use: 0
update_count: 3
update_time: 2014-01-02 11:11:39
created: 2014-01-02 11:11:36
removed: NULL
type: User
vm_type: User
account_id: 2
domain_id: 1
service_offering_id: 1
reservation_id: ab656607-c35a-409e-90aa-9a029703b3ef
hypervisor_type: KVM
disk_offering_id: NULL
owner: 2
host_name: vm2
display_name: vm2
desired_state: NULL
dynamically_scalable: 0
display_vm: 1
power_state: NULL
power_state_update_time: NULL
power_state_update_count: 0
power_host: NULL
1 row in set (0.00 sec)
was:
env:4.3,kvm
steps:
1. create a advanced zone and add a host
2. deploy 2 vms
3. from host stop the vm
4. check the vm state in Cloudstack
actual result:
during vm sync ,agent manager throws NULLpointer exception and due to this it fail to update the vm state.
VM":{"state":"PowerOn","host":"centos62"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":3,"wait":0}}] }
2014-01-02 08:56:14,614 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
2014-01-02 08:56:14,615 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
2014-01-02 08:56:14,672 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM does not require investigation so I'm marking it as Stopped: VM[User|vm2]
2014-01-02 08:56:14,673 WARN [o.a.c.alerts] (AgentManager-Handler-13:null) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: VM (name: vm2, id: 7) stopped unexpectedly on host id:3, availability zone id:1, pod id:1
2014-01-02 08:56:14,786 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM is not HA enabled so we're done.
2014-01-02 08:56:14,825 WARN [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) Caught:
java.lang.NullPointerException
at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1268)
at com.cloud.ha.HighAvailabilityManagerImpl.scheduleRestart(HighAvailabilityManagerImpl.java:346)
at com.cloud.vm.VirtualMachineManagerImpl.compareState(VirtualMachineManagerImpl.java:2719)
at com.cloud.vm.VirtualMachineManagerImpl.deltaHostSync(VirtualMachineManagerImpl.java:2325)
at com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:2855)
at com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:292)
at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.processRequest(AgentManagerImpl.java:1184)
at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.doTask(AgentManagerImpl.java:1270)
at com.cloud.agent.manager.ClusteredAgentManagerImpl$ClusteredAgentHandler.doTask(ClusteredAgentManagerImpl.java:677)
at com.cloud.utils.nio.Task.run(Task.java:83)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:701)
2014-01-02 08:56:14,827 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 3-196: Sending Seq 3-196: { Ans: , MgmtId: 7020459589851, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.Answer":{"result":false,"wait":0}}] }
2014-01-02 08:56:15,657 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Processing Seq 4-1523: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2014-01-02 08:56:15,755 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Sending Seq 4-1523: { Ans: , MgmtId: 7020459589851, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
virsh # destroy i-2-7-VM
Domain i-2-7-VM destroyed
virsh # list
Id Name State
----------------------------------------------------
1 s-4-VM running
2 v-3-VM running
3 r-6-VM running
but on cloudstack it still shows as running.
mysql> select * from vm_instance where id=7\G;
*************************** 1. row ***************************
id: 7
name: vm2
uuid: ff79a39f-0309-47c9-be1a-62b7f9223943
instance_name: i-2-7-VM
state: Running
vm_template_id: 4
guest_os_id: 112
private_mac_address: 02:00:52:5d:00:03
private_ip_address: 10.1.1.240
pod_id: 1
data_center_id: 1
host_id: 3
last_host_id: 3
proxy_id: NULL
proxy_assign_time: NULL
vnc_password: U8wzZMnrqJ/JXjGSV5QeStfk3S6tTpeN
ha_enabled: 0
limit_cpu_use: 0
update_count: 3
update_time: 2014-01-02 11:11:39
created: 2014-01-02 11:11:36
removed: NULL
type: User
vm_type: User
account_id: 2
domain_id: 1
service_offering_id: 1
reservation_id: ab656607-c35a-409e-90aa-9a029703b3ef
hypervisor_type: KVM
disk_offering_id: NULL
owner: 2
host_name: vm2
display_name: vm2
desired_state: NULL
dynamically_scalable: 0
display_vm: 1
power_state: NULL
power_state_update_time: NULL
power_state_update_count: 0
power_host: NULL
1 row in set (0.00 sec)
Fix Version/s: 4.3.0
Assignee: Kelven Yang
Summary: kvm:NPE when agentmanager tries to update the destroyed vm state during vmsync (was: kvm:NPE when agentmanager tries to update the stopped vm state during vmsync)
> kvm:NPE when agentmanager tries to update the destroyed vm state during vmsync
> -------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-5713
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5713
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: KVM
> Affects Versions: 4.3.0
> Reporter: sadhu suresh
> Assignee: Kelven Yang
> Priority: Critical
> Fix For: 4.3.0
>
>
> env:4.3,kvm
> steps:
> 1. create a advanced zone and add a host
> 2. deploy 2 vms
> 3. from host destroy the vm
> 4. check the vm state in Cloudstack
> actual result:
> during vm sync ,agent manager throws NULLpointer exception and due to this it fail to update the vm state.
> VM":{"state":"PowerOn","host":"centos62"}},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":3,"wait":0}}] }
> 2014-01-02 08:56:14,614 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
> 2014-01-02 08:56:14,615 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentManager-Handler-13:null) VM i-2-7-VM: cs state = Running and realState = Stopped
> 2014-01-02 08:56:14,672 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM does not require investigation so I'm marking it as Stopped: VM[User|vm2]
> 2014-01-02 08:56:14,673 WARN [o.a.c.alerts] (AgentManager-Handler-13:null) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: VM (name: vm2, id: 7) stopped unexpectedly on host id:3, availability zone id:1, pod id:1
> 2014-01-02 08:56:14,786 DEBUG [c.c.h.HighAvailabilityManagerImpl] (AgentManager-Handler-13:null) VM is not HA enabled so we're done.
> 2014-01-02 08:56:14,825 WARN [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) Caught:
> java.lang.NullPointerException
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1268)
> at com.cloud.ha.HighAvailabilityManagerImpl.scheduleRestart(HighAvailabilityManagerImpl.java:346)
> at com.cloud.vm.VirtualMachineManagerImpl.compareState(VirtualMachineManagerImpl.java:2719)
> at com.cloud.vm.VirtualMachineManagerImpl.deltaHostSync(VirtualMachineManagerImpl.java:2325)
> at com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:2855)
> at com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:292)
> at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.processRequest(AgentManagerImpl.java:1184)
> at com.cloud.agent.manager.AgentManagerImpl$AgentHandler.doTask(AgentManagerImpl.java:1270)
> at com.cloud.agent.manager.ClusteredAgentManagerImpl$ClusteredAgentHandler.doTask(ClusteredAgentManagerImpl.java:677)
> at com.cloud.utils.nio.Task.run(Task.java:83)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:701)
> 2014-01-02 08:56:14,827 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 3-196: Sending Seq 3-196: { Ans: , MgmtId: 7020459589851, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.Answer":{"result":false,"wait":0}}] }
> 2014-01-02 08:56:15,657 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Processing Seq 4-1523: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> 2014-01-02 08:56:15,755 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-1523: Sending Seq 4-1523: { Ans: , MgmtId: 7020459589851, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> virsh # destroy i-2-7-VM
> Domain i-2-7-VM destroyed
> virsh # list
> Id Name State
> ----------------------------------------------------
> 1 s-4-VM running
> 2 v-3-VM running
> 3 r-6-VM running
> but on cloudstack it still shows as running.
> mysql> select * from vm_instance where id=7\G;
> *************************** 1. row ***************************
> id: 7
> name: vm2
> uuid: ff79a39f-0309-47c9-be1a-62b7f9223943
> instance_name: i-2-7-VM
> state: Running
> vm_template_id: 4
> guest_os_id: 112
> private_mac_address: 02:00:52:5d:00:03
> private_ip_address: 10.1.1.240
> pod_id: 1
> data_center_id: 1
> host_id: 3
> last_host_id: 3
> proxy_id: NULL
> proxy_assign_time: NULL
> vnc_password: U8wzZMnrqJ/JXjGSV5QeStfk3S6tTpeN
> ha_enabled: 0
> limit_cpu_use: 0
> update_count: 3
> update_time: 2014-01-02 11:11:39
> created: 2014-01-02 11:11:36
> removed: NULL
> type: User
> vm_type: User
> account_id: 2
> domain_id: 1
> service_offering_id: 1
> reservation_id: ab656607-c35a-409e-90aa-9a029703b3ef
> hypervisor_type: KVM
> disk_offering_id: NULL
> owner: 2
> host_name: vm2
> display_name: vm2
> desired_state: NULL
> dynamically_scalable: 0
> display_vm: 1
> power_state: NULL
> power_state_update_time: NULL
> power_state_update_count: 0
> power_host: NULL
> 1 row in set (0.00 sec)
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)