Poller not synced with cron

Post support questions that directly relate to Linux/Unix operating systems.

Moderators: Developers, Moderators

Post Reply
User avatar
AdamKadmon
Posts: 6
Joined: Tue Oct 03, 2006 6:18 pm
Location: Broomfield, CO. USA

Poller not synced with cron

Post by AdamKadmon »

Hi Forum,

I've seen a post or two about this, and have verified that:
1. There is only one cron job running (for this...).
2. Cronjob looks like this (under cacti(user))

Code: Select all

*/5 * * * * php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1
3. Here's a snip from /var/log/cron to verify, there is only one of these running, and nearly exactly every 5 minutes:

Code: Select all

Sep 25 06:05:01 cotwiki01 crond[31351]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:10:01 cotwiki01 crond[32559]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:15:01 cotwiki01 crond[1310]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:20:01 cotwiki01 crond[2567]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:25:01 cotwiki01 crond[3784]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:30:01 cotwiki01 crond[4991]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:35:01 cotwiki01 crond[5552]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:40:01 cotwiki01 crond[6752]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:45:01 cotwiki01 crond[7960]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:50:01 cotwiki01 crond[8862]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 06:55:01 cotwiki01 crond[10066]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:00:01 cotwiki01 crond[11282]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:05:01 cotwiki01 crond[12493]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:10:01 cotwiki01 crond[13710]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:15:02 cotwiki01 crond[14917]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:20:01 cotwiki01 crond[16030]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:25:01 cotwiki01 crond[17234]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:30:01 cotwiki01 crond[18436]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:35:01 cotwiki01 crond[18795]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:40:01 cotwiki01 crond[20132]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:45:01 cotwiki01 crond[21369]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
Sep 25 07:50:01 cotwiki01 crond[22095]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log 2>&1)
4. Here's a snip of the resultant poller.log:

Code: Select all

OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
OK u:0.00 s:0.03 r:1.12
5. And finally, the cacti.log:

Code: Select all

09/25/2008 06:10:03 AM - SYSTEM STATS: Time:1.2252 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:15:02 AM - SYSTEM STATS: Time:1.1713 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:20:02 AM - SYSTEM STATS: Time:1.1795 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:25:03 AM - SYSTEM STATS: Time:1.1788 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:32:44 AM - POLLER: Poller[0] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a   '300' second Cron, but 463 seconds have passed since the last poll!
09/25/2008 06:32:45 AM - SYSTEM STATS: Time:1.4475 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:35:03 AM - SYSTEM STATS: Time:1.2571 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:40:02 AM - SYSTEM STATS: Time:1.1846 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:46:19 AM - POLLER: Poller[0] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a   '300' second Cron, but 378 seconds have passed since the last poll!
09/25/2008 06:46:20 AM - SYSTEM STATS: Time:1.1668 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:50:02 AM - SYSTEM STATS: Time:1.1865 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 06:55:02 AM - SYSTEM STATS: Time:1.2040 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:00:02 AM - SYSTEM STATS: Time:1.3005 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:05:02 AM - SYSTEM STATS: Time:1.1801 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:10:03 AM - SYSTEM STATS: Time:1.2254 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:15:26 AM - POLLER: Poller[0] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a   '300' second Cron, but 325 seconds have passed since the last poll!
09/25/2008 07:15:27 AM - SYSTEM STATS: Time:1.2306 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:20:03 AM - SYSTEM STATS: Time:1.1755 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:25:03 AM - SYSTEM STATS: Time:1.3849 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:33:37 AM - POLLER: Poller[0] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a   '300' second Cron, but 515 seconds have passed since the last poll!
09/25/2008 07:33:38 AM - SYSTEM STATS: Time:1.1939 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:35:03 AM - SYSTEM STATS: Time:1.1676 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:40:02 AM - SYSTEM STATS: Time:1.2498 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:47:01 AM - POLLER: Poller[0] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a   '300' second Cron, but 420 seconds have passed since the last poll!
09/25/2008 07:47:03 AM - SYSTEM STATS: Time:1.1813 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
09/25/2008 07:50:02 AM - SYSTEM STATS: Time:1.4212 Method:cmd.php Processes:1 Threads:N/A Hosts:8 HostsPerProcess:8 DataSources:83 RRDsProcessed:73
This is all running on a CentOS 5.1 system. I installed cacti via yum, removed the extra cron job from /etc/cron.d and do get graphs, just with a few gaps here and there, and I would like to get rid of 'em. I don't have this issue on another system running cacti (Debian Etch).

Hope someone can help! :D

Thanks,

Adam
User avatar
AdamKadmon
Posts: 6
Joined: Tue Oct 03, 2006 6:18 pm
Location: Broomfield, CO. USA

Post by AdamKadmon »

Additional point of note:
I've been watching the logs all day, after turning up logging to DEBUG, and am noticing a very interesting behavior here.

The cron log shows that the job is kicked off in a timely fashion

Code: Select all

Sep 25 13:30:01 cotwiki01 crond[19748]: (cacti) CMD (php -q /var/www/cacti/poller.php --force --debug >> /var/www/cacti/log/poller.log && date >> /var/www/cacti/log/poller.log 2>&1)
but the cacti.log shows that periodically, nothing happens for sometimes over a minute.

I've attached the chunk of DEBUG output from a moment where it doesn't work, and it doesn't even begin logging until a full minute after cron kicked it off.

There must be something happening to poller.php or cmd.php periodically that hangs it up.

Thanks again,

Adam
Attachments
cacti_error.txt
from 20080925:133155 to 20080925:133153
(65.9 KiB) Downloaded 160 times
User avatar
AdamKadmon
Posts: 6
Joined: Tue Oct 03, 2006 6:18 pm
Location: Broomfield, CO. USA

Post by AdamKadmon »

Bump...
Post Reply

Who is online

Users browsing this forum: No registered users and 2 guests