[Kimchi-devel] [PATCH] [Wok 3/5] Log user requests

25 Feb 2016

Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com>
---
 src/wok/control/base.py | 81 +++++++++++++++++++++++++++++++++++++++++++++----
 src/wok/root.py         | 27 +++++++++++++++++
 src/wok/server.py       | 11 +++++++
 src/wok/utils.py        | 12 ++++++++
 src/wokd.in             |  4 +++
 5 files changed, 129 insertions(+), 6 deletions(-)

diff --git a/src/wok/control/base.py b/src/wok/control/base.py
index 363fd60..f44771e 100644
--- a/src/wok/control/base.py
+++ b/src/wok/control/base.py
@@ -32,6 +32,15 @@ from wok.control.utils import validate_params
 from wok.exception import InvalidOperation, InvalidParameter
 from wok.exception import MissingParameter, NotFoundError
 from wok.exception import OperationFailed, UnauthorizedError, WokException
+from wok.reqlogger import RequestRecord
+from wok.utils import get_plugin_from_request
+
+
+LOG_DISABLED_METHODS = ['GET']
+
+# Default request log messages
+COLLECTION_DEFAULT_LOG = "request on collection"
+RESOURCE_DEFAULT_LOG = "request on resource"
 
 
 class Resource(object):
@@ -58,6 +67,7 @@ class Resource(object):
         self.model_args = (ident,)
         self.role_key = None
         self.admin_methods = []
+        self.log_map = {}
 
     def _redirect(self, action_result, code=303):
         uri_params = []
@@ -102,7 +112,8 @@ class Resource(object):
     def _generate_action_handler_base(self, action_name, render_fn,
                                       destructive=False, action_args=None):
         def wrapper(*args, **kwargs):
-            validate_method(('POST'), self.role_key, self.admin_methods)
+            method = 'POST'
+            validate_method((method), self.role_key, self.admin_methods)
             try:
                 self.lookup()
                 if not self.is_authorized():
@@ -137,6 +148,17 @@ class Resource(object):
                 raise cherrypy.HTTPError(500, e.message)
             except WokException, e:
                 raise cherrypy.HTTPError(500, e.message)
+            finally:
+                params = {}
+                if model_args:
+                    params = {'ident': str(model_args[0])}
+
+                RequestRecord(
+                    self.getRequestMessage(method, action_name) % params,
+                    app=get_plugin_from_request(),
+                    req=method,
+                    user=cherrypy.session.get(USER_NAME, 'N/A')
+                ).log()
 
         wrapper.__name__ = action_name
         wrapper.exposed = True
@@ -162,6 +184,18 @@ class Resource(object):
             raise cherrypy.HTTPError(500, e.message)
         except InvalidOperation, e:
             raise cherrypy.HTTPError(400, e.message)
+        finally:
+            method = 'DELETE'
+            params = {}
+            if self.model_args:
+                params = {'ident': str(self.model_args[0])}
+
+            RequestRecord(
+                self.getRequestMessage(method, 'default') % params,
+                app=get_plugin_from_request(),
+                req=method,
+                user=cherrypy.session.get(USER_NAME, 'N/A')
+            ).log()
 
     @cherrypy.expose
     def index(self, *args, **kargs):
@@ -203,14 +237,23 @@ class Resource(object):
         return user_name in users or len(set(user_groups) & set(groups)) > 0
 
     def update(self, *args, **kargs):
+        params = parse_request()
+
         try:
             update = getattr(self.model, model_fn(self, 'update'))
         except AttributeError:
             e = InvalidOperation('WOKAPI0003E', {'resource':
                                                  get_class_name(self)})
             raise cherrypy.HTTPError(405, e.message)
+        finally:
+            method = 'PUT'
+            RequestRecord(
+                self.getRequestMessage(method) % params,
+                app=get_plugin_from_request(),
+                req=method,
+                user=cherrypy.session.get(USER_NAME, 'N/A')
+            ).log()
 
-        params = parse_request()
         validate_params(params, self, 'update')
 
         args = list(self.model_args) + [params]
@@ -222,6 +265,13 @@ class Resource(object):
     def get(self):
         return wok.template.render(get_class_name(self), self.data)
 
+    def getRequestMessage(self, method, action='default'):
+        """
+        Provide customized user activity log message in inherited classes
+        through log_map attribute.
+        """
+        return self.log_map.get(method, {}).get(action, RESOURCE_DEFAULT_LOG)
+
     @property
     def data(self):
         """
@@ -273,6 +323,7 @@ class Collection(object):
         self.model_args = []
         self.role_key = None
         self.admin_methods = []
+        self.log_map = {}
 
     def create(self, params, *args):
         try:
@@ -341,18 +392,28 @@ class Collection(object):
         data = self.filter_data(resources, fields_filter)
         return wok.template.render(get_class_name(self), data)
 
+    def getRequestMessage(self, method):
+        """
+        Provide customized user activity log message in inherited classes
+        through log_map attribute.
+        """
+        return self.log_map.get(method, {}).get('default',
+                                                COLLECTION_DEFAULT_LOG)
+
     @cherrypy.expose
     def index(self, *args, **kwargs):
+        params = {}
         method = validate_method(('GET', 'POST'),
                                  self.role_key, self.admin_methods)
 
         try:
             if method == 'GET':
-                filter_params = cherrypy.request.params
-                validate_params(filter_params, self, 'get_list')
-                return self.get(filter_params)
+                params = cherrypy.request.params
+                validate_params(params, self, 'get_list')
+                return self.get(params)
             elif method == 'POST':
-                return self.create(parse_request(), *args)
+                params = parse_request()
+                return self.create(params, *args)
         except InvalidOperation, e:
             raise cherrypy.HTTPError(400, e.message)
         except InvalidParameter, e:
@@ -365,6 +426,14 @@ class Collection(object):
             raise cherrypy.HTTPError(500, e.message)
         except WokException, e:
             raise cherrypy.HTTPError(500, e.message)
+        finally:
+            if method not in LOG_DISABLED_METHODS:
+                RequestRecord(
+                    self.getRequestMessage(method) % params,
+                    app=get_plugin_from_request(),
+                    req=method,
+                    user=cherrypy.session.get(USER_NAME, 'N/A')
+                ).log()
 
 
 class AsyncCollection(Collection):
diff --git a/src/wok/root.py b/src/wok/root.py
index 174a9b9..084613f 100644
--- a/src/wok/root.py
+++ b/src/wok/root.py
@@ -32,8 +32,17 @@ from wok.control import sub_nodes
 from wok.control.base import Resource
 from wok.control.utils import parse_request
 from wok.exception import MissingParameter, OperationFailed
+from wok.reqlogger import RequestRecord
+from wok.utils import get_plugin_from_request
 
 
+ROOT_REQUESTS = {
+    'POST': {
+        'login': "User '%(username)s' login",
+        'logout': "User '%(username)s' logout",
+    },
+}
+
 class Root(Resource):
     def __init__(self, model, dev_env=False):
         super(Root, self).__init__(model)
@@ -129,6 +138,7 @@ class WokRoot(Root):
         self.paths = wok_paths
         self.domain = 'wok'
         self.messages = messages
+        self.log_map = ROOT_REQUESTS
 
     @cherrypy.expose
     def login(self, *args):
@@ -144,10 +154,27 @@ class WokRoot(Root):
             user_info = auth.login(username, password)
         except OperationFailed:
             raise cherrypy.HTTPError(401)
+        finally:
+            method = 'POST'
+            RequestRecord(
+                self.getRequestMessage(method, 'login') % params,
+                app=get_plugin_from_request(),
+                req=method,
+                user=cherrypy.session.get(auth.USER_NAME, 'N/A')
+            ).log()
 
         return json.dumps(user_info)
 
     @cherrypy.expose
     def logout(self):
+        method = 'POST'
+        params = {'username': cherrypy.session.get(auth.USER_NAME, 'N/A')}
+        RequestRecord(
+            self.getRequestMessage(method, 'logout') % params,
+            app=get_plugin_from_request(),
+            req=method,
+            user=params['username']
+        ).log()
+
         auth.logout()
         return '{}'
diff --git a/src/wok/server.py b/src/wok/server.py
index 75b41d5..e27124e 100644
--- a/src/wok/server.py
+++ b/src/wok/server.py
@@ -36,6 +36,7 @@ from wok.model import model
 from wok.proxy import start_proxy, terminate_proxy
 from wok.root import WokRoot
 from wok.safewatchedfilehandler import SafeWatchedFileHandler
+from wok.reqlogger import MAX_FILE_SIZE, NUM_BACKUP_FILES, WOK_REQUEST_LOGGER
 from wok.utils import get_enabled_plugins, import_class
 
 LOGGING_LEVEL = {"debug": logging.DEBUG,
@@ -65,6 +66,7 @@ class Server(object):
         start_proxy(options)
 
         make_dirs = [
+            os.path.abspath(config.get_log_download_path()),
             os.path.dirname(os.path.abspath(options.access_log)),
             os.path.dirname(os.path.abspath(options.error_log)),
             os.path.dirname(os.path.abspath(config.get_object_store()))
@@ -130,6 +132,15 @@ class Server(object):
         # Add error log file to cherrypy configuration
         cherrypy.log.error_log.addHandler(h)
 
+        # Request logger setup
+        h = logging.handlers.RotatingFileHandler(options.req_log, 'a',
+                                                 maxBytes=MAX_FILE_SIZE,
+                                                 backupCount=NUM_BACKUP_FILES)
+        h.setFormatter(logging.Formatter('%(message)s'))
+        reqLogger = logging.getLogger(WOK_REQUEST_LOGGER)
+        reqLogger.setLevel(logging.INFO)
+        reqLogger.addHandler(h)
+
         # only add logrotate if wok is installed
         if paths.installed:
 
diff --git a/src/wok/utils.py b/src/wok/utils.py
index e2f1d8e..7b1aa06 100644
--- a/src/wok/utils.py
+++ b/src/wok/utils.py
@@ -120,6 +120,18 @@ def get_all_tabs():
     return tabs
 
 
+def get_plugin_from_request():
+    """
+    Returns name of plugin being requested. If no plugin, returns 'wok'.
+    """
+    script_name = cherrypy.request.script_name
+    split = script_name.split('/')
+    if len(split) > 2 and split[1] == 'plugins':
+        return split[2]
+
+    return 'wok'
+
+
 def import_class(class_path):
     module_name, class_name = class_path.rsplit('.', 1)
     try:
diff --git a/src/wokd.in b/src/wokd.in
index 7255d3c..c91f07a 100644
--- a/src/wokd.in
+++ b/src/wokd.in
@@ -36,6 +36,7 @@ if not config.paths.installed:
 
 ACCESS_LOG = "wok-access.log"
 ERROR_LOG = "wok-error.log"
+REQ_LOG = "wok-req.log"
 
 
 def main(options):
@@ -76,6 +77,9 @@ def main(options):
     parser.add_option('--error-log',
                       default=os.path.join(logDir, ERROR_LOG),
                       help="Error log file")
+    parser.add_option('--req-log',
+                      default=os.path.join(logDir, REQ_LOG),
+                      help="User Request log file")
     parser.add_option('--environment', default=runningEnv,
                       help="Running environment of wok server")
     parser.add_option('--test', action='store_true',
-- 
1.9.1

    