¿Por qué Cacti sigue esperando procesos de sondeo muertos?

11

Actualmente estoy configurando un nuevo servidor Debian (6.0.5). Puse Cacti (0.8.7g) ayer y he estado luchando con eso desde entonces.

Problema inicial

El problema inicial que estaba observando era que mis gráficos no se actualizaban. Así que revisé mi cacti.logy encontré este mensaje relacionado:

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

Eso no puede ser bueno, ¿verdad? Así que fui a verificar y comencé poller.phpyo mismo (vía sudo -u www-data php poller.php --force). Lanzará muchos mensajes (que se parecen a lo que esperaría) y luego se bloqueará por un minuto. Después de ese 1 minuto, repetirá el siguiente mensaje:

Waiting on 1 of 1 pollers.

Esto continúa durante 4 minutos más hasta que el proceso finaliza por la fuerza por más de 298 segundos.

Hasta ahora tan bueno

Continué durante una buena hora tratando de determinar qué encuestador aún podría estar funcionando, hasta que llegué a la conclusión de que simplemente no hay un encuestador en ejecución .

Depuración

Revisé poller.phppara ver cómo se emite esa advertencia y por qué. En la línea 368, Cacti recuperará el número de procesos terminados de la base de datos y usará ese valor para calcular cuántos procesos aún se están ejecutando. Entonces, ¡veamos ese valor!

Agregué el siguiente código de depuración en 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";

Resultado

Esto imprimirá lo siguiente dentro de un segundo de comenzar poller.php:

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

Entonces los valores se leen y son válidos. Hasta que lleguemos a la parte donde sigue girando:

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

De repente, el valor se ha ido. ¿Por qué? Poner var_dump()allí confirma el problema:

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

El valor de retorno es NULL. ¿Cómo puede ser eso cuando se consulta SELECT COUNT()...? ( SELECT COUNT()siempre debe devolver una fila de resultados, ¿no?)

Más depuración

Así que entré lib\database.phpy eché un vistazo a eso db_fetch_cell(). Un poco de prueba confirmó que el conjunto de resultados está realmente vacío.

Así que agregué mi propio código de consulta de la base de datos para ver qué haría eso:

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

Esto dará salida

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

Entonces, ¿los datos están ahí y se puede acceder sin problemas, solo que no con el método que Cacti está usando?

¡Verifica eso!

He habilitado el registro de MySQL para asegurarme de que no estoy imaginando cosas. Efectivamente, cuando el mensaje de error se repite, se cacti.loglee como si estuviera preguntando como loco:

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

Pero MySQL no registra ninguna de estas consultas. Sin embargo, cuando agrego mi propio código de consulta de base de datos, aparece muy bien.

ingrese la descripción de la imagen aquí
Click para agrandar

¿Qué diablos está pasando aquí?

Cavar más profundo...

Llegué a la conclusión de que la conexión de la base de datos debe perderse en algún lugar del proceso y a adodb simplemente no le importa.

Entonces, después de un poco de investigación, finalmente coloqué el mensaje de depuración en la drivers/adodb-mysql.inc.phplínea 529 de la _closefunción. Quería ver cuándo se cierra la conexión.

De hecho (finalmente) activé la depuración de PHP y me di cuenta de que mysql_query()se llamaba con una identificación de conexión booleana (un indicador de una conexión cerrada intencionalmente).

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

¿Qué imprime eso?

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

Y ahora estoy demasiado cansado para investigar eso ...

php debian-squeeze cacti Der Hochstapler
fuente

Respuestas:

6

Investigué un poco más y me di cuenta de que el cierre de la conexión a la base de datos es intencional. La conexión debe restablecerse para la próxima ejecución de sondeo. Pero no lo es.

Aquí hay un extracto de 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);
}

También lo verifiqué db_connect_realy, de hecho, se llama después de usleepcompletarse. Entonces ahí es donde seguiré cavando.

Por el momento, modifiqué la sección así:

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

Ahora el sondeo se ejecuta sin advertencias y se están dibujando mis gráficos. Sin embargo, todavía hay un problema. No todos mis gráficos se están dibujando correctamente, como se puede ver en la siguiente imagen:

Un gráfico representado que muestra los resultados de la solución
Click para agrandar

Supuse que esto se debe a que el sondeo se ejecuta muy raramente para ciertas fuentes de datos. Para resolver eso, cambié a la columna vertebral (que quería hacer de todos modos) y lo configuré para usar 4 hilos.

Configuración de sondeo de cactus

Hasta ahora tan bueno...

Actualizar

Profundicé en este problema y pensé que lo había solucionado. Supuse que la conexión no se almacena correctamente después del intento de reconexión del sondeo.

Mi intento de resolver eso parecía prometedor al principio, pero los gráficos resultantes todavía estaban defectuosos. Entonces el problema es más profundo.

La solución que desarrollé antes y que presenté en esta respuesta todavía funciona perfectamente. Decidí no invertir más tiempo en este tema y seguir con la solución. Lo siento.

Der Hochstapler
fuente