You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Diego Spinola Castro <sp...@gmail.com> on 2014/03/17 17:48:57 UTC
NetworkUsage
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 ?
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@citrix.com>.
Kishan, can you please help Diego to debug further this network usage problem? We’ve already figured out its not a backend problem, and management server updates its cloud db correctly. So there is something off with the usage component not cherry-picking the data from cloud to cloud_usage db.
Thanks,
Alena.
From: Diego Spinola Castro <sp...@gmail.com>>
Date: Wednesday, March 26, 2014 at 5:41 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: Kishan Kavala <Ki...@citrix.com>>, "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>
Subject: Re: NetworkUsage
Hi guys, just bumping up this issue.
2014-03-18 15:01 GMT-03:00 Alena Prokharchyk <Al...@citrix.com>>:
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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 10:29 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 10:12 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 8:46 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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" <Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:25 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:00 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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"
><sp...@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 ?
>
>
>
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
Hi guys, just bumping up this issue.
2014-03-18 15:01 GMT-03:00 Alena Prokharchyk <Al...@citrix.com>:
> 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 <sp...@gmail.com>
> Date: Tuesday, March 18, 2014 at 10:29 AM
>
> To: Alena Prokharchyk <al...@citrix.com>
> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
> Kavala <Ki...@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.Prokharchyk@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 <sp...@gmail.com>
>> Date: Tuesday, March 18, 2014 at 10:12 AM
>>
>> To: Alena Prokharchyk <al...@citrix.com>
>> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
>> Kavala <Ki...@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.Prokharchyk@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 <sp...@gmail.com>
>>> Date: Tuesday, March 18, 2014 at 8:46 AM
>>> To: Alena Prokharchyk <al...@citrix.com>
>>> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
>>> Kavala <Ki...@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.Prokharchyk@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 | 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.Prokharchyk@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
>>>> ><sp...@gmail.com>>
>>>> >Date: Monday, March 17, 2014 at 11:25 AM
>>>> >To: Alena Prokharchyk
>>>> ><al...@citrix.com>>
>>>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>>>> ><us...@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
>>>> ><Al...@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
>>>> ><sp...@gmail.com>>
>>>> >Date: Monday, March 17, 2014 at 11:00 AM
>>>> >To: Alena Prokharchyk
>>>> ><al...@citrix.com>>
>>>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>>>> ><us...@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
>>>> ><Al...@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"
>>>> ><sp...@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 ?
>>>> >
>>>> >
>>>> >
>>>>
>>>>
>>>
>>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@citrix.com>.
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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 10:29 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 10:12 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 8:46 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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" <Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:25 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:00 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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"
><sp...@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 ?
>
>
>
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
Take a look at: http://www.fpaste.org/86434/51637081/
2014-03-18 14:15 GMT-03:00 Alena Prokharchyk <Al...@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 <sp...@gmail.com>
> Date: Tuesday, March 18, 2014 at 10:12 AM
>
> To: Alena Prokharchyk <al...@citrix.com>
> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
> Kavala <Ki...@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.Prokharchyk@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 <sp...@gmail.com>
>> Date: Tuesday, March 18, 2014 at 8:46 AM
>> To: Alena Prokharchyk <al...@citrix.com>
>> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
>> Kavala <Ki...@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.Prokharchyk@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 | 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" <Al...@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
>>> ><sp...@gmail.com>>
>>> >Date: Monday, March 17, 2014 at 11:25 AM
>>> >To: Alena Prokharchyk
>>> ><al...@citrix.com>>
>>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>>> ><us...@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
>>> ><Al...@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
>>> ><sp...@gmail.com>>
>>> >Date: Monday, March 17, 2014 at 11:00 AM
>>> >To: Alena Prokharchyk
>>> ><al...@citrix.com>>
>>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>>> ><us...@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
>>> ><Al...@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"
>>> ><sp...@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 ?
>>> >
>>> >
>>> >
>>>
>>>
>>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 10:12 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 8:46 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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" <Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:25 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:00 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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"
><sp...@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 ?
>
>
>
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
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 <Al...@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 <sp...@gmail.com>
> Date: Tuesday, March 18, 2014 at 8:46 AM
> To: Alena Prokharchyk <al...@citrix.com>
> Cc: "users@cloudstack.apache.org" <us...@cloudstack.apache.org>, Kishan
> Kavala <Ki...@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.Prokharchyk@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 | 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" <Al...@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
>> ><sp...@gmail.com>>
>> >Date: Monday, March 17, 2014 at 11:25 AM
>> >To: Alena Prokharchyk
>> ><al...@citrix.com>>
>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>> ><us...@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
>> ><Al...@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
>> ><sp...@gmail.com>>
>> >Date: Monday, March 17, 2014 at 11:00 AM
>> >To: Alena Prokharchyk
>> ><al...@citrix.com>>
>> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
>> ><us...@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
>> ><Al...@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"
>> ><sp...@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 ?
>> >
>> >
>> >
>>
>>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@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 <sp...@gmail.com>>
Date: Tuesday, March 18, 2014 at 8:46 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@cloudstack.apache.org>>, Kishan Kavala <Ki...@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 <Al...@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 | 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" <Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:25 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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
><sp...@gmail.com>>>
>Date: Monday, March 17, 2014 at 11:00 AM
>To: Alena Prokharchyk
><al...@citrix.com>>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>>"
><us...@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
><Al...@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"
><sp...@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 ?
>
>
>
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
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 <Al...@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 | 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" <Al...@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
> ><sp...@gmail.com>>
> >Date: Monday, March 17, 2014 at 11:25 AM
> >To: Alena Prokharchyk
> ><al...@citrix.com>>
> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
> ><us...@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
> ><Al...@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
> ><sp...@gmail.com>>
> >Date: Monday, March 17, 2014 at 11:00 AM
> >To: Alena Prokharchyk
> ><al...@citrix.com>>
> >Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
> ><us...@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
> ><Al...@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"
> ><sp...@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 ?
> >
> >
> >
>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@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 | 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" <Al...@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
><sp...@gmail.com>>
>Date: Monday, March 17, 2014 at 11:25 AM
>To: Alena Prokharchyk
><al...@citrix.com>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
><us...@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
><Al...@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
><sp...@gmail.com>>
>Date: Monday, March 17, 2014 at 11:00 AM
>To: Alena Prokharchyk
><al...@citrix.com>>
>Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>"
><us...@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
><Al...@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"
><sp...@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 ?
>
>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@citrix.com>.
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$InterceptorDispatcher.intercept:125-GenericDaoBase.update:774-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-GenericDaoBase.update:1262-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualNetworkApplianceManagerImpl$NetworkUsageTask.run:948-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267 / -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 : update, update, update, -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,
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 <sp...@gmail.com>>
Date: Monday, March 17, 2014 at 11:25 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@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 <Al...@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 <sp...@gmail.com>>
Date: Monday, March 17, 2014 at 11:00 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@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 <Al...@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$Runn
ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAnd
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+Tric
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" <sp...@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 ?
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
Hi, sorry. i went lost with this huge log.
2014-03-17 15:10 GMT-03:00 Alena Prokharchyk <Al...@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 <sp...@gmail.com>
> Date: Monday, March 17, 2014 at 11:00 AM
> To: Alena Prokharchyk <al...@citrix.com>
> Cc: "users@cloudstack.apache.org" <us...@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.Prokharchyk@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$Runn
>>
>> ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAnd
>> 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+Tric
>> 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" <sp...@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 ?
>>
>>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@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 <sp...@gmail.com>>
Date: Monday, March 17, 2014 at 11:00 AM
To: Alena Prokharchyk <al...@citrix.com>>
Cc: "users@cloudstack.apache.org<ma...@cloudstack.apache.org>" <us...@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 <Al...@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$Runn
ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAnd
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+Tric
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" <sp...@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 ?
Re: NetworkUsage
Posted by Diego Spinola Castro <sp...@gmail.com>.
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 <Al...@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$Runn
> ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAnd
> 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+Tric
> 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" <sp...@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 ?
>
>
Re: NetworkUsage
Posted by Alena Prokharchyk <Al...@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$Runn
ableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAnd
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+Tric
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" <sp...@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 ?