[
https://issues.apache.org/jira/browse/CLOUDSTACK-9208?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15082477#comment-15082477
]
ASF GitHub Bot commented on CLOUDSTACK-9208:
--------------------------------------------
GitHub user kansal opened a pull request:
https://github.com/apache/cloudstack/pull/1307
CLOUDSTACK-9208: Assertion Error in VM_POWER_STATE handler- Fixed
Root Cause: In the case of VM_POWER_STATE handler, if PowerOff or
PowerReportMissing state is encountered,
handlePowerOffReportWithNoPendingJobsOnVM() is called. If the VM is already in
stopped state, so in DB the host ID is set to NULL. But in the above function,
the sendStop() is still called on the empty hostID which results in the
assertion error.
Fix: Added a condition in the sendStop() itself to check for the host id.
You can merge this pull request into a Git repository by running:
$ git pull https://github.com/kansal/cloudstack CLOUDSTACK-9208
Alternatively you can review and apply these changes as the patch at:
https://github.com/apache/cloudstack/pull/1307.patch
To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:
This closes #1307
----
commit ec7be7d18351ccd5a29c7db454bc4426bead9a79
Author: Kshitij Kansal <kansa...@gmail.com>
Date: 2016-01-05T06:17:09Z
CLOUDSTACK-9208: Assertion Error in VM_POWER_STATE handler- Fixed
----
> Assertion Error in VM_POWER_STATE handler.
> ------------------------------------------
>
> Key: CLOUDSTACK-9208
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9208
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Reporter: Kshitij Kansal
> Assignee: Kshitij Kansal
> Priority: Minor
>
> 1. Enable the assertions.
> LOG
> 2015-12-31 04:09:06,687 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:ctx-981a85d4) (logid:863754b8) Found 0 networks to
> update RvR status.
> 2015-12-31 04:09:07,394 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Ping from 5(10.147.40.18)
> 2015-12-31 04:09:07,394 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Process host VM state
> report from ping process. host: 5
> 2015-12-31 04:09:07,416 INFO [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Unable to find matched
> VM in CloudStack DB. name: New Virtual Machine
> 2015-12-31 04:09:07,420 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Process VM state report.
> host: 5, number of records in report: 5
> 2015-12-31 04:09:07,420 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) VM state report. host:
> 5, vm id: 69, power state: PowerOff
> 2015-12-31 04:09:07,530 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) VM state report is
> updated. host: 5, vm id: 69, power state: PowerOff
> 2015-12-31 04:09:07,540 INFO [c.c.v.VirtualMachineManagerImpl]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) VM r-69-VM is at Stopped
> and we received a power-off report while there is no pending jobs on it
> 2015-12-31 04:09:07,541 ERROR [o.a.c.f.m.MessageDispatcher]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Unexpected exception
> when calling
> com.cloud.vm.ClusteredVirtualMachineManagerImpl.HandlePowerStateReport
> java.lang.reflect.InvocationTargetException
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.apache.cloudstack.framework.messagebus.MessageDispatcher.dispatch(MessageDispatcher.java:75)
> at
> org.apache.cloudstack.framework.messagebus.MessageDispatcher.onPublishMessage(MessageDispatcher.java:45)
> at
> org.apache.cloudstack.framework.messagebus.MessageBusBase$SubscriptionNode.notifySubscribers(MessageBusBase.java:441)
> at
> org.apache.cloudstack.framework.messagebus.MessageBusBase.publish(MessageBusBase.java:178)
> at
> com.cloud.vm.VirtualMachinePowerStateSyncImpl.processReport(VirtualMachinePowerStateSyncImpl.java:87)
> at
> com.cloud.vm.VirtualMachinePowerStateSyncImpl.processHostVmStatePingReport(VirtualMachinePowerStateSyncImpl.java:70)
> at
> com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:2879)
> at
> com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:309)
> at
> com.cloud.agent.manager.DirectAgentAttache$PingTask.runInContext(DirectAgentAttache.java:192)
> 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 java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> 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: java.lang.AssertionError: Who's not checking the agent id before
> sending? ... (finger wagging)
> at com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:429)
> at com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:364)
> at
> com.cloud.vm.VirtualMachineManagerImpl.sendStop(VirtualMachineManagerImpl.java:1339)
> ... 27 more
> 2015-12-31 04:09:07,543 WARN [c.c.a.m.DirectAgentAttache]
> (DirectAgentCronJob-3:ctx-3ba82e46) (logid:02dcbd48) Unable to complete the
> ping task
> java.lang.RuntimeException: InvocationTargetException when invoking event
> handler for subject: vm.powerstate
> at
> org.apache.cloudstack.framework.messagebus.MessageDispatcher.dispatch(MessageDispatcher.java:84)
> at
> org.apache.cloudstack.framework.messagebus.MessageDispatcher.onPublishMessage(MessageDispatcher.java:45)
> at
> org.apache.cloudstack.framework.messagebus.MessageBusBase$SubscriptionNode.notifySubscribers(MessageBusBase.java:441)
> at
> org.apache.cloudstack.framework.messagebus.MessageBusBase.publish(MessageBusBase.java:178)
> at
> com.cloud.vm.VirtualMachinePowerStateSyncImpl.processReport(VirtualMachinePowerStateSyncImpl.java:87)
> at
> com.cloud.vm.VirtualMachinePowerStateSyncImpl.processHostVmStatePingReport(VirtualMachinePowerStateSyncImpl.java:70)
> at
> com.cloud.vm.VirtualMachineManagerImpl.processCommands(VirtualMachineManagerImpl.java:2879)
> at
> com.cloud.agent.manager.AgentManagerImpl.handleCommands(AgentManagerImpl.java:309)
> at
> com.cloud.agent.manager.DirectAgentAttache$PingTask.runInContext(DirectAgentAttache.java:192)
> 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 java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> 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)
> 2015-12-31 04:09:10,972 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-ff090f45) (logid:38f2d7f8) Zone 1 is ready to launch
> console proxy
> 2015-12-31 04:09:10,973 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-ff090f45) (logid:38f2d7f8) Zone 2 is not ready to launch
> console proxy yet
> 2015-12-31 04:09:11,153 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-4d8194c3) (logid:bdeb5f78) Zone 1 is ready to launch
> secondary storage VM
> 2015-12-31 04:09:11,166 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-4d8194c3) (logid:bdeb5f78) Zone 2 is not ready to launch
> secondary storage VM yet
> 2015-12-31 04:09:11,551 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-8:null) (logid SeqA 2-481000: Processing Seq 2-481000:
> { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":45,"_loadInfo":"
> {\n \"connections\": []\n}
> ","wait":0}}] }
> 2015-12-31 04:09:11,557 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-8:null) (logid SeqA 2-481000: Sending Seq 2-481000: {
> Ans: , MgmtId: 7020459589851, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-12-31 04:09:16,474 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-904c4f5a) (logid:7376bd5c) Begin cleanup expired
> async-jobs
> 2015-12-31 04:09:16,488 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-904c4f5a) (logid:7376bd5c) End cleanup expired
> async-jobs
> 2015-12-31 04:09:21,589 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-9:null) (logid SeqA 2-481001: Processing Seq 2-481001:
> { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":45,"_loadInfo":"
> {\n \"connections\": []\n}
> ","wait":0}}] }
> 2015-12-31 04:09:21,596 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-9:null) (logid SeqA 2-481001: Sending Seq 2-481001: {
> Ans: , MgmtId: 7020459589851, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2015-12-31 04:09:26,474 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-9f3afa6f) (logid:31dbd0f4) Begin cleanup expired
> async-jobs
> 2015-12-31 04:09:26,486 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-9f3afa6f) (logid:31dbd0f4) End cleanup expired
> async-jobs
> 2015-12-31 04:09:31,589 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-10:null) (logid SeqA 2-481002: Processing Seq 2-481002:
> { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":45,"_loadInfo":"
> {\n \"connections\": []\n}
> ","wait":0}}] }
> 2015-12-31 04:09:31,596 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
