Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 6E43418C1E for ; Tue, 5 Jan 2016 12:12:40 +0000 (UTC) Received: (qmail 80149 invoked by uid 500); 5 Jan 2016 12:12:40 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 80121 invoked by uid 500); 5 Jan 2016 12:12:40 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 79954 invoked by uid 500); 5 Jan 2016 12:12:40 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 79898 invoked by uid 99); 5 Jan 2016 12:12:40 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 05 Jan 2016 12:12:40 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 03C002C1F64 for ; Tue, 5 Jan 2016 12:12:40 +0000 (UTC) Date: Tue, 5 Jan 2016 12:12:40 +0000 (UTC) From: "ASF GitHub Bot (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-9208) Assertion Error in VM_POWER_STATE handler. MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-9208?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15082942#comment-15082942 ] ASF GitHub Bot commented on CLOUDSTACK-9208: -------------------------------------------- Github user DaanHoogland commented on the pull request: https://github.com/apache/cloudstack/pull/1307#issuecomment-168983922 @kansal I remember a discussion in a prior PR but not the number. The scenario would be something like hypervisor has been disconnected or rebooted and cloudstack didn't try to restart the VM somewhere else. > 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)