Cacti first maps calculation reaaaaaalllllly slow !

[Djoul2706]

Hi!
I'm using cacti for a while and i'm facing an issue i can't go through..
First my conf :
- Ubuntu 
- 8 core server with 8gb of ram
- Spine as poller
- around 1000 rrds
- dsstats (also used in weathermaps)

And 50 weathermaps.

The poller is run in less than 10sec.
Logs don't show any special error or warning.

As far as no weathermap are activated cacti (and the server) is perfect. 
When i activate some weathermaps, The first calculation is so slow that it takes more than 5 mn to end it and the next calculation starts before the previous ended. It causes an increase of mysqld process up to 800% after few poller cycle. When 800% is reached, server starts to be slower and polling duration rises.. 
The only way to get out is to restart mysqld process or even the server.

I tried few stuffs :
- add weathermaps one by one per poller cycle. It helps a lot but as soon as a modification is done on one weathermap the next calculation  will take a lot of time and so on...
- tune mysql configuration with no success
- activate only weathermaps without warnings
- use dsstats collection data for each target in weathermaps conf
- re install weathermap plugin

But it's still there !
Does anyone face or faced the same trouble?
What can i do? 

Thanks for any reply.
Julien

[Howie]

Can you post (or PM) a sample map config?

I've done quite a bit of work on performance for the next release (it's about twice as fast in general), and I'd be interested to see if it'll help you.

Are you saying that the second run on all these maps is faster than the first?

Are you using poller_output, or just reading rrd files directly? (or did you leave it with dsstats?)

[Djoul2706]

Thanks for your quick reply.

This is one extract of config file :

HTMLSTYLE overlib
TITLE ...

KEYPOS DEFAULT 925 38 Traffic Load
KEYSTYLE DEFAULT horizontal 150
KEYTEXTCOLOR 0 0 0
KEYOUTLINECOLOR 0 0 0
KEYBGCOLOR 255 255 255
BGCOLOR 255 255 255
TITLECOLOR 0 0 0
TIMECOLOR 0 0 0
SCALE DEFAULT 0 0 255 0 0
SCALE DEFAULT 0 5 0 240 0
SCALE DEFAULT 5 10 0 192 255
SCALE DEFAULT 10 15 32 32 255
SCALE DEFAULT 15 30 140 0 255
SCALE DEFAULT 30 50 240 240 0
SCALE DEFAULT 50 70 255 192 0
SCALE DEFAULT 70 100 255 0 0

SET cacti_path_rra /var/www/cacti/rra
SET cacti_url /cacti/


# regular NODEs:
NODE node02388
LABEL ....
ICON images/routeurf1.png
POSITION 250 50

NODE node02425
LABEL ....
ICON images/routeurf1.png
POSITION 250 150

NODE node02446
LABEL ....
ICON images/routeurf1.png
POSITION 250 250

NODE node02465
LABEL ....
ICON images/routeurf1.png
POSITION 250 350
[...]

NODE node06403
LABEL ....
ICON images/Cloud-Filled.png
POSITION 750 300


# regular LINKs:
LINK node02617-node06403
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=806
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=806&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:820:traffic_in:traffic_out
NODES node02617 node06403

LINK node02708-node06403
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=807
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=807&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:821:traffic_in:traffic_out
NODES node02708 node06403

LINK node02708-node02388
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=808
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=808&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:822:traffic_in:traffic_out
NODES node02708 node02388

LINK node02617-node02425
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=809
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=809&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:823:traffic_in:traffic_out
NODES node02617 node02425

LINK node02708-node02446
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=810
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=810&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:824:traffic_in:traffic_out
NODES node02708 node02446

LINK node02708-node02487a
WIDTH 4
INFOURL /cacti/graph.php?rra_id=all&local_graph_id=811
OVERLIBGRAPH /cacti/graph_image.php?local_graph_id=811&rra_id=0&graph_nolegend=true&graph_height=100&graph_width=300
TARGET 8*dsstats:825:traffic_in:traffic_out
NODES node02708 node02487a


Yes, the second run is way faster. The issue is only with the first run (and after any modification).
I used poller_output but took it of to try... Should I put it back ?
As you can see it in the config file I call directly the dsstats values in the database...

Thank you!
Julien

[Howie]

Well, with poller_output and rrd targets, there is a reason for the first run for a new target to be slower (it has to figure out which DS ID the rrd filename corresponds to, and adds a line in the weathermap_data table).

With dsstats, it should just be pulling out the right value, because the ID is already there in the target string.

One thing you might want to try, if you've switched all your maps over to dsstats, is clear the weathermap_data table. It might still try to collect data from poller_output for entries in there, even though they aren't used anymore.

I know I've made some changes in this code recently too, to cache database results. I'll check what it was.

[Howie]

I've just checked the code - definitely erase weathermap_data. The poller_output code will still be filling in values that you are never reading.

'TRUNCATE TABLE weathermap_data' should do it for you in mysql.

I'm just testing the current svn version on my system to make sure it's usable. If it's OK, I'll make up a pre-release zip for you to test with.

[Djoul2706]

I just did it before seeing your answer and it seems that it fixed my issues...

but I don't understand what the weathermap_data stands for ?
because it's not filled anymore.

[Howie]

The way poller_output works is in two parts:

1) When rrd_use_poller_output is enabled, and you have a target with an rrdfile, then weathermap looks into the Cacti database to figure out the datasource ID. It then puts a new row in weathermap_data.

2) When the poller runs, poller_output is called before most of weathermap (which runs after the main poller stuff). The weathermap poller_output handler is given DS IDs by cacti, which it looks for in weathermap_data, to see if it's interested in them. If it is, it updates the values in weathermap_data.

So this is why it takes a few poller cycles before new values start to appear.

However, nothing in weathermap keeps track of whether values are still being read from weathermap_data (at the moment), so if you change your maps often, or decide not to use poller_output anymore, then the weathermap poller_output code will carry on checking for those values. This is why truncating the tables makes such a difference.

I've been trying the current 0.98dev on my Cacti system this afternoon, and it seems to be mostly OK. I'll clean it up over the weekend. My own set of 50 maps went from 67 seconds to 35 seconds when I switched from 0.97a to 0.98dev.

[ncfrak]

Hello Howie,

I'm working with Julien on this issue. We had another cacti installed on the very same server but it became unusable for about 1min30 (even on the cli) at each polling. After extensive troubleshooting we think it was a problem with the database and the IO writings/readings.
Anyways, we decided to start from scratch (again)! Long story short : we used a script to create the hosts, theirs graphs and the same weathermaps as before.


1. Is it possible to not render the weathermaps if the previous rendering is not terminated within the 5 minutes? That would definitely prevent the server from stacking up mysql processes due to weathermap and ultimately never comes back to normal.

Now, we have around 50 weathermaps and if we activate them all at the same time, the weathermap rendering is not done within 300 seconds. So we have to activate them one by one.
We can do this once, but what happens if we need to restart the server? Will it process the weathermaps like they are freshly new?

2. Is it possible to fully take advantage of the 8 cores (parallel execution of the renderings?) ?


3
Can you explain the following. What triggered the processes to finally finish ?

09/28/2011 04:35:32 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:32 +0200: 7 maps were run in 22 seconds with 146 warnings.
09/28/2011 04:35:29 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:29 +0200: 7 maps were run in 912 seconds with 146 warnings.
09/28/2011 04:35:29 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:29 +0200: 7 maps were run in 1520 seconds with 146 warnings.
09/28/2011 04:35:28 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:28 +0200: 7 maps were run in 1528 seconds with 146 warnings.
09/28/2011 04:35:28 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:28 +0200: 7 maps were run in 316 seconds with 146 warnings.
09/28/2011 04:35:28 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:28 +0200: 7 maps were run in 616 seconds with 146 warnings.
09/28/2011 04:35:28 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 16:35:28 +0200: 7 maps were run in 1208 seconds with 146 warnings.

[Howie]

1. Is it possible to not render the weathermaps if the previous rendering is not terminated within the 5 minutes? That would definitely prevent the server from stacking up mysql processes due to weathermap and ultimately never comes back to normal.

Weathermap runs within the Cacti poller process. I thought that the poller already had protection against multiple copies running...

Now, we have around 50 weathermaps and if we activate them all at the same time, the weathermap rendering is not done within 300 seconds. So we have to activate them one by one.
We can do this once, but what happens if we need to restart the server? Will it process the weathermaps like they are freshly new?

Restart as in reboot? No - it's just the contents of the weathermap_data table that matters. That's a regular disk-backed table, so it survives reboots etc.

2. Is it possible to fully take advantage of the 8 cores (parallel execution of the renderings?) ?

Not currently. Although there is nothing to stop you using weathermap-cacti-rebuild.php to run the map rebuild process outside of the poller. In 0.98, you can specify map IDs to rebuild, so you could 'load balance' that way.

3
Can you explain the following. What triggered the processes to finally finish ?

No idea! Did anything else happen at 16:35? (e.g. restart mysql?) Seems like they are all blocking on some external resource. Have you taken a look at how many concurrent connections mysql has at that time? Could be something opening connections and not closing them, then eventually the old ones time out...

Just to get an idea of how many data sources your maps use, how many rows are in weathermap_data, and also in data_local? (The 'Technical Support' page in System Utilities should tell you). Or if you are using dsstats now, what does "grep TARGET configs/*.conf' | wc -l" give you?

[Howie]

Also, I should have something ready to test for early 0.98 soon. Would you be willing to try it? I'm using it on my production Cacti, and it's working OK for me, for what that's worth. Memory usage and runtime are greatly reduced.

[ncfrak]

Yes we'd love to try 0.98!

No idea! Did anything else happen at 16:35? (e.g. restart mysql?) Seems like they are all blocking on some external resource. Have you taken a look at how many concurrent connections mysql has at that time? Could be something opening connections and not closing them, then eventually the old ones time out...

Just to get an idea of how many data sources your maps use, how many rows are in weathermap_data, and also in data_local? (The 'Technical Support' page in System Utilities should tell you). Or if you are using dsstats now, what does "grep TARGET configs/*.conf' | wc -l" give you?

No we didn't check the number of concurrent connections, we'll do next time.
weathermap_data = 0
data_local = 2287

grep TARGET configs/*.conf | wc -l = 2184

[ncfrak]

Me again...
I've stopped a map at 4:00pm and activated it again at 5:33 pm and here is the stats that I've got :

09/28/2011 05:40:41 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 17:40:41 +0200: 9 maps were run in 29 seconds with 152 warnings.
09/28/2011 05:40:19 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 17:40:19 +0200: 9 maps were run in 309 seconds with 152 warnings.
09/28/2011 05:40:12 PM - SYSTEM DSSTATS STATS: Type:HOURLY, Time:0.3842
09/28/2011 05:40:12 PM - SYSTEM THOLD STATS: Time:0.0028 Tholds:0 Hosts:0
09/28/2011 05:40:12 PM - SYSTEM STATS: Time:10.8087 Method:spine Processes:8 Threads:8 Hosts:583 HostsPerProcess:73 DataSources:4113 RRDsProcessed:1941
09/28/2011 05:35:11 PM - SYSTEM DSSTATS STATS: Type:HOURLY, Time:0.5989
09/28/2011 05:35:10 PM - SYSTEM THOLD STATS: Time:0.0026 Tholds:0 Hosts:0
09/28/2011 05:35:10 PM - SYSTEM STATS: Time:9.3849 Method:spine Processes:8 Threads:8 Hosts:583 HostsPerProcess:73 DataSources:4113 RRDsProcessed:1941
09/28/2011 05:30:34 PM - WEATHERMAP: Poller[0] STATS: Weathermap 0.97a run complete - Wed, 28 Sep 11 17:30:34 +0200: 8 maps were run in 23 seconds with 152 warnings.


This is why I asked you the question about the reboot. The data should be in the database already however the rendering took 309 seconds. I'm confused about this long rendering

[Howie]

What are all those 150+ warnings? Do they offer a clue?

Could you still check those other numbers (table sizes, number of targets)?

EDIT: Sorry, I missed some replies above - please ignore that last part

[ncfrak]

What are all those 150+ warnings? Do they offer a clue?

Could you still check those other numbers (table sizes, number of targets)?

The warnings are mostly errors like this one:
09/28/2011 05:55:33 PM - WEATHERMAP: Poller[0] WARNING: [Map 94] mapRTR.conf: ReadData: LINK RTRA7-RTRB, target: /var/www/cacti/rra/321/867.rrd on config line 444 of /var/www/cacti/plugins/weathermap/configs/mapRTR.conf had no valid data, according to WeatherMapDataSource_rrd

It should be noted that I activated a map that is warning-free

I posted the others numbers in my above post:
weathermap_data = 0
data_local = 2287

grep TARGET configs/*.conf | wc -l = 2184


Also, I'd like to try out the 0.98 version

[Howie]

OK - I'll package something up for you tonight...

There are a few changes to do with using indexes in queries that might also make a difference when you have so many targets, relative to datasources (almost 100%, or are they duplicated?).