Refactor and tests (#14) (#15)

* Added tests, start refactor work on signals

* Update get_request_info function to work with dict objects, which
  would allow changing and inserting various fields easier
* Added a message formatter that will take our siem_data (created by
  updated function above) and format it as a valid json string, while
  stripping the open and closing brackets.
* Updated the signals handlers so that they use our new methods (defined
  above)
* Added tests for all the above

* variable name update

* Tests and refactor for middlewares

* Rename middlewares.py -> middleware.py

* Since name changed, needs updated here also

* Prevent error when user refresh logout page

* Add optional django-ipware integration

Co-authored-by: Andre Engelbrecht <andre@tehnode.co.uk>

auditing/__init__.py

@@ -6,30 +6,38 @@
 from django.dispatch import receiver
 from django.conf import settings
 
-from . utils import get_request_info
+from .utils import get_request_info, format_log_message
 
 
 logger = logging.getLogger(__name__)
 
-USER_FIELD = getattr(settings, 'AUDIT_USERNAME_FIELD', 'username')
-
 
 @receiver(user_logged_in)
-def login_logger(sender, request, **kwargs):
-    _msg = '"Django Login successful", "username": "{}", {}'
-    logger.info(_msg.format(request.POST[USER_FIELD],
-                            get_request_info(request)))
+def login_logger(sender, **kwargs):
+    msg_data = get_request_info(kwargs['request'])
+    msg_data['username'] = kwargs['user'].get_username()
+    logger.info('"Django Login successful", {}'.format(
+        format_log_message(msg_data)))
 
 
 @receiver(user_login_failed)
-def login_failed_logger(sender, request, **kwargs):
-    _msg = '"Django Login failed", "username": "{}", {}'
-    logger.warn(_msg.format(request.POST[USER_FIELD],
-                            get_request_info(request)))
+def login_failed_logger(sender, **kwargs):
+    USER_FIELD = getattr(settings, 'AUDIT_USERNAME_FIELD', 'username')
+    msg_data = get_request_info(kwargs['request'])
+    msg_data['username'] = kwargs['credentials'][USER_FIELD]
+    logger.warn('"Django Login failed", {}'.format(
+        format_log_message(msg_data)))
 
 
 @receiver(user_logged_out)
-def logout_logger(sender, request, **kwargs):
-    _msg = '"Django Logout successful", "username": "{}", {}'
-    logger.info(_msg.format(request.user,
-                            get_request_info(request)))
+def logout_logger(sender, **kwargs):
+    msg_data = get_request_info(kwargs['request'])
+    user = kwargs.get('user', None)
+
+    if user is not None:
+        msg_data['username'] = user.get_username()
+        logger.info('"Django Logout successful", {}'.format(
+            format_log_message(msg_data)))
+    else:
+        logger.debug('"Django Logout failed", {}'.format(
+            format_log_message(msg_data)))

auditing/middleware.py

@@ -0,0 +1,65 @@
+import logging
+import json
+
+from django.conf import settings
+from . utils import get_request_info, format_log_message
+
+
+logger = logging.getLogger(__name__)
+
+
+# AUDITING_REQUEST_RESPONSE_KEYS_REGEX = getattr(settings,
+#                                                'AUDITING_REQUEST_RESPONSE_KEYS_REGEX',
+#                                                r'(HTTP_COOKIE|HTTP_USER_|SERVER_NAME|CSRF_|QUERY_|REMOTE_)')
+
+# Assume all codes, and only remove or ignore the ones that are not to be
+# analyzed
+AUDIT_RESPONSE_STATUS_IGNORED = getattr(settings,
+                                        'AUDIT_RESPONSE_STATUS_IGNORED',
+                                        (200, 201, 202, 301, 302))
+
+AUDIT_REQUEST_POST_IGNORED = getattr(settings,
+                                     'AUDIT_REQUEST_POST_IGNORED',
+                                     ('password', 'password1', 'password2'))
+
+
+def http_headers_logging_middleware(get_response):
+
+    def middleware(request):
+        msg_data = get_request_info(request)
+
+        # Remove any sensitive POST data that we don't want in the logs
+        if request.method == 'POST':
+            post_data = request.POST.copy()
+            for k in AUDIT_REQUEST_POST_IGNORED:
+                post_data.pop(k, None)
+            msg_data['post'] = post_data
+
+            msg = '"Http Request POST", {}'.format(format_log_message(msg_data))
+            logger.debug(msg)
+
+        resp = get_response(request)
+
+        if resp.status_code not in AUDIT_RESPONSE_STATUS_IGNORED:
+            msg_data['status'] = resp.status_code
+            msg = '"Http Response", {}'.format(format_log_message(msg_data))
+            logger.error(msg)
+
+        # Add response headers to data
+        msg_data.update(resp.items())
+
+        # Add response cookies
+        msg_data['Resp-Cookies'] = resp.cookies.output()
+
+        # Finally create a debug log message
+        msg_data.update({
+            'method': request.method,
+            'status': resp.status_code,
+        })
+
+        msg = '"Http Response", {}'.format(format_log_message(msg_data))
+        logger.debug(msg)
+
+        return resp
+
+    return middleware