Introducción al Registro de Consultas Lentas

El registro de consultas lentas (slow query log) es una funcionalidad crítica en MySQL diseñada para identificar sentencias SQL que exceden un tiempo límite de ejecución determinado. Específicamente, el sistema captura aquellas consultas cuyo tiempo de respuesta supera el valor configurado en la variable long_query_time. Por defecto, este umbral se establece en 10 segundos, lo que significa que cualquier operación que tarde más de ese periodo será registrada.

Es importante notar que esta característica no está activada por defecto en la mayoría de las instalaciones. Su habilitación debe ser manual, ya que la escritura continua de logs puede impactar el rendimiento del servidor. Por ello, se recomienda activarla principalmente durante fases de diagnóstico o ajuste de rendimiento. El destino de estos registros puede ser un archivo plano en el sistema de archivos o una tabla dentro de la base de datos.

Según la documentación oficial, el log incluye sentencias que tardan más de long_query_time segundos y que requieren examinar al menos un número mínimo de filas definido por min_examined_row_limit. Los tiempos pueden registrarse con precisión de microsegundos cuando se escribe en archivos, mientras que en tablas solo se guardan los segundos enteros.

Parámetros de Configuración Clave

Para gestionar adecuadamente el registro de consultas lentas, es necesario comprender las siguientes variables de sistema:

• slow_query_log: Controla el estado del log. Un valor de 'ON' (o 1) lo habilita, mientras que 'OFF' (o 0) lo desactiva.
• slow_query_log_file: Define la ruta completa donde se almacenará el archivo de log. Si no se especifica, MySQL utiliza un nombre predeterminado basado en el hostname del servidor.
• long_query_time: Establece el umbral de tiempo en segundos. Las consultas que superen este valor se registran.
• log_queries_not_using_indexes: Cuando está activo, registra también las consultas que no hacen uso de índices, incluso si su tiempo de ejecución es bajo. Esto es útil para detectar ineficiencias en el diseño de consultas.
• log_output: Determina el destino del log. Puede ser 'FILE' (archivo), 'TABLE' (tabla mysql.slow_log) o ambos simultáneamente ('FILE,TABLE'). Escribir en tabla consume más recursos del sistema.

Configuración del Registro

Activación del Log

Por defecto, la variable slow_query_log suele estar desactivada. Puede habilitarse dinámicamente para la sesión actual o globalmente mediante comandos SQL, aunque este cambio no persiste tras un reinicio del servicio.

mysql> SHOW VARIABLES LIKE 'slow_query%';
+---------------------+---------------------------------------------+
| Variable_name       | Value                                       |
+---------------------+---------------------------------------------+
| slow_query_log      | OFF                                         |
| slow_query_log_file | /var/lib/mysql/db-server-slow.log           |
+---------------------+---------------------------------------------+

mysql> SET GLOBAL slow_query_log = 'ON';
Query OK, 0 rows affected (0.05 sec)

mysql> SHOW VARIABLES LIKE 'slow_query%';
+---------------------+---------------------------------------------+
| Variable_name       | Value                                       |
+---------------------+---------------------------------------------+
| slow_query_log      | ON                                          |
| slow_query_log_file | /var/lib/mysql/db-server-slow.log           |
+---------------------+---------------------------------------------+

Para que la configuración sea permanente, es necesario editar el archivo de configuración my.cnf (o my.ini en Windows) y reiniciar el servidor MySQL.

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slowqueries.log

Ajuste del Umbral de Tiempo

La variable long_query_time define qué se considera "lento". El valor predeterminado es 10 segundos, pero en entornos de alta demanda se suele reducir a 1 o 2 segundos. Es importante destacar que una consulta que dure exactamante el tiempo del umbral no se registrará; debe superarlo estrictamente.

mysql> SHOW VARIABLES LIKE 'long_query_time';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+

mysql> SET GLOBAL long_query_time = 2;
Query OK, 0 rows affected (0.00 sec)

Nota: Al modificar variables globales mediante SET GLOBAL, los cambios pueden no reflejarse inmediatamente en la sesión actual. Es necesario abrir una nueva conexión o consultar SHOW GLOBAL VARIABLES para verificar el nuevo valor.

Para probar el funcionamiento, se puede ejecutar una consulta que fuerce una espera:

mysql> SELECT SLEEP(5);
+----------+
| SLEEP(5) |
+----------+
|        0 |
+----------+
1 row in set (5.00 sec)

Al revisar el archivo de log especificado, se debería encontrar una entrada similar a esta:

# Time: 2023-10-25T14:30:10.123456Z
# User@Host: admin[admin] @ localhost []  Id:    12
# Query_time: 5.004321  Lock_time: 0.000123 Rows_sent: 1  Rows_examined: 0
SET timestamp=1698244210;
SELECT SLEEP(5);

Destino del Log: Archivo vs Tabla

La variable log_output permite elegir dónde se almacenan los datos. La opción 'TABLE' guarda la información en la tabla mysql.slow_log, lo que facilita consultas SQL sobre el historial, pero implica mayor sobrecarga.

mysql> SET GLOBAL log_output = 'TABLE';
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT SLEEP(3);
+----------+
| SLEEP(3) |
+----------+
|        0 |
+----------+
1 row in set (3.00 sec)

mysql> SELECT start_time, user_host, query_time, sql_text FROM mysql.slow_log;
+---------------------+---------------------------+------------+------------------+
| start_time          | user_host                 | query_time | sql_text         |
+---------------------+---------------------------+------------+------------------+
| 2023-10-25 14:35:00 | admin[admin] @ localhost  | 00:00:03   | SELECT SLEEP(3)  |
+---------------------+---------------------------+------------+------------------+

Para entornos productivos sensibles al rendimiento, se recomienda priorizar la escritura en archivos ('FILE').

Consultas sin Índices

Activar log_queries_not_using_indexes ayuda a idetnificar consultas que realizan escaneos completos de tabla. Esto es vital para la optimización, ya que una consulta rápida que no usa índices podría volverse lenta cuando el volumen de datos crezca.

mysql> SET GLOBAL log_queries_not_using_indexes = 1;

Cabe mencionar que esto registrará incluso consultas que usen un índice pero realicen un escaneo completo del mismo (full index scan), ya que no limitan significativamente las filas examinadas.

Herramienta de Aálisis: mysqldumpslow

Analizar manualmente los archivos de log puede ser ineficiente cuando el volumen de datos es alto. MySQL incluye la utilidad mysqldumpslow para resumir y ordenar la información contenida en el log de consultas lentas.

Algunas de las opciones más útiles incluyen:

• -s: Criterio de ordenamiento (t: tiempo, l: bloqueo, r: filas enviadas, c: count).
• -t: Número de resultados a mostrar (top n).
• -g: Patrón de búsqueda (regex) para filtrar consultas.
• -a: No abstraer números y strings (muestra la consulta exacta).

Ejemplos de uso práctico:

Obtener las 15 consultas que más tiempo de ejecución acumulan:

mysqldumpslow -s t -t 15 /var/log/mysql/slowqueries.log

Identificar las 10 consultas que más veces se han ejecutado:

mysqldumpslow -s c -t 10 /var/log/mysql/slowqueries.log

Buscar consultas específicas que contengan una unión izquierda y ordenarlas por tiempo:

mysqldumpslow -s t -t 10 -g "LEFT JOIN" /var/log/mysql/slowqueries.log

Para evitar que la salida sature la terminal, se recomienda combinar el comando con herramientas de paginación:

mysqldumpslow -s r -t 20 /var/log/mysql/slowqueries.log | more