Mengapa Cacti terus menunggu proses poller mati?

11

Saat ini saya sedang menyiapkan server Debian (6.0.5) baru. Saya meletakkan Cacti (0.8.7g) di atasnya kemarin dan telah berjuang sejak itu.

Masalah awal

Masalah awal yang saya amati, adalah grafik saya tidak diperbarui. Jadi saya memeriksa cacti.logpesan saya dan menemukan ini:

POLLER: Poller[0] Maximum runtime of 298 seconds exceeded. Exiting.

Itu tidak baik, bukan? Jadi saya pergi memeriksa dan mulai poller.phpsendiri (via sudo -u www-data php poller.php --force). Ini akan memompa banyak pesan (yang semuanya terlihat seperti apa yang saya harapkan) dan kemudian tunggu sebentar. Setelah 1 menit itu, itu akan mengulang pesan berikut:

Waiting on 1 of 1 pollers.

Ini berlangsung selama 4 menit lagi sampai proses ini secara paksa berakhir untuk berjalan lebih lama dari 298s.

Sejauh ini baik

Saya melanjutkan selama satu jam yang baik mencoba menentukan poller apa yang mungkin masih berjalan, sampai saya sampai pada kesimpulan bahwa tidak ada polling berjalan .

Debugging

Saya memeriksa poller.phpuntuk melihat bagaimana peringatan itu dikeluarkan dan mengapa. Pada baris 368, Cacti akan mengambil jumlah proses yang selesai dari database dan menggunakan nilai itu untuk menghitung berapa banyak proses yang masih berjalan. Jadi, mari kita lihat nilainya!

Saya menambahkan kode debug berikut ke dalam 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";

Hasil

Ini akan mencetak yang berikut dalam beberapa detik sejak mulai poller.php:

Finished: 0 - Started: 1
Waiting on 1 of 1 pollers.
Finished: 1 - Started: 1

Jadi nilainya sedang dibaca dan valid. Sampai kita sampai pada bagian di mana ia terus berulang:

Finished:  - Started: 1
Waiting on 1 of 1 pollers.

Tiba-tiba, nilainya hilang. Mengapa? Menempatkan var_dump()di sana mengkonfirmasi masalah:

NULL
Finished:  - Started: 1
Waiting on 1 of 1 pollers.

Nilai pengembaliannya adalah NULL. Bagaimana bisa saat bertanya SELECT COUNT()...? ( SELECT COUNT()harus selalu mengembalikan satu baris hasil, bukan?)

Lebih banyak debugging

Jadi saya pergi ke lib\database.phpdan melihat itu db_fetch_cell(). Sedikit pengujian dikonfirmasi, bahwa hasil yang disetel sebenarnya kosong.

Jadi saya menambahkan kode kueri basis data saya sendiri di sana untuk melihat apa yang akan dilakukan:

$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 );

Ini akan menampilkan

Finished:  - Started: 1
array(1) {
  ["COUNT(*)"]=>
  string(1) "2"
}
Waiting on 1 of 1 pollers.

Jadi, data ada di sana dan dapat diakses tanpa masalah, hanya saja tidak dengan metode yang Cacti gunakan?

Periksa itu!

Saya mengaktifkan logging MySQL untuk memastikan saya tidak membayangkan hal-hal. Benar saja, ketika pesan kesalahan diulang, cacti.logbunyinya seolah-olah sedang bertanya seperti mad:

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'"

Tetapi tidak satu pun dari pertanyaan ini dicatat oleh MySQL. Namun, ketika saya menambahkan kode kueri basis data saya sendiri, itu muncul dengan baik.

masukkan deskripsi gambar di sini
klik untuk memperbesar

Apa yang terjadi di sini?

Menggali lebih dalam...

Saya menyimpulkan bahwa koneksi database harus hilang di suatu tempat dalam proses dan adodb tidak peduli.

Jadi setelah sedikit menggali, saya akhirnya menempatkan pesan debug drivers/adodb-mysql.inc.php, baris 529, dalam _closefungsi. Saya ingin melihat ketika koneksi ditutup.

Saya sebenarnya (akhirnya) menyalakan debugging PHP dan menyadari mysql_query()dipanggil dengan koneksi boolean id (indikator koneksi yang sengaja ditutup).

// returns true or false
function _close()
{
    @mysql_close($this->_connectionID);
    echo "!!!! CLOSED !!!!\n";
    debug_print_backtrace();
    $this->_connectionID = false;
}

Apa yang tercetak itu?

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

Dan sekarang saya terlalu lelah untuk menyelidiki itu ...

Der Hochstapler
sumber

Jawaban:

6

Saya menyelidiki sedikit lebih jauh dan menyadari bahwa penutupan koneksi ke database disengaja. Koneksi harus dibangun kembali untuk menjalankan pemungutan suara berikutnya. Tapi ternyata tidak.

Berikut kutipan dari 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);
}

Saya juga memeriksa db_connect_realdan, pada kenyataannya, dipanggil setelah usleepselesai. Jadi di situlah saya akan terus menggali.

Untuk saat ini, saya memodifikasi bagian seperti ini:

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);
}

Sekarang poller berjalan tanpa peringatan apa pun dan grafik saya sedang digambar. Namun, masih ada masalah. Tidak semua grafik saya digambar dengan benar, seperti yang dapat dilihat dari gambar berikut:

Grafik yang diberikan menunjukkan hasil dari solusi
klik untuk memperbesar

Saya berasumsi ini karena poller berjalan terlalu jarang untuk sumber data tertentu. Untuk mengatasinya, saya beralih ke tulang belakang (yang ingin saya lakukan tetap) dan mengaturnya untuk menggunakan 4 utas.

Konfigurasi poller Cacti

Sejauh ini baik...

Memperbarui

Saya menggali lebih dalam tentang masalah ini dan berpikir saya telah memperbaikinya. Saya berasumsi koneksi tidak disimpan dengan benar setelah upaya menghubungkan kembali poller.

Upaya saya untuk menyelesaikan itu tampak menjanjikan pada awalnya, tetapi grafik yang dihasilkan masih salah. Jadi masalahnya terletak lebih dalam.

Solusi yang saya kembangkan sebelumnya dan disajikan dalam jawaban ini masih berfungsi dengan baik. Saya memutuskan untuk tidak menginvestasikan waktu lagi pada masalah ini dan tetap dengan solusinya. Maaf.

Der Hochstapler
sumber