创刊号
我观察的最初问题是我的图表没有更新.所以我检查了我的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";
结果
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");
$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根本不关心.
经过一番挖掘后,我终于将调试消息放在_close函数的drivers / adodb-MysqL.inc.PHP第529行.我想看看连接什么时候关闭.
我实际上(最后)打开了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的摘录：
if ($poller_runs_completed < $poller_runs) {
db_close();
// Debug message by myself
echo "RECONNECTING IN " . $sleep_time . "\n";
usleep($sleep_time * 1000000);
db_connect_real($database_hostname,$database_username,$database_password,$database_default,$database_type,$database_port);
}
我还检查了db_connect_real,事实上,它在usleep完成后被调用.这就是我将继续挖掘的地方.
目前,我修改了这样的部分：
if ($poller_runs_completed < $poller_runs) {
//db_close();
// Debug message by myself
echo "RECONNECTING IN " . $sleep_time . "\n";
usleep($sleep_time * 1000000);
//db_connect_real($database_hostname,$database_port);
}
现在轮询器运行没有任何警告,我的图表正在绘制.然而,仍然存在一个问题.并非所有图表都被正确绘制,如下图所示：
我认为这是由于轮询器对于某些数据源运行得太少.为了解决这个问题,我切换到spine(无论如何我想做)并将其设置为使用4个线程.
到现在为止还挺好…
更新
我深入研究了这个问题,并认为我已经解决了这个问题.我认为在重新连接轮询器之后没有正确存储连接.
我一开始尝试解决这个问题看起来很有希望,但结果图仍然有问题.所以问题更深层次.
