From 81883ab2ae98d5008b08e572410cd53965cb4550 Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Fri, 17 Oct 2025 10:40:45 +0300 Subject: [PATCH 01/10] Add basic setup for `django-structlog`, Celery included --- config/django/base.py | 11 ++- config/settings/loggers/settings.py | 4 + config/settings/loggers/setup.py | 114 ++++++++++++++++++++++++++++ requirements/base.txt | 1 + styleguide_example/errors/apis.py | 11 ++- styleguide_example/tasks/celery.py | 22 ++++++ styleguide_example/tasks/tasks.py | 2 +- 7 files changed, 160 insertions(+), 5 deletions(-) create mode 100644 config/settings/loggers/settings.py create mode 100644 config/settings/loggers/setup.py diff --git a/config/django/base.py b/config/django/base.py index 700dcd62..94040bc3 100644 --- a/config/django/base.py +++ b/config/django/base.py @@ -188,7 +188,12 @@ INSTALLED_APPS, MIDDLEWARE = DebugToolbarSetup.do_settings(INSTALLED_APPS, MIDDLEWARE) +from config.settings.loggers.settings import * # noqa +from config.settings.loggers.setup import LoggersSetup # noqa -SHELL_PLUS_IMPORTS = [ - "from styleguide_example.blog_examples.print_qs_in_shell.utils import print_qs" -] +INSTALLED_APPS, MIDDLEWARE = LoggersSetup.setup_settings(INSTALLED_APPS, MIDDLEWARE) +LoggersSetup.setup_structlog() +LOGGING = LoggersSetup.setup_logging() + + +SHELL_PLUS_IMPORTS = ["from styleguide_example.blog_examples.print_qs_in_shell.utils import print_qs"] diff --git a/config/settings/loggers/settings.py b/config/settings/loggers/settings.py new file mode 100644 index 00000000..360a428d --- /dev/null +++ b/config/settings/loggers/settings.py @@ -0,0 +1,4 @@ +import logging + +DJANGO_STRUCTLOG_STATUS_4XX_LOG_LEVEL = logging.INFO +DJANGO_STRUCTLOG_CELERY_ENABLED = True diff --git a/config/settings/loggers/setup.py b/config/settings/loggers/setup.py new file mode 100644 index 00000000..a082f4d1 --- /dev/null +++ b/config/settings/loggers/setup.py @@ -0,0 +1,114 @@ +import logging + +import structlog + + +class IgnoreFilter(logging.Filter): + def filter(self, record): + return False + + +class LoggersSetup: + """ + We use a class, just for namespacing convenience. + """ + + @staticmethod + def setup_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None): + INSTALLED_APPS = INSTALLED_APPS + ["django_structlog"] + + django_structlog_middleware = "django_structlog.middlewares.RequestMiddleware" + + if middleware_position is None: + MIDDLEWARE = MIDDLEWARE + [django_structlog_middleware] + else: + # Grab a new copy of the list, since insert mutates the internal structure + _middleware = MIDDLEWARE[::] + _middleware.insert(middleware_position, django_structlog_middleware) + + MIDDLEWARE = _middleware + + return INSTALLED_APPS, MIDDLEWARE + + @staticmethod + def setup_structlog(): + structlog.configure( + processors=[ + structlog.contextvars.merge_contextvars, + structlog.stdlib.filter_by_level, + structlog.processors.TimeStamper(fmt="iso", utc=True), + structlog.stdlib.add_logger_name, + structlog.stdlib.add_log_level, + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.StackInfoRenderer(), + structlog.dev.set_exc_info, + structlog.processors.format_exc_info, + # structlog.processors.dict_tracebacks, + structlog.processors.UnicodeDecoder(), + structlog.processors.CallsiteParameterAdder( + { + structlog.processors.CallsiteParameter.FILENAME, + structlog.processors.CallsiteParameter.FUNC_NAME, + structlog.processors.CallsiteParameter.LINENO, + } + ), + structlog.stdlib.ProcessorFormatter.wrap_for_formatter, + ], + logger_factory=structlog.stdlib.LoggerFactory(), + cache_logger_on_first_use=True, + ) + + @staticmethod + def setup_logging(): + return { + "version": 1, + "disable_existing_loggers": False, + "formatters": { + "json_formatter": { + "()": structlog.stdlib.ProcessorFormatter, + "processor": structlog.processors.JSONRenderer(), + }, + "plain_console": { + "()": structlog.stdlib.ProcessorFormatter, + "processor": structlog.dev.ConsoleRenderer(), + }, + }, + "filters": { + "ignore": { + "()": "config.settings.loggers.setup.IgnoreFilter", + }, + }, + "handlers": { + # Important notes regarding handlers. + # + # 1. Make sure you use handlers adapted for your project. + # These handlers configurations are only examples for this library. + # See python's logging.handlers: https://docs.python.org/3/library/logging.handlers.html + # + # 2. You might also want to use different logging configurations depending of the environment. + # Different files (local.py, tests.py, production.py, ci.py, etc.) or only conditions. + # See https://docs.djangoproject.com/en/dev/topics/settings/#designating-the-settings + "console": { + "class": "logging.StreamHandler", + "formatter": "plain_console", + } + }, + "loggers": { + # We want to get rid of the runserver logs + "django.server": {"propagate": False, "handlers": ["console"], "filters": ["ignore"]}, + # We want to get rid of the logs for 4XX and 5XX + "django.request": {"propagate": False, "handlers": ["console"], "filters": ["ignore"]}, + "django_structlog": { + "handlers": ["console"], + "level": "INFO", + }, + "celery": { + "handlers": ["console"], + "level": "INFO", + }, + "styleguide_example": { + "handlers": ["console"], + "level": "INFO", + }, + }, + } diff --git a/requirements/base.txt b/requirements/base.txt index a049514b..1cc904f1 100644 --- a/requirements/base.txt +++ b/requirements/base.txt @@ -13,6 +13,7 @@ django-filter==25.2 django-extensions==4.1 django-cors-headers==4.9.0 django-storages==1.14.6 +django-structlog[celery]==9.1.1 drf-jwt==1.19.2 diff --git a/styleguide_example/errors/apis.py b/styleguide_example/errors/apis.py index be24bdc2..f71c7b1e 100644 --- a/styleguide_example/errors/apis.py +++ b/styleguide_example/errors/apis.py @@ -1,3 +1,4 @@ +import structlog from rest_framework.response import Response from rest_framework.views import APIView @@ -8,6 +9,8 @@ from styleguide_example.errors.services import trigger_errors from styleguide_example.users.services import user_create +logger = structlog.get_logger(__name__) + class TriggerErrorApi(APIView): def get(self, request): @@ -30,6 +33,12 @@ def get(self, request): class TriggerUnhandledExceptionApi(APIView): def get(self, request): - raise Exception("Oops") + log = logger.bind() + + try: + raise Exception("Oops") + except Exception: + log.exception("unhandled_exception") + raise return Response() diff --git a/styleguide_example/tasks/celery.py b/styleguide_example/tasks/celery.py index f3452d15..37d82459 100644 --- a/styleguide_example/tasks/celery.py +++ b/styleguide_example/tasks/celery.py @@ -1,13 +1,22 @@ from __future__ import absolute_import, unicode_literals +import logging import os +import structlog from celery import Celery +from celery.signals import setup_logging +from django.dispatch import receiver +from django_structlog.celery import signals +from django_structlog.celery.steps import DjangoStructLogInitStep + +from config.settings.loggers.setup import LoggersSetup # set the default Django settings module for the 'celery' program. os.environ.setdefault("DJANGO_SETTINGS_MODULE", "config.django.base") app = Celery("styleguide_example") +app.steps["worker"].add(DjangoStructLogInitStep) # Using a string here means the worker doesn't have to serialize # the configuration object to child processes. @@ -17,3 +26,16 @@ # Load task modules from all registered Django app configs. app.autodiscover_tasks() + + +@setup_logging.connect +def receiver_setup_logging(loglevel, logfile, format, colorize, **kwargs): # pragma: no cover + logging.config.dictConfig(LoggersSetup.setup_logging()) + LoggersSetup.setup_structlog() + + +@receiver(signals.bind_extra_task_metadata) +def receiver_bind_extra_request_metadata(sender, signal, task=None, logger=None, **kwargs): + # We want to add the task name to the task_succeeded event + if task is not None: + structlog.contextvars.bind_contextvars(task=task.name) diff --git a/styleguide_example/tasks/tasks.py b/styleguide_example/tasks/tasks.py index dba9ff73..9e318290 100644 --- a/styleguide_example/tasks/tasks.py +++ b/styleguide_example/tasks/tasks.py @@ -1,6 +1,6 @@ from celery import shared_task -@shared_task +@shared_task(bind=True) def debug_task(self): print("Request: {0!r}".format(self.request)) From ad4e687a6c18b5b82d09d23b0a7af874a6235bd5 Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Fri, 17 Oct 2025 10:49:15 +0300 Subject: [PATCH 02/10] Replace example for non-concurrent task with struclog --- .../celery_non_concurrent/tasks.py | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/styleguide_example/blog_examples/celery_non_concurrent/tasks.py b/styleguide_example/blog_examples/celery_non_concurrent/tasks.py index d69b6b5d..bb35ea6a 100644 --- a/styleguide_example/blog_examples/celery_non_concurrent/tasks.py +++ b/styleguide_example/blog_examples/celery_non_concurrent/tasks.py @@ -1,16 +1,18 @@ -import logging from functools import wraps +import structlog from celery import shared_task from styleguide_example.tasks import celery_app inspect = celery_app.control.inspect -logger = logging.getLogger(__name__) +logger = structlog.get_logger(__name__) def non_concurrent_task(_func=None, *args, **kwargs): + log = logger.bind() + def wrapper(func): @wraps(func) def inner(_bound_self, *_func_args, **_func_kwargs): @@ -27,7 +29,10 @@ def inner(_bound_self, *_func_args, **_func_kwargs): running_task_count += 1 if running_task_count > 1: - logger.warning(f"[non_concurrent_task] Task {_bound_self.name} is already running") + log.warning( + "non_concurrent_task", + message=f"[non_concurrent_task] Task {_bound_self.name} is already running", + ) return return func(*_func_args, **_func_kwargs) @@ -42,7 +47,10 @@ def inner(_bound_self, *_func_args, **_func_kwargs): @non_concurrent_task def test_non_concurrent_task(): - logger.info("A non-concurrent task is running") + log = logger.bind() + + log.info("non_concurrent_task", message="A non-concurrent task is running") import time + time.sleep(10) - logger.info("A non-concurrent task finished") + log.info("non_concurrent_task", message="A non-concurrent task finished") From e36faa85a9526468b339b51123614601ad23bee5 Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Fri, 17 Oct 2025 10:51:30 +0300 Subject: [PATCH 03/10] Use `structlog` in debug toolbar setup --- config/settings/debug_toolbar/setup.py | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/config/settings/debug_toolbar/setup.py b/config/settings/debug_toolbar/setup.py index 20bfed7c..85e90af7 100644 --- a/config/settings/debug_toolbar/setup.py +++ b/config/settings/debug_toolbar/setup.py @@ -1,11 +1,12 @@ -import logging - +import structlog from django.urls import include, path -logger = logging.getLogger("configuration") +logger = structlog.getLogger("styleguide_example.configuration") def show_toolbar(*args, **kwargs) -> bool: + log = logger.bind() + """ The general idea is the following: @@ -30,7 +31,7 @@ def show_toolbar(*args, **kwargs) -> bool: try: import debug_toolbar # noqa except ImportError: - logger.info("No installation found for: django_debug_toolbar") + log.info("django_debug_toolbar.setup", message="No installation found for: django_debug_toolbar") return False return True @@ -43,8 +44,10 @@ class DebugToolbarSetup: @staticmethod def do_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None): + log = logger.bind() + _show_toolbar: bool = show_toolbar() - logger.info(f"Django Debug Toolbar in use: {_show_toolbar}") + log.info("django_debuhg_toolbar.setup", message=f"Django Debug Toolbar in use: {_show_toolbar}") if not _show_toolbar: return INSTALLED_APPS, MIDDLEWARE From 9b0ac3c92632c6858e758d9830b25f030a9fcfed Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Fri, 17 Oct 2025 11:24:30 +0300 Subject: [PATCH 04/10] Cannot use logger while Django settings are running --- config/django/base.py | 14 +++++------ config/settings/debug_toolbar/setup.py | 9 -------- config/settings/loggers/settings.py | 12 ++++++++++ config/settings/loggers/setup.py | 32 ++++++++++++++++++++++---- 4 files changed, 46 insertions(+), 21 deletions(-) diff --git a/config/django/base.py b/config/django/base.py index 94040bc3..778986e4 100644 --- a/config/django/base.py +++ b/config/django/base.py @@ -174,6 +174,13 @@ DEFAULT_AUTO_FIELD = "django.db.models.BigAutoField" +from config.settings.loggers.settings import * # noqa +from config.settings.loggers.setup import LoggersSetup # noqa + +INSTALLED_APPS, MIDDLEWARE = LoggersSetup.setup_settings(INSTALLED_APPS, MIDDLEWARE) +LoggersSetup.setup_structlog() +LOGGING = LoggersSetup.setup_logging() + from config.settings.celery import * # noqa from config.settings.cors import * # noqa from config.settings.email_sending import * # noqa @@ -188,12 +195,5 @@ INSTALLED_APPS, MIDDLEWARE = DebugToolbarSetup.do_settings(INSTALLED_APPS, MIDDLEWARE) -from config.settings.loggers.settings import * # noqa -from config.settings.loggers.setup import LoggersSetup # noqa - -INSTALLED_APPS, MIDDLEWARE = LoggersSetup.setup_settings(INSTALLED_APPS, MIDDLEWARE) -LoggersSetup.setup_structlog() -LOGGING = LoggersSetup.setup_logging() - SHELL_PLUS_IMPORTS = ["from styleguide_example.blog_examples.print_qs_in_shell.utils import print_qs"] diff --git a/config/settings/debug_toolbar/setup.py b/config/settings/debug_toolbar/setup.py index 85e90af7..416662b4 100644 --- a/config/settings/debug_toolbar/setup.py +++ b/config/settings/debug_toolbar/setup.py @@ -1,12 +1,7 @@ -import structlog from django.urls import include, path -logger = structlog.getLogger("styleguide_example.configuration") - def show_toolbar(*args, **kwargs) -> bool: - log = logger.bind() - """ The general idea is the following: @@ -31,7 +26,6 @@ def show_toolbar(*args, **kwargs) -> bool: try: import debug_toolbar # noqa except ImportError: - log.info("django_debug_toolbar.setup", message="No installation found for: django_debug_toolbar") return False return True @@ -44,10 +38,7 @@ class DebugToolbarSetup: @staticmethod def do_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None): - log = logger.bind() - _show_toolbar: bool = show_toolbar() - log.info("django_debuhg_toolbar.setup", message=f"Django Debug Toolbar in use: {_show_toolbar}") if not _show_toolbar: return INSTALLED_APPS, MIDDLEWARE diff --git a/config/settings/loggers/settings.py b/config/settings/loggers/settings.py index 360a428d..b1e0e4a7 100644 --- a/config/settings/loggers/settings.py +++ b/config/settings/loggers/settings.py @@ -1,4 +1,16 @@ import logging +from enum import Enum + +from config.env import env, env_to_enum + + +class LoggingFormat(Enum): + DEV = "dev" + JSON = "json" + LOGFMT = "logfmt" + + +LOGGING_FORMAT = env_to_enum(LoggingFormat, env("LOGGING_FORMAT", default=LoggingFormat.DEV.value)) DJANGO_STRUCTLOG_STATUS_4XX_LOG_LEVEL = logging.INFO DJANGO_STRUCTLOG_CELERY_ENABLED = True diff --git a/config/settings/loggers/setup.py b/config/settings/loggers/setup.py index a082f4d1..cf3e0d7a 100644 --- a/config/settings/loggers/setup.py +++ b/config/settings/loggers/setup.py @@ -2,6 +2,8 @@ import structlog +logger = structlog.getLogger("styleguide_example.configuration") + class IgnoreFilter(logging.Filter): def filter(self, record): @@ -60,17 +62,37 @@ def setup_structlog(): @staticmethod def setup_logging(): + from django.conf import settings + + from config.settings.loggers.settings import LoggingFormat + + logging_format = settings.LOGGING_FORMAT + formatter = "dev" + + if logging_format == LoggingFormat.DEV: + formatter = "dev" + + if logging_format == LoggingFormat.JSON: + formatter = "json" + + if logging_format == LoggingFormat.LOGFMT: + formatter = "logfmt" + return { "version": 1, "disable_existing_loggers": False, "formatters": { - "json_formatter": { + "dev": { "()": structlog.stdlib.ProcessorFormatter, - "processor": structlog.processors.JSONRenderer(), + "processor": structlog.dev.ConsoleRenderer(), }, - "plain_console": { + "logfmt": { "()": structlog.stdlib.ProcessorFormatter, - "processor": structlog.dev.ConsoleRenderer(), + "processor": structlog.processors.LogfmtRenderer(), + }, + "json": { + "()": structlog.stdlib.ProcessorFormatter, + "processor": structlog.processors.JSONRenderer(), }, }, "filters": { @@ -90,7 +112,7 @@ def setup_logging(): # See https://docs.djangoproject.com/en/dev/topics/settings/#designating-the-settings "console": { "class": "logging.StreamHandler", - "formatter": "plain_console", + "formatter": formatter, } }, "loggers": { From 7a94628e0e6a38cb73fb6fd526ddd20d372b5877 Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Fri, 17 Oct 2025 16:44:15 +0300 Subject: [PATCH 05/10] Add different structlog processors, based on the renderer --- config/settings/loggers/setup.py | 24 ++++++++++++++++++++++-- 1 file changed, 22 insertions(+), 2 deletions(-) diff --git a/config/settings/loggers/setup.py b/config/settings/loggers/setup.py index cf3e0d7a..d98c1add 100644 --- a/config/settings/loggers/setup.py +++ b/config/settings/loggers/setup.py @@ -34,6 +34,27 @@ def setup_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None): @staticmethod def setup_structlog(): + from django.conf import settings + + from config.settings.loggers.settings import LoggingFormat + + logging_format = settings.LOGGING_FORMAT + + extra_processors = [] + + if logging_format == LoggingFormat.DEV: + extra_processors = [ + structlog.processors.format_exc_info, + ] + + if logging_format in [LoggingFormat.JSON, LoggingFormat.LOGFMT]: + dict_tracebacks = structlog.processors.ExceptionRenderer( + structlog.processors.ExceptionDictTransformer(show_locals=False) + ) + extra_processors = [ + dict_tracebacks, + ] + structlog.configure( processors=[ structlog.contextvars.merge_contextvars, @@ -44,8 +65,7 @@ def setup_structlog(): structlog.stdlib.PositionalArgumentsFormatter(), structlog.processors.StackInfoRenderer(), structlog.dev.set_exc_info, - structlog.processors.format_exc_info, - # structlog.processors.dict_tracebacks, + *extra_processors, structlog.processors.UnicodeDecoder(), structlog.processors.CallsiteParameterAdder( { From d62f227735a9d8c11441536ca864e90731491188 Mon Sep 17 00:00:00 2001 From: Radoslav Georgiev Date: Tue, 21 Oct 2025 10:39:41 +0300 Subject: [PATCH 06/10] Add structlog support for gunicorn --- config/django/base.py | 2 - gunicorn.conf.py | 99 +++++++++++++++++++++++++++++++++++++++---- 2 files changed, 91 insertions(+), 10 deletions(-) diff --git a/config/django/base.py b/config/django/base.py index 778986e4..dde308af 100644 --- a/config/django/base.py +++ b/config/django/base.py @@ -83,8 +83,6 @@ ROOT_URLCONF = "config.urls" -print(os.path.join(APPS_DIR, "templates")) - TEMPLATES = [ { "BACKEND": "django.template.backends.django.DjangoTemplates", diff --git a/gunicorn.conf.py b/gunicorn.conf.py index a7596f80..b4599637 100644 --- a/gunicorn.conf.py +++ b/gunicorn.conf.py @@ -1,8 +1,91 @@ -# If you are not having memory issues, just delete this. -# This is primarily to prevent memory leaks -# Based on https://devcenter.heroku.com/articles/python-gunicorn -# Based on https://adamj.eu/tech/2019/09/19/working-around-memory-leaks-in-your-django-app/ -# https://docs.gunicorn.org/en/latest/settings.html#max-requests -# https://docs.gunicorn.org/en/latest/settings.html#max-requests-jitter -max_requests = 1200 -max_requests_jitter = 100 +# https://mattsegal.dev/django-gunicorn-nginx-logging.html +# https://albersdevelopment.net/2019/08/15/using-structlog-with-gunicorn/ + +import logging +import logging.config +import re + +import structlog + + +def combined_logformat(logger, name, event_dict): + if event_dict.get("logger") == "gunicorn.access": + message = event_dict["event"] + + parts = [ + r"(?P\S+)", # host %h + r"\S+", # indent %l (unused) + r"(?P\S+)", # user %u + r"\[(?P