[
https://issues.apache.org/jira/browse/CLOUDSTACK-9208?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15956578#comment-15956578
]
ASF GitHub Bot commented on CLOUDSTACK-9208:
--------------------------------------------
Github user DaanHoogland commented on the issue:
https://github.com/apache/cloudstack/pull/1997
so that is two situations
1. it is known to be powered off (no sendStop() should be performed at all)
2. it is unknown because their is no report. Wouldn't one first check the
host to send the stop command to before sending it?
That said, I am +0 on this code, the check is not harming in any way.
> 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.15#6346)
