[
https://issues.apache.org/jira/browse/CLOUDSTACK-9208?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15083773#comment-15083773
]
ASF GitHub Bot commented on CLOUDSTACK-9208:
--------------------------------------------
Github user wido commented on the pull request:
https://github.com/apache/cloudstack/pull/1307#issuecomment-169132663
Agree with @DaanHoogland the code doesn't seem bad and probably fixes the
issue. But something is wrong here indeed. Codewise it looks good.
> 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)
