Ok, backend reports it correctly. So here is the sequence for the problem:
1. Backend – VR – report the networking data to the CS MS 2. Networking data never gets inserted to the cloud_usage DB. Kishan, can you please help to figure out why Usage server doesn’t insert this data to cloud_usage DB? Thanks, Alena. From: Diego Spinola Castro <spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>> Date: Tuesday, March 18, 2014 at 10:29 AM To: Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>> Cc: "users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>" <users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>, Kishan Kavala <kishan.kav...@citrix.com<mailto:kishan.kav...@citrix.com>> Subject: Re: NetworkUsage Take a look at: http://www.fpaste.org/86434/51637081/ 2014-03-18 14:15 GMT-03:00 Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>: Diego, Check for these messages in the CS log: [{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-3-VM","bytesSen t":0,"bytesReceived":0,"result":true,"details":"success","wait":0}}] } And see if you are seeing non-0 bytesReceived/bytesSent reported from the backend for any day after 2013-11-08 -Alena. From: Diego Spinola Castro <spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>> Date: Tuesday, March 18, 2014 at 10:12 AM To: Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>> Cc: "users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>" <users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>, Kishan Kavala <kishan.kav...@citrix.com<mailto:kishan.kav...@citrix.com>> Subject: Re: NetworkUsage Hi Alena, there's no records after 2013-11-08 (when i did the upgrade to CS 4.2). If there are no records for Feb2 in the DB, can you check if CS reported any usage during this day? How do i do that? 2014-03-18 13:45 GMT-03:00 Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>: Ok, so having 0 for some router records is actually fine as either the Vrs are stopped, or there are no vms. Good you’ve confirmed that’s not the problem. Now we have to debug something different – API not returning certain types of usage. For that, you have to: 1. go to cloud_usage DB 2. Select * from cloudusage where usage_type in (4,5) And see if there are any records for the Feb 2 are present. If there are, then its an API problem – when data is present in the DB, but API doesn’t return it. If there are no records for Feb2 in the DB, can you check if CS reported any usage during this day? Thanks, Alena. From: Diego Spinola Castro <spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>> Date: Tuesday, March 18, 2014 at 8:46 AM To: Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>> Cc: "users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>" <users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>, Kishan Kavala <kishan.kav...@citrix.com<mailto:kishan.kav...@citrix.com>> Subject: Re: NetworkUsage HI Alena, thanks for the answer. Let me explain better my case. Regarding those accounts , i have a lot of them without any instance running, there's also some vrouters of that list which are even stopped. I'm trying get the traffic count from usage api, i don't know why but all usage type 4 is zero, there's the commands i'm running: Trying get UsageType=4 curl "http://localhost:8096/client/api?command=listUsageRecords&startdate=2014-02-01&enddate=2014-02-01&type=4"; Neither Type 4 nor 5 are returning. This used to work before upgrade to 4.2. BTW i have only one management server. 2014-03-17 20:54 GMT-03:00 Alena Prokharchyk <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>: Diego, spent some more time on debugging your issue. Might not be related to transaction refactoring as it went in after 4.2. And records for some accounts actually got non-0 network stat: 0 network stats: mysql> select count(*) from user_statistics where net_bytes_received=0 or net_bytes_sent=0 order by account_id; +----------+ | count(*) | +----------+ | 26 | +----------+ 1 row in set (0.00 sec) Non-0 network stats mysql> select count(*) from user_statistics where net_bytes_received!=0 or net_bytes_sent!=0 order by account_id; +----------+ | count(*) | +----------+ | 207 | +----------+ 1 row in set (0.00 sec) Adding Kishan to the thread as he has more expertise in Network usage calculation and he might be able to help us. I would divide problematic accounts (Networks) that are not getting usage stats update, into 2 categories: CATEGORY #1 Networks having non-0 current_bytes* and 0 net_bytes received This situation is totally normal as net_bytes_received get updated only when VR gets stopped. Yet on Diego’s setup, those entries are not counted when do network usage calculation. Here is the account having problems: mysql> select * from user_statistics where account_id=176; +-----+----------------+------------+-------------------+-----------+------ --------+------------+--------------------+----------------+--------------- ---------+--------------------+--------------------+----------------+ | id | data_center_id | account_id | public_ip_address | device_id | device_type | network_id | net_bytes_received | net_bytes_sent | current_bytes_received | current_bytes_sent | agg_bytes_received | agg_bytes_sent | +-----+----------------+------------+-------------------+-----------+------ --------+------------+--------------------+----------------+--------------- ---------+--------------------+--------------------+----------------+ | 228 | 1 | 176 | NULL | 1193 | DomainRouter | 366 | 0 | 0 | 4271398427<tel:4271398427> | 2014478889 | 0 | 0 | +-----+----------------+------------+-------------------+-----------+------ --------+------------+--------------------+----------------+--------------- ---------+--------------------+--------------------+----------------+ 1 row in set (0.00 sec) And here is the Usage log: 1. 2014-03-17 03:15:02,779 DEBUG [usage.parser.NetworkUsageParser] (Usage-Job-1:null) Parsing all Network usage events for account: 176 2. 2014-03-17 03:15:02,779 DEBUG [usage.parser.NetworkUsageParser] (Usage-Job-1:null) No usage record (0 bytes used) generated for account: 176 Kishan, is it by design not to count current_bytes in network usage? Can you please double check the code, because it doesn’t look right to me as the VR may not go into Stopped state for a while, yet we have to calculate the usage CATEGORY #2 Accounts (networks) having all 0s for net_bytes_received/net_bytes_sent/current_bytes_received/current_bytes_sent Diego, for those accounts we have to figure out whether the backend reporting any usage for the Vrs. To debug that, you have to: A) get all the VR names mysql> select name from vm_instance where removed is null and vm_type='DomainRouter' and account_id in (select account_id from user_statistics where net_bytes_received = 0 and net_bytes_sent=0 and current_bytes_received=0 and curre +-----------+ | name | +-----------+ | r-621-VM | | r-651-VM | | r-658-VM | | r-671-VM | | r-682-VM | | r-886-VM | | r-892-VM | | r-915-VM | | r-934-VM | | r-935-VM | | r-986-VM | | r-1002-VM | | r-1004-VM | | r-1030-VM | | r-1148-VM | | r-1205-VM | | r-1221-VM | +-----------+ B) Search for NetworkUsageAnswer and routerName in the log to locate statements like that. Do it on your today’s log and the log(s) from couple of days before. You might also want to run some traffic 2014-03-17 14:41:12,661 DEBUG [agent.transport.Request] (DirectAgent-15:null) Seq 1-281411626: Processing: { Ans: , MgmtId: 4278190080<tel:4278190080>, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-3-VM","bytesSen t":0,"bytesReceived":0,"result":true,"details":"success","wait":0}}] } If you see that the backend reports non-0 value, it means that the Management server fails to save it. If the backend reports 0, and yet you are sure that there is a network traffic generated on the routers above, there might be some error in a way we collect the traffic on the VR. Also how many management servers do you have in your setup? -Alena. On 3/17/14, 12:05 PM, "Alena Prokharchyk" <alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>> wrote: >Diego, please go ahead and file a bug with Priority Critical against CS. >Looks like there is some bug in a way to commit db statement in >transaction resulting in the DB not being updated: > >2014-03-17 13:14:15,431 TRACE [db.Transaction.Transaction] >(RouterMonitor-1:null) txn: Not committing because transaction started >elsewhere: >-GenericDaoBase.update:814-ComponentInstantiationPostProcessor$Interceptor >Dispatcher.intercept:125-GenericDaoBase.update:774-ComponentInstantiationP >ostProcessor$InterceptorDispatcher.intercept:125-GenericDaoBase.update:126 >2-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125- >VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:948-Executors$Runn >ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAn >dReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165- >ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267 / >-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:900-Executors$Run >nableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runA >ndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165 >-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267-ThreadPoolExecuto >r.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:701 : >update, update, update, >-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:900-Executors$Run >nableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runA >ndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165 >-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267-ThreadPoolExecuto >r.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:701, > > > Attach the latest log from this email to the bug. > >Unfortunately, there is no way to workaround it on your side as its a >code issue. > >-Alena. > >From: Diego Spinola Castro ><spinolacas...@gmail.com<mailto:spinolacas...@gmail.com><mailto:spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>>> >Date: Monday, March 17, 2014 at 11:25 AM >To: Alena Prokharchyk ><alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com><mailto:alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>> >Cc: >"users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>" ><users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>> >Subject: Re: NetworkUsage > >Hi, sorry. i went lost with this huge log. > > > >2014-03-17 15:10 GMT-03:00 Alena Prokharchyk ><alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com><mailto:alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>>: >Diego, the log you’ve provided, doesn’t contain “Rolling back the >transaction” statement. You should wait for this particular error to >happen (while logging on TRACE), and then take a log snippet. > >From: Diego Spinola Castro ><spinolacas...@gmail.com<mailto:spinolacas...@gmail.com><mailto:spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>>> >Date: Monday, March 17, 2014 at 11:00 AM >To: Alena Prokharchyk ><alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com><mailto:alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>> >Cc: >"users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>" ><users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>> >Subject: Re: NetworkUsage > >Hi, Alena. thanks for the tips, i got some logs: >http://www.fpaste.org/86141/13950791/ > > >2014-03-17 14:27 GMT-03:00 Alena Prokharchyk ><alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com><mailto:alena.prokharc...@citrix.com<mailto:alena.prokharc...@citrix.com>>>: >Diego, > >Unfortunately CS lock lack the needed info for debugging the problem. I >see only transaction roll back statement: > >2014-03-17 06:01:22,363 DEBUG [db.Transaction.Transaction] >(RouterMonitor-1:null) Rolling back the transaction: Time = 2 Name = >-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:900-Executors$Run >n >ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAn >d >Reset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165- > > >To debug it further, you need to change the log level from DEBUG to TRACE >for a certain class by modifying log4 properties (no MS restart is >required) > > >Here is the link on how to do it: > >https://cwiki.apache.org/confluence/display/CLOUDSTACK/Useful+Tips+and+Tri >c >ks, "How to enable trace logging for a particular class in CloudStack?² >section. Replace category name with: > ><category name=³com.cloud.utils.db"> > <priority value=³TRACE"/> > </category> > > > > > >After the change is done, wait till you see TRACE statements in the log, >and till the error "Rolling back the transaction" occurs again. Take the >log snippet and send it out. After you are done with that, you will need >to remove TRACE config from log4 properties file, otherwise your logs will >grow huge. > >-Alena. > > >On 3/17/14, 9:48 AM, "Diego Spinola Castro" ><spinolacas...@gmail.com<mailto:spinolacas...@gmail.com><mailto:spinolacas...@gmail.com<mailto:spinolacas...@gmail.com>>> >wrote: > >>Hi guys, i've been running into a issue when getting network traffic from >>usage server. All records are Zero, i have a CS 4.2.0 install. >> >>Here the usage.logs http://www.fpaste.org/86116/13950748/ >>And management-server.log http://www.fpaste.org/86118/07486613/ >> >>Does anyone know what is wrong ? > > >
