✨ [#586] Replace logging with structlog

.gitignore

@@ -30,6 +30,7 @@ local.py
 /static/
 /mail/
 /log/*.log*
+/log/*.jsonl*
 /log/nginx/*.log*
 .env
 

CHANGELOG.rst

@@ -33,8 +33,8 @@ Change history
 * Upgrade npm packages to fix vulnerabilities
 * Fixed admin logout button
 * [:objects-api:`550`] Implement cache for objecttypes
-* [:objects-api:`550`] add OBJECTTYPE_VERSION_CACHE_TIMEOUT environment variable `documentation <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#cache>`_
-* [:objects-api:`572`] Add db connection pooling environment variables `documentation <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#database>`_
+* [:objects-api:`550`] add OBJECTTYPE_VERSION_CACHE_TIMEOUT environment variable (see `documentation for environment variables for caching <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#cache>`_)
+* [:objects-api:`572`] Add db connection pooling environment variables (see `documentation for environment variables for database <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#database>`_)
 
   * DB_POOL_ENABLED
   * DB_POOL_MIN_SIZE
@@ -46,7 +46,7 @@ Change history
   * DB_POOL_RECONNECT_TIMEOUT
   * DB_POOL_NUM_WORKERS
 
-* [:objects-api:`566`] Add DB_CONN_MAX_AGE environment variable `documentation <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#database>`_
+* [:objects-api:`566`] Add DB_CONN_MAX_AGE environment variable (see `documentation for environment variables for database <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config.html#database>`_)
 
 3.0.3 (2025-04-03)
 ------------------
@@ -132,8 +132,7 @@ Change history
 .. warning::
 
     Previous configuration files used for ``setup_configuration`` do not work.
-    See the `documentation <https://objects-and-objecttypes-api.readthedocs.io/en/latest/installation/config_cli.html>`_
-    for the available settings that can now be configured through ``setup_configuration``.
+    See :ref:`installation_config_cli` for the available settings that can now be configured through ``setup_configuration``.
 
 * added support for configuring permissions through ``django-setup-configuration``
   version ``0.4.0`` [#497]

Dockerfile

@@ -6,6 +6,9 @@ RUN apt-get update && apt-get upgrade -y && apt-get install -y --no-install-reco
         build-essential \
         git \
         libpq-dev \
+        # required for (log) routing support in uwsgi
+        libpcre3 \
+        libpcre3-dev \
     && rm -rf /var/lib/apt/lists/*
 
 
@@ -44,6 +47,7 @@ RUN apt-get update && apt-get upgrade -y && apt-get install -y --no-install-reco
         gdal-bin \
         libgdal-dev \
         gettext \
+        libpcre3 \
     && rm -rf /var/lib/apt/lists/*
 
 RUN pip install pip "setuptools>=70.0.0"
@@ -60,6 +64,7 @@ COPY ./bin/celery_worker.sh /celery_worker.sh
 COPY ./bin/celery_flower.sh /celery_flower.sh
 COPY ./bin/check_celery_worker_liveness.py ./bin/
 COPY ./bin/setup_configuration.sh /setup_configuration.sh
+COPY ./bin/uwsgi.ini /
 RUN mkdir /app/log /app/config /app/tmp
 
 # copy frontend build statics

bin/docker_start.sh

@@ -50,6 +50,7 @@ fi
 # Start server
 >&2 echo "Starting server"
 uwsgi \
+    --ini "${SCRIPTPATH}/uwsgi.ini" \
     --http :$uwsgi_port \
     --http-keepalive \
     --manage-script-name \

bin/uwsgi.ini

@@ -0,0 +1,32 @@
+; Docs:
+; * https://uwsgi-docs.readthedocs.io/en/latest/Logging.html
+; * https://uwsgi-docs.readthedocs.io/en/latest/LogEncoders.html
+; Reference article: https://blog.rama.io/json-logging-with-uwsgi
+[uwsgi]
+; logger definition for the django app logs, which are already structured
+logger = djangologger stdio
+; logger definition for the uwsgi server logs
+logger = uwsgilogger stdio
+
+; any message starting with { is assumed to already be structured ->
+; send it to the djangologger
+log-route = djangologger ^{.*$
+; send any message not starting with { to the uwsgilogger
+log-route = uwsgilogger ^((?!\{).)*$
+
+; leave already JSON formatted django logs as is
+log-encoder = format:djangologger ${msg}
+; Encode uWSGI server logs as JSON
+log-encoder = json:uwsgilogger {"source": "uwsgi", "type": "server", "timestamp": "${strftime:%%Y-%%m-%%dT%%H:%%M:%%S%%z}", "event": "${msg}", "level": "info"}
+
+; these are uwsgi's own request logs (not to be confused with the request logs emitted
+; by the application!)
+logger-req = stdio
+; pragamatic approach - these variables are *not* JSON escaped and can lead to broken
+; output lines. there's no security risk involved there, at worst a log scraper fails to
+; parse the message as json
+; TODO: perhaps we can extract trace IDs here for spans -> using uwsgi vars!
+log-format = {"source": "uwsgi", "event": "request", "method": "%(method)", "path": "%(uri)", "duration_in_ms": %(msecs), "status": %(status), "bytes": %(rsize), "referer": "%(referer)", "host": "%(host)", "timestamp": "%(iso8601timestamp)", "remote_ip": "%(addr)", "level": "info"}
+
+; finally, ensure that all log lines are separated with a newline
+log-encoder = nl

docs/installation/config.rst

@@ -43,22 +43,38 @@ Database
 * ``DB_POOL_NUM_WORKERS``: Number of background worker threads used to maintain the pool state. Background workers are used for example to create new connections and to clean up connections when they are returned to the pool. Defaults to: ``3``.
 
 
-Cross-Origin-Resource-Sharing
------------------------------
+Logging
+-------
 
-* ``CORS_ALLOW_ALL_ORIGINS``: allow cross-domain access from any client. Defaults to: ``False``.
-* ``CORS_ALLOWED_ORIGINS``: explicitly list the allowed origins for cross-domain requests. Example: http://localhost:3000,https://some-app.gemeente.nl. Defaults to: ``[]``.
-* ``CORS_ALLOWED_ORIGIN_REGEXES``: same as ``CORS_ALLOWED_ORIGINS``, but supports regular expressions. Defaults to: ``[]``.
-* ``CORS_EXTRA_ALLOW_HEADERS``: headers that are allowed to be sent as part of the cross-domain request. By default, Authorization, Accept-Crs and Content-Crs are already included. The value of this variable is added to these already included headers. Defaults to: ``[]``.
+* ``LOG_STDOUT``: whether to log to stdout or not. Defaults to: ``True``.
+* ``LOG_LEVEL``: control the verbosity of logging output. Available values are ``CRITICAL``, ``ERROR``, ``WARNING``, ``INFO`` and ``DEBUG``. Defaults to: ``WARNING``.
+* ``LOG_QUERIES``: enable (query) logging at the database backend level. Note that you must also set ``DEBUG=1``, which should be done very sparingly!. Defaults to: ``False``.
+* ``LOG_REQUESTS``: enable logging of the outgoing requests. Defaults to: ``False``.
+* ``LOG_OUTGOING_REQUESTS_EMIT_BODY``: Whether or not outgoing request bodies should be logged. Defaults to: ``True``.
+* ``LOG_OUTGOING_REQUESTS_DB_SAVE``: Whether or not outgoing request logs should be saved to the database. Defaults to: ``False``.
+* ``LOG_OUTGOING_REQUESTS_DB_SAVE_BODY``: Whether or not outgoing request bodies should be saved to the database. Defaults to: ``True``.
+* ``LOG_OUTGOING_REQUESTS_MAX_AGE``: The amount of time after which request logs should be deleted from the database. Defaults to: ``7``.
+* ``ENABLE_STRUCTLOG_REQUESTS``: enable structured logging of requests. Defaults to: ``True``.
+* ``LOG_FORMAT_CONSOLE``: The format for the console logging handler, possible options: ``json``, ``plain_console``. Defaults to: ``json``.
 
 
 Celery
 ------
 
+* ``CELERY_LOGLEVEL``: control the verbosity of logging output for celery, independent of ``LOG_LEVEL``. Available values are ``CRITICAL``, ``ERROR``, ``WARNING``, ``INFO`` and ``DEBUG``. Defaults to: ``INFO``.
 * ``CELERY_RESULT_BACKEND``: the URL of the backend/broker that will be used by Celery to send the notifications. Defaults to: ``redis://localhost:6379/1``.
 * ``CELERY_TASK_HARD_TIME_LIMIT``: Task hard time limit in seconds. The worker processing the task will be killed and replaced with a new one when this is exceeded. Defaults to: ``900``.
 
 
+Cross-Origin-Resource-Sharing
+-----------------------------
+
+* ``CORS_ALLOW_ALL_ORIGINS``: allow cross-domain access from any client. Defaults to: ``False``.
+* ``CORS_ALLOWED_ORIGINS``: explicitly list the allowed origins for cross-domain requests. Example: http://localhost:3000,https://some-app.gemeente.nl. Defaults to: ``[]``.
+* ``CORS_ALLOWED_ORIGIN_REGEXES``: same as ``CORS_ALLOWED_ORIGINS``, but supports regular expressions. Defaults to: ``[]``.
+* ``CORS_EXTRA_ALLOW_HEADERS``: headers that are allowed to be sent as part of the cross-domain request. By default, Authorization, Accept-Crs and Content-Crs are already included. The value of this variable is added to these already included headers. Defaults to: ``[]``.
+
+
 Elastic APM
 -----------
 
@@ -98,11 +114,6 @@ Optional
 * ``EMAIL_HOST_PASSWORD``: password to connect to the mail server. Defaults to: ``(empty string)``.
 * ``EMAIL_USE_TLS``: whether to use TLS or not to connect to the mail server. Should be True if you're changing the ``EMAIL_PORT`` to 487. Defaults to: ``False``.
 * ``DEFAULT_FROM_EMAIL``: The default email address from which emails are sent. Defaults to: ``objects@example.com``.
-* ``LOG_STDOUT``: whether to log to stdout or not. Defaults to: ``True``.
-* ``LOG_LEVEL``: control the verbosity of logging output. Available values are ``CRITICAL``, ``ERROR``, ``WARNING``, ``INFO`` and ``DEBUG``. Defaults to: ``WARNING``.
-* ``LOG_QUERIES``: enable (query) logging at the database backend level. Note that you must also set ``DEBUG=1``, which should be done very sparingly!. Defaults to: ``False``.
-* ``LOG_REQUESTS``: enable logging of the outgoing requests. Defaults to: ``False``.
-* ``CELERY_LOGLEVEL``: control the verbosity of logging output for celery, independent of ``LOG_LEVEL``. Available values are ``CRITICAL``, ``ERROR``, ``WARNING``, ``INFO`` and ``DEBUG``. Defaults to: ``INFO``.
 * ``SESSION_COOKIE_AGE``: For how long, in seconds, the session cookie will be valid. Defaults to: ``1209600``.
 * ``SESSION_COOKIE_SAMESITE``: The value of the SameSite flag on the session cookie. This flag prevents the cookie from being sent in cross-site requests thus preventing CSRF attacks and making some methods of stealing session cookie impossible.Currently interferes with OIDC. Keep the value set at Lax if used. Defaults to: ``Lax``.
 * ``CSRF_COOKIE_SAMESITE``: The value of the SameSite flag on the CSRF cookie. This flag prevents the cookie from being sent in cross-site requests. Defaults to: ``Strict``.
@@ -115,10 +126,6 @@ Optional
 * ``SITE_DOMAIN``: Defines the primary domain where the application is hosted. Defaults to: ``(empty string)``.
 * ``SENTRY_DSN``: URL of the sentry project to send error reports to. Default empty, i.e. -> no monitoring set up. Highly recommended to configure this.
 * ``DISABLE_2FA``: Whether or not two factor authentication should be disabled. Defaults to: ``False``.
-* ``LOG_OUTGOING_REQUESTS_EMIT_BODY``: Whether or not outgoing request bodies should be logged. Defaults to: ``True``.
-* ``LOG_OUTGOING_REQUESTS_DB_SAVE``: Whether or not outgoing request logs should be saved to the database. Defaults to: ``False``.
-* ``LOG_OUTGOING_REQUESTS_DB_SAVE_BODY``: Whether or not outgoing request bodies should be saved to the database. Defaults to: ``True``.
-* ``LOG_OUTGOING_REQUESTS_MAX_AGE``: The amount of time after which request logs should be deleted from the database. Defaults to: ``7``.
 
 
 

requirements/base.in

@@ -1,11 +1,13 @@
 open-api-framework
 
-
 # Core python libraries
 glom # data represenation based on spec
 jsonschema
 furl
 
+# Django libraries
+django-structlog[celery]
+
 # Common ground libraries
 django-setup-configuration>=0.5.0
 notifications-api-common[setup-configuration]

requirements/base.txt

@@ -14,6 +14,7 @@ asgiref==3.8.1
     #   django
     #   django-axes
     #   django-cors-headers
+    #   django-structlog
 asn1crypto==1.5.1
     # via webauthn
 attrs==20.3.0
@@ -32,6 +33,7 @@ cbor2==5.6.2
     # via webauthn
 celery==5.4.0
     # via
+    #   django-structlog
     #   flower
     #   notifications-api-common
     #   open-api-framework
@@ -94,6 +96,7 @@ django==5.2.1
     #   django-setup-configuration
     #   django-simple-certmanager
     #   django-solo
+    #   django-structlog
     #   django-two-factor-auth
     #   djangorestframework
     #   djangorestframework-inclusions
@@ -122,6 +125,8 @@ django-filter==24.2
     #   open-api-framework
 django-formtools==2.3
     # via django-two-factor-auth
+django-ipware==7.0.1
+    # via django-structlog
 django-jsonform==2.22.0
     # via
     #   mozilla-django-oidc-db
@@ -164,6 +169,8 @@ django-solo==2.2.0
     #   mozilla-django-oidc-db
     #   notifications-api-common
     #   zgw-consumers
+django-structlog==9.1.1
+    # via -r requirements/base.in
 django-two-factor-auth==1.17.0
     # via maykin-2fa
 djangorestframework==3.15.2
@@ -246,7 +253,7 @@ notifications-api-common==0.7.2
     # via
     #   -r requirements/base.in
     #   commonground-api-common
-open-api-framework==0.9.6
+open-api-framework==0.10.0
     # via -r requirements/base.in
 orderedmultidict==1.0.1
     # via furl
@@ -295,6 +302,8 @@ python-dotenv==1.0.0
     # via
     #   open-api-framework
     #   pydantic-settings
+python-ipware==3.0.0
+    # via django-ipware
 pytz==2024.1
     # via flower
 pyyaml==6.0.1
@@ -335,6 +344,8 @@ six==1.16.0
     #   qrcode
 sqlparse==0.5.0
     # via django
+structlog==25.3.0
+    # via django-structlog
 tornado==6.5
     # via flower
 typing-extensions==4.9.0

requirements/ci.txt

@@ -26,6 +26,7 @@ asgiref==3.8.1
     #   django
     #   django-axes
     #   django-cors-headers
+    #   django-structlog
 asn1crypto==1.5.1
     # via
     #   -c requirements/base.txt
@@ -173,6 +174,7 @@ django==5.2.1
     #   django-setup-configuration
     #   django-simple-certmanager
     #   django-solo
+    #   django-structlog
     #   django-two-factor-auth
     #   djangorestframework
     #   djangorestframework-inclusions
@@ -221,6 +223,11 @@ django-formtools==2.3
     #   -c requirements/base.txt
     #   -r requirements/base.txt
     #   django-two-factor-auth
+django-ipware==7.0.1
+    # via
+    #   -c requirements/base.txt
+    #   -r requirements/base.txt
+    #   django-structlog
 django-jsonform==2.22.0
     # via
     #   -c requirements/base.txt
@@ -301,6 +308,10 @@ django-solo==2.2.0
     #   mozilla-django-oidc-db
     #   notifications-api-common
     #   zgw-consumers
+django-structlog==9.1.1
+    # via
+    #   -c requirements/base.txt
+    #   -r requirements/base.txt
 django-two-factor-auth==1.17.0
     # via
     #   -c requirements/base.txt
@@ -484,7 +495,7 @@ notifications-api-common==0.7.2
     #   -c requirements/base.txt
     #   -r requirements/base.txt
     #   commonground-api-common
-open-api-framework==0.9.6
+open-api-framework==0.10.0
     # via
     #   -c requirements/base.txt
     #   -r requirements/base.txt
@@ -612,6 +623,11 @@ python-dotenv==1.0.0
     #   -r requirements/base.txt
     #   open-api-framework
     #   pydantic-settings
+python-ipware==3.0.0
+    # via
+    #   -c requirements/base.txt
+    #   -r requirements/base.txt
+    #   django-ipware
 pytz==2024.1
     # via
     #   -c requirements/base.txt
@@ -721,6 +737,11 @@ sqlparse==0.5.0
     #   -c requirements/base.txt
     #   -r requirements/base.txt
     #   django
+structlog==25.3.0
+    # via
+    #   -c requirements/base.txt
+    #   -r requirements/base.txt
+    #   django-structlog
 tblib==1.7.0
     # via -r requirements/test-tools.in
 tornado==6.5