Cacti & Boost: Weathermap last_calc not calculated correctly

[blade84]

Hi,
I'm really stuck with this problem.
After googling many hours and searching this forum I hoped that somebody could point me in the right direction.

I recently upgraded our cacti installation to versioin 0.8.8a dependent on boost 5.1 with one minute polling.
Everything works perfectly except for Weathermap displaying the correct link usage.
It is way too high, e.g. 3092616.52%.
I use the “rrd_use_poller_output 1” option.
I also set the correct Bandwidth, e.g. “BANDWIDTH 20G”

Strange thing is, on some few graphs, link usage is beeing calculated correctly.
So I went to compare all outputs of two links, one calculated correctly, one not.
I also compared the structure of the .rrd files with rrdtool info.
Still I couldn't figure out any difference between them.

These are my findings / outputs so far:
working: 12797
not working: 12736

Code: Select all

mysql> select * from poller_output_boost where local_data_id = '12797' or local_data_id = '12736';
+---------------+-------------+---------------------+------------------+
| local_data_id | rrd_name    | time                | output           |
+---------------+-------------+---------------------+------------------+
|         12736 | traffic_in  | 2012-12-09 12:03:02 | 2456149964309576 |
|         12736 | traffic_out | 2012-12-09 12:03:02 | 2998069066379327 |
|         12736 | traffic_in  | 2012-12-09 12:04:02 | 2456165916259355 |
|         12736 | traffic_out | 2012-12-09 12:04:02 | 2998103913342185 |
|         12736 | traffic_in  | 2012-12-09 12:05:02 | 2456180197599986 |
|         12736 | traffic_out | 2012-12-09 12:05:02 | 2998138107448774 |
|         12797 | traffic_in  | 2012-12-09 12:03:01 | 1781253693286711 |
|         12797 | traffic_out | 2012-12-09 12:03:01 | 1216371371048478 |
|         12797 | traffic_in  | 2012-12-09 12:04:01 | 1781298169991870 |
|         12797 | traffic_out | 2012-12-09 12:04:01 | 1216391009262304 |
|         12797 | traffic_in  | 2012-12-09 12:05:01 | 1781340911750276 |
|         12797 | traffic_out | 2012-12-09 12:05:01 | 1216410076523569 |
+---------------+-------------+---------------------+------------------+

mysql> select * from weathermap_data where local_data_id = '12797' or local_data_id = '12736';
+-----+---------------------------------------------+------------------+-----------+---------------+
| id  || data_source_name | last_time  | last_value | last_calc         | sequence | local_data_id |
+-----+---------------------------------------------+--------------------+-------------------------|
| 415 || traffic_in  | 1355051102 | 2456180197599986 | 2456180197599986 |    15450 |         12736 |
| 416 || traffic_out | 1355051102 | 2998138107448774 | 2998138107448774 |    15450 |         12736 |
| 491 || traffic_in  | 1355051101 | 1781340911750276 | 712362640.1      |    15342 |         12797 |
| 492 || traffic_out | 1355051101 | 1216410076523569 | 317787687.75     |    15342 |         12797 |
+-----+---------------+------------+------------------+------------------+----------+--------------+

I went to take a look at the weathermap/setup.php where the calculations are beeing done but still couldn't figure out why one link should be calculated correctly and one just takes the “last_value” as “last_calc”.

root@localhost:~# cat /var/log/cacti/cacti.log | grep 2456180197599986
12/09/2012 12:05:02 PM - SPINE: Poller[0] Host[450] TH[1] DS[12736] SNMP: v2: 213.144.128.209, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.83886081, value: 2456180197599986
12/09/2012 12:05:03 PM - WEATHERMAP: Poller[0] WM poller_output: Got one! /var/www/cacti/rra/r1ams2_core_traffic_in_12736.rrd:traffic_in -> 1355051102 2456180197599986
12/09/2012 12:05:03 PM - WEATHERMAP: Poller[0] WM poller_output: Got one! /var/www/cacti/rra/r1ams2_core_traffic_in_12736.rrd:traffic_in -> 1355051102 2456180197599986
12/09/2012 12:05:03 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 2456180197599986 (was 2456165916259355, period was 60)
12/09/2012 12:05:06 PM - WEATHERMAP: Poller[0] DEBUG: [wmrrd_read_from_poller_output@WeatherMapDataSource_rrd.php:178] [Map 14] Backbone: RRD ReadData: poller_output - result is 2456180197599986,2998138107448774
12/09/2012 12:06:02 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 236045992.93333 (was 2456180197599986, period was 60)
12/09/2012 12:06:02 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 2456194360359562 (was 2456180197599986, period was 60)
12/09/2012 12:07:54 PM - BOOST: Poller[0] NOTE: Updating Local Data Id:'12736', Template:traffic_in:traffic_out, Output: 1355051102:2456180197599986:2998138107448774
12/09/2012 12:07:54 PM - POLLER: Poller[0] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: plugins/boost/boost_rrdupdate.php 2880 /usr/bin/rrdupdate /var/www/cacti/rra/r1ams2_core_traffic_in_12736.rrd --template traffic_in:traffic_out 1355051102:2456180197599986:2998138107448774]

root@localhost:~# cat /var/log/cacti/cacti.log | grep 1781340911750276
12/09/2012 12:05:01 PM - SPINE: Poller[0] Host[33] TH[1] DS[12797] SNMP: v2: 213.144.128.207, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.83886083, value: 1781340911750276
12/09/2012 12:05:01 PM - WEATHERMAP: Poller[0] WM poller_output: Got one! /var/www/cacti/rra/r1fra1_core_traffic_in_12797.rrd:traffic_in -> 1355051101 1781340911750276
12/09/2012 12:05:01 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 1781340911750276 (was 1781298169991870, period was 60)
12/09/2012 12:05:01 PM - WEATHERMAP: Poller[0] WM poller_output: Got one! /var/www/cacti/rra/r1fra1_core_traffic_in_12797.rrd:traffic_in -> 1355051101 1781340911750276
12/09/2012 12:06:01 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 1781383646293177 (was 1781340911750276, period was 60)
12/09/2012 12:06:01 PM - WEATHERMAP: Poller[0] WM poller_output: Final value is 712242381.68333 (was 1781340911750276, period was 60)
12/09/2012 12:26:41 PM - BOOST: Poller[0] NOTE: Updating Local Data Id:'12797', Template:traffic_in:traffic_out, Output: 1355051101:1781340911750276:1216410076523569


Has somebody ever experienced such a problem?
Any help is greatly appreciated.
Many thanks for your patience.

[Howie]

Well, looking at the code in weathermap_poller_output, I'd guess that one of your RRDs has DS that are defined as GAUGE and the other as COUNTER...

What does "rrdtool info rrdfile.rrd" look like for both? (just the first section)

[blade84]

Hi Howie,
First of all, many thanks for taking the time to help me. I really appreciate it.

I have already analyzed the rrd files but couldn't find any difference so far. Here is the output of rrdinfo:


root@localhost:~# rrdtool info /var/www/cacti/rra/r1fra1_core_traffic_in_12797.rrd
filename = "/var/www/cacti/rra/r1fra1_core_traffic_in_12797.rrd"
rrd_version = "0003"
step = 60
last_update = 1355407022
header_size = 5224
ds[traffic_in].index = 0
ds[traffic_in].type = "COUNTER"
ds[traffic_in].minimal_heartbeat = 600
ds[traffic_in].min = 0.0000000000e+00
ds[traffic_in].max = NaN
ds[traffic_in].last_ds = "1953956798678615"
ds[traffic_in].value = 7.5744798990e+08
ds[traffic_in].unknown_sec = 0
ds[traffic_out].index = 1
ds[traffic_out].type = "COUNTER"
ds[traffic_out].minimal_heartbeat = 600
ds[traffic_out].min = 0.0000000000e+00
ds[traffic_out].max = NaN
ds[traffic_out].last_ds = "1304597066805034"
ds[traffic_out].value = 4.6834895059e+08
ds[traffic_out].unknown_sec = 0

root@localhost:~# rrdtool info /var/www/cacti/rra/r1ams2_core_traffic_in_12736.rrd
filename = "/var/www/cacti/rra/r1ams2_core_traffic_in_12736.rrd"
rrd_version = "0003"
step = 60
last_update = 1355408162
header_size = 5224
ds[traffic_in].index = 0
ds[traffic_in].type = "COUNTER"
ds[traffic_in].minimal_heartbeat = 600
ds[traffic_in].min = 0.0000000000e+00
ds[traffic_in].max = NaN
ds[traffic_in].last_ds = "2536049685522913"
ds[traffic_in].value = 4.1470229623e+08
ds[traffic_in].unknown_sec = 0
ds[traffic_out].index = 1
ds[traffic_out].type = "COUNTER"
ds[traffic_out].minimal_heartbeat = 600
ds[traffic_out].min = 0.0000000000e+00
ds[traffic_out].max = NaN
ds[traffic_out].last_ds = "3181098169986063"
ds[traffic_out].value = 9.2318928760e+08
ds[traffic_out].unknown_sec = 0


I have now deactivated all other weathermaps and have created a new one out of the default example simple.conf containing the two links (attached).
I also attached a weathermap debug output during one poller run and two images of the corresponding graphs.

If you need more information I will gladly provide it.
Thanks.

Cheers
Blade

[Howie]

Interestingly, I've been getting this on my maps now - they use dsstats, rather than poller_output, and dsstats is also making the same mistake... (in this case, Weathermap is just querying data that dsstats has already calculated).

Code: Select all

	local_data_id	rrd_name	value	calculated
	1749	traffic_in	444922894264061	444922894264061
	1749	traffic_out	367213334931493	367213334931493

I suspect TheWitness and I both got this code from the Thold plugin, but something seems to have changed recently on my system to affect this - I think all the dsstats-based links went crazy at the same time.

[Howie]

So after adding some debug code to dsstats, I can see:

Code: Select all

Fri, 14 Dec 2012 16:10:03 UTC
array (
  'local_data_id' => '1749',
  'rrd_name' => 'traffic_out',
  'time' => '2012-12-14 16:10:02',
  'output' => '367236366730250',
)
type is 1

Type 1 is 'GAUGE' (type 2 is COUNTER).

So something upstream is giving the incorrect type...

[blade84]

Yes, you are right. I quickly switched "case" number at "switch($required['data_source_type_id'])" in setup.php and most of my links were displayed correctly, except those that have been correct before the change.

As I'm only using (traffic) COUNTER rrds for my weathermaps I modified the switch at line 717 in setup.php so that in both cases, "case 1" and "case 2" the same calculations are done for COUNTER.
Problem is, this isn't really a workaround because I'll be stuck if I ever wanted to draw GAUGE links...

But if you and me we both are experiencing those problems then there surely are some other people stuck with the same poblem.
Do you have any idea why this is happening?

[Howie]

I figured out the problem, but not a fix yet.

Further up in the same function, it fetches a list of all the ds names and determines their type. It assumes that every ds name is unique though! So now I think back, I added a graph for something new, with traffic_in and traffic_out GAUGE DS, and now I have a type 1 AND type 2.

Code: Select all

+---------------------+---------------------+----------+
| data_source_name    | data_source_type_id | rrd_step |
+---------------------+---------------------+----------+
| traffic_in          |                   2 |      300 |
| traffic_in          |                   1 |      300 |
| traffic_out         |                   1 |      300 |
| traffic_out         |                   2 |      300 |
+---------------------+---------------------+----------+

I guess the type 1 comes later in the list, so it overwrites the type 2. This will affect thold, dsstats and weathermap's poller_output, since they all use the same code.

[Howie]

Two quick fixes:

1) change the name of your GAUGE traffic_in/traffic_out DS names

2) I just tried commenting out a few lines and it seems to work:

(this is is dsstats, but weathermap has equivalent lines just above the switch statement we're talking about)

Code: Select all

 #if (!isset($ds_types[$result["rrd_name"]]["data_source_type_id"])) {
                                                        $polling_interval = db_fetch_cell("SELECT rrd_step FROM data_template_data WHERE local_data_id=" . $data_source["local_data_id"]);
                                                        $ds_type          = db_fetch_cell("SELECT data_source_type_id FROM data_template_rrd WHERE local_data_id=" . $data_source["local_data_id"]);
                                                #}else{
                                                #       $polling_interval = $ds_types[$result["rrd_name"]]["rrd_step"];
                                                #       $ds_type          = $ds_types[$result["rrd_name"]]["data_source_type_id"];
                                                #}

I suspect this will impact performance, since it's forcing an extra couple of database queries per data source. My poller times seem stable though.

[blade84]

Hi Howie,

First of all thanks for your efforts, hope you had a good start into 2013!
I didn't find any time to look into this again until now.

I didn't find the mentioned lines similar to dsstats.
After some attempts I found another work around (though not a really good one).
As you said I figured there has to be something changed in the SQL queries so I added this:

Code: Select all

 and data_template_rrd.data_source_name<>'ds'

to the end of the sql query at line 662 in setup.php:

Code: Select all

$requiredlist = db_fetch_assoc("select distinct weathermap_data.id, weathermap_data.last_value, weathermap_data.last_time, weathermap_data.data_source_name, data_template_data.data_source_path, data_template_data.local_data_id, data_template_rrd.data_source_type_id from weathermap_data, data_template_data, data_template_rrd where weathermap_data.local_data_id=data_template_data.local_data_id and data_template_rrd.local_data_id=data_template_data.local_data_id and weathermap_data.local_data_id<>0 and data_template_rrd.data_source_name<>'ds';");

In my case it seems it is the data_source_name 'ds' that is somehow overwriteing type COUNTER to GAUGE
So afther this change I only get type 2 (COUNTER) as a result for my traffic graphs.

Regards