Harikrishna Patnala created CLOUDSTACK-9094:
-----------------------------------------------
Summary: Multiple threads are being used to collect the stats from
the same VR
Key: CLOUDSTACK-9094
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9094
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server, Virtual Router
Affects Versions: 4.6.0
Reporter: Harikrishna Patnala
Assignee: Harikrishna Patnala
Fix For: 4.7.0
>From the logs we can see that the management server is sending the
>networkusagecommand to a VR twice within a very short interval. This doesn't
>have any impact on the network usage being reported, however it seems to
>consume direct agent threads unnecessarily.
See the below snippet from the logs where networkusage command was sent to the
same VR at the same time
2014-03-04 00:02:07,178 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-113:null) Seq 10-1242718973: Executing request
2014-03-04 00:02:07,482 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-113:null) Seq 10-1242718973: Response Received:
2014-03-04 00:02:07,482 DEBUG [agent.transport.Request] (DirectAgent-113:null)
Seq 10-1242718973: Processing: { Ans: , MgmtId: 144027776315500, via: 10, Ver:
v1, Flags: 10,
[{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-59-VM","bytesSent":2937782,"bytesReceived":114175352,"result":true,"details":"","wait":0}}]
}
2014-03-04 00:02:07,482 DEBUG [agent.transport.Request] (RouterMonitor-1:null)
Seq 10-1242718973: Received: { Ans: , MgmtId: 144027776315500, via: 10, Ver:
v1, Flags: 10, { NetworkUsageAnswer } }
2014-03-04 00:02:07,482 DEBUG [agent.manager.AgentManagerImpl]
(RouterMonitor-1:null) Details from executing class
com.cloud.agent.api.NetworkUsageCommand:
2014-03-04 00:02:07,198 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-244:null) Seq 10-1242718974: Executing request
2014-03-04 00:02:07,510 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-244:null) Seq 10-1242718974: Response Received:
2014-03-04 00:02:07,510 DEBUG [agent.transport.Request] (DirectAgent-244:null)
Seq 10-1242718974: Processing: { Ans: , MgmtId: 144027776315500, via: 10, Ver:
v1, Flags: 10,
[{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-59-VM","bytesSent":2937782,"bytesReceived":114175352,"result":true,"details":"","wait":0}}]
}
2014-03-04 00:02:07,510 DEBUG [agent.transport.Request] (RouterMonitor-1:null)
Seq 10-1242718974: Received: { Ans: , MgmtId: 144027776315500, via: 10, Ver:
v1, Flags: 10, { NetworkUsageAnswer } }
2014-03-04 00:02:07,510 DEBUG [agent.manager.AgentManagerImpl]
(RouterMonitor-1:null) Details from executing class
com.cloud.agent.api.NetworkUsageCommand:
2014-03-04 00:02:07,513 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null)
Router stats changed from the time NetworkUsageCommand was sent. Ignoring
current answer. Router: r-59-VM Rcvd: 114175352Sent: 2937782
2014-03-04 00:02:07,514 DEBUG [db.Transaction.Transaction]
(RouterMonitor-1:null) Rolling back the transaction: Time = 2 Name =
-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:900-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267-ThreadPoolExecutor.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:701;
called by
-Transaction.rollback:897-Transaction.removeUpTo:840-Transaction.close:664-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:955-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267-ThreadPoolExecutor.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:701
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
