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 | 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, 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>
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>>
>Date: Monday, March 17, 2014 at 11:25 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>>
>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>>:
>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>>
>Date: Monday, March 17, 2014 at 11:00 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>>
>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>>:
>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>>
>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 ?
>
>
>
