MySQL, rotado de slow logs

Hace un tiempo publicamos una entrada acerca de cómo activar el log de Slow Query's para MySQL. Esta práctica suele ser bastante habitual y recomendada. Si una query tarda mucho en ejecutarse puede comprometer todo el rendimiento del sistema. Así que mejor saber cual es, para poder solucionarla (si es posible).

El detalle que nos trae a cuenta es que este log, al final es un fichero de texto con muchas entradas, pero que crece de forma indefinida y cada vez ocupa más o más espacio. Para evitar que crezca de forma descontrolada, lo que debemos hacer es rotarlo. Para hacer esta tarea, los sistemas GNU/Linux emplean logrotate.

Logrotate tiene dos técnicas de rotación,

• copytruncate, copia el fichero a uno nuevo y luego lo trunca.
• no copytruncate, emplea la función rename del sistema para mover el fichero a uno nuevo. Luego el daemon que escribe necesita recibir la señal de reopen.

El problema que tenemos es que truncar el fichero de logs de MySQL puede hacer que éste se bloquee y cambiar el nombre del fichero y reiniciar el servicio, no siempre es posible, ya que dejaríamos el sistema por un tiempo sin servicio. Puede no ser mucho, pero suficiente. Para solucionar este problema, desde el blog de Percona ofrecen una solución. Lo primero es crear el fichero de configuración en logrotate (mysql-slow).

/var/log/mysql/slow_query.log {
   nocompress
   create 660 mysql mysql
   size 1G
   dateext
   missingok
   notifempty
   sharedscripts
   postrotate
      mysql -u logrotate -ppasswd -e 'select @@global.long_query_time into @lqt_save; set global long_query_time=2000; select sleep(2); FLUSH LOGS; select sleep(2); set global long_query_time=@lqt_save;'
   endscript
   rotate 150

A diferencia del código original, nosotros vamos a configurar un usuario que tenga acceso restringido al servicio MySQL para poder hacer las operaciones que necesita. El usuario será logrotate,

mysql> CREATE USER 'logrotate'@'localhost' IDENTIFIED BY 'passwd';
mysql> GRANT select,file,super,reload ON *.* TO 'logrotate'@'localhost';

La idea de crear este usuario es para evitar problemas de seguridad de acceder con root o tener el sistema sin contraseña para localhost.

Con el usuario ya creado, probamos si el fichero de configuración de logrotate funciona. Para ello,

shell> logrotate -vf /etc/logrotate.d/mysql-slow

Si no hay fallos, el fichero de logs se rotará de forma automatizada.

Leer más

Coloreando log's

Una de las partes más importantes de los sistemas GNU/Linux es fa facilidad que tiene este de saber todo lo que pasa en el sistema. Syslog está prácticamente integrado en todo el software que existe y por lo tanto saber algo de nuestro sistema es simplemente cuestión de ir a un log para verlo. De ahí la vital importancia de syslog/rsyslog y de la carpeta /var/log.

Sin embargo, fijo que a todos nos ha pasado, cuando tenemos que mirar muchas líneas de log puede resultar un poco monótono e incluso molesto no tener unos colores que te vayan indicando las palabras clave sobre las que deberías fijarte más. Puesto que los ficheros de log son texto plano, su contenido se puede listar de muchas formas: tail, cat, less, more, etc. pero ninguno de estos colorea la salida. Así que vamos a ver cómo conseguir una salida de colores para nuestro log.

Para empezar vamos a instalar ccze, un paquete que se encargará de dar color a nuestro contenido.

shell> apt-get install ccze

Tras su instalación ya tenemos listo el sistema de coloreado y podemos hacer lo siguiente para ver el log,

shell> ccze -A < /var/log/syslog

Puesto que esta forma de ver los log's puede no resultar 100% cómoda, vamos a crear una pequeña función en el alias de nuestro usuario que haga lo mismo, pero de forma más sencilla. Para hacerlo debemos editar el fichero ~/.bashrc y agregar las siguiente líneas al final del mismo.

log() {
   ccze -A < $1 | less -R
}

Ahora que ya tenemos la nueva función creada, le indicamos a nuestro usuario que vuelva a leer el contenido de dicho fichero, para que tenga la nueva función disponible,

shell> source ~/.bashrc

Y ya podemos hacerlo siguiente,

shell> log /var/log/syslog
May 24 13:58:02 se groupadd[922]: new group: name=postdrop, GID=106
May 24 14:00:16 se groupadd[128]: group added to /etc/group: name=scanner, GID=107
May 24 14:00:16 se groupadd[128]: group added to /etc/gshadow: name=scanner
May 24 14:00:16 se groupadd[128]: new group: name=scanner, GID=107
May 24 14:00:18 se groupadd[147]: group added to /etc/group: name=messagebus, GID=108
May 24 14:00:18 se groupadd[147]: group added to /etc/gshadow: name=messagebus
May 24 14:00:18 se groupadd[147]: new group: name=messagebus, GID=108

Lógicamente, en la función log yo empleo less, pero cada uno que emplee el paginador con el que más cómodo se sienta.

A mayores de colorear, el comando ccze tiene también alguna que otra ventaja, como puede ser la conversión automática de fechas en UnixTime a formato legible automáticamente. Este tipo de fechas nos las podemos encontrar en ficheros de log de Squid o de Zabbix.

La entrada Coloreando log's la puedes leer en Puppet Linux.

Leer más

Apache, severity log

Apache es el más extendido servidor web que existe actualmente. Tiene tanto versiones para Windows como para GNU/Linux, pero incomprensiblemente no es capaz de enviar a syslog la información de log's que genera. Aunque existen formas de realizar esto, por ejemplo, empleando logger, de forma nativa Apache2 no es capaz de hacerlo. Esto hace que fuera necesario generar un propio sistema de log's en Apache. Al igual que en syslog, existe varios niveles de información que se pueden adaptar a cada uno de los sites o de los virtualhosts. A continuación os dejo los que existen y el tipo de filtrado de información que ofrecen.

• emerg
  Sólo envía notificaciones de emergencia en caso de que el sistema no sea funcional.
• alert
  
  Alerta de acciones que deben ser corregidas inmediatamente para poder seguir trabajando.
• crit
  Informa de condiciones críticas en el sistema.
• error
  Notifica de condiciones de error.
• warn
  Alerta de las condiciones de advertencia (warning).
• notice
  Es el modo debug normal con ciertas informaciones relevantes.
• info
  
  Indica información relevante para el sistema.
  Suele ser el nivel por defecto de los virtualhosts.
• debug
  
  Modo debug completo. Escribe todo lo que hace el sistema. Es especial para desarrollo o para depuración del servidor Apache.

...
LogLevel crit
...
<directory "/admin/webapp/">
    LogLevel info
</directory>
...

Existen numerosos trucos que hacen posible el envío de log's de los sites de Apache a syslog y el más extendido es el que emplea logger para hacerlo, cambiando las líneas,

ErrorLog  apache/site-error.log
CustomLog apache/site-access.log combined

por,

ErrorLog  "|/usr/bin/logger -t apache -p local1.notice"
CustomLog "|/usr/bin/logger -t apache -p local1.notice" combined

Si esta entrada te pareció interesante, quizás también te interese ver Apache: Prefork vs. Worker.

La entrada Apache, severity log la puede leer en Puppet Linux.

Leer más

imuxsock drop messages from pid

Esta semana tocó actualización de IDS's y entre otras muchas cosas, una de las que tocó actualizar fueron las reglas. Por supuesto, el proceso está automatizado con Puppet, lo que garantiza que se haga correctamente y sobre todo, de forma desatendida. El problema viene siempre por el mismo lado. Una vez las reglas son terminadas de cargar y se produce el reload del servicio, en este caso estamos hablando de Snort, éste falló. Este fallo es casi fijo originado por algún parámetro en una regla que no está a funcionar. Aunque las versiones sean las indicadas por el fabricante, es raro que algo no falle en alguna regla. Pues bien, el fallo ya lo comenté y lo podéis ver aquí, Sin embargo, para saber en qué fichero y regla estaba a fallar tuve que revisar los log's. Bien, esto se soluciona rápidamente con un tail y no tendría mayor problema. Sin embargo cuando lo ejecuté me salió éste interesante mensaje,

shell> tail -f /var/log/syslog
Feb 23 12:28:12 S-s snort[28653]:       Ports: 23 
Feb 23 12:28:12 S-s snort[28653]:       Are You There Threshold: 20
Feb 23 12:28:12 S-s snort[28653]:       Normalize: YES
Feb 23 12:28:12 S-s snort[28653]:       Detect Anomalies: YES
Feb 23 12:28:12 S-s snort[28653]:     FTP CONFIG:
Feb 23 12:28:12 S-s snort[28653]:       FTP Server: default
Feb 23 12:28:12 S-s snort[28653]:         Ports (PAF): 21 2100 3535 
Feb 23 12:28:12 S-s rsyslogd-2177: imuxsock begins to drop messages from pid 28653 due to rate-limiting

Por algún motivo, a la gente de rSyslog se le ocurrió poner un límite en el número de líneas que un proceso puede enviar cada cierto tiempo. Esto me parece perfecto, ya que es una forma de proteger el sistema. Si un proceso está enviando muchas cosas a los log's es que algo debe andar raro y no creo que de base nos pongamos a mirar 20k líneas de log's. Sin embargo, en este caso lo que podría ser una facility interesante, fue un proceso molesto. Snort estaba a decir donde fallaba, pero no era era capaz de salir en los log's, pues se cortaba por imuxsock.

Lo que tenía que hacer, era aumentar el límite de líneas que rSyslog dejaba pasar para cada proceso. Para ello, después de una breve lectura del manual, encuentro la solución, agregar las siguientes líneas al fichero de configuración (/etc/rsyslog.conf).

$ModLoad imuxsock # provides support for local system logging
$SystemLogRateLimitInterval 2
$SystemLogRateLimitBurst 1000

Tras el cambio, simplemente reiniciamos el servicio y listo, ya tenemos todo el log como nos interesaba para evaluarlo.

La entrada imuxsock drop messages from pid la puedes leer en Puppet Linux.

Leer más

Zabbix, alerts to log

Zabbix trae muchas formas de alertarnos de que un trigger (y por lo tanto algo no esperado) ha pasado. Las más comunes son en envío de mail's o avisar directamente por Jabber. Ya hace tiempo vimos aquí cómo enviar las notificaciones a Twitter. Hoy vamos a explicar cómo poder almacenar dichas alertas en nuestro log de sistema o tratarlas directamente desde syslog. Para lograr esto, emplearemos el comando logger, que se encargará de hacer el envío ordenado al servicio del sistema, que luego será el que se encargue de procesarlo. Una vez el mensaje en syslog, podremos mandarlo a otro servidor, crear cadenas de filtrado especiales, o lo que queramos.

Lo primero es crear el pequeño script que es necesario para procesar las alertas generadas.

#!/bin/bash

/usr/bin/logger -p syslog.notice -t zabbix-alert $2

Como vemos es realmente sencillo. Una simple llamada a logger y le pasamos como parámetro $2, que es el contenido del mensaje generado. En $1 tendremos almacenado la dirección a la que se envía. Yo guardé este script como sendToLog.sh y a continuación le di permisos de ejecución. La carpeta donde almacenar el script está en la variable de configuración AlertScriptsPath y por defecto es /etc/zabbix/alert.d.

Todo lo que nos queda por hacer ahora es configurar la parte del envío de alertas desde Zabbix. Lo primero es crear un nuevo Media types de tipo script.

SendToLog Media Type

Y a continuación agregar éste a un usuario. Si nos interesa que quede registro de todas las alertas, lo agregamos a un usuario con permisos completos, como pudiera ser admin.

Añadir Media Type a usuario

Una vez aceptado, simplemente nos queda por crear una acción que envíe todas las alertas a éste usuario y por éste tipo y es comenzaría a funcionar. El resultado sería similar a éste,

shell> tail -f /var/log/syslog
Feb 9 17:17:22 zabbix zabbix-alert: PROBLEM: server-h not responds
Feb 9 17:24:25 zabbix zabbix-alert: OK: server-f not responds
Feb 9 17:24:58 zabbix zabbix-alert: PROBLEM: server-d, restarted
Feb 9 17:26:00 zabbix zabbix-alert: OK: server-d, restarted
Feb 9 17:28:33 zabbix zabbix-alert: OK: server-f not responds

Nota: En la versión 1.8 de Zabbix es funcionamiento y configuración es el mismo, con la salvedad de que en la creación del Media Type, es necesario indicarle la ruta completa del fichero, no únicamente el fichero de script.

Leer más

Loguear comandos en GNU/Linux

Hace unos días descubrí por casualidad un interesante proyecto, snoopy, que no es más que un pequeño wrapper que se encarga de 'loguear' todos aquellos comandos que un usuario ejecuta en la shell en los ficheros de log. Gracias a ello, podemos saber en todo momento qué fue lo que se ejecutó y sobre todo, quién lo ejecutó. snoopy es por lo tanto un comando muy interesante, ya que de forma muy simple, permite depurar responsabilidades.

Para instalar snoopy puedes hacerlo desde repositorios o desde código fuente, descargable desde aquí.

shell> apt-get install snoopy

o bien,

shell> wget snoopy
shell> tar zxvf snoopy-1.8.0.tar.gz
shelL> cd snoopy-1.8.0
shell> ./configure
shell> make
shell> make install
shell> echo "/usr/local/lib/snoopy.so" >> /etc/ld.so.preload

Tras tenerlo instalado, lo único que será necesario será reiniciar la sesión de usuario y ya cargará la nueva directiva de logueo. Tras ello, en /var/log/auth.log quedará un registro de todo aquello que se está ejecutando en el sistema y quién lo ha ejecutado.

shell> tail -f /var/log/auth.log
Sep  6 13:03:24 server_5 snoopy[7890]: [uid:0 sid:7707 tty:/dev/pts/2 cwd:/root filename:/usr/bin/tail]: tail -f /var/log/auth.log
Sep  6 13:03:29 server_5 snoopy[7904]: [uid:1002 sid:7830 tty:/dev/pts/0 cwd:/home/javier filename:/bin/su]: su
Sep  6 13:04:36 server_5 snoopy[7970]: [uid:1002 sid:7918 tty:/dev/pts/4 cwd:/home/javier filename:/bin/ls]: ls --color=auto -l

Como se puede observar, queda la sesión (tty) de la persona que lo ha ejecutado, no el nombre, así que habrá que emplear el comando who para saber quién la tenía. Para ello,

shell> who /var/log/wtmp

A partir de ahora siempre podréis saber quién ejecutó qué comando.

Leer más

Habilitar log de inicio en GNU/Linux

En GNU/Linux cuando el sistema está arrancando, hay algunos log's que se pierden y no quedan escritos en ningún lado y dmesg tiene un límite, así que si nos interesa que estos eventos queden registrados lo podemos conseguir cambiando el contenido del fichero /etc/default/bootlogd de NO a YES,

# Run bootlogd at startup ?
BOOTLOGD_ENABLE=YES

En el próximo reinicio, los log's de arranque se escribirán en /var/log/boot.

Leer más

syslog-ng stats off

La versión 3.x de syslog-ng incluye una mejora, o no tan mejora, que hace que por defecto, cada 10 minutos (600 segundos) se envíen al propio sistema de syslog las estadísticas de uso, causando así unos molestos mensajes que no aportan gran cosa al sistema.

Jun 27 21:02:13 efactura syslog-ng[1992]: Log statistics;
processed='center(queued)=879', processed='center(received)=879',
processed='destination(d_boot)=0', processed='destination(d_auth)=0',
processed='destination(d_cron)=117', processed='destination(d_mlal)=0',
processed='destination(d_kern)=0', processed='destination(d_mesg)=557',
processed='destination(d_cons)=0', processed='destination(d_spol)=0',
processed='destination(d_mail)=205', processed='source(s_sys)=879'
Jun 27 21:12:13 efactura syslog-ng[1992]: Log statistics;
processed='center(queued)=880', processed='center(received)=880',
processed='destination(d_boot)=0', processed='destination(d_auth)=0',
processed='destination(d_cron)=117', processed='destination(d_mlal)=0',
processed='destination(d_kern)=0', processed='destination(d_mesg)=558',
processed='destination(d_cons)=0', processed='destination(d_spol)=0',
processed='destination(d_mail)=205', processed='source(s_sys)=880'

Estos mensajes, en mi caso no me proveen de ninguna utilidad, por lo que me interesa suprimirlos, así que vamos a ver cómo hacerlo. Según la documentación, bastaría con añadir la variable stats, con un valor cero para que dejasen de aparecer, quedando tal que así,

options {
...
        stats (0);
};

En caso de que estos valores sean de vuestro interés, también se puede crear un filtro que los envíe a un fichero stats.log (por ejemplo). El filtro podría ser tal que así,

filter f_stats {
    match("^syslog-ng\[[[:digit:]]+\]: STATS")
  or
    match("^syslog-ng\[[[:digit:]]+\]: Log statistics");
};

Leer más

Zabbix: monitorizando log's

Zabbix nos permite obtener los log's de un determinado equipo y en función de su contenido, en base a expresiones regulares, sacar alertas. Esto puede ser algo muy útil por ejemplo, para controlar el número de accesos ssh fallidos a un determinado equipo en un tiempo X predeterminado.

Incluso si avanzamos más, se podrían escalar lo dicho anteriormente a toda la red, por lo que  si a un rango de red es atacada en el mismo momento por un acceso de ssh, puede ser que estén atacando a todos los equipos. Este tipo de avisos también los podremos controlar con zabbix.

Para comenzar a monitorizar los log's primero hay que asegurarse de que en la configuración del equipo agente esté correctamente configurado el nombre del equipo. El nombre que esté en zabbix_agentd.conf debe de coincidir con el nombre del equipo del zabbix-server. Esto es por que la monitorización de log's se realiza mediante check's activos, es el cliente el que envía los datos, no el servidor el que se los pide.

Leer más