Skip to content

Commit 3f15386

Browse files
RadoRadoRadoRado
authored
Merge pull request #549 from HackSoftware/logging/setup-structlogging
Logging: Setup `django-structlog`
2 parents 0d3a001 + 3135195 commit 3f15386

File tree

10 files changed

+346
-26
lines changed

10 files changed

+346
-26
lines changed

‎config/django/base.py‎

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -83,8 +83,6 @@
8383

8484
ROOT_URLCONF = "config.urls"
8585

86-
print(os.path.join(APPS_DIR, "templates"))
87-
8886
TEMPLATES = [
8987
{
9088
"BACKEND": "django.template.backends.django.DjangoTemplates",
@@ -174,6 +172,13 @@
174172

175173
DEFAULT_AUTO_FIELD = "django.db.models.BigAutoField"
176174

175+
from config.settings.loggers.settings import * # noqa
176+
from config.settings.loggers.setup import LoggersSetup # noqa
177+
178+
INSTALLED_APPS, MIDDLEWARE = LoggersSetup.setup_settings(INSTALLED_APPS, MIDDLEWARE)
179+
LoggersSetup.setup_structlog()
180+
LOGGING = LoggersSetup.setup_logging()
181+
177182
from config.settings.celery import * # noqa
178183
from config.settings.cors import * # noqa
179184
from config.settings.email_sending import * # noqa
@@ -189,6 +194,4 @@
189194
INSTALLED_APPS, MIDDLEWARE = DebugToolbarSetup.do_settings(INSTALLED_APPS, MIDDLEWARE)
190195

191196

192-
SHELL_PLUS_IMPORTS = [
193-
"from styleguide_example.blog_examples.print_qs_in_shell.utils import print_qs"
194-
]
197+
SHELL_PLUS_IMPORTS = ["from styleguide_example.blog_examples.print_qs_in_shell.utils import print_qs"]

‎config/settings/debug_toolbar/setup.py‎

Lines changed: 0 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,5 @@
1-
import logging
2-
31
from django.urls import include, path
42

5-
logger = logging.getLogger("configuration")
6-
73

84
def show_toolbar(*args, **kwargs) -> bool:
95
"""
@@ -30,7 +26,6 @@ def show_toolbar(*args, **kwargs) -> bool:
3026
try:
3127
import debug_toolbar # noqa
3228
except ImportError:
33-
logger.info("No installation found for: django_debug_toolbar")
3429
return False
3530

3631
return True
@@ -44,7 +39,6 @@ class DebugToolbarSetup:
4439
@staticmethod
4540
def do_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None):
4641
_show_toolbar: bool = show_toolbar()
47-
logger.info(f"Django Debug Toolbar in use: {_show_toolbar}")
4842

4943
if not _show_toolbar:
5044
return INSTALLED_APPS, MIDDLEWARE

‎config/settings/loggers/settings.py‎

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,16 @@
1+
import logging
2+
from enum import Enum
3+
4+
from config.env import env, env_to_enum
5+
6+
7+
class LoggingFormat(Enum):
8+
DEV = "dev"
9+
JSON = "json"
10+
LOGFMT = "logfmt"
11+
12+
13+
LOGGING_FORMAT = env_to_enum(LoggingFormat, env("LOGGING_FORMAT", default=LoggingFormat.DEV.value))
14+
15+
DJANGO_STRUCTLOG_STATUS_4XX_LOG_LEVEL = logging.INFO
16+
DJANGO_STRUCTLOG_CELERY_ENABLED = True

‎config/settings/loggers/setup.py‎

Lines changed: 141 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,141 @@
1+
import logging
2+
3+
import structlog
4+
5+
6+
class IgnoreFilter(logging.Filter):
7+
def filter(self, record):
8+
return False
9+
10+
11+
class LoggersSetup:
12+
"""
13+
We use a class, just for namespacing convenience.
14+
"""
15+
16+
@staticmethod
17+
def setup_settings(INSTALLED_APPS, MIDDLEWARE, middleware_position=None):
18+
INSTALLED_APPS = INSTALLED_APPS + ["django_structlog"]
19+
20+
django_structlog_middleware = "django_structlog.middlewares.RequestMiddleware"
21+
22+
if middleware_position is None:
23+
MIDDLEWARE = MIDDLEWARE + [django_structlog_middleware]
24+
else:
25+
# Grab a new copy of the list, since insert mutates the internal structure
26+
_middleware = MIDDLEWARE[::]
27+
_middleware.insert(middleware_position, django_structlog_middleware)
28+
29+
MIDDLEWARE = _middleware
30+
31+
return INSTALLED_APPS, MIDDLEWARE
32+
33+
@staticmethod
34+
def setup_structlog():
35+
from config.settings.loggers.settings import LOGGING_FORMAT, LoggingFormat
36+
37+
logging_format = LOGGING_FORMAT
38+
39+
extra_processors = []
40+
41+
if logging_format == LoggingFormat.DEV:
42+
extra_processors = [
43+
structlog.processors.format_exc_info,
44+
]
45+
46+
if logging_format in [LoggingFormat.JSON, LoggingFormat.LOGFMT]:
47+
dict_tracebacks = structlog.processors.ExceptionRenderer(
48+
structlog.processors.ExceptionDictTransformer(show_locals=False)
49+
)
50+
extra_processors = [
51+
dict_tracebacks,
52+
]
53+
54+
structlog.configure(
55+
processors=[
56+
structlog.contextvars.merge_contextvars,
57+
structlog.stdlib.filter_by_level,
58+
structlog.processors.TimeStamper(fmt="iso", utc=True),
59+
structlog.stdlib.add_logger_name,
60+
structlog.stdlib.add_log_level,
61+
structlog.stdlib.PositionalArgumentsFormatter(),
62+
structlog.processors.StackInfoRenderer(),
63+
structlog.dev.set_exc_info,
64+
*extra_processors,
65+
structlog.processors.UnicodeDecoder(),
66+
structlog.processors.CallsiteParameterAdder(
67+
{
68+
structlog.processors.CallsiteParameter.FILENAME,
69+
structlog.processors.CallsiteParameter.FUNC_NAME,
70+
structlog.processors.CallsiteParameter.LINENO,
71+
}
72+
),
73+
structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
74+
],
75+
logger_factory=structlog.stdlib.LoggerFactory(),
76+
cache_logger_on_first_use=True,
77+
)
78+
79+
@staticmethod
80+
def setup_logging():
81+
from config.settings.loggers.settings import LOGGING_FORMAT, LoggingFormat
82+
83+
logging_format = LOGGING_FORMAT
84+
formatter = "dev"
85+
86+
if logging_format == LoggingFormat.DEV:
87+
formatter = "dev"
88+
89+
if logging_format == LoggingFormat.JSON:
90+
formatter = "json"
91+
92+
if logging_format == LoggingFormat.LOGFMT:
93+
formatter = "logfmt"
94+
95+
return {
96+
"version": 1,
97+
"disable_existing_loggers": False,
98+
"formatters": {
99+
"dev": {
100+
"()": structlog.stdlib.ProcessorFormatter,
101+
"processor": structlog.dev.ConsoleRenderer(),
102+
},
103+
"logfmt": {
104+
"()": structlog.stdlib.ProcessorFormatter,
105+
"processor": structlog.processors.LogfmtRenderer(),
106+
},
107+
"json": {
108+
"()": structlog.stdlib.ProcessorFormatter,
109+
"processor": structlog.processors.JSONRenderer(),
110+
},
111+
},
112+
"filters": {
113+
"ignore": {
114+
"()": "config.settings.loggers.setup.IgnoreFilter",
115+
},
116+
},
117+
"handlers": {
118+
"console": {
119+
"class": "logging.StreamHandler",
120+
"formatter": formatter,
121+
}
122+
},
123+
"loggers": {
124+
# We want to get rid of the runserver logs
125+
"django.server": {"propagate": False, "handlers": ["console"], "filters": ["ignore"]},
126+
# We want to get rid of the logs for 4XX and 5XX
127+
"django.request": {"propagate": False, "handlers": ["console"], "filters": ["ignore"]},
128+
"django_structlog": {
129+
"handlers": ["console"],
130+
"level": "INFO",
131+
},
132+
"celery": {
133+
"handlers": ["console"],
134+
"level": "INFO",
135+
},
136+
"styleguide_example": {
137+
"handlers": ["console"],
138+
"level": "INFO",
139+
},
140+
},
141+
}

‎gunicorn.conf.py‎

Lines changed: 134 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,134 @@
1-
# If you are not having memory issues, just delete this.
2-
# This is primarily to prevent memory leaks
3-
# Based on https://devcenter.heroku.com/articles/python-gunicorn
4-
# Based on https://adamj.eu/tech/2019/09/19/working-around-memory-leaks-in-your-django-app/
5-
# https://docs.gunicorn.org/en/latest/settings.html#max-requests
6-
# https://docs.gunicorn.org/en/latest/settings.html#max-requests-jitter
7-
max_requests = 1200
8-
max_requests_jitter = 100
1+
# https://mattsegal.dev/django-gunicorn-nginx-logging.html
2+
# https://albersdevelopment.net/2019/08/15/using-structlog-with-gunicorn/
3+
4+
import logging
5+
import logging.config
6+
import re
7+
8+
import structlog
9+
10+
11+
def combined_logformat(logger, name, event_dict):
12+
if event_dict.get("logger") == "gunicorn.access":
13+
message = event_dict["event"]
14+
15+
parts = [
16+
r"(?P<host>\S+)", # host %h
17+
r"\S+", # indent %l (unused)
18+
r"(?P<user>\S+)", # user %u
19+
r"\[(?P<time>.+)\]", # time %t
20+
r'"(?P<request>.+)"', # request "%r"
21+
r"(?P<status>[0-9]+)", # status %>s
22+
r"(?P<size>\S+)", # size %b (careful, can be '-')
23+
r'"(?P<referer>.*)"', # referer "%{Referer}i"
24+
r'"(?P<agent>.*)"', # user agent "%{User-agent}i"
25+
]
26+
pattern = re.compile(r"\s+".join(parts) + r"\s*\Z")
27+
m = pattern.match(message)
28+
res = m.groupdict()
29+
30+
if res["user"] == "-":
31+
res["user"] = None
32+
33+
res["status"] = int(res["status"])
34+
35+
if res["size"] == "-":
36+
res["size"] = 0
37+
else:
38+
res["size"] = int(res["size"])
39+
40+
if res["referer"] == "-":
41+
res["referer"] = None
42+
43+
event_dict.update(res)
44+
method, path, version = res["request"].split(" ")
45+
46+
event_dict["method"] = method
47+
event_dict["path"] = path
48+
event_dict["version"] = version
49+
50+
return event_dict
51+
52+
53+
def gunicorn_event_name_mapper(logger, name, event_dict):
54+
logger_name = event_dict.get("logger")
55+
56+
if logger_name not in ["gunicorn.error", "gunicorn.access"]:
57+
return event_dict
58+
59+
GUNICORN_BOOTING = "gunicorn.booting"
60+
GUNICORN_REQUEST = "gunicorn.request_handling"
61+
GUNICORN_SIGNAL = "gunicorn.signal_handling"
62+
63+
event = event_dict["event"].lower()
64+
65+
if logger_name == "gunicorn.error":
66+
event_dict["message"] = event
67+
68+
if event.startswith("starting"):
69+
event_dict["event"] = GUNICORN_BOOTING
70+
71+
if event.startswith("listening"):
72+
event_dict["event"] = GUNICORN_BOOTING
73+
74+
if event.startswith("using"):
75+
event_dict["event"] = GUNICORN_BOOTING
76+
77+
if event.startswith("booting"):
78+
event_dict["event"] = GUNICORN_BOOTING
79+
80+
if event.startswith("handling signal"):
81+
event_dict["event"] = GUNICORN_SIGNAL
82+
83+
if logger_name == "gunicorn.access":
84+
event_dict["event"] = GUNICORN_REQUEST
85+
86+
return event_dict
87+
88+
89+
timestamper = structlog.processors.TimeStamper(fmt="iso", utc=True)
90+
pre_chain = [
91+
# Add the log level and a timestamp to the event_dict if the log entry
92+
# is not from structlog.
93+
structlog.stdlib.add_log_level,
94+
structlog.stdlib.add_logger_name,
95+
timestamper,
96+
combined_logformat,
97+
gunicorn_event_name_mapper,
98+
]
99+
100+
# https://github.com/benoitc/gunicorn/blob/master/gunicorn/glogging.py#L47
101+
CONFIG_DEFAULTS = {
102+
"version": 1,
103+
"disable_existing_loggers": False,
104+
"root": {"level": "INFO", "handlers": ["default"]},
105+
"loggers": {
106+
"gunicorn.error": {"level": "INFO", "handlers": ["default"], "propagate": False, "qualname": "gunicorn.error"},
107+
"gunicorn.access": {
108+
"level": "INFO",
109+
"handlers": ["default"],
110+
"propagate": False,
111+
"qualname": "gunicorn.access",
112+
},
113+
"django_structlog": {
114+
"level": "INFO",
115+
"handlers": [],
116+
"propagate": False,
117+
},
118+
},
119+
"handlers": {
120+
"default": {
121+
"class": "logging.StreamHandler",
122+
"formatter": "json_formatter",
123+
},
124+
},
125+
"formatters": {
126+
"json_formatter": {
127+
"()": structlog.stdlib.ProcessorFormatter,
128+
"processor": structlog.processors.JSONRenderer(),
129+
"foreign_pre_chain": pre_chain,
130+
}
131+
},
132+
}
133+
134+
logging.config.dictConfig(CONFIG_DEFAULTS)

‎requirements/base.txt‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ django-filter==25.2
1313
django-extensions==4.1
1414
django-cors-headers==4.9.0
1515
django-storages==1.14.6
16+
django-structlog[celery]==9.1.1
1617

1718
drf-jwt==1.19.2
1819

0 commit comments

Comments
 (0)