[SOLVED] WARNING: Poller Output Table not Empty

[gandalf]

Please open a new bug as given by http://www.cacti.net/bugs.ph and provide your solution. This helps keeping track of all those issue
Reinhard

[D43m0n]

Thanks for the patch, unfortunately I don't have the plugin arch installed so I can't apply this patch...

Could anyone help me to show me where to apply the patch in poller.php?

Thnx!

[GeneralMandible]

I'm experiencing similar issues. Could someone be more specific as to how to apply this fix?

Thanks!

[cdnvballer]

I'm not clear on this neither, what exactly is the fix?

I'm seeing the following now, on a 0.8.7d setup that is polling 1-minute intervals with 5-minute cron:

03/03/2009 02:13:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 330, Data Sources: users(DS[6]), traffic_in(DS[10]), traffic_out(DS[10]), traffic_in(DS[11]), traffic_out(DS[11]), traffic_in(DS[12]), traffic_out(DS[12]), traffic_in(DS[13]), traffic_out(DS[13]), asa5min_cpu(DS[18]), asa_memfree(DS[19]), asa_memused(DS[20]), asa_conn(DS[21]), traffic_in(DS[22]), traffic_out(DS[22]), traffic_in(DS[23]), traffic_out(DS[23]), traffic_in(DS[24]), traffic_out(DS[24]), traffic_in(DS[25]), traffic_out(DS[25]), Additional Issues Remain. Only showing first 20
03/03/2009 02:13:01 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
03/03/2009 02:13:01 PM - SYSTEM STATS: Time:1.2668 Method:spine Processes:30 Threads:40 Hosts:31 HostsPerProcess:2 DataSources:360 RRDsProcessed:2
03/03/2009 02:13:03 PM - SYSTEM STATS: Time:2.3567 Method:spine Processes:30 Threads:40 Hosts:31 HostsPerProcess:2 DataSources:360 RRDsProcessed:188

I've tried rebuilding poller cache, but it didn't seem to help.. pls help...

[cdnvballer]

BTW,
my only solution thus far is to disable spine and go back to cmd.php...
hmm...

[scruboy01]

I was seeing this message for one of the switchports being monitored. It was causing issues for all of the traffic graphs on the one switch. I decided to disable the offending DS for one polling cycle. After that, the next DS number started showing issues. I tried disabling all DS's for that device for one polling cycle. All DS's are now getting updated properly.

I'm not sure if this matters or not, but I also deleted the bad entry in the poller_output table.


Don't know why this works, just know that it did...

[TheWitness]

Looks like there were entries missing in the poller item table. Saving the host should have done effectively the same thing.

TheWitness

[Atkatla]

I have the same problem as cdnvballer.
I am using:0.7.8d, boost 2.4, spine

Log:

Code: Select all

03/10/2009 02:42:18 PM - SYSTEM STATS: Time:11.1322 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25333 RRDsProcessed:0 
03/10/2009 02:41:16 PM - SYSTEM STATS: Time:11.4300 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25333 RRDsProcessed:0 
03/10/2009 02:41:04 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 4472, Data Sources: 5sec(DS[4001]), 60sec(DS[4001]), 5sec(DS[4002]), 60sec(DS[4002]), 5sec(DS[4003]), 60sec(DS[4003]), 5sec(DS[4004]), 60sec(DS[4004]), 5sec(DS[4005]), 60sec(DS[4005]), 5sec(DS[4006]), 60sec(DS[4006]), traffic_in(DS[4013]), traffic_out(DS[4013]), traffic_in(DS[4014]), traffic_out(DS[4014]), traffic_in(DS[4015]), traffic_out(DS[4015]), traffic_in(DS[4016]), traffic_out(DS[4016]), traffic_in(DS[4017]), Additional Issues Remain. Only showing first 20 
03/10/2009 02:40:20 PM - SYSTEM STATS: Time:18.4554 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25333 RRDsProcessed:0 
03/10/2009 02:40:09 PM - SYSTEM STATS: Time:5.1963 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25328 RRDsProcessed:0 
03/10/2009 02:40:09 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting. 
03/10/2009 02:40:04 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 178, Data Sources: mem_buffers(DS[2901]), (DS[2903]), proc(DS[2905]), (DS[2906]), (DS[2907]), hdd_free(DS[2911]), hdd_used(DS[2911]), traffic_in(DS[26909]), traffic_out(DS[26909]), traffic_in(DS[26910]), traffic_out(DS[26910]), traffic_in(DS[26911]), traffic_out(DS[26911]), traffic_in(DS[26912]), traffic_out(DS[26912]), traffic_in(DS[26913]), traffic_out(DS[26913]), traffic_in(DS[26914]), traffic_out(DS[26914]), traffic_in(DS[26915]), traffic_out(DS[26915]), Additional Issues Remain. Only showing first 20 
03/10/2009 02:39:13 PM - SYSTEM STATS: Time:11.2050 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25328 RRDsProcessed:0 
03/10/2009 02:38:08 PM - SYSTEM BOOST STATS: Time:351.3460 RRDUpdates:1521657 
03/10/2009 02:38:05 PM - SYSTEM STATS: Time:22.4950 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25328 RRDsProcessed:0 
03/10/2009 02:36:29 PM - SYSTEM STATS: Time:12.2291 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25328 RRDsProcessed:0

This always happens a few minutes after boost finished upadating the RRD-Files.

[TheWitness]

Is any of this stuff running on Windoz? If so, you have to insure that the task does not wait on completion of the previous run.

Its a Windoz thing.

TheWitness

[Atkatla]

Nope, I am using OpenSuse11.

[charlesdf23]

Same issue here on Centos 5.

Code: Select all

03/11/2009 02:38:02 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 24193, Data Sources: traffic_in(DS[16355]), traffic_out(DS[16355]), traffic_in(DS[16357]), traffic_out(DS[16357]), traffic_in(DS[16361]), traffic_out(DS[16361]), traffic_in(DS[16366]), traffic_out(DS[16366]), traffic_in(DS[16370]), traffic_out(DS[16370]), traffic_in(DS[16375]), traffic_out(DS[16375]), traffic_in(DS[16381]), traffic_out(DS[16381]), traffic_in(DS[16386]), traffic_out(DS[16386]), traffic_in(DS[16391]), traffic_out(DS[16391]), traffic_in(DS[16395]), traffic_out(DS[16395]), traffic_in(DS[16400]), Additional Issues Remain.  Only showing first 20
03/11/2009 02:39:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[33108])
03/11/2009 02:41:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[54337])
03/11/2009 02:45:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[22668])
03/11/2009 03:05:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[28996])
03/11/2009 03:24:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_in(DS[15245])
03/11/2009 03:29:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_in(DS[54499])
03/11/2009 03:33:02 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[31517])
03/11/2009 03:35:04 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 2, Data Sources: traffic_in(DS[45231]), traffic_out(DS[57920])
03/11/2009 03:36:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[9211])
03/11/2009 03:37:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty.  Issues Found: 1, Data Sources: traffic_out(DS[9958])

It's almost always a different DS when it has an issue.

[Atkatla]

Another symptom: my DS count varies after the boost updates.
Some snippets from the log file. In the parts between the snippets there were no unusual messages.

Code: Select all

03/12/2009 10:02:49 AM - SYSTEM STATS: Time:14.0978 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 10:01:45 AM - SYSTEM STATS: Time:13.1124 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 10:01:33 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 25254, Data Sources: (DS[2903]), proc(DS[2905]), (DS[2906]), (DS[2907]), hdd_free(DS[2910]), hdd_used(DS[2910]), 5sec(DS[2912]), 60sec(DS[2912]), 5sec(DS[2913]), 60sec(DS[2913]), 5sec(DS[2914]), 60sec(DS[2914]), 5sec(DS[2915]), 60sec(DS[2915]), 5sec(DS[2916]), 60sec(DS[2916]), 5sec(DS[2917]), 60sec(DS[2917]), traffic_in(DS[2919]), traffic_out(DS[2919]), traffic_in(DS[2920]), Additional Issues Remain. Only showing first 20 
03/12/2009 10:00:54 AM - SYSTEM STATS: Time:0.2575 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 10:00:54 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting. 
03/12/2009 10:00:20 AM - SYSTEM STATS: Time:14.3708 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 10:00:17 AM - SYSTEM BOOST STATS: Time:476.7569 RRDUpdates:1494798 
03/12/2009 10:00:06 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 15139, Data Sources: mem_swap(DS[2902]), (DS[2903]), proc(DS[2905]), (DS[2906]), (DS[2907]), 5sec(DS[2912]), 60sec(DS[2912]), 5sec(DS[2913]), 60sec(DS[2913]), 5sec(DS[2914]), 60sec(DS[2914]), 5sec(DS[2915]), 60sec(DS[2915]), 5sec(DS[2916]), 60sec(DS[2916]), 5sec(DS[2917]), 60sec(DS[2917]), traffic_in(DS[2919]), traffic_out(DS[2919]), traffic_in(DS[2920]), traffic_out(DS[2920]), Additional Issues Remain. Only showing first 20 
03/12/2009 10:00:02 AM - SYSTEM STATS: Time:15.3225 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 10:00:02 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting. 
03/12/2009 09:58:07 AM - SYSTEM STATS: Time:38.2147 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 09:56:20 AM - SYSTEM STATS: Time:16.2669 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0
...
03/12/2009 09:02:20 AM - SYSTEM STATS: Time:12.6936 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 09:01:17 AM - SYSTEM STATS: Time:12.3517 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 09:01:05 AM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 25254, Data Sources: (DS[2903]), proc(DS[2905]), (DS[2906]), (DS[2907]), hdd_free(DS[2910]), hdd_used(DS[2910]), 5sec(DS[2912]), 60sec(DS[2912]), 5sec(DS[2913]), 60sec(DS[2913]), 5sec(DS[2914]), 60sec(DS[2914]), 5sec(DS[2915]), 60sec(DS[2915]), 5sec(DS[2916]), 60sec(DS[2916]), 5sec(DS[2917]), 60sec(DS[2917]), traffic_in(DS[2919]), traffic_out(DS[2919]), traffic_in(DS[2920]), Additional Issues Remain. Only showing first 20 
03/12/2009 09:00:17 AM - SYSTEM STATS: Time:0.3033 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 09:00:17 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting. 
03/12/2009 09:00:16 AM - SYSTEM STATS: Time:14.9959 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25085 RRDsProcessed:0 
03/12/2009 08:59:26 AM - SYSTEM STATS: Time:22.2920 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 08:58:50 AM - SYSTEM BOOST STATS: Time:392.0947 RRDUpdates:1532392 
03/12/2009 08:57:48 AM - SYSTEM STATS: Time:15.5044 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0 
03/12/2009 08:56:40 AM - SYSTEM STATS: Time:19.3260 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:25254 RRDsProcessed:0
...
03/12/2009 08:01:28 AM - SYSTEM STATS: Time:10.8561 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:24745 RRDsProcessed:0 
03/12/2009 08:00:19 AM - SYSTEM STATS: Time:17.7638 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:24745 RRDsProcessed:0 
03/12/2009 08:00:04 AM - SPINE: Poller[0] FATAL: Connection Failed, Error:'1040', Message:'Too many connections' (Spine thread) 
03/12/2009 08:00:01 AM - SYSTEM STATS: Time:0.3120 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:24326 RRDsProcessed:0 
03/12/2009 08:00:01 AM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting. 
03/12/2009 07:59:36 AM - SYSTEM BOOST STATS: Time:498.9042 RRDUpdates:1522486 
03/12/2009 07:59:18 AM - SYSTEM STATS: Time:27.2789 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:24326 RRDsProcessed:0 
03/12/2009 07:57:41 AM - SYSTEM STATS: Time:15.3399 Method:spine Processes:2 Threads:40 Hosts:74 HostsPerProcess:37 DataSources:24326 RRDsProcessed:0

I am doing hourly boost updates. 1GB php memory limit.

[TheWitness]

I'm not clear on this neither, what exactly is the fix?

I'm seeing the following now, on a 0.8.7d setup that is polling 1-minute intervals with 5-minute cron:

03/03/2009 02:13:01 PM - POLLER: Poller[0] WARNING: Poller Output Table not Empty. Issues Found: 330, Data Sources: users(DS[6]), traffic_in(DS[10]), traffic_out(DS[10]), traffic_in(DS[11]), traffic_out(DS[11]), traffic_in(DS[12]), traffic_out(DS[12]), traffic_in(DS[13]), traffic_out(DS[13]), asa5min_cpu(DS[18]), asa_memfree(DS[19]), asa_memused(DS[20]), asa_conn(DS[21]), traffic_in(DS[22]), traffic_out(DS[22]), traffic_in(DS[23]), traffic_out(DS[23]), traffic_in(DS[24]), traffic_out(DS[24]), traffic_in(DS[25]), traffic_out(DS[25]), Additional Issues Remain. Only showing first 20
03/03/2009 02:13:01 PM - POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
03/03/2009 02:13:01 PM - SYSTEM STATS: Time:1.2668 Method:spine Processes:30 Threads:40 Hosts:31 HostsPerProcess:2 DataSources:360 RRDsProcessed:2
03/03/2009 02:13:03 PM - SYSTEM STATS: Time:2.3567 Method:spine Processes:30 Threads:40 Hosts:31 HostsPerProcess:2 DataSources:360 RRDsProcessed:188

I've tried rebuilding poller cache, but it didn't seem to help.. pls help...

This issue is likely due to the following:

Processes = 30
Threads = 40
Script Servers = ?? (Guess 5)

MySQL Connections Required for Poller is

30 * 40 + 30 * 5 = 1350

Most MySQL servers don't allow more than 100 without changes. AKA Crash without better planning.

TheWitness

[Atkatla]

Hmm, my poller settings:
Maximum Concurrent Poller Processes: 2
Maximum Threads per Process: 40
Number of PHP Script Servers:1

That makes 2*40+2*1= 82. Shouldnt be a problem?

[TheWitness]

Well, that was not what you had shown earlier. Now, check you my.cnf in the /etc directory, if you don't have one, you won't have enough extra to render graphs. I typically keep about 1000 connections available for systems where many people are viewing graphs and spine is broad and wide (aka lot's of connections).

TheWitness