wsgi(minor): add proper request logging

passbook/core/views/authentication.py

@@ -1,5 +1,5 @@
 """passbook core authentication views"""
-from typing import Dict
+from typing import Dict, Optional
 
 from django.contrib import messages
 from django.contrib.auth import login, logout
@@ -53,7 +53,7 @@ class LoginView(UserPassesTestMixin, FormView):
             self.template_name = 'login/with_sources.html'
         return super().get_context_data(**kwargs)
 
-    def get_user(self, uid_value) -> User:
+    def get_user(self, uid_value) -> Optional[User]:
         """Find user instance. Returns None if no user was found."""
         for search_field in CONFIG.y('passbook.uid_fields'):
             # Workaround for E-Mail -> email
@@ -61,7 +61,7 @@ class LoginView(UserPassesTestMixin, FormView):
                 search_field = 'email'
             users = User.objects.filter(**{search_field: uid_value})
             if users.exists():
-                LOGGER.debug("Found user %s with uid_field %s", users.first(), search_field)
+                LOGGER.debug("Found user", user=users.first(), uid_field=search_field)
                 return users.first()
         return None
 

passbook/ldap/ldap_connector.py

@@ -222,7 +222,7 @@ class LDAPConnector:
         attrs = {
             'distinguishedName': str(user_dn),
             'cn': str(username),
-            'description': str('t=' + time()),
+            'description': 't=' + str(time()),
             'sAMAccountName': str(username_trunk),
             'givenName': str(user.name),
             'displayName': str(user.username),

passbook/root/settings.py

@@ -47,7 +47,7 @@ AUTH_USER_MODEL = 'passbook_core.User'
 
 CSRF_COOKIE_NAME = 'passbook_csrf'
 SESSION_COOKIE_NAME = 'passbook_session'
-SESSION_ENGINE = "django.contrib.sessions.backends.cache"
+SESSION_ENGINE = "django.contrib.sessions.backends.db"
 SESSION_CACHE_ALIAS = "default"
 LANGUAGE_COOKIE_NAME = 'passbook_language'
 
@@ -319,10 +319,3 @@ for _app in INSTALLED_APPS:
 if DEBUG:
     INSTALLED_APPS.append('debug_toolbar')
     MIDDLEWARE.append('debug_toolbar.middleware.DebugToolbarMiddleware')
-
-DBBACKUP_STORAGE = 'storages.backends.s3boto.S3BotoStorage'
-DBBACKUP_STORAGE_OPTIONS = {
-    'access_key': 'my_id',
-    'secret_key': 'my_secret',
-    'bucket_name': 'my_bucket_name'
-}

passbook/root/wsgi.py

@@ -6,12 +6,71 @@ It exposes the WSGI callable as a module-level variable named ``application``.
 For more information on this file, see
 https://docs.djangoproject.com/en/2.1/howto/deployment/wsgi/
 """
-
 import os
+from time import time
 
 from django.core.wsgi import get_wsgi_application
-from sentry_sdk.integrations.wsgi import SentryWsgiMiddleware
+from structlog import get_logger
 
-os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'passbook.root.settings')
+os.environ.setdefault("DJANGO_SETTINGS_MODULE", "passbook.root.settings")
 
-application = SentryWsgiMiddleware(get_wsgi_application())
+LOGGER = get_logger()
+
+
+class WSGILogger:
+    """ This is the generalized WSGI middleware for any style request logging. """
+
+    def __init__(self, application):
+        self.application = application
+
+    def __healthcheck(self, start_response):
+        start_response('204 OK', [])
+        return [b'']
+
+    def __call__(self, environ, start_response):
+        start = time()
+        status_codes = []
+        content_lengths = []
+
+        if environ.get('HTTP_HOST').startswith('kubernetes-healthcheck-host'):
+            # Don't log kubernetes health/readiness requests
+            return self.__healthcheck(start_response)
+
+        def custom_start_response(status, response_headers, exc_info=None):
+            status_codes.append(int(status.partition(' ')[0]))
+            for name, value in response_headers:
+                if name.lower() == 'content-length':
+                    content_lengths.append(int(value))
+                    break
+            return start_response(status, response_headers, exc_info)
+        retval = self.application(environ, custom_start_response)
+        runtime = int((time() - start) * 10**6)
+        content_length = content_lengths[0] if content_lengths else 0
+        self.log(status_codes[0], environ, content_length,
+                 ip_header=None, runtime=runtime)
+        return retval
+
+    def log(self, status_code, environ, content_length, **kwargs):
+        """
+        Apache log format 'NCSA extended/combined log':
+        "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\""
+        see http://httpd.apache.org/docs/current/mod/mod_log_config.html#formats
+        """
+        ip_header = kwargs.get('ip_header', None)
+        if ip_header:
+            host = environ.get(ip_header, '')
+        else:
+            host = environ.get('REMOTE_ADDR', '')
+        query_string = ''
+        if environ.get('QUERY_STRING') != '':
+            query_string = f"?{environ.get('QUERY_STRING')}"
+        LOGGER.info(f"{environ.get('PATH_INFO', '')}{query_string}",
+                    host=host,
+                    method=environ.get('REQUEST_METHOD', ''),
+                    protocol=environ.get('SERVER_PROTOCOL', ''),
+                    status=status_code,
+                    size=content_length / 1000 if content_length > 0 else '-',
+                    runtime=kwargs.get('runtime'))
+
+
+application = WSGILogger(get_wsgi_application())