Detectando problemas leyendo los logs

Gustavo Orrillo
- 05/13/2022 - 2 min. de lectura

Creo que una buena manera de empezar este post es diciendo "que podríamos hacer sin los logs?". Y la verdad es que no mucho. Una vez que el sistema se pone en producción, en los logs se almacena valiosa información. En Odoo se puede llegar a almacenar que errores que ocurren en el sistema, en Argentina muchas veces se muestran los requests para la factura electrónica, mensajes de debug del sistema, tiempos de ejecución de cada uno de los requests, entre otros. En PostgreSQL se loguea por lo pronto; información sobre cada uno de los errores. Pero también se puede loguear los queries que duran más que un tiempo determinado (por ejemplo 500 milisegundos)

En Odoo el uso de los archivos de log se configura en el archivo de configuración (por ejemplo odoo-server.conf). 

logfile = /var/log/odoo/odoo-server.log
logrotate = True
loglevel = debug

Por lo general configuro Odoo para que loguee de esa manera. No es del todo ideal ya que da un alto grado de detalle en los logs (modo debug) y le indico al sistema que habilite el logrotate para que rote los archivos de log. 

Una opción que se utiliza en los sistemas que tienen problemas de performance, es 

loglevel = debug_rpc

Opción que loguea la duración de cada uno de los requests de Odoo, opción muy util para tareas de profiling. Esto genera un log con el siguiente formato

2022-03-03 12:35:34,090 4106 DEBUG mydb odoo.api: call my.contract(13,).write({'grant_ids': [[1, 31, {'percent': 22}], [4, 32, False], [4, 33, False]]}) 
2022-03-03 12:35:43,773 4106 DEBUG mydb odoo.http.rpc.request: poll: None None: time:50.013s mem: 645048.0k -> 681752.0k (diff: 36704.0k) 

Siempre que reinicio Odoo desde la línea de comandos, lo hago de la siguiente manera:

sudo systemctl restart odoo-server && tail -f /var/log/odoo/odoo-server.log

Que le indica al sistema primero que se reinicie Odoo. Y despues que te muestre en forma continua por pantalla el archivo de log. Esto te permite conocer en forma instantánea si el sistema pudo iniciarse sin problemas.

Para PostgreSQL por lo general me gusta configurar una opción de los archivos de log, log_min_duration_statement, que loguea cada una de las sentencias de SQL que dura más del tiempo indicado, por ejemplo. 

log_min_duration_statement = 500

Le indica a la base de datos que loguee cada una de las sentencias SQL que dura más de medio segundo (en Odoo, cada una de las sentencias de SQL debe durar por lo general menos de medio segundo. Solo aquellas que involucra consultas de reporting deben durar más de un segundo). Esto produce un output como el siguiente:

2022-05-11 14:09:10 UTC::@:[10214]:LOG:  checkpoint starting: time
2022-05-11 14:09:14 UTC:10.0.1.141(46008):odoo@GIFP:[15757]:LOG:  duration: 20226.718 ms  statement: SELECT "plan_table_line".id FROM "plan_table_line" LEFT JOIN "plan_table_contract" as "plan_table
_line__contract_id" ON ("plan_table_line"."contract_id" = "plan_table_line__contract_id"."id") WHERE ("plan_table_line"."plan_id" in (53537)) ORDER BY "plan_table_line__contract_id"."id" ,"plan_table_line
"."sequence"  
2022-05-11 14:09:34 UTC:10.0.1.141(46008):odoo@GIFP:[15757]:LOG:  duration: 20630.542 ms  statement: SELECT "plan_table_line".id FROM "plan_table_line" LEFT JOIN "plan_table_contract" as "plan_table
_line__contract_id" ON ("plan_table_line"."contract_id" = "plan_table_line__contract_id"."id") WHERE ("plan_table_line"."plan_id" in (53537)) ORDER BY "plan_table_line__contract_id"."id" ,"plan_table_line
"."sequence"  

Como se puede ver en este ouput de log de SQL, que cada una de dichas sentencias de SQL dura como mínimo unos veinte segundos. Lo cual es problemático pero nos da una pista de en que tablas se pueden encontrar problemas de performance. Luego las mismas se pueden analizar con un explain para conocer su plan de ejecución y saber más que pasos tomar para optimizar la performance de la base de datos.


Acerca de:

Gustavo Orrillo

Passionate about programming, he has implemented Odoo for different types of businesses since 2010. In Moldeo Interactive he is a founding Partner and Programmer; In addition to writing on the Blog about different topics related to the developments he makes.