Feat/logging

.env.example

@@ -21,4 +21,12 @@ OIDC_OP_JWKS_ENDPOINT=
 OIDC_RP_CLIENT_ID=
 OIDC_RP_CLIENT_SECRET=
 OIDC_RP_SIGN_ALGO= # example: RS256
-OIDC_RP_SCOPES= # example: openid email profile
+OIDC_RP_SCOPES= # example: openid email profile
+
+# Logging / debugging
+DJANGO_LOG_LEVEL= # example: DEBUG, INFO, WARNING, ERROR
+OIDC_LOG_LEVEL= # example: DEBUG, INFO
+GUNICORN_LOG_LEVEL= # example: debug, info, warning, error
+GUNICORN_WORKERS= # example: 2
+GUNICORN_THREADS= # example: 2
+GUNICORN_TIMEOUT= # example: 120

Dockerfile

@@ -18,4 +18,4 @@ RUN python manage.py collectstatic --noinput
 
 EXPOSE 8000
 
-CMD ["sh", "-c", "python manage.py migrate && python -m bde.generate_robots && gunicorn bde.wsgi:application --bind 0.0.0.0:8000"]
+CMD ["sh", "-c", "python manage.py migrate && python -m bde.generate_robots && gunicorn -c bde/gunicorn.conf.py bde.wsgi:application"]

auth/auth_backends.py

@@ -1,29 +1,66 @@
+import logging
+
 from mozilla_django_oidc.auth import (  # type: ignore[import-untyped]
     OIDCAuthenticationBackend,
 )
 
 
+logger = logging.getLogger(__name__)
+
+
 class CustomOIDCBackend(OIDCAuthenticationBackend):
+
+    @staticmethod
+    def _claims_context(claims):
+        return {
+            "sub": claims.get("sub"),
+            "preferred_username": claims.get("preferred_username"),
+            "email": claims.get("email"),
+            "name": claims.get("name"),
+        }
+
     def create_user(self, claims):
-        user = super().create_user(claims)
+        logger.debug("OIDC create_user start: %s", self._claims_context(claims))
+        try:
+            user = super().create_user(claims)
 
-        name = claims.get("name", user.username)
+            name = claims.get("name", user.username)
 
-        user.username = claims.get("preferred_username", user.username)
-        user.first_name = name.split(" ")[0] if " " in name else name
-        user.last_name = " ".join(name.split(" ")[1:]) if " " in name else ""
-        user.email = claims.get("email", "")
-        user.save()
+            user.username = claims.get("preferred_username", user.username)
+            user.first_name = name.split(" ")[0] if " " in name else name
+            user.last_name = " ".join(name.split(" ")[1:]) if " " in name else ""
+            user.email = claims.get("email", "")
+            user.save()
 
-        return user
+            logger.info("OIDC create_user success for username=%s", user.username)
+            return user
+        except Exception:
+            logger.exception(
+                "OIDC create_user failed: %s", self._claims_context(claims)
+            )
+            raise
 
     def update_user(self, user, claims):
-        name = claims.get("name", user.username)
+        logger.debug(
+            "OIDC update_user start for username=%s claims=%s",
+            user.username,
+            self._claims_context(claims),
+        )
+        try:
+            name = claims.get("name", user.username)
 
-        user.username = claims.get("preferred_username", user.username)
-        user.first_name = name.split(" ")[0] if " " in name else name
-        user.last_name = " ".join(name.split(" ")[1:]) if " " in name else ""
-        user.email = claims.get("email", "")
-        user.save()
+            user.username = claims.get("preferred_username", user.username)
+            user.first_name = name.split(" ")[0] if " " in name else name
+            user.last_name = " ".join(name.split(" ")[1:]) if " " in name else ""
+            user.email = claims.get("email", "")
+            user.save()
 
-        return user
+            logger.info("OIDC update_user success for username=%s", user.username)
+            return user
+        except Exception:
+            logger.exception(
+                "OIDC update_user failed for username=%s claims=%s",
+                user.username,
+                self._claims_context(claims),
+            )
+            raise

bde/env.py

@@ -115,3 +115,15 @@ def OIDC_RP_SIGN_ALGO(self) -> str:
     @property
     def OIDC_RP_SCOPES(self) -> str:
         return self.get("OIDC_RP_SCOPES", "")
+
+    @property
+    def DJANGO_LOG_LEVEL(self) -> str:
+        return self.get("DJANGO_LOG_LEVEL", "INFO")
+
+    @property
+    def OIDC_LOG_LEVEL(self) -> str:
+        return self.get("OIDC_LOG_LEVEL", "DEBUG")
+
+    @property
+    def GUNICORN_LOG_LEVEL(self) -> str:
+        return self.get("GUNICORN_LOG_LEVEL", "debug")

bde/gunicorn.conf.py

@@ -0,0 +1,18 @@
+import os
+
+
+bind = "0.0.0.0:8000"
+workers = int(os.getenv("GUNICORN_WORKERS", "2"))
+threads = int(os.getenv("GUNICORN_THREADS", "2"))
+timeout = int(os.getenv("GUNICORN_TIMEOUT", "120"))
+
+accesslog = "-"
+errorlog = "-"
+loglevel = os.getenv("GUNICORN_LOG_LEVEL", "debug")
+capture_output = True
+enable_stdio_inheritance = True
+
+access_log_format = (
+    '%(h)s %(l)s %(u)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s" '
+    "rt=%(M)sms req_id=%({x-request-id}i)s fwd=%({x-forwarded-for}i)s"
+)

bde/settings.py

@@ -131,6 +131,46 @@
 
 DEFAULT_AUTO_FIELD = "django.db.models.BigAutoField"
 
+LOGGING = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "formatters": {
+        "verbose": {"format": "%(asctime)s %(levelname)s %(name)s %(message)s"},
+    },
+    "handlers": {
+        "console": {
+            "class": "logging.StreamHandler",
+            "formatter": "verbose",
+        },
+    },
+    "root": {
+        "handlers": ["console"],
+        "level": env.DJANGO_LOG_LEVEL,
+    },
+    "loggers": {
+        "django": {
+            "handlers": ["console"],
+            "level": env.DJANGO_LOG_LEVEL,
+            "propagate": False,
+        },
+        "django.request": {
+            "handlers": ["console"],
+            "level": "ERROR",
+            "propagate": False,
+        },
+        "mozilla_django_oidc": {
+            "handlers": ["console"],
+            "level": env.OIDC_LOG_LEVEL,
+            "propagate": False,
+        },
+        "auth.auth_backends": {
+            "handlers": ["console"],
+            "level": env.OIDC_LOG_LEVEL,
+            "propagate": False,
+        },
+    },
+}
+
 # Django Browser Reload (for development only)
 if DEBUG:
     INSTALLED_APPS += [

docker-compose.yaml

@@ -1,7 +1,7 @@
 services:
   web:
     build: .
-    command: sh -c "python manage.py migrate && python -m bde.generate_robots && gunicorn bde.wsgi:application --bind 0.0.0.0:8000"
+    command: sh -c "python manage.py migrate && python -m bde.generate_robots && gunicorn -c bde/gunicorn.conf.py bde.wsgi:application"
     volumes:
       - .:/app
       - ./uploads:/app/uploads