[config] Add structured logs

Organizing log data in a structured format makes easier
to read and analyze them.

With this commit, log messages will always have a structured
format. The default mode is to print the messages to the
console in a plain format, but it can also be configured
to print them in JSON format.

We have added structured logs to GrimoireLab using the
'structlog' package.

By default, tests will run silent. If developers want to get
log messages printed to the console, activate the environment
variable 'GRIMOIRELAB_TESTING_VERBOSE'.

Signed-off-by: Santiago Dueñas <[email protected]>

Author: sduenas

README.md

@@ -80,7 +80,7 @@ $ pip install -e .
 ```
 
 #### Poetry
-We use [poetry](https://python-poetry.org/) for dependency management and 
+We use [poetry](https://python-poetry.org/) for dependency management and
 packaging. You can install it following its [documentation](https://python-poetry.org/docs/#installation).
 Once you have installed it, you can install grimoirelab-core and the dependencies
 in a project isolated environment using:
@@ -134,7 +134,7 @@ Commands:
 
 ## Configuration
 
-The first step is to run a Redis server, a MySQL database and an OpenSearch 
+The first step is to run a Redis server, a MySQL database and an OpenSearch
 container that will be used for communicating components and storing results.
 Please refer to their documentation to know how to install and run them.
 
@@ -202,3 +202,6 @@ Valkey, and OpenSearch).
 ```
 (.venv)$ pytest
 ```
+
+Set the environment variable `GRIMOIRELAB_TESTING_VERBOSE` to activate the
+verbose mode.

config/settings/testing.py

@@ -1,20 +1,41 @@
-from grimoirelab.core.config.settings import *  # noqa: F403,F401
-from grimoirelab.core.config.settings import INSTALLED_APPS, _RQ_DATABASE, RQ
-
+import os
 import warnings
 
+from grimoirelab.core.config.settings import *  # noqa: F403,F401
+from grimoirelab.core.config.settings import (
+    INSTALLED_APPS,
+    _RQ_DATABASE,
+    RQ,
+    LOGGING,
+)
+
 import django_rq.queues
 
 from fakeredis import FakeRedis, FakeStrictRedis
 
+
 INSTALLED_APPS.append("tests")
 
-LOGGING = {
-    "version": 1,
-    "disable_existing_loggers": True,
-    "loggers": {
-        "grimoirelab.core": {"level": "CRITICAL"},
-    },
+GRIMOIRELAB_TESTING_VERBOSE = os.environ.get(
+    "GRIMOIRELAB_TESTING_VERBOSE",
+    "False",
+).lower() in ("true", "1")
+
+# Logging configuration for testing
+#
+# By default, logging is silent and doesn't print messages to the console.
+# Set 'GRIMOIRELAB_TESTING_VERBOSE' to 'True' to print messages to the console.
+#
+LOGGING["handlers"]["testing"] = {
+    "class": "logging.NullHandler",
+}
+
+LOGGING["loggers"] = {
+    "": {
+        "handlers": ["default"] if GRIMOIRELAB_TESTING_VERBOSE else ["testing"],
+        "level": "DEBUG",
+        "propagate": True,
+    }
 }
 
 SQL_MODE = [

poetry.lock

@@ -61,6 +61,8 @@ opensearch-py = "^3.0.0"
 djangorestframework-simplejwt = "^5.4.0"
 django-storages = {version = "^1.14.6", extras = ["google"]}
 drf-spectacular = "^0.28.0"
+django-structlog = "^9.0.1"
+structlog = "^25.2.0"
 grimoirelab-toolkit = {version = ">=1.2.0", allow-prereleases = true}
 perceval = {version = ">=1.3.4", allow-prereleases = true}
 sortinghat = {version = ">=1.11.0", allow-prereleases = true}

pyproject.toml

@@ -0,0 +1,157 @@
+# -*- coding: utf-8 -*-
+#
+# GrimoireLab logging setup.
+#
+# Logging is configured using 'structlog', 'django-structlog',
+# and the standard library 'logging' module.
+#
+# More info:
+#
+# https://django-structlog.readthedocs.io/en/latest/
+# https://docs.djangoproject.com/en/4.2/topics/logging/#configuring-logging
+#
+
+import structlog
+
+
+# Default column styles for the console renderer.
+
+styles = structlog.dev._ColorfulStyles
+
+logger_name_formatter = structlog.dev.KeyValueColumnFormatter(
+    key_style=None,
+    value_style=styles.bright + styles.logger_name,
+    reset_style=styles.reset,
+    value_repr=str,
+    prefix="[",
+    postfix="]",
+)
+
+console_columns = [
+    structlog.dev.Column(
+        "timestamp",
+        structlog.dev.KeyValueColumnFormatter(
+            key_style=None,
+            value_style=styles.timestamp,
+            reset_style=styles.reset,
+            value_repr=str,
+        ),
+    ),
+    structlog.dev.Column(
+        "level",
+        structlog.dev.LogLevelColumnFormatter(
+            structlog.dev.ConsoleRenderer.get_default_level_styles(),
+            reset_style=styles.reset,
+        ),
+    ),
+    structlog.dev.Column("logger", logger_name_formatter),
+    structlog.dev.Column("logger_name", logger_name_formatter),
+    structlog.dev.Column(
+        "event",
+        structlog.dev.KeyValueColumnFormatter(
+            key_style=None,
+            value_style=styles.bright,
+            reset_style=styles.reset,
+            value_repr=str,
+        ),
+    ),
+    # Default formatter for all keys not explicitly mentioned.
+    structlog.dev.Column(
+        "",
+        structlog.dev.KeyValueColumnFormatter(
+            key_style=styles.kv_key,
+            value_style=styles.kv_value,
+            reset_style=styles.reset,
+            value_repr=str,
+        ),
+    ),
+]
+
+
+# Configuration of chain processors for logs not generated by structlog.
+# This will add default fields such the log level, timestamp, etc.
+
+pre_chain_processors = [
+    structlog.processors.TimeStamper(fmt="iso", utc=True),
+    structlog.stdlib.add_log_level,
+    structlog.stdlib.add_logger_name,
+    structlog.stdlib.ExtraAdder(),
+]
+
+
+# Default logging configuration for GrimoireLab
+
+_GRIMOIRELAB_LOGGING_CONFIG = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "plain": {
+            "()": structlog.stdlib.ProcessorFormatter,
+            "processors": [
+                structlog.stdlib.ProcessorFormatter.remove_processors_meta,
+                structlog.dev.ConsoleRenderer(columns=console_columns),
+            ],
+            "foreign_pre_chain": pre_chain_processors,
+        },
+        "json": {
+            "()": structlog.stdlib.ProcessorFormatter,
+            "processors": [
+                structlog.stdlib.ProcessorFormatter.remove_processors_meta,
+                structlog.processors.JSONRenderer(),
+            ],
+            "foreign_pre_chain": pre_chain_processors,
+        },
+        "not_structured": {
+            "format": "[%(asctime)s - %(name)s - %(levelname)s] - %(message)s",
+        },
+    },
+    "handlers": {
+        "default": {
+            "class": "logging.StreamHandler",
+            "formatter": "plain",
+        },
+        "json": {
+            "class": "logging.StreamHandler",
+            "formatter": "json",
+        },
+    },
+}
+
+
+def configure_grimoirelab_logging(
+    json_mode: bool = False,
+    debug: bool = False,
+) -> None:
+    """
+    Set up the GrimoireLab logging settings.
+
+    :param json_mode: If True, use JSON format for logging.
+    :param debug: If True, set logging level to DEBUG.
+    """
+    structlog.configure(
+        processors=[
+            structlog.contextvars.merge_contextvars,
+            structlog.stdlib.filter_by_level,
+            structlog.stdlib.PositionalArgumentsFormatter(),
+            structlog.processors.TimeStamper(fmt="iso", utc=True),
+            structlog.stdlib.add_log_level,
+            structlog.stdlib.add_logger_name,
+            structlog.processors.StackInfoRenderer(),
+            structlog.processors.format_exc_info,
+            structlog.processors.UnicodeDecoder(),
+            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        wrapper_class=structlog.stdlib.BoundLogger,
+        cache_logger_on_first_use=True,
+    )
+
+    logging_settings = dict(_GRIMOIRELAB_LOGGING_CONFIG)
+    logging_settings["loggers"] = {
+        "": {
+            "handlers": ["json"] if json_mode else ["default"],
+            "level": "DEBUG" if debug else "INFO",
+        },
+    }
+
+    return logging_settings