Gaps in some graphs, not others

egironda · Post by **egironda** » Mon Mar 06, 2006 1:00 pm

cacti 0.8.6h patched
cactid 0.8.6g patched
30 Threads (increased to 40 with no effect)

mysql Ver 14.7 Distrib 4.1.11
php 4.3.4 w/ mem set to 128M
NET-SNMP version: 5.1.3.1

I have increasingly been having gaps in some graphs, but not all.

Sometimes it's traffic graphs, sometimes it's scripts or other OIDs... there doesn't seem to be any pattern, except that it happens for all of the graphs on a single host.

I have pored over my debug output, which is plentiful as I have 165 hosts and over 2000 graphs. The problem is, I don't know what I'm looking for.

Things I know:

- The hosts are not going into disabled state.

- The poller is retreiving the values correctly, per the log file, and seems to be inserting them into the DB ok.

- The log often has a message like this for the host which is getting gaps:
03/06/2006 09:40:19 AM - CACTID: Poller[0] Host[197] RECACHE: Processing 2 items in the auto reindex cache for 'blah.blahblah.com' I couldn't find evidence indicating what this means.

- Cacti, mysql, and nagios are all running on this box, but I haven't seen any resource constraints in evidence. I upgraded it to 4G of RAM last week, to no effect.

I'm going to let it run for a while in Debug mode, and see if I can catch the errors when a gap actually occurs... I am kinda stumped though, and would appreciate any pointers in the right direction.

I'll be glad to upload any debug output etc, but as I said there's an awful lot of it so I'd rather be looking for something specific.

Thanks in advance.

egironda · Post by **egironda** » Mon Mar 06, 2006 3:03 pm

Here is some logged data from when a gap in the graph appeared. I chose just the traffic data source to keep things from being too confusing, however, this same problem is happening on all graphs on that host at the same time.

It sure seems like it's polling and getting the data, but the rrd file doesn't show that data. I have things as verbose as they go, it'd seem, and there aren't any errors. Where else can I look?

03/06/2006 10:50:12 AM - CACTID: Poller[0] Host[205] RECACHE: Processing 2 items
in the auto reindex cache for 'xxxxxs-1'
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '626': 'update
poller_reindex set assert_value='85995920' where host_id='205' and data_query_i
d='1' and arg1='.1.3.6.1.2.1.1.3.0''
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '626': OK
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '627': 'update
poller_reindex set assert_value='85995920' where host_id='205' and data_query_i
d='2' and arg1='.1.3.6.1.2.1.1.3.0''
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '627': OK
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Query ID '511': 'SELECT
action,hostname,snmp_community,snmp_version,snmp_username,snmp_password,rrd_name
,rrd_path,arg1,arg2,arg3,local_data_id,rrd_num,snmp_port,snmp_timeout FROM polle
r_item WHERE host_id=205 ORDER BY arg1'
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Query ID '511': OK
03/06/2006 10:50:12 AM - CACTID: Poller[0] Host[205] DS[3026] SNMP: v1: xxxxx
s-1, dsname: traffic_in, oid: .1.3.6.1.2.1.2.2.1.10.2, value: 201352123
03/06/2006 10:50:12 AM - CACTID: Poller[0] Host[205] DS[3026] SNMP: v1: xxxxx
s-1, dsname: traffic_out, oid: .1.3.6.1.2.1.2.2.1.16.2, value: 11539800

03/06/2006 10:50:12 AM - CACTID: Poller[0] Host[205] DEBUG: The POPEN returned t
he following File Descriptor 48
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: The Value of Active Threads is
14
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: The Value of Active Threads is
14
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: The Value of Active Threads is
13

03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '628': 'INSERT
INTO poller_output (local_data_id,rrd_name,time,output) VALUES (3026,'traffic_i
n','2006-03-06 10:50:01','201352123'),(3026,'traffic_out','2006-03-06 10:50:01',
'11539800'),(3020,'load_1min','2006-03-06 10:50:01','0'),(3022,'load_5min','2006
-03-06 10:50:01','0'),(3021,'load_15min','2006-03-06 10:50:01','0'),(3019,'cpu_u
ser','2006-03-06 10:50:01','4815'),(3017,'cpu_nice','2006-03-06 10:50:01','1115'
),(3018,'cpu_system','2006-03-06 10:50:01','6786'),(3023,'mem_buffers','2006-03-
06 10:50:01','46268'),(3024,'mem_cache','2006-03-06 10:50:01','65920'),(3025,'me
m_free','2006-03-06 10:50:01','372020'),(3027,'hdd_free','2006-03-06 10:50:01','
70967892'),(3027,'hdd_used','2006-03-06 10:50:01','604660'),(3016,'','2006-03-06
10:50:01','listen:3')'

03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: MySQL Insert ID '628': OK
03/06/2006 10:50:12 AM - CACTID: Poller[0] Host[205] DEBUG: HOST COMPLETE: About
to Exit Host Polling Thread Function
03/06/2006 10:50:12 AM - CACTID: Poller[0] DEBUG: The Value of Active Threads is
12

03/06/2006 10:50:12 AM - POLLER: Poller[0] CACTI2RRD: /usr/local/rrdtool-1.2.12/
bin/rrdtool update /usr/share/cacti/site/rra/xxxxx1_traffic_in_3026.rrd --tem
plate traffic_out:traffic_in 1141671001:11539800:201352123

rrd:

 <row><v> NaN </v><v> NaN </v></row>

[/img]

egironda · Post by **egironda** » Mon Mar 06, 2006 6:36 pm

More grist for the mill...

When I do a clear cache, I get this in my log. I believe these are data sources which no longer exist, and I'm not sure why it is erroring on them.

03/06/2006 03:33:21 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=2358"
03/06/2006 03:33:20 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=2155"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1860"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1769"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1739"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1738"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1724"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1723"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1709"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1708"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1694"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1693"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1678"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1677"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1662"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1661"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=1646"
03/06/2006 03:33:19 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=38 and data_template_rrd.local_data_id=1645"
03/06/2006 03:33:16 PM - CMDPHP: Poller[0] ERROR: SQL Assoc Failed "select snmp_query_graph_rrd.snmp_field_name, data_template_rrd.id as data_template_rrd_id from (snmp_query_graph_rrd,data_template_rrd) where snmp_query_graph_rrd.data_template_rrd_id=data_template_rrd.local_data_template_rrd_id and snmp_query_graph_rrd.snmp_query_graph_id= and snmp_query_graph_rrd.data_template_id=41 and data_template_rrd.local_data_id=211"

egironda · Post by **egironda** » Mon Mar 06, 2006 7:59 pm

After some more log file watching, I think I've come to the conclusion that the cacti logic is ok up until the point the rrd file gets updated - which is to say, it doesn't always. Having hit the far edge of my troubleshooting skills I'm going to enlist some assistance, but would welcome any recommendations or knowledge from others on this one...

egironda · Post by **egironda** » Mon Mar 06, 2006 8:16 pm

One last datapoint - it appears that a huge number of my graphs stopped updating after my upgrade from 0.8.6g -> 0.8.6h. I'd made that upgrade to fix some other problems, and while I thought at the time it'd worked it seems it may have introduced this rrd-non-updatey problem.

So, that's a start. Now, anyone have a clue as to how to fix it?

_JPL_ · Post by **_JPL_** » Tue Mar 07, 2006 2:00 pm

I've had a problem like this before that exhibited the same issues...namely gaps in graphs. Turns out the problem was that there were 2 cron jobs running the cacti poller. One I entered manually from a previous install and one that got installed during an upgrade in /etc/cron. I simply removed the one from /etc/cron (my preference) and the gaps stopped.

egironda · Post by **egironda** » Tue Mar 07, 2006 3:35 pm

I double checked, only one cron job. In fact, we modified it to write its sterr and stout to a file so we could examine it, with no useful results...

I need to figure out how to make rrdtool more verbose when invoked by Cacti I think. Anyone have an inkling?

Post by **TheWitness** » Tue Mar 07, 2006 5:58 pm

What version of MySQL are you running? Also, one of the patches on the web site appears to may have caused some issues. Have you applied all the patches to Cacti 0.8.6h?

TheWitness

egironda · Post by **egironda** » Tue Mar 07, 2006 7:07 pm

I have applied all the patches from the website to date.

mysql version:
mysql Ver 14.7 Distrib 4.1.11, for pc-linux-gnu (i386)

I just changed the following values in php.ini and things seem to be looking better (knock on wood!)... if this fixes it, I'll be a happy camper.

max_execution_time = 120 ; Maximum execution time of each script, in seconds
max_input_time = 120 ; Maximum amount of time each script may spend parsing request data
memory_limit = 128M ; Maximum amount of memory a script may consume (8MB)

I already had the memory bumped to 128, but I bumped the max input time and the max execution time to 120 seconds from their defaults of 30 and 60 respectively. I'll let you know how it goes...

Post by **TheWitness** » Tue Mar 07, 2006 10:56 pm

There may be another change to lib/database.php that you will have to make to get rid of these errors. Keep me posted on what you find...

TheWitness

egironda · Post by **egironda** » Tue Mar 07, 2006 11:20 pm

Well, the original graphs I was having trouble with are okay now, but a new set of graphs I added after I thought it was fixed are now having gapping issues... so I guess it's not fixed. It's only the new graphs, which is the strangest part. I'm going to clear the poller cache and do that song and dance, just to be sure.

I'll take any ideas you've got.

It seems to me that this is what's happening, but please correct my understanding of the program flow if I am wrong.

1. cactid polls successfully
2. hands off data to mysql.
3. cacti grabs data from mysql and hands to rrdtool,
4. cacti clears the data from mysql
5. rrdtool inserts data into the rrd file

The problem is happening somewhere around 5, becuase I actually see the correct rrdtool syntax in the logs, and it will run just fine on the commandline with the correct user... it just sometimes doesn't make it into the file when cacti runs.

Post by **TheWitness** » Wed Mar 08, 2006 8:42 pm

This could be an issue with Cygwin versions. Are you running Windows? Do you have Cygwin installed? Did you compile yourself?

TheWitness

egironda · Post by **egironda** » Thu Mar 09, 2006 3:16 pm

Nope, no Cygwin. Running it under Debian.

The weirdest thing to me is that it's only certain graphs... if it was all or nothing, it'd be easier to figure out.

I'm still not sure how the other ones started working, as by the time they started working again, I was more or less banging on keys in frustration.

I also started using a newer version of php after the problems started again, in hopes that it was related, but no change.

Post by **TheWitness** » Thu Mar 09, 2006 6:01 pm

Do you receive any warnings in the log? Any count issues on RRA's updated. I suspect a timeout issue.

TheWitness

egironda · Post by **egironda** » Thu Mar 09, 2006 7:03 pm

Not sure what you mean by count issues. My rrd output in the log is the normal sort:

OK u:0.08 s:0.10 r:13.08
OK u:0.08 s:0.10 r:13.08
OK u:0.08 s:0.10 r:13.08
OK u:0.08 s:0.10 r:13.08
OK u:0.08 s:0.10 r:13.08

The end of the poll looks like this:
03/09/2006 03:50:15 PM - SYSTEM STATS: Time:14.0982 Method:cactid Processes:1 Threads:20 Hosts:166 HostsPerProcess:166 DataSources:2753 RRDsProcessed:2136
03/09/2006 03:50:15 PM - EXPORT STATS: ExportTime:0.0017 TotalGraphs:0

Which looks right. I have 2136 rrd files, after deleting some old ones which aren't in use anymore..

I get this error on occasion:

cacti.cron.stderr:CACTID: ERROR: Problem with MySQL: 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '' at line 1'

I get these, but they are corrolated with a different problem as far as I'm aware, and the graphs I'm worried about aren't the ones these are upsetting:

CACTID: Host[133] ERROR: The POPEN timed out
CACTID: Host[133] DS[3091] WARNING: Result from SCRIPT not valid. Partial Result
: ...
CACTID: Host[138] ERROR: The POPEN timed out
CACTID: Host[138] DS[3123] WARNING: Result from SCRIPT not valid. Partial Result

I can send debug output for the host in question, but I'd rather send it by email so I don't have to strip out all the identifying info... Let me know if you think it'll help

Gaps in some graphs, not others

Gaps in some graphs, not others

Who is online