我目前正在设置一个新的 Debian (6.0.5) 服务器。我昨天把 Cacti (0.8.7g) 放在上面,从那以后就一直在和它作斗争。
创刊号
我观察到的最初问题是我的图表没有更新。所以我检查了我的cacti.log
并发现了这条有关的消息:
POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.
这不太好,对吧?所以我去检查并开始poller.php
自己(通过sudo -u www-data php poller.php --force
)。它将输出大量消息(看起来都像我期望的那样)然后挂起一分钟。1 分钟后,它将循环显示以下消息:
Waiting on 1 of 1 pollers.
这将持续 4 分钟,直到该进程因运行时间超过 298 秒而被强制终止。
到目前为止,一切都很好
我花了一个小时试图确定哪些轮询器可能仍在运行,直到我得出结论,根本没有正在运行的轮询器。
调试
我检查poller.php
了该警告是如何发出的以及原因。在第 368 行,Cacti 将从数据库中检索已完成的进程数,并使用该值计算仍在运行的进程数。那么,让我们看看这个值!
我将以下调试代码添加到poller.php
:
$finished_processes = db_fetch_cell("SELECT count(*) FROM cacti.poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00'");
print "Finished: " . $finished_processes . " - Started: " . $started_processes . "\n";
结果
这将在启动后的一秒钟内打印以下内容poller.php
:
Finished: 0 - Started: 1
Waiting on 1 of 1 pollers.
Finished: 1 - Started: 1
所以这些值正在被读取并且是有效的。直到我们到达它不断循环的部分:
Finished: - Started: 1
Waiting on 1 of 1 pollers.
突然,价值消失了。为什么?放在var_dump()
那里确认了这个问题:
NULL
Finished: - Started: 1
Waiting on 1 of 1 pollers.
返回值为NULL
。查询时怎么会这样SELECT COUNT()...
?(SELECT COUNT()
应该总是返回一个结果行,不是吗?)
更多调试
所以我进去lib\database.php
看了看db_fetch_cell()
。一些测试证实,结果集实际上是空的。
所以我在其中添加了我自己的数据库查询代码,看看它会做什么:
$finished_processes = db_fetch_cell("SELECT count(*) FROM poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00'");
print "Finished: " . $finished_processes . " - Started: " . $started_processes . "\n";
$mysqli = new mysqli("localhost","cacti","cacti","cacti");
$result = $mysqli->query("SELECT COUNT(*) FROM poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00';");
$row = $result->fetch_assoc();
var_dump( $row );
这将输出
Finished: - Started: 1
array(1) {
["COUNT(*)"]=>
string(1) "2"
}
Waiting on 1 of 1 pollers.
那么,数据就在那里并且可以毫无问题地访问,只是不是使用 Cacti 使用的方法?
仔细检查!
我启用了 MySQL 日志记录以确保我不是在想象事情。果然,当错误消息循环时,cacti.log
读取起来就好像它在疯狂查询一样:
06/29/2012 08:44:00 PM - CMDPHP: Poller[0] DEVEL: SQL Cell: "SELECT count(*) FROM cacti.poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00'"
06/29/2012 08:44:01 PM - CMDPHP: Poller[0] DEVEL: SQL Cell: "SELECT count(*) FROM cacti.poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00'"
06/29/2012 08:44:02 PM - CMDPHP: Poller[0] DEVEL: SQL Cell: "SELECT count(*) FROM cacti.poller_time WHERE poller_id=0 AND end_time>'0000-00-00 00:00:00'"
但是这些查询都没有被 MySQL 记录下来。然而,当我添加自己的数据库查询代码时,它显示得很好。
这到底是怎么回事?
深层发掘...
我得出的结论是,数据库连接一定是在这个过程中的某个地方丢失了,而 adodb 根本不在乎。
因此,经过一番挖掘,我最终将调试消息放在函数drivers/adodb-mysql.inc.php
的第 529 行中_close
。我想看看连接何时关闭。
我实际上(最终)打开了 PHP 调试并意识到mysql_query()
使用布尔连接 ID(有意关闭连接的指示符)调用。
// returns true or false
function _close()
{
@mysql_close($this->_connectionID);
echo "!!!! CLOSED !!!!\n";
debug_print_backtrace();
$this->_connectionID = false;
}
那打印什么?
oliver@j27773:/etc/php5/conf.d$ sudo -u www-data php /usr/share/cacti/site/poller.php --force
06/30/2012 01:33:49 AM - POLLER: Poller[0] NOTE: Poller Int: '60', Cron Int: '300', Time Since Last: '61', Max Runtime '298', Poller Runs: '5'
06/30/2012 01:33:49 AM - POLLER: Poller[0] DEBUG: About to Spawn a Remote Process [CMD: /usr/bin/php, ARGS: -q "/usr/share/cacti/site/cmd.php" 0 3]
Finished: 0 - Started: 1
Waiting on 1 of 1 pollers.
Finished: 1 - Started: 1
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_apache_sb_keepalive_100.rrd --template apache_sb_keepalive 1341012829:0
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_apache_reqpersec_95.rrd --template apache_reqpersec 1341012829:.0228409
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_apache_bytesperreq_90.rrd --template apache_bytesperreq 1341012829:13925.7
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_cpu_85.rrd --template cpu 1341012829:1
OK u:0.00 s:0.00 r:1.00
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_hdd_used_80.rrd --template hdd_used:hdd_total 1341012829:924741632:2677886976
OK u:0.00 s:0.00 r:1.00
OK u:0.00 s:0.01 r:1.00
OK u:0.00 s:0.01 r:1.00
06/30/2012 01:33:50 AM - POLLER: Poller[0] CACTI2RRD: /usr/bin/rrdtool update /var/lib/cacti/rra/j27773_servers_jiffybox_net_apache_sb_wait_105.rrd --template apache_sb_wait 1341012829:9
OK u:0.00 s:0.01 r:1.00
OK u:0.00 s:0.01 r:1.00
06/30/2012 01:33:50 AM - SYSTEM STATS: Time:1.1261 Method:cmd.php Processes:1 Threads:N/A Hosts:2 HostsPerProcess:2 DataSources:7 RRDsProcessed:6
Loop Time is: 1.1291718482971
Sleep Time is: 58.867464065552
Total Time is: 1.1325359344482
!!!! CLOSED !!!!
#0 ADODB_mysql->_close() called at [/usr/share/php/adodb/adodb.inc.php:2141]
#1 ADOConnection->Close() called at [/usr/share/cacti/site/lib/database.php:68]
#2 db_close() called at [/usr/share/cacti/site/poller.php:455]
^C06/30/2012 01:33:55 AM - CMDPHP: Poller[0] WARNING: Cacti Master Poller process terminated by user
现在我太累了,无法调查……
我确实进一步调查了一下,意识到关闭与数据库的连接是有意的。应该为下一次轮询运行重新建立连接。但事实并非如此。
以下是摘录自
poller.php
:我也检查
db_connect_real
过,它实际上是在usleep
完成后调用的。所以这就是我将继续挖掘的地方。目前,我修改了这样的部分:
现在轮询器在没有任何警告的情况下运行,并且正在绘制我的图表。然而,还有一个问题。并非我所有的图表都被正确绘制,如下图所示:
点击放大
我认为这是由于轮询器对于某些数据源运行太少所致。为了解决这个问题,我切换到spine(无论如何我都想这样做)并将其设置为使用 4 个线程。
到目前为止,一切都很好...
更新
我深入研究了这个问题,并认为我已经解决了它。我假设在轮询器尝试重新连接后连接没有正确存储。
我试图解决这个问题,起初看起来很有希望,但生成的图表仍然有问题。所以问题就更深了。
我之前开发并在此答案中提出的解决方法仍然可以完美运行。我决定不再在这个问题上投入更多时间并继续使用解决方法。对不起。