El sistema de log de Drupal
Para saber qué limitaciones tiene el log de Drupal y qué mejoras introduce Monolog, primero hay que conocer en que consisten ambos sistemas.
¿Qué nos proporciona Drupal?
El sistema de log más comunmente usado que nos ofrece Drupal es dblog, una herramienta que registra eventos y errores que ocurren dentro del sitio, almacenando estos registros directamente en la base de datos del sistema. Aunque dblog es útil por su accesibilidad y simplicidad de integración, puede presentar problemas significativos de rendimiento cuando se enfrenta a una alta cantidad de tráfico o a registros frecuentes y voluminosos.
Por otro lado existe syslog, una alternativa más robusta a la gestión de logs. Permite a los administradores de sistemas recopilar y almacenar mensajes de log en un servidor dedicado, centralizando de este modo los registros de múltiples sistemas en un único lugar, aunque puede ser más complejo de configurar y es menos accesible para usuarios con un conocimiento límitado en sistemas.
¿Que hago si no quiero que todo vaya al mismo sitio?
Drupal de manera nativa sólo permite elegir una forma de gestionar todos los logs. En algunas ocasiones, necesitamos que dependiendo de la fuente del log, este se almacene de forma diferente, para ello Monolog, permite gestionar cada canal, pudiendo procesar los mensajes, elegir su formato y el destino.
En el caso que nos ocupa en este artículo queremos mantener dblog para errores críticos, para facilitar el seguimiento de ciertos logs, configurando un límite, para evitar llenar la base de datos.
Los logs relacionados con ciertas acciones, informativos o de APIs externas los queremos separar en archivos de logs, ya que es información que nos puede resultar útil para localizar problemas pero que por almacenar mucha información y muy recurrente, puede fácilmente saturar la base de datos y ocultar otros errores importantes..
Un Monolog para gobernarlos a todos
Monolog es una librería de PHP ampliamente utilizada para el manejo de logs. A través de su enfoque modular, permite a los desarrolladores enviar mensajes de log a una variedad de destinos, como archivos, bases de datos y servicios de monitoreo. En Drupal, el módulo Monolog integra esta potente herramienta para extender y mejorar el sistema de log nativo, ofreciendo mayor flexibilidad y opciones para gestionar los registros del sistema.
Cómo usar Monolog en Drupal
En el propio readme del módulo se pueden encontrar muy buenos ejemplos y conocer que se puede hacer con él.
Entre los beneficios de usarlo, se incluyen:
- Niveles de registro configurables
- Múltiples handlers, formatters y processors
- Todo el poder y flexibilidad de Monolog
El módulo Monolog no tiene una interfaz gráfica, toda la configuración se realiza mediante archivos "*.services.yml". Se debe crear un fichero de servicio monolog.services.yml
y cargarlo desde el fichero settings.php
:
$settings['container_yamls'][] = 'sites/default/monolog.services.yml';
El módulo Monolog de Drupal sobreescribirá el comportamiento de registro de logs de Drupal. Para seguir utilizando los canales de logs de Drupal (servicios con etiqueta 'logger') como dblog u otros, es necesario añadirlos a la configuración del módulo.
- Por ejemplo, para usar dblog en el canal por defecto se debe tener lo siguiente en el fichero de servicio de monolog que cargamos en el
settings.php
:
parameters:
monolog.channel_handlers:
default:
handlers:
- name: 'drupal.dblog'
Handlers
En Monolog, un handler es el componente responsable de determinar qué se hace con cada registro de log. Básicamente, los handlers definen cómo y dónde se almacenan o envían los mensajes de log. Por ejemplo, un handler puede escribir los logs en un archivo, enviarlos a un servicio externo como Slack, o insertarlos en una base de datos.
Cada handler puede configurarse con diferentes parámetros, como el nivel mínimo de log que manejará (por ejemplo, DEBUG, INFO, WARNING, ERROR, etc.) y otros comportamientos específicos relacionados con el destino del log. Monolog viene con una variedad de handlers predefinidos para manejar los logs de diversas maneras, y también permite a los desarrolladores crear handlers personalizados si sus necesidades específicas no están cubiertas por los existentes.
La flexibilidad de los handlers permite a Monolog adaptarse a diferentes entornos y requisitos de log, proporcionando la capacidad de gestionar logs de forma eficiente y efectiva en una amplia gama de aplicaciones.
En el siguiente ejemplo usaremos el RotatingFileHandler. Veremos la configuración más simple que permite a Monolog para registrar logs en un archivo en modo "rotativo":
parameters:
monolog.channel_handlers:
default:
handlers:
- name: 'default_rotating_file'
services:
monolog.handler.default_rotating_file:
class: Monolog\Handler\RotatingFileHandler
arguments: ['private://logs/debug.log', 10, 'DEBUG']
La propiedad name que se configure en la sección parameters/monolog.channel_handlers
es libre pero deberá coincidir con el nombre que se ponga en la sección services/monolog.handler.[HANDLER_NAME]
Esta configuración registrará cada mensaje con un nivel de log mayor (o igual) que debug en un archivo llamado debug.log ubicado en la carpeta logs en el sistema de archivos privado. Los archivos se rotarán cada día y el número máximo de archivos a mantener será 10.
El módulo Monolog registra automáticamente un handler para cada logger de Drupal habilitado.
Ejemplo para mandar los errores del canal cron de logs a Slack:
parameters:
monolog.channel_handlers:
cron:
handlers:
- name: 'cron_slack'
services:
monolog.handler.cron_slack:
class: Monolog\Handler\SlackHandler
arguments: ['slack-token', 'monolog', 'Drupal', true, null, 'ERROR']
Formatters
Monolog puede alterar el formato del mensaje usando formatters. Un formatter necesita ser registrado como servicio en el Servicio de Contenedor de Drupal. El módulo Monolog proporciona un conjunto de formatters ya definidos como el line formatter y el json formatter.
Ejemplo para enviar todos los logs específicos de PHP a un archivo separado en formato JSON:
parameters:
monolog.channel_handlers:
php:
handlers:
- name: 'php_rotating_file'
formatter: 'json'
services:
monolog.handler.php_rotating_file:
class: Monolog\Handler\RotatingFileHandler
arguments: ['private://logs/php.log', 10, 'DEBUG']
Si no se especifica el formatter, el módulo usará por defecto el line formatter. Es posible enviar un log a múltiples handlers cada uno con su propio formatter.
Processors
Monolog puede alterar los mensajes escritos en una instalación de logs usando processors. El módulo proporciona un conjunto de processors ya definidos para añadir información como el usuario actual, la URI de la solicitud, la IP del cliente, etc. Los processors se definen como servicios bajo el espacio de nombre monolog.processor.
Para editar la lista de processors usados, es necesario sobreescribir el parámetro monolog.processors en monolog.services.yml
y establecer los que se necesiten:
parameters:
monolog.processors:
- 'message_placeholder'
- 'current_user'
- 'request_uri'
- 'ip'
- 'referer'
- 'filter_backtrace'
Ejemplo de configuración usando formatters y processors:
parameters:
monolog.channel_handlers:
php:
handlers:
- name: 'rotating_file'
formatter: 'json'
processors: ['current_user']
default:
handlers: ['drupal.dblog']
services:
monolog.handler.rotating_file:
class: Monolog\Handler\RotatingFileHandler
arguments: ['private://logs/debug.log', 10, 'DEBUG']
Esto enviará los logs de PHP al RotatingFileHandler
con un formatter JSON y solo con el processor identificado por current_user.
Monolog Extra, extendiendo Monolog en Drupal
En Metadrop hemos desarrollado el módulo Monolog Extra, extiendiendo las capacidades del módulo Monolog y proporcionando configuraciones avanzadas y handlers personalizados. Utilizado para abordar necesidades específicas de log, como la rotación de archivos.
Actualmente proporciona un processor para limitar el número de caracteres del mensaje de log llamado TruncateMessagesProcessor
. También consta de un handler de tipo rotativo que evita errores en la creación de logs, crea la carpeta si no existe y registra logs si existe algún error en el proceso.
Ejemplo de configuración monolog.services.yml
parameters:
monolog.channel_handlers:
mymodule_file_log:
handlers:
- name: 'mymodule.safe_rotating_handler'
processors: ['mymodule.truncate_messages']
Ejemplo de definición en un módulo custom, por ejemplo mymodule.services.yml
services:
monolog.handler.mymodule.safe_rotating_handler:
class: Drupal\monolog_extra\Logger\Handler\SafeRotatingFileHandler
arguments: ['@file_system', '@logger.channel.mymodule_file_handler', 'private://mymodule/logs/mymodule.log', 14]
monolog.processor.mymodule.truncate_messages:
class: Drupal\monolog_extra\Logger\Processor\TruncateMessagesProcessor
arguments: [1000]
logger.channel.mymodule_file_handler:
class: Drupal\Core\Logger\LoggerChannel
factory: logger.factory:get
arguments: ['mymodule_file_handler']
logger.channel.mymodule_file_log:
class: Drupal\Core\Logger\LoggerChannel
factory: logger.factory:get
arguments: ['mymodule_file_log']
A partir del ejemplo anterior, se define un log con un límite de archivos de 14, los logs se guardarán en la carpeta private://mymodule/logs/
, en el caso de producirse algún error al crearse el log, se registrará en el canal mymodule_file_handler
, y el mensaje de log introducido se procesará y limitará a 1000 caracteres.
Problemas que nos hemos encontrado
Desde Metadrop hemos detectado una serie de errores y limitaciones a la hora de usar Monolog.
Incompatibilidad con Stream Wrappers en Drupal
A la hora de definir los directorios principales, cómo son los privados, públicos o los temporales Drupal usa Stream Wrappers, de esa manera es más facil representar las rutas sin tener que poner la ruta real al servirdos, por ejemplo "private:// "o "public://".
Monolog utiliza la función glob()
en el RotatingFileHandler
para capturar los logs de un directorio, pero glob()
no soporta los Stream Wrappers de Drupal, causando errores en la obtención y gestión de estos logs.
En la issue propuesta por Metadrop Monolog glob does not support stream wrappers se propone extender la clase SafeRotatingFileHandler
del módulo Monolog Extra y añadir el método getGlobPattern
para convertir los stream wrappers de Drupal en rutas reales antes de utilizarlas. Esto se logra mediante el uso de la función realpath
del sistema de archivos de Drupal.
La implementación de getGlobPattern es la siguiente:
protected function getGlobPattern(): string {
$pattern = parent::getGlobPattern();
if (preg_match('#^(\w+://)(.+)#', $pattern, $matches)) {
$stream_wrapper_prefix = $matches[1];
$rest_of_pattern = $matches[2];
$real_path = $this->fileSystem->realpath($stream_wrapper_prefix);
if ($real_path) {
return $real_path . DIRECTORY_SEPARATOR . $rest_of_pattern;
}
}
return $pattern;
}
La issue ha sido resuelta en el módulo Monolog Extra únicamente.
Referencia: PHP StreamWrapper support for glob, Drupal Monolog Issue #3326496, PHP Monolog Issue.
Problema en la rotación de archivos de Log
Usando el módulo Monolog Extra, los logs antiguos no se eliminan debido a que el método logFileCanBeCreated
crea un archivo vacío para verificar su capacidad de escritura, que interfiere con el mecanismo de rotación.
public function logFileCanBeCreated() {
$url = $this->getUrl();
@fopen($url, 'a');
set_error_handler([$this, 'customErrorHandler']);
$stream = fopen($url, 'a');
restore_error_handler();
if (is_resource($stream)) {
$can_be_created = TRUE;
}
else {
$can_be_created = FALSE;
$this->loggerChannel->critical($this->t('The stream or file :file could not be opened: :message', [
':file' => $url,
':message' => self::$errorMessage,
]));
}
return $can_be_created;
}
Método RotatingFileHandler::write
protected function write(LogRecord $record): void
{
// on the first record written, if the log is new, we rotate (once per day) after the log has been written so that the new file exists
if (null === $this->mustRotate) {
$this->mustRotate = null === $this->url || !file_exists($this->url);
}
...
Debido que el método logFileCanBeCreated
crea el archivo pero no lo elimina, el método write no establece la propiedad mustRotate
porque no se cumple la condición de que el fichero no exista, y por lo tanto el método rotate
dónde se comprueba el número de ficheros y se eliminan los que ya existen, no es llamado.
El método RotatingFileHandler::rotate
es el siguiente:
protected function rotate(): void
{
....
// skip GC of old logs if files are unlimited
if (0 === $this->maxFiles) {
return;
}
$logFiles = glob($this->getGlobPattern());
if (false === $logFiles) {
// failed to glob
return;
}
if ($this->maxFiles >= \count($logFiles)) {
// no files to remove
return;
}
// Sorting the files by name to remove the older ones
usort($logFiles, function ($a, $b) {
return strcmp($b, $a);
});
foreach (\array_slice($logFiles, $this->maxFiles) as $file) {
if (is_writable($file)) {
// suppress errors here as unlink() might fail if two processes
// are cleaning up/rotating at the same time
set_error_handler(function (int $errno, string $errstr, string $errfile, int $errline): bool {
return false;
});
unlink($file);
restore_error_handler();
}
}
}
Se propone eliminar el archivo una vez verificada su creación, permitiendo que Monolog identifique correctamente los archivos nuevos y ejecute la rotación.
La implementación delogFileCanBeCreated
después de la corrección es la siguiente:
public function logFileCanBeCreated() {
$url = $this->getUrl();
$can_be_created = FALSE;
set_error_handler([$this, 'customErrorHandler']);
try {
$file_exist_before = file_exists($url);
$stream = fopen($url, 'a');
if (is_resource($stream)) {
fclose($stream);
if (!$file_exist_before) {
unlink($url);
}
$can_be_created = TRUE;
}
} catch (\Exception $e) {
self::$errorMessage = $e->getMessage();
}
restore_error_handler();
if (!$can_be_created) {
$this->loggerChannel->critical($this->t('The stream or file :file could not be opened: :message', [
':file' => $url,
':message' => self::$errorMessage,
]));
}
return $can_be_created;
}
La issue ha sido resuelta en el módulo Monolog Extra únicamente.
Referencia: The method logFileCanBeCreated avoids the rotate method
Cómo leer los logs
Hay múltiples herramientas para leer logs, la forma más sencilla es mostrando la salida en tiempo real, aunque es más complicado de interpretar y encontrar la información.
En la mayoría de casos los logs se almacenan en sistemas GNU/Linux por lo que conocer cómo leer archivos desde la consola es importante.
Con el comando tail -f
permite mostrar las últimas líneas en tiempo real de los logs.
tail -f private-files/my_module/logs/my_module_api-202*
Usando grep
se puede buscar una palabra en concreto, además de que soporta expresiones regulares y puedes elegir cuántas líneas mostrar y puede ser combinado con el anterior comando usando pipe (caracter "|").
tail -f /var/log/auth.log | grep "session opened"
También hay otras herramientas cómo lnav o goaccess que permiten filtrar, ordenar y hacer una búsqueda y seguimiento más intensivo sobre los logs.
También se pueden integrar otros sistemas externos cómo ELK (elasticsearch / logstash / kibana) o Grafana Loki para montar un monitor del sistema a partir de logs.
Conclusión
La integración de Monolog junto con Monolog Extra proporciona a Drupal capacidades de log avanzadas y flexibles. Sin embargo, es crucial estar al tanto de las incompatibilidades y problemas potenciales que pueden surgir, como el manejo de Stream Wrappers y la rotación de archivos de log. Con las soluciones propuestas, los desarrolladores pueden optimizar la gestión de logs y asegurar un rendimiento fiable y eficiente. Aprovechar al máximo estas herramientas implica no solo utilizarlas adecuadamente sino también involucrar y aprender de la comunidad activa de Drupal.