From 69054bc5909ad6200daf8b99ab30056dcc84dda6 Mon Sep 17 00:00:00 2001 From: Victor Seva Date: Sun, 25 Oct 2020 09:56:30 +0100 Subject: [PATCH] TT#96400 using structlog via python-structlog * https://django-structlog.readthedocs.io/en/latest/ django-structlog is a structured logging integration for Django project using structlog Logging will then produce additional cohesive metadata on each logs that makes it easier to track events or incidents. * https://www.structlog.org/en/stable/ structlog makes logging in Python less painful and more powerful by adding structure to your log entries. Change-Id: I087574a8d7e04ddb32d86077b0e5478a9f41e11b --- Makefile | 3 +- repoapi/celery.py | 58 ++++++++++++++++++++++++++++++++++++-- repoapi/settings/common.py | 41 +++++++++++++++++++++++++-- requirements/common.txt | 1 + t/Dockerfile | 2 +- 5 files changed, 99 insertions(+), 6 deletions(-) diff --git a/Makefile b/Makefile index 5a2d79c..79ff865 100644 --- a/Makefile +++ b/Makefile @@ -49,11 +49,12 @@ shell: venv_prod run_dev: venv_dev IP=$(shell ip a show dev eth0 scope global | grep inet | awk '{print $$2}' | cut -d/ -f1); \ source $(VAR_DIR)/venv_dev/bin/activate && \ + DJANGO_LOG_LEVEL=DEBUG \ ./manage.py runserver_plus $$IP:8000 --settings="repoapi.settings.dev" worker_dev: venv_dev source $(VAR_DIR)/venv_dev/bin/activate && \ - DJANGO_SETTINGS_MODULE=repoapi.settings.dev \ + DJANGO_LOG_LEVEL=DEBUG DJANGO_SETTINGS_MODULE=repoapi.settings.dev \ $(VAR_DIR)/venv_dev/bin/celery -A repoapi worker \ --loglevel=info diff --git a/repoapi/celery.py b/repoapi/celery.py index 65049ff..34f9543 100644 --- a/repoapi/celery.py +++ b/repoapi/celery.py @@ -1,4 +1,4 @@ -# Copyright (C) 2016 The Sipwise Team - http://sipwise.com +# Copyright (C) 2016-2020 The Sipwise Team - http://sipwise.com # # This program is free software: you can redistribute it and/or modify it # under the terms of the GNU General Public License as published by the Free @@ -12,15 +12,19 @@ # # You should have received a copy of the GNU General Public License along # with this program. If not, see . +import logging import os +import structlog from celery import Celery +from celery.signals import setup_logging +from django_structlog.celery.steps import DjangoStructLogInitStep # set the default Django settings module for the 'celery' program. os.environ.setdefault("DJANGO_SETTINGS_MODULE", "repoapi.settings.prod") app = Celery("repoapi") - +app.steps["worker"].add(DjangoStructLogInitStep) # Using a string here means the worker doesn't have to serialize # the configuration object to child processes. # - namespace='CELERY' means all celery-related configuration keys @@ -31,6 +35,56 @@ app.config_from_object("repoapi.conf:settings", namespace="CELERY") app.autodiscover_tasks() +@setup_logging.connect +def receiver_setup_logging(loglevel, logfile, format, colorize, **kwargs): + logging.config.dictConfig( + { + "version": 1, + "disable_existing_loggers": False, + "formatters": { + "plain_console": { + "()": structlog.stdlib.ProcessorFormatter, + "processor": structlog.dev.ConsoleRenderer(), + }, + }, + "handlers": { + "console": { + "class": "logging.StreamHandler", + "formatter": "plain_console", + } + }, + "loggers": { + "django_structlog": { + "handlers": ["console"], + "level": "INFO", + }, + "repoapi": { + "handlers": ["console"], + "level": os.getenv("DJANGO_LOG_LEVEL", "INFO"), + }, + }, + } + ) + + structlog.configure( + processors=[ + structlog.stdlib.filter_by_level, + structlog.stdlib.add_logger_name, + structlog.stdlib.add_log_level, + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.StackInfoRenderer(), + structlog.processors.format_exc_info, + structlog.processors.UnicodeDecoder(), + structlog.processors.ExceptionPrettyPrinter(), + structlog.stdlib.ProcessorFormatter.wrap_for_formatter, + ], + context_class=structlog.threadlocal.wrap_dict(dict), + logger_factory=structlog.stdlib.LoggerFactory(), + wrapper_class=structlog.stdlib.BoundLogger, + cache_logger_on_first_use=True, + ) + + @app.task() def jbi_parse_hotfix(jbi_id, path): app.send_task("hotfix.tasks.hotfix_released", args=[jbi_id, path]) diff --git a/repoapi/settings/common.py b/repoapi/settings/common.py index d629c39..b92e6ec 100644 --- a/repoapi/settings/common.py +++ b/repoapi/settings/common.py @@ -1,4 +1,4 @@ -# Copyright (C) 2015 The Sipwise Team - http://sipwise.com +# Copyright (C) 2015-2020 The Sipwise Team - http://sipwise.com # # This program is free software: you can redistribute it and/or modify it # under the terms of the GNU General Public License as published by the Free @@ -17,6 +17,8 @@ import os from os.path import dirname +import structlog + BASE_DIR = dirname(dirname(dirname(os.path.abspath(__file__)))) INSTALLED_APPS = [ @@ -53,6 +55,8 @@ MIDDLEWARE = ( "django.contrib.messages.middleware.MessageMiddleware", "django.middleware.clickjacking.XFrameOptionsMiddleware", "django.middleware.security.SecurityMiddleware", + "django_structlog.middlewares.RequestMiddleware", + "django_structlog.middlewares.CeleryMiddleware", ) ROOT_URLCONF = "repoapi.urls" @@ -121,8 +125,23 @@ SWAGGER_SETTINGS = { LOGGING = { "version": 1, "disable_existing_loggers": False, - "handlers": {"console": {"class": "logging.StreamHandler"}}, + "formatters": { + "plain_console": { + "()": structlog.stdlib.ProcessorFormatter, + "processor": structlog.dev.ConsoleRenderer(), + }, + }, + "handlers": { + "console": { + "class": "logging.StreamHandler", + "formatter": "plain_console", + } + }, "loggers": { + "django_structlog": { + "handlers": ["console"], + "level": "INFO", + }, "repoapi": { "handlers": ["console"], "level": os.getenv("DJANGO_LOG_LEVEL", "INFO"), @@ -130,6 +149,24 @@ LOGGING = { }, } +structlog.configure( + processors=[ + structlog.stdlib.filter_by_level, + structlog.stdlib.add_logger_name, + structlog.stdlib.add_log_level, + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.StackInfoRenderer(), + structlog.processors.format_exc_info, + structlog.processors.UnicodeDecoder(), + structlog.processors.ExceptionPrettyPrinter(), + structlog.stdlib.ProcessorFormatter.wrap_for_formatter, + ], + context_class=structlog.threadlocal.wrap_dict(dict), + logger_factory=structlog.stdlib.LoggerFactory(), + wrapper_class=structlog.stdlib.BoundLogger, + cache_logger_on_first_use=True, +) + JENKINS_TOKEN = "sipwise_jenkins_ci" CELERY_TASK_SERIALIZER = "json" diff --git a/requirements/common.txt b/requirements/common.txt index 03796bf..019f8e7 100644 --- a/requirements/common.txt +++ b/requirements/common.txt @@ -10,6 +10,7 @@ django-filter<2.3 django-jsonify django-object-tools django-rest-swagger +django-structlog django-timezone-field>=3.1,<4.0 # last version supporting django 1.11 djangorestframework>=3.6,<3.7 drfapikey diff --git a/t/Dockerfile b/t/Dockerfile index d4e144c..2b83215 100644 --- a/t/Dockerfile +++ b/t/Dockerfile @@ -5,7 +5,7 @@ FROM docker.mgm.sipwise.com/sipwise-buster:latest # is updated with the current date. It will force refresh of all # of the base images and things like `apt-get update` won't be using # old cached versions when the Dockerfile is built. -ENV REFRESHED_AT 2020-10-12 +ENV REFRESHED_AT 2020-10-25 # test execution; we need the backport of python3-junitxml from our own # repository since it's not part of Debian/buster