Recurring Problem - WARNING: Poller Output Table not Empty

[albmen]

Hi,

I've a medium-sized cacti installation where I'm currently using cacti-0.8.7i-PIA and spine-0.8.7i.
From time to time in my cacti.log I have the following messages:

02/15/2012 09:10:18 AM - SYSTEM STATS: Time:16.8262 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:489 RRDsProcessed:266
02/15/2012 09:10:31 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSToutB60(DS[1146])
02/15/2012 09:10:50 AM - SYSTEM STATS: Time:18.8888 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:489 RRDsProcessed:264
02/15/2012 09:11:01 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSTinB60(DS[1146])
02/15/2012 09:11:21 AM - SYSTEM STATS: Time:19.0225 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:489 RRDsProcessed:267
02/15/2012 09:11:31 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSToutB60(DS[1146])

and obviously the graph related to that datasource is not graphing anymore (the problem is quite frequent and it isn't related always to the same datasource)
To fix the broken datasource I've to open, from the gui, the datasource identified by the id and then click "save".

The lines below are related to the start of the problem

02/14/2012 07:25:18 PM - SYSTEM STATS: Time:16.6241 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:267
02/14/2012 07:25:50 PM - SYSTEM STATS: Time:18.7194 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:264
02/14/2012 07:26:20 PM - SYSTEM STATS: Time:18.8084 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:268
02/14/2012 07:26:48 PM - SYSTEM STATS: Time:17.0427 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:280
02/14/2012 07:27:22 PM - SPINE: Poller[0] Host[30] TH[1] DS[1161] WARNING: SNMP timeout detected [2000 ms], ignoring host '172.20.69.1'
02/14/2012 07:27:22 PM - SYSTEM STATS: Time:20.6636 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:283
02/14/2012 07:27:50 PM - SYSTEM STATS: Time:18.7426 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:283
02/14/2012 07:27:50 PM - PCOMMAND: Poller[0] Host[30] WARNING: Recache Event Detected for Host
02/14/2012 07:27:54 PM - CMDPHP: Poller[0] WARNING: SNMP Get Timeout for Host:'172.20.69.1', and OID:'.1.3.6.1.2.1.2.1.0'
02/14/2012 07:27:58 PM - CMDPHP: Poller[0] WARNING: SNMP Walk Timeout for Host:'172.20.69.1', and OID:'.1.3.6.1.2.1.2.2.1.1'
02/14/2012 07:27:58 PM - PCOMMAND: Poller[0] Host[37] WARNING: Recache Event Detected for Host
02/14/2012 07:28:00 PM - RECACHE STATS: RecacheTime:9.2754 HostsRecached:2
02/14/2012 07:28:18 PM - SYSTEM STATS: Time:16.6354 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:282
02/14/2012 07:28:18 PM - PCOMMAND: Poller[0] Host[30] WARNING: Recache Event Detected for Host
02/14/2012 07:28:20 PM - RECACHE STATS: RecacheTime:1.6806 HostsRecached:1
02/14/2012 07:28:31 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSTinB60(DS[1146])
02/14/2012 07:28:50 PM - SYSTEM STATS: Time:18.7361 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:277
02/14/2012 07:29:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSToutB60(DS[1146])
02/14/2012 07:29:18 PM - SYSTEM STATS: Time:16.6504 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:274
02/14/2012 07:29:18 PM - PCOMMAND: Poller[0] Host[30] WARNING: Recache Event Detected for Host
02/14/2012 07:29:20 PM - PCOMMAND: Poller[0] Host[37] WARNING: Recache Event Detected for Host
02/14/2012 07:29:21 PM - RECACHE STATS: RecacheTime:2.7871 HostsRecached:2
02/14/2012 07:29:31 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSTinB60(DS[1146])
02/14/2012 07:29:49 PM - SYSTEM STATS: Time:17.3084 Method:spine Processes:4 Threads:8 Hosts:62 HostsPerProcess:16 DataSources:490 RRDsProcessed:269
02/14/2012 07:30:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 1, Data Sources: tai_IFSTinB60(DS[1146])

Perhaps the bold-line is related to my problem (even if the host resulting in snmp timeout is note the same related to the datasource 1146)?


Some questions:

1. is it a known problem?
2. is there a preferred way to debug this behavior?
3. have you got any clue?

Thank you very much...and sorry for my poor english

[phil_w]

I also get this issue a lot, I've not been able to eliminate it yet.

At first it seemed to be down to the memory allowed for scripts in php.ini so I've increased that and it seems to occur less often now.

Also running the script in cli repair_database.php seems to cure this temporarily the problem always recurs.

I'm using the latest EzCacti 0.6 as it comes with cacti 0.8.7c and PIA 2.2 using spine poller.

02/16/2012 09:16:01 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 2227, Data Sources: 5min_cpu(DS[2088]), cisco_memfree(DS[2089]), cisco_memused(DS[2090]), traffic_in(DS[2091]), traffic_out(DS[2091]), traffic_in(DS[2092]), traffic_out(DS[2092]), traffic_in(DS[2093]), traffic_out(DS[2093]), traffic_in(DS[2094]), traffic_out(DS[2094]), traffic_in(DS[2095]), traffic_out(DS[2095]), traffic_in(DS[2096]), traffic_out(DS[2096]), traffic_in(DS[2097]), traffic_out(DS[2097]), traffic_in(DS[2098]), traffic_out(DS[2098]), traffic_in(DS[2099]), traffic_out(DS[2099]), Additional Issues Remain. Only showing first 20

[albmen]

Hi phil_w,

I've no limits for memory usage in my php.ini, and the problem seems to be completely random.
I spent three days without noticing the issue but today I had the error again in a completely unrelated datasource (different host and different graph template).

Any help would be greatly appreciated.

[albmen]

Hi all,

probably I've found the root cause of the error:

mysql> select local_data_id,poller_id,host_id,action,present,hostname,rrd_name,rrd_path,rrd_step,rrd_next_step,rrd_num from poller_item where local_data_id=1146;
+---------------+-----------+---------+--------+---------+----------+----------------+----------------------------------------------------+----------+---------------+---------+
| local_data_id | poller_id | host_id | action | present | hostname | rrd_name | rrd_path | rrd_step | rrd_next_step | rrd_num |
+---------------+-----------+---------+--------+---------+----------+----------------+----------------------------------------------------+----------+---------------+---------+
| 1146 | 0 | 37 | 0 | 1 | 1.1.1.4 | tai_IFSTinB60 | /export/CACTI/cacti-0.8.7i-PIA-3.1/rra/37/1146.rrd | 60 | 0 | 2 |
| 1146 | 0 | 37 | 0 | 1 | 1.1.1.4 | tai_IFSToutB60 | /export/CACTI/cacti-0.8.7i-PIA-3.1/rra/37/1146.rrd | 60 | 30 | 2 |
+---------------+-----------+---------+--------+---------+----------+----------------+----------------------------------------------------+----------+---------------+---------+

The field rrd_next_step for the two rra stored in datasource 1146 are disaligned. I temporary fixed the problem with the following sql step:

mysql> update poller_item set rrd_next_step=0 where local_data_id=1146;

Is there any cacti developer who can help me to understand why these values, from time to time, become disaligned?

Thanks

[albmen]

Update:

I think the bug 1904, http://bugs.cacti.net/view.php?id=1904, could be related to my issue.
Is there a fix available for this problem?

[hid3nax]

I have similar problem I described in this thread BUT THE PROBLEM ISN'T SOLVED: http://forums.cacti.net/viewtopic.php?f=21&t=46154

I have made some testing and here is what I found.

I used `screen` on my cacti box where I launched such command:

Code: Select all

while true; do mysql -ucactiuser -p******** cactistats -e "SELECT * FROM poller_item WHERE rrd_next_step!= '0';" >> /root/cactistats && sleep 1; done

I left this for a while and in the morning I found there to be some data in the 'cactistats' file. As far as I understand, there shouldn't be any. This problem needs to be solved ASAP since it's really annoying.

Could anyone help please?

[gandalf]

During a reent investigation of the "poller_output table not empty" issue, I found:
- that related data sources are always related to a Data Query
- all data sources that I found were broken in either
- the related data template had not checked "Index Type", "Index Value", "Output Type ID" and hence an SQL returned wrong results
(e.g. my "old" tenplate for "Alteon Loadbalancers" shows such an issue
- or data template was fine, but there was no (correct) data for those fields entered on the data source
(e.g. a hrStorage ds had no correct indexes given in it's data source)
After fixing those errors, all was fine again.
R.