Add structlog (#7937)

* Add structlog
Closes #3960

* fix formatting

* make log writing optional

* ignore logfiles

* fix variable naming

.gitignore

@@ -88,6 +88,10 @@ env/
 src/backend/InvenTree/InvenTree/locale_stats.json
 src/backend/InvenTree/InvenTree/licenses.txt
 
+# Logs
+src/backend/InvenTree/logs.json
+src/backend/InvenTree/logs.log
+
 # node.js
 node_modules/
 

docs/docs/start/config.md

@@ -65,7 +65,9 @@ The following basic options are available:
 | INVENTREE_DEBUG_QUERYCOUNT | debug_querycount | Enable [query count logging](https://github.com/bradmontgomery/django-querycount) in the terminal | False |
 | INVENTREE_DEBUG_SHELL | debug_shell | Enable [administrator shell](https://github.com/djk2/django-admin-shell) (only in debug mode) | False |
 | INVENTREE_LOG_LEVEL | log_level | Set level of logging to terminal | WARNING |
+| INVENTREE_JSON_LOG | json_log | log as json | False |
 | INVENTREE_DB_LOGGING | db_logging | Enable logging of database messages | False |
+| INVENTREE_WRITE_LOG | write_log | Enable writing of log messages to file at config base | False |
 | INVENTREE_TIMEZONE | timezone | Server timezone | UTC |
 | INVENTREE_ADMIN_ENABLED | admin_enabled | Enable the [django administrator interface]({% include "django.html" %}/ref/contrib/admin/) | True |
 | INVENTREE_ADMIN_URL | admin_url | URL for accessing [admin interface](../settings/admin.md) | admin |

src/backend/InvenTree/InvenTree/settings.py

@@ -20,6 +20,7 @@ from django.core.validators import URLValidator
 from django.http import Http404
 
 import pytz
+import structlog
 from dotenv import load_dotenv
 
 from InvenTree.cache import get_cache_config, is_global_cache_enabled
@@ -91,31 +92,86 @@ ENABLE_PLATFORM_FRONTEND = get_boolean_setting(
 )
 
 # Configure logging settings
-log_level = get_setting('INVENTREE_LOG_LEVEL', 'log_level', 'WARNING')
+LOG_LEVEL = get_setting('INVENTREE_LOG_LEVEL', 'log_level', 'WARNING')
+JSON_LOG = get_boolean_setting('INVENTREE_JSON_LOG', 'json_log', False)
+WRITE_LOG = get_boolean_setting('INVENTREE_WRITE_LOG', 'write_log', False)
 
-logging.basicConfig(level=log_level, format='%(asctime)s %(levelname)s %(message)s')
-
-if log_level not in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']:
-    log_level = 'WARNING'  # pragma: no cover
+logging.basicConfig(level=LOG_LEVEL, format='%(asctime)s %(levelname)s %(message)s')
 
+if LOG_LEVEL not in ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']:
+    LOG_LEVEL = 'WARNING'  # pragma: no cover
 LOGGING = {
     'version': 1,
     'disable_existing_loggers': False,
-    'handlers': {'console': {'class': 'logging.StreamHandler'}},
-    'root': {'handlers': ['console'], 'level': log_level},
     'filters': {
         'require_not_maintenance_mode_503': {
             '()': 'maintenance_mode.logging.RequireNotMaintenanceMode503'
         }
     },
+    'formatters': {
+        'json_formatter': {
+            '()': structlog.stdlib.ProcessorFormatter,
+            'processor': structlog.processors.JSONRenderer(),
+        },
+        'plain_console': {
+            '()': structlog.stdlib.ProcessorFormatter,
+            'processor': structlog.dev.ConsoleRenderer(),
+        },
+        'key_value': {
+            '()': structlog.stdlib.ProcessorFormatter,
+            'processor': structlog.processors.KeyValueRenderer(
+                key_order=['timestamp', 'level', 'event', 'logger']
+            ),
+        },
+    },
+    'handlers': {
+        'console': {'class': 'logging.StreamHandler', 'formatter': 'plain_console'}
+    },
+    'loggers': {
+        'django_structlog': {'handlers': ['console'], 'level': LOG_LEVEL},
+        'inventree': {'handlers': ['console'], 'level': LOG_LEVEL},
+    },
 }
 
+
+# Add handlers
+if WRITE_LOG and JSON_LOG:  # pragma: no cover
+    LOGGING['handlers']['log_file'] = {
+        'class': 'logging.handlers.WatchedFileHandler',
+        'filename': str(BASE_DIR.joinpath('logs.json')),
+        'formatter': 'json_formatter',
+    }
+    LOGGING['loggers']['django_structlog']['handlers'] += ['log_file']
+elif WRITE_LOG:  # pragma: no cover
+    LOGGING['handlers']['log_file'] = {
+        'class': 'logging.handlers.WatchedFileHandler',
+        'filename': str(BASE_DIR.joinpath('logs.log')),
+        'formatter': 'key_value',
+    }
+    LOGGING['loggers']['django_structlog']['handlers'] += ['log_file']
+
+structlog.configure(
+    processors=[
+        structlog.contextvars.merge_contextvars,
+        structlog.stdlib.filter_by_level,
+        structlog.processors.TimeStamper(fmt='iso'),
+        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.stdlib.ProcessorFormatter.wrap_for_formatter,
+    ],
+    logger_factory=structlog.stdlib.LoggerFactory(),
+    cache_logger_on_first_use=True,
+)
 # Optionally add database-level logging
 if get_setting('INVENTREE_DB_LOGGING', 'db_logging', False):
-    LOGGING['loggers'] = {'django.db.backends': {'level': log_level or 'DEBUG'}}
+    LOGGING['loggers'] = {'django.db.backends': {'level': LOG_LEVEL or 'DEBUG'}}
 
 # Get a logger instance for this setup file
-logger = logging.getLogger('inventree')
+logger = structlog.getLogger('inventree')
 
 # Load SECRET_KEY
 SECRET_KEY = config.get_secret_key()
@@ -265,6 +321,7 @@ INSTALLED_APPS = [
     'dbbackup',  # Backups - django-dbbackup
     'taggit',  # Tagging
     'flags',  # Flagging - django-flags
+    'django_structlog',  # Structured logging
     'allauth',  # Base app for SSO
     'allauth.account',  # Extend user with accounts
     'allauth.socialaccount',  # Use 'social' providers
@@ -300,6 +357,7 @@ MIDDLEWARE = CONFIG.get(
         'InvenTree.middleware.Check2FAMiddleware',  # Check if the user should be forced to use MFA
         'maintenance_mode.middleware.MaintenanceModeMiddleware',
         'InvenTree.middleware.InvenTreeExceptionProcessor',  # Error reporting
+        'django_structlog.middlewares.RequestMiddleware',  # Structured logging
     ],
 )
 

src/backend/InvenTree/config_template.yaml

@@ -42,8 +42,13 @@ debug_shell: False
 # Options: DEBUG / INFO / WARNING / ERROR / CRITICAL
 log_level: WARNING
 
+# Configure if logs should be output in JSON format
+# Use environment variable INVENTREE_JSON_LOG
+json_log: False
 # Enable database-level logging, or use the environment variable INVENTREE_DB_LOGGING
 db_logging: False
+# Enable writing a log file, or use the environment variable INVENTREE_WRITE_LOG
+write_log: False
 
 # Select default system language , or use the environment variable INVENTREE_LANGUAGE
 language: en-us

src/backend/requirements.in

@@ -26,6 +26,7 @@ django-q-sentry                         # sentry.io integration for django-q
 django-sesame                           # Magic link authentication
 django-sql-utils                        # Advanced query annotation / aggregation
 django-sslserver                        # Secure HTTP development server
+django-structlog                        # Structured logging
 django-stdimage                         # Advanced ImageField management
 django-taggit                           # Tagging support
 django-user-sessions                    # user sessions in DB

src/backend/requirements.txt

@@ -10,6 +10,7 @@ asgiref==3.8.1 \
     # via
     #   django
     #   django-cors-headers
+    #   django-structlog
 async-timeout==4.0.3 \
     --hash=sha256:4640d96be84d82d02ed59ea2b7105a0f7b33abe8703703cd0ab0bf87c427522f \
     --hash=sha256:7405140ff1230c310e51dc27b3145b9092d659ce68ff733fb0cefe3ee42be028
@@ -389,6 +390,7 @@ django==4.2.16 \
     #   django-sql-utils
     #   django-sslserver
     #   django-stdimage
+    #   django-structlog
     #   django-taggit
     #   django-user-sessions
     #   django-weasyprint
@@ -445,6 +447,10 @@ django-import-export==3.3.9 \
     --hash=sha256:16797965e93a8001fe812c61e3b71fb858c57c1bd16da195fe276d6de685348e \
     --hash=sha256:dd6cabc08ed6d1bd37a392e7fb542bd7d196b615c800168f5c69f0f55f49b103
     # via -r src/backend/requirements.in
+django-ipware==7.0.1 \
+    --hash=sha256:d9ec43d2bf7cdf216fed8d494a084deb5761a54860a53b2e74346a4f384cff47 \
+    --hash=sha256:db16bbee920f661ae7f678e4270460c85850f03c6761a4eaeb489bdc91f64709
+    # via django-structlog
 django-js-asset==2.2.0 \
     --hash=sha256:0c57a82cae2317e83951d956110ce847f58ff0cdc24e314dbc18b35033917e94 \
     --hash=sha256:7ef3e858e13d06f10799b56eea62b1e76706f42cf4e709be4e13356bc0ae30d8
@@ -503,6 +509,10 @@ django-stdimage==6.0.2 \
     --hash=sha256:880ab14828be56b53f711c3afae83c219ddd5d9af00850626736feb48382bf7f \
     --hash=sha256:9a73f7da48c48074580e2b032d5bdb7164935dbe4b9dc4fb88a7e112f3d521c8
     # via -r src/backend/requirements.in
+django-structlog==8.1.0 \
+    --hash=sha256:0229b9a2efbd24a4e3500169788e53915c2429521e34e41dd58ccc56039bef3f \
+    --hash=sha256:1072564bd6f36e8d3ba9893e7b31c1c46e94301189fedaecc0fb8a46525a3214
+    # via -r src/backend/requirements.in
 django-taggit==6.1.0 \
     --hash=sha256:ab776264bbc76cb3d7e49e1bf9054962457831bd21c3a42db9138b41956e4cf0 \
     --hash=sha256:c4d1199e6df34125dd36db5eb0efe545b254dec3980ce5dd80e6bab3e78757c3
@@ -1229,6 +1239,10 @@ python-fsutil==0.14.1 \
     --hash=sha256:0d45e623f0f4403f674bdd8ae7aa7d24a4b3132ea45c65416bd2865e6b20b035 \
     --hash=sha256:8fb204fa8059f37bdeee8a1dc0fff010170202ea47c4225ee71bb3c26f3997be
     # via django-maintenance-mode
+python-ipware==3.0.0 \
+    --hash=sha256:9117b1c4dddcb5d5ca49e6a9617de2fc66aec2ef35394563ac4eecabdf58c062 \
+    --hash=sha256:fc936e6e7ec9fcc107f9315df40658f468ac72f739482a707181742882e36b60
+    # via django-ipware
 python3-openid==3.2.0 \
     --hash=sha256:33fbf6928f401e0b790151ed2b5290b02545e8775f982485205a066f874aaeaf \
     --hash=sha256:6626f771e0417486701e0b4daff762e7212e820ca5b29fcc0d05f6f8736dfa6b
@@ -1646,6 +1660,10 @@ sqlparse==0.5.1 \
     # via
     #   django
     #   django-sql-utils
+structlog==24.4.0 \
+    --hash=sha256:597f61e80a91cc0749a9fd2a098ed76715a1c8a01f73e336b746504d1aad7610 \
+    --hash=sha256:b27bfecede327a6d2da5fbc96bd859f114ecc398a6389d664f62085ee7ae6fc4
+    # via django-structlog
 tablib[html, ods, xls, xlsx, yaml]==3.5.0 \
     --hash=sha256:9821caa9eca6062ff7299fa645e737aecff982e6b2b42046928a6413c8dabfd9 \
     --hash=sha256:f6661dfc45e1d4f51fa8a6239f9c8349380859a5bfaa73280645f046d6c96e33