Cron Log doesn't Match Cacti Log

[icewalker]

I'm running the poller.php in a crontab. I've noticed some blanks in my graphs, always around midnight and it would appear across EVERY graph for all devices.

So I was curious to see if something else was getting in the way of cron. What I have found is that cron says it ran the poller.php, but the cacti log says otherwise.

Has anybody seen something similar? I've included the log entries from around midnight.

Cron Log

Sep 29 23:50:01 R0B-WEBP02 crond[7526]: (root) CMD (php /var/www/html/cacti/poller.php > /dev/null 2>&1)
Sep 29 23:55:01 R0B-WEBP02 crond[7836]: (root) CMD (php /var/www/html/cacti/poller.php > /dev/null 2>&1)
Sep 30 00:00:01 R0B-WEBP02 crond[8131]: (root) CMD (php /var/www/html/cacti/poller.php > /dev/null 2>&1)
Sep 30 00:05:01 R0B-WEBP02 crond[8351]: (root) CMD (php /var/www/html/cacti/poller.php > /dev/null 2>&1)
Sep 30 00:10:01 R0B-WEBP02 crond[8646]: (root) CMD (php /var/www/html/cacti/poller.php > /dev/null 2>&1)

Cacti Log

09/29/2008 11:50:10 PM - SYSTEM STATS: Time:9.2679 Method:cmd.php Processes:1 Threads:N/A Hosts:14 HostsPerProcess:14 DataSources:67 RRDsProcessed:50
09/29/2008 11:55:10 PM - SYSTEM STATS: Time:9.2561 Method:cmd.php Processes:1 Threads:N/A Hosts:14 HostsPerProcess:14 DataSources:67 RRDsProcessed:50
09/30/2008 12:05:02 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 601 seconds have passed since the last poll!
09/30/2008 12:05:13 AM - SYSTEM STATS: Time:10.7801 Method:cmd.php Processes:1 Threads:N/A Hosts:14 HostsPerProcess:14 DataSources:67 RRDsProcessed:50
09/30/2008 12:10:10 AM - SYSTEM STATS: Time:9.2540 Method:cmd.php Processes:1 Threads:N/A Hosts:14 HostsPerProcess:14 DataSources:67 RRDsProcessed:50

I've changed my crontab entry to the following (as of this post) in the hopes of getting more data.

*/5 * * * * root php /var/www/html/cacti/poller.php > /var/log/poller.log 2>&1

cacti version 0.8.7b
rrdtool version rrdtool-1.3.1-1.fc10
OS Level - RHEL 5 x86_64

Thanks

James

[Ateo]

The only time I've seen this error logged is when I force execute poller.php while I was testing a custom script. So, from my experience, the error tells me that the poller was executed once (or more) between the 5 minute cron job. Does your system clock drift?

[icewalker]

OK, I've narrowed down why my poller.php is not working properly. It isn't poller.php, but rather an issue with the MySQL Server at mignight.

Code: Select all

OK u:0.00 s:0.00 r:8.10
OK u:0.00 s:0.00 r:8.10
OK u:0.00 s:0.00 r:9.11
OK u:0.00 s:0.00 r:9.11
OK u:0.00 s:0.00 r:9.11
OK u:0.00 s:0.00 r:9.11
10/02/2008 11:55:10 PM - SYSTEM STATS: Time:9.2516 Method:cmd.php Processes:1 Threads:N/A Hosts:14 HostsPerProcess:14 DataSources:67 RRDsProcessed:50
FATAL: Cannot connect to MySQL server on 'xxxxxxxxx'. Please make sure you have specified a valid MySQL database name in 'include/config.php'
10/03/2008 12:05:02 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 601 seconds have passed since the last poll!
OK u:0.00 s:0.00 r:1.05
OK u:0.00 s:0.00 r:1.05
OK u:0.00 s:0.00 r:1.05
OK u:0.00 s:0.00 r:1.05
OK u:0.00 s:0.00 r:1.05

At first, I thought it was the MySQL Backup, but that runs at 12:15 AM. But it turns out that there is "other" maintenance that I was not aware of that occurs at Midnight that appears to be causing the problem. I'll have a chat with the other MySQL Admin.

Thanks for all the help.

James