Análisis de registro de PostgreSQL con pgBadger

A veces, los registros son lo último que se revisa cuando las cosas van mal, pero generalmente son lo primero que pide ayuda a gritos cuando algo sucede. Revisar manualmente los registros en busca de problemas ayuda, pero ¿por qué no usar analizadores de registros para generar automáticamente informes que brinden información sobre la base de datos antes de que algo salga mal?

El analizador de registro de PostgreSQL “pgBadger” es un programa de “informe de análisis de registro de PostgreSQL rápido” de código abierto escrito en Perl que toma la salida del registro de una instancia de PostgreSQL en ejecución y la procesa en un archivo HTML. El informe que genera muestra toda la información encontrada en un formato de informe agradable y fácil de leer. Estos informes pueden ayudar a arrojar luz sobre los errores que ocurren en el sistema, el comportamiento de los puntos de control, el comportamiento del vacío, las tendencias y otra información básica pero crucial para un sistema PostgreSQL.

Configuración de registro de PostgreSQL

Para usar pgBadger de manera efectiva, se debe configurar el inicio de sesión en PostgreSQL para proporcionar a pgBadger la mayor cantidad de información posible. Se pueden modificar algunas opciones para permitir que el sistema de la base de datos registre información útil para que pgBadger genere informes útiles. La documentación completa para la configuración de PostgreSQL se puede encontrar en la página de github de pgBadger, pero a continuación se incluye información básica.

Cuando se ejecuta, pgBadger procesará los registros de PostgreSQL, ya sean syslog, stderr o csvlog, siempre que las líneas de registro tengan suficiente información en el prefijo.

Ejemplos de valores de log_line_prefix:

Si destino_registro ='syslog'

log_line_prefix = 'user=%u,db=%d,app=%aclient=%h '

Si log_destination ='stderr'

log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h '

Ajustes de configuración básicos para establecer en postgresql.conf:

log_checkpoints = on
log_connections = on
log_disconnections = on
log_lock_waits = on
log_temp_files = 0
log_autovacuum_min_duration = 0
log_error_verbosity = default
log_statement = off
lc_messages='C'

Log_min_duration_statement = (see below)

Una de las partes más útiles de los informes de pgBadger es el informe de consulta lenta, que se basa en las consultas de registro de la base de datos que superan el valor log_min_duration_statement. Este valor se representa en milisegundos, y cualquier consulta que se complete con un tiempo mayor al que se registrará y luego generará informes por pgBadger. Esto es útil para encontrar y analizar consultas que tardan más de lo deseado.

Si bien establecer este valor en 0 para registrar todas las consultas proporcionaría la mayor cantidad de información, eso puede terminar fácilmente generando archivos de registro que son demasiado grandes y afectar el rendimiento de la base de datos debido a la escritura constante del registro. Un valor más sensato no proporcionará recuentos de consultas perfectos, pero aún centrará los informes en consultas de ejecución lenta en general. Si las consultas que se ejecutan un par de minutos se consideran "lentas", sería bueno establecer el valor en un minuto. Si las consultas que se ejecutan durante más de unos pocos segundos se consideran "lentas", entonces también funcionaría establecer el valor en algo así como 5 segundos.

Generación de registros

La generación de registros se realiza a través de la línea de comandos utilizando el ejecutable pgBadger. Hay una gran cantidad de opciones, pero la configuración más básica es proporcionar el prefijo de la línea de registro que usa la base de datos, el archivo de registro y el archivo html de salida.

./pgbadger --prefix '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h ' postgresql.log -o postgresql.html
[========================>] Parsed 560607407 bytes of 560607407 (100.00%), queries: 2929645, events: 5

Para obtener más información sobre las diferentes opciones para pgBadger, consulte la documentación o ejecute el binario con el parámetro de entrada --help.

Generación avanzada de registros

Dado que la generación de informes sobre registros es una simple ejecución de la línea de comandos, los scripts y programas personalizados se pueden configurar para generar informes automáticamente, almacenados en servidores web, enviados por correo electrónico o archivados en almacenamiento a largo plazo. Explore las diferentes opciones disponibles para la generación de informes y sea creativo con los sistemas de automatización para la generación y entrega de informes.

Revisión de registros

Revisar los registros es donde entra la diversión. El informe que se generó ahora se puede abrir en un navegador web y revisar.

Estadísticas globales

La sección de estadísticas globales contiene información básica que se encuentra en el registro de PostgreSQL, que incluye:

• Consultas:número de consultas encontradas, duración, número de consultas normalizadas, etc.
• Eventos:número total de eventos, eventos normalizados, etc.
• Vacíos:el número total de vacíos automáticos y análisis automáticos encontrados.
• Archivos temporales:la cantidad total de archivos temporales encontrados, el tamaño máximo y el tamaño promedio.
• Sesión:número total de sesiones, tiempo máximo de sesiones, duración total de las sesiones, duración promedio de las sesiones, promedio de consultas encontradas por sesión, promedio de duración de las consultas por sesión.
• Conexiones:número total de conexiones, pico de conexiones y número total de bases de datos conectadas.

Nota: Los resultados relacionados con consultas, recuentos de consultas o duración de consultas serán inexactos con valores de log_min_duration_statement mayores que 0.

Ejemplo:

Conexiones

La página de conexiones muestra gráficos que detallan la información de conexión que se encuentra en los registros. Siempre que log_connections y log_disconnections estén activados, los valores aquí serán precisos. Los gráficos disponibles son:

• Conexiones establecidas:muestra el número máximo, mínimo y promedio de conexiones a lo largo del tiempo.
• Conexiones por base de datos:un gráfico circular y una vista de tabla que muestra el número de conexiones para cada base de datos encontrada.
• Conexiones por usuario:un gráfico circular y una vista de tabla que muestra la cantidad de conexiones para cada usuario encontrado.
• Conexiones por host:un gráfico circular y una vista de tabla que muestran la cantidad de conexiones para cada host de origen encontrado.

Ejemplo:

Sesiones

La página de sesiones es similar a la página de conexiones, pero contiene más información relacionada con las sesiones.

• Sesiones simultáneas:un gráfico de líneas que muestra el número de sesiones a lo largo del tiempo.
• Histograma de tiempos de sesión:un gráfico de barras y una tabla que muestra los tiempos de sesión.
• Sesiones por base de datos:un gráfico circular y una vista de tabla que muestran el número de sesiones para cada base de datos encontrada.
• Sesiones por usuario:un gráfico circular y una vista de tabla que muestran el número de sesiones para cada usuario encontrado.
• Sesiones por host:un gráfico circular y una vista de tabla que muestran la cantidad de sesiones para cada host de origen encontrado.
• Sesiones por aplicación:el número de sesiones conectadas por aplicación.

Puntos de control

La página de puntos de control proporciona información sobre el proceso del punto de control, incluida la cantidad de búferes escritos, archivos WAL y otra información general.

• Búferes de punto de control:un gráfico de líneas que muestra la cantidad de búferes escritos por el proceso de punto de control a lo largo del tiempo.
• Archivos WAL de puntos de control:un gráfico de líneas que muestra la cantidad de archivos WAL agregados, eliminados o reciclados por el punto de control a lo largo del tiempo.
• Distancia del punto de control:un gráfico de líneas que muestra la distancia y la estimación de los puntos de control.
• Actividad de puntos de control:una tabla que muestra los cuatro puntos de datos anteriores en forma de tabla.

Archivos temporales

La página de archivos temporales contiene información sobre los archivos temporales, que se crean cuando una consulta se queda sin work_mem y necesita usar el disco para clasificar o filtrar los resultados antes de devolverlos a las aplicaciones. Estos archivos se eliminan automáticamente cuando se completa la consulta, y conocer la actividad del archivo temporal ayuda al administrador a ajustar el parámetro work_mem.

• Tamaño de los archivos temporales:un gráfico de líneas que muestra el espacio utilizado por los archivos temporales a lo largo del tiempo.
• Número de archivos temporales:un gráfico de líneas que muestra el número de archivos temporales utilizados a lo largo del tiempo.
• Actividad de archivos temporales:una tabla que muestra la información proporcionada en los gráficos anteriores pero en forma de tabla.

Aspiradoras

Esta página muestra información sobre VACUUM y ANALYZE que ocurren en la base de datos. Esta información es útil para saber si el proceso de autovacío está haciendo su trabajo lo suficientemente bien o no, o si está atascado y necesita más recursos.

• Distribución de vacíos/análisis:gráfico de líneas que muestra los vacíos y los análisis a lo largo del tiempo, así como información sobre la tabla que consumió la mayor parte de la potencia de procesamiento de la CPU.
• Análisis por tabla:un gráfico circular y una tabla que muestran las tablas con la mayor cantidad de análisis, lo que sugiere que estas tablas se encuentran en un alto estado de cambio.
• Vacíos por mesa:un gráfico circular y una tabla que muestran las mesas con la mayor cantidad de vacíos, lo que sugiere que estas mesas se encuentran en un alto estado de cambio.
• Tuplas eliminadas por tabla:un gráfico circular y una tabla que muestran el número de tuplas y páginas eliminadas en procesos de vacío para tablas.
• Páginas eliminadas por tabla:un gráfico circular y una tabla que muestran la cantidad de páginas y tuplas eliminadas en procesos de vacío para tablas.
• Actividad de autovacío:una tabla que muestra los VACUUM y ANALYZE a lo largo del tiempo por hora.

Cerraduras

La página de bloqueos contiene solo algunos datos, pero es información útil para saber cuándo hay procesos que pueden estar retrasando otras consultas durante largos períodos de tiempo.

• Cerraduras por tipos
• Consultas en espera más frecuentes:una lista de consultas que se encuentran en espera, ordenadas de la más frecuente a la menos.
• Consultas que más esperaron:una lista de consultas y cuánto tiempo esperaron, ordenadas de mayor a menor.

Consultas

La página Consultas es a veces la más interesante, ya que muestra información sobre los tipos de consultas que provienen de las aplicaciones y los usuarios. Esta información puede ayudar a comprender mejor qué tipo de base de datos genera una aplicación o un usuario coloca en el sistema de la base de datos, lo que puede ayudar a futuros ajustes. Al igual que antes, la precisión de estos números depende del valor de log_min_duration_statement, ya que cualquier valor superior a 0 no registrará consultas.

• Consultas por tipo:un gráfico circular y una tabla que muestran la cantidad de diferentes tipos de consultas, como INSERTAR, ACTUALIZAR, ELIMINAR, SELECCIONAR, etc.
• Consultas por base de datos:un gráfico circular y una tabla que muestran el número de consultas encontradas por base de datos.
• Consultas por aplicación:un gráfico circular y una tabla que muestran el número de consultas encontradas por aplicación.
• Número de consultas canceladas:información sobre las consultas que se cancelaron.

Superior

La página superior tiene información sobre los tiempos de consulta, las consultas más lentas en general, la frecuencia de consulta y más. Es probable que se encuentren consultas problemáticas específicas aquí:

• Histograma de tiempos de consulta:un histograma que representa cuántas consultas se incluyen en cada grupo de tiempos.
• Consultas individuales más lentas:una lista de las consultas más lentas encontradas, ordenadas de mayor a menor.
• Consultas que consumen mucho tiempo:una lista de consultas normalizadas y su duración total, ordenadas de mayor a menor tiempo consumido.
• Consultas más frecuentes:una lista de consultas normalizadas y cuántas veces se ejecutaron, ordenadas de mayor a menor.
• Consultas más lentas normalizadas:una lista de consultas normalizadas y su duración promedio, ordenadas de mayor a menor.

Eventos

La página final son los eventos, que tienen información sobre los propios registros y cualquier cosa que no sea una consulta, un vacío o un punto de control.

• Niveles de registro:Los diferentes niveles de registros aparecieron por línea, como CONTEXT, LOG, STATEMENT, HINTs, WARNINGs y otros.
• Distribución de eventos:un gráfico de líneas de eventos a lo largo del tiempo para eventos de PÁNICO, FATAL, ERROR y ADVERTENCIA.
• Errores/Eventos más frecuentes:una lista de EVENTOS y su frecuencia, ordenados de más común a menos.

Contribuir

El proyecto pgBadger es gratuito y existe bajo la licencia de PostgreSQL. Actualmente está bien mantenido y actualizado para funcionar con versiones más nuevas de PostgreSQL a medida que se desarrolla. ¿Tiene ideas para mejorar pgBadger? Bifurca el proyecto y muestra a la comunidad tus mejoras.

Para enviar errores, visite la página de problemas de github.