Carlos, this one is nothing to worry about, except when you want to use the
usage service. it is an error in the handling of xapi output that causes
the stats collection to stop. It should be fixed in newer versions, safe
that it encounters a vm for which it can not collect data. volume data IIRC.
On Mon, Sep 29, 2014 at 7:10 PM, Carlos Reategui <create...@gmail.com>
wrote:
> Hi All,
> I have a small deployment that has been happily running for a while which I
> upgraded to 4.3 a few months ago and recently to 4.3.1 and things still
> continued to be fine. I was looking through the logs today and found the
> following. Is this something to worry about?
>
> thanks
> Carlos
>
>
> 2014-09-29 09:57:45,977 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-3:ctx-2442c5e7) StorageCollector is running...
>
> 2014-09-29 09:57:46,118 DEBUG [c.c.a.t.Request]
> (StatsCollector-3:ctx-2442c5e7) Seq 6-1169489929: Received: { Ans: ,
> MgmtId: 233845174730255, via: 6, Ver: v1, Flags: 10, { GetStorageStatsAnsw
>
> er } }
>
> 2014-09-29 09:57:46,126 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-15:ctx-d4cc7fd1) Seq 1-1343946763: Executing request
>
> 2014-09-29 09:57:46,505 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-12:ctx-4723a663) Seq 1-1343946761: Response Received:
>
> 2014-09-29 09:57:46,506 DEBUG [c.c.a.t.Request]
> (StatsCollector-1:ctx-e9025fba) Seq 1-1343946761: Received: { Ans: ,
> MgmtId: 233845174730255, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer
>
> } }
>
> 2014-09-29 09:57:46,521 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-16:ctx-42c4666a) Seq 2-868941833: Executing request
>
> 2014-09-29 09:57:46,843 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.8262499999999999
>
> 2014-09-29 09:57:46,843 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.155
>
> 2014-09-29 09:57:46,843 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 98.50999999999999
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.10999999999999999
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.11250000000000002
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.11
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.11
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.73
>
> 2014-09-29 09:57:46,844 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Vm cpu utilization 0.16999999999999998
>
> 2014-09-29 09:57:46,908 WARN [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-14:ctx-8c8b0402) Error while collecting disk stats from :
>
> You gave an invalid object reference. The object may have recently been
> deleted. The class parameter gives the type of reference given, and the
> handle parameter echoes the bad value given.
>
> at com.xensource.xenapi.Types.checkResponse(Types.java:209)
>
> at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
>
> at
>
> com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
>
> at
> com.xensource.xenapi.VBDMetrics.getIoReadKbs(VBDMetrics.java:210)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.getVmStats(CitrixResourceBase.java:2863)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2763)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:493)
>
> at
>
> com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>
> at
>
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
>
> 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.run(FutureTask.java:262)
>
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
>
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
>
> 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)
>
> 2014-09-29 09:57:46,910 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-14:ctx-8c8b0402) Seq 1-1343946762: Response Received:
>
> 2014-09-29 09:57:46,910 DEBUG [c.c.a.t.Request]
> (StatsCollector-2:ctx-062f6e46) Seq 1-1343946762: Received: { Ans: ,
> MgmtId: 233845174730255, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer }
>
> }
>
> 2014-09-29 09:57:46,951 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-17:ctx-eace30a5) Seq 2-868941834: Executing request
>
> 2014-09-29 09:57:46,959 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-16:ctx-42c4666a) Seq 2-868941833: Response Received:
>
> 2014-09-29 09:57:46,959 DEBUG [c.c.a.t.Request]
> (StatsCollector-1:ctx-e9025fba) Seq 2-868941833: Received: { Ans: ,
> MgmtId: 233845174730255, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer }
> }
>
> 2014-09-29 09:57:47,667 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-15:ctx-d4cc7fd1) Seq 1-1343946763: Response Received:
>
> 2014-09-29 09:57:47,667 DEBUG [c.c.a.t.Request]
> (StatsCollector-3:ctx-2442c5e7) Seq 1-1343946763: Received: { Ans: ,
> MgmtId: 233845174730255, via: 1, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
>
> 2014-09-29 09:57:47,673 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-18:ctx-b8ff00e6) Seq 2-868941835: Executing request
>
> 2014-09-29 09:57:47,771 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.31
>
> 2014-09-29 09:57:47,771 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.26
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.22999999999999998
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.69
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.0
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.26
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.18
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.27
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.21
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.17
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.11499999999999999
>
> 2014-09-29 09:57:47,772 DEBUG [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Vm cpu utilization 0.2
>
> 2014-09-29 09:57:47,851 WARN [c.c.h.x.r.CitrixResourceBase]
> (DirectAgent-17:ctx-eace30a5) Error while collecting disk stats from :
>
> You gave an invalid object reference. The object may have recently been
> deleted. The class parameter gives the type of reference given, and the
> handle parameter echoes the bad value given.
>
> at com.xensource.xenapi.Types.checkResponse(Types.java:209)
>
> at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
>
> at
>
> com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
>
> at
> com.xensource.xenapi.VBDMetrics.getIoReadKbs(VBDMetrics.java:210)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.getVmStats(CitrixResourceBase.java:2863)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2763)
>
> at
>
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:493)
>
> at
>
> com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>
> at
>
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
>
> 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.run(FutureTask.java:262)
>
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
>
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
>
> 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)
>
> 2014-09-29 09:57:47,852 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-17:ctx-eace30a5) Seq 2-868941834: Response Received:
>
> 2014-09-29 09:57:47,853 DEBUG [c.c.a.t.Request]
> (StatsCollector-2:ctx-062f6e46) Seq 2-868941834: Received: { Ans: ,
> MgmtId: 233845174730255, via: 2, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
>
> 2014-09-29 09:57:48,474 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-18:ctx-b8ff00e6) Seq 2-868941835: Response Received:
>
> 2014-09-29 09:57:48,475 DEBUG [c.c.a.t.Request]
> (StatsCollector-3:ctx-2442c5e7) Seq 2-868941835: Received: { Ans: ,
> MgmtId: 233845174730255, via: 2, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
>
> 2014-09-29 09:57:48,480 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-8:ctx-b5417deb) Seq 1-1343946764: Executing request
>
> 2014-09-29 09:57:49,872 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-8:ctx-b5417deb) Seq 1-1343946764: Response Received:
>
> 2014-09-29 09:57:49,872 DEBUG [c.c.a.t.Request]
> (StatsCollector-3:ctx-2442c5e7) Seq 1-1343946764: Received: { Ans: ,
> MgmtId: 233845174730255, via: 1, Ver: v1, Flags: 10, {
> GetStorageStatsAnswer } }
>
> 2014-09-29 09:57:51,198 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-15:null) SeqA 9-1076169: Processing Seq 9-1076169: {
> Cmd , MgmtId: -1, via: 9, Ver: v1, Flags: 11,
>
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":90,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
>
--
Daan
