From 6dd190c9d920125ffdb7b4c6ba33efe8fcfd33f1 Mon Sep 17 00:00:00 2001
From: Smruti Soumitra Khuntia <sk698p@att.com>
Date: Wed, 20 Feb 2019 15:44:41 +0530
Subject: [PATCH] End user logging for audit traceabilty

Changes for Client to support new end user header
and add end user name to logs.

Change-Id: If1a43197c59cac60caca2a517bcf053fa33f82c4
---
 armada/api/__init__.py   | 12 ++++++++++-
 armada/api/middleware.py | 46 +++++++++++++++++++++++++++++-----------
 armada/common/session.py |  5 ++++-
 3 files changed, 49 insertions(+), 14 deletions(-)

diff --git a/armada/api/__init__.py b/armada/api/__init__.py
index 233a4b7e..05e645c4 100644
--- a/armada/api/__init__.py
+++ b/armada/api/__init__.py
@@ -88,13 +88,19 @@ class BaseResource(object):
         resp.status = status_code
 
     def log_error(self, ctx, level, msg):
-        extra = {'user': 'N/A', 'req_id': 'N/A', 'external_ctx': 'N/A'}
+        extra = {
+            'user': 'N/A',
+            'req_id': 'N/A',
+            'external_ctx': 'N/A',
+            'end_user': 'N/A',
+        }
 
         if ctx is not None:
             extra = {
                 'user': ctx.user,
                 'req_id': ctx.request_id,
                 'external_ctx': ctx.external_marker,
+                'end_user': ctx.end_user,
             }
 
         self.logger.log(level, msg, extra=extra)
@@ -129,6 +135,7 @@ class ArmadaRequestContext(object):
         self.authenticated = False
         self.request_id = str(uuid.uuid4())
         self.external_marker = ''
+        self.end_user = None  # Initial User
 
     def set_log_level(self, level):
         if level in ['error', 'info', 'debug']:
@@ -152,6 +159,9 @@ class ArmadaRequestContext(object):
     def set_external_marker(self, marker):
         self.external_marker = marker
 
+    def set_end_user(self, end_user):
+        self.end_user = end_user
+
     def to_policy_view(self):
         policy_dict = {}
 
diff --git a/armada/api/middleware.py b/armada/api/middleware.py
index 135ea156..fa8a66db 100644
--- a/armada/api/middleware.py
+++ b/armada/api/middleware.py
@@ -81,10 +81,18 @@ class ContextMiddleware(object):
         ctx = req.context
 
         ext_marker = req.get_header('X-Context-Marker')
+        end_user = req.get_header('X-End-User')
 
         if ext_marker is not None and self.is_valid_uuid(ext_marker):
             ctx.set_external_marker(ext_marker)
 
+        # Set end user from req header in context obj if available
+        # else set the user as end user.
+        if end_user is not None:
+            ctx.set_end_user(end_user)
+        else:
+            ctx.set_end_user(ctx.user)
+
     def is_valid_uuid(self, id, version=4):
         try:
             uuid_obj = UUID(id, version=version)
@@ -115,12 +123,19 @@ class LoggingMiddleware(object):
             return
 
         ctx = req.context
-        extra = {
-            'user': ctx.user,
-            'req_id': ctx.request_id,
-            'external_ctx': ctx.external_marker,
-        }
-        self.logger.info("Request %s %s" % (req.method, req.url), extra=extra)
+
+        # Get audit logging attributes from context
+        user = getattr(ctx, 'user', None)
+        req_id = getattr(ctx, 'request_id', None)
+        external_ctx = getattr(ctx, 'external_marker', None)
+        end_user = getattr(ctx, 'end_user', None)
+
+        # Log request with audit params
+        self.logger.info(
+            "user=%s request_id=%s ext_ctx=%s end_user=%s Request: %s %s %s",
+            user or '-', req_id or '-', external_ctx or '-', end_user or '-',
+            req.method, req.uri, req.query_string)
+
         self._log_headers(req.headers)
 
     def process_response(self, req, resp, resource, req_succeeded):
@@ -130,14 +145,21 @@ class LoggingMiddleware(object):
             return
 
         ctx = req.context
-        extra = {
-            'user': ctx.user,
-            'req_id': ctx.request_id,
-            'external_ctx': ctx.external_marker,
-        }
+
+        # Get audit logging attributes from context
+        user = getattr(ctx, 'user', None)
+        req_id = getattr(ctx, 'request_id', None)
+        external_ctx = getattr(ctx, 'external_marker', None)
+        end_user = getattr(ctx, 'end_user', None)
+
         resp.append_header('X-Armada-Req', ctx.request_id)
+
+        # Log response with audit params
         self.logger.info(
-            "%s %s - %s" % (req.method, req.uri, resp.status), extra=extra)
+            "user=%s request_id=%s ext_ctx=%s end_user=%s Response: %s %s %s",
+            user or '-', req_id or '-', external_ctx or '-', end_user or '-',
+            req.method, req.uri, resp.status)
+
         self.logger.debug("Response body:%s", resp.body)
 
     def _log_headers(self, headers):
diff --git a/armada/common/session.py b/armada/common/session.py
index ce84bbbf..6d1277e8 100644
--- a/armada/common/session.py
+++ b/armada/common/session.py
@@ -41,12 +41,14 @@ class ArmadaSession(object):
                  scheme='http',
                  token=None,
                  marker=None,
+                 end_user=None,
                  timeout=None):
 
         self._session = requests.Session()
         self._session.headers.update({
             'X-Auth-Token': token,
-            'X-Context-Marker': marker
+            'X-Context-Marker': marker,
+            'X-End-User': end_user,
         })
         self.host = host
         self.scheme = scheme
@@ -62,6 +64,7 @@ class ArmadaSession(object):
                                                                  timeout)
         self.token = token
         self.marker = marker
+        self.end_user = end_user
         self.logger = LOG
 
     # TODO Add keystone authentication to produce a token for this session