Add feature to log operations of users to Horizon

To enable this feature, you can see the
/doc/source/topics/settings.rst on this patch.

Change-Id: I784b92104be244f7f288d7648c20e61e0a0c1d09
Implements: blueprint operation-history-log

doc/source/topics/settings.rst

@@ -1520,6 +1520,66 @@ Can be used to selectively disable certain costly extensions for performance
 reasons.
 
 
+``OPERATION_LOG_ENABLED``
+-------------------------
+
+.. versionadded:: 10.0.0(Newton)
+
+Default: ``False``
+
+This setting can be used to log operations of all of users on Horizon.
+In this log, it can include date and time of an operation, an operation URL,
+user information such as domain, project and user, and so on.
+And this log format is configurable. In detail, you can see OPERATION_LOG_OPTIONS.
+
+.. note::
+
+  If you use this feature, you need to configure the logger setting like
+  a outputting path for operation log in ``local_settings.py``.
+
+
+``OPERATION_LOG_OPTIONS``
+------------------------
+
+.. versionadded:: 10.0.0(Newton)
+
+Default::
+
+        {
+         'mask_fields': ['password'],
+         'target_methods': ['POST'],
+         'format': ("[%(domain_name)s] [%(domain_id)s] [%(project_name)s]"
+             " [%(project_id)s] [%(user_name)s] [%(user_id)s] [%(request_scheme)s]"
+             " [%(referer_url)s] [%(request_url)s] [%(message)s] [%(method)s]"
+             " [%(http_status)s] [%(param)s]"),
+        }
+
+This setting controls the behavior of the operation log.
+
+* ``mask_fields`` is a list of keys of post data which should be masked from the
+  point of view of security. Fields like ``password`` should be included.
+  The fields specified in ``mask_fields`` are logged as ``********``.
+* ``target_methods`` is a request method which is logged to a operation log.
+  The valid methods are ``POST``, ``GET``, ``PUT``, ``DELETE``.
+* ``format`` defines the operation log format.
+  Currently you can use the following keywords.
+  The default value contains all keywords.
+
+  * %(domain_name)s
+  * %(domain_id)s
+  * %(project_name)s
+  * %(project_id)s
+  * %(user_name)s
+  * %(user_id)s
+  * %(request_scheme)s
+  * %(referer_url)s
+  * %(request_url)s
+  * %(message)s
+  * %(method)s
+  * %(http_status)s
+  * %(param)s
+
+
 Django Settings (Partial)
 =========================
 

horizon/middleware/__init__.py

@@ -0,0 +1,19 @@
+# Copyright 2016 NEC Corporation.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+from horizon.middleware import base
+from horizon.middleware import operation_log
+
+HorizonMiddleware = base.HorizonMiddleware
+OperationLogMiddleware = operation_log.OperationLogMiddleware

horizon/middleware/operation_log.py

@@ -0,0 +1,162 @@
+# Copyright 2016 NEC Corporation.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+import json
+import logging
+
+from django.conf import settings
+from django.contrib import messages as django_messages
+from django.core.exceptions import MiddlewareNotUsed
+
+import six.moves.urllib.parse as urlparse
+
+LOG = logging.getLogger(__name__)
+
+
+class OperationLogMiddleware(object):
+    """Middleware to output operation log.
+
+    This log can includes information below.
+      <domain name>, <domain id>
+      <project name>, <project id>
+      <user name>, <user id>
+      <request scheme>, <referer url>, <request url>
+      <message>, <method>, <http status>
+      <request parameters>
+    And log format is defined OPERATION_LOG_OPTIONS.
+    """
+
+    @property
+    def OPERATION_LOG(self):
+        # In order to allow to access from mock in test cases.
+        return self._logger
+
+    def __init__(self):
+        if not getattr(settings, "OPERATION_LOG_ENABLED", False):
+            raise MiddlewareNotUsed
+
+        # set configurations
+        _log_option = getattr(settings, "OPERATION_LOG_OPTIONS", {})
+        _available_methods = ['POST', 'GET', 'PUT', 'DELETE']
+        _methods = _log_option.get("target_methods", ['POST'])
+        _default_format = (
+            "[%(domain_name)s] [%(domain_id)s] [%(project_name)s]"
+            " [%(project_id)s] [%(user_name)s] [%(user_id)s]"
+            " [%(request_scheme)s] [%(referer_url)s] [%(request_url)s]"
+            " [%(message)s] [%(method)s] [%(http_status)s] [%(param)s]")
+        self.target_methods = [x for x in _methods if x in _available_methods]
+        self.mask_fields = getattr(_log_option, "mask_fields", ['password'])
+        self.format = getattr(_log_option, "format", _default_format)
+        self.static_rule = ['/js/', '/static/']
+        self._logger = logging.getLogger('horizon.operation_log')
+
+    def process_response(self, request, response):
+        """Log user operation."""
+        log_format = self._get_log_format(request)
+        if not log_format:
+            return response
+
+        params = self._get_parameters_from_request(request)
+        # log a message displayed to user
+        messages = django_messages.get_messages(request)
+        result_message = None
+        if messages:
+            result_message = ', '.join('%s: %s' % (message.tags, message)
+                                       for message in messages)
+        elif 'action' in request.POST:
+            result_message = request.POST['action']
+        params['message'] = result_message
+        params['http_status'] = response.status_code
+
+        self.OPERATION_LOG.info(log_format, params)
+
+        return response
+
+    def process_exception(self, request, exception):
+        """Log error info when exception occured."""
+        log_format = self._get_log_format(request)
+        if log_format is None:
+            return
+
+        params = self._get_parameters_from_request(request, True)
+        params['message'] = exception
+        params['http_status'] = '-'
+
+        self.OPERATION_LOG.info(log_format, params)
+
+    def _get_log_format(self, request):
+        """Return operation log format."""
+        if not (hasattr(request, 'user') and
+                request.user.is_authenticated()):
+            return
+        method = request.method.upper()
+        if not (method in self.target_methods):
+            return
+        if method == 'GET':
+            request_url = urlparse.unquote(request.path)
+            for rule in self.static_rule:
+                if rule in request_url:
+                    return
+        return self.format
+
+    def _get_parameters_from_request(self, request, exception=False):
+        """Get parameters to log in OPERATION_LOG."""
+        user = request.user
+        referer_url = None
+        try:
+            referer_dic = urlparse.urlsplit(
+                urlparse.unquote(request.META.get('HTTP_REFERER')))
+            referer_url = referer_dic[2]
+            if referer_dic[3]:
+                referer_url += "?" + referer_dic[3]
+            if isinstance(referer_url, str):
+                referer_url = referer_url.decode('utf-8')
+        except Exception:
+            pass
+        return {
+            'domain_name': getattr(user, 'domain_name', None),
+            'domain_id': getattr(user, 'domain_id', None),
+            'project_name': getattr(user, 'project_name', None),
+            'project_id': getattr(user, 'project_id', None),
+            'user_name': getattr(user, 'username', None),
+            'user_id': request.session.get('user_id', None),
+            'request_scheme': request.scheme,
+            'referer_url': referer_url,
+            'request_url': urlparse.unquote(request.path),
+            'method': request.method if not exception else None,
+            'param': self._get_request_param(request),
+        }
+
+    def _get_request_param(self, request):
+        """Change POST data to JSON string and mask data."""
+        params = {}
+        try:
+            params = request.POST.copy()
+            if not params:
+                params = json.loads(request.body)
+        except Exception:
+            pass
+        for key in params.items():
+            # replace a value to a masked characters
+            for key in self.mask_fields:
+                params[key] = '*' * 8
+
+        # when a file uploaded (E.g create image)
+        files = request.FILES.values()
+        if len(list(files)) > 0:
+            filenames = ', '.join(
+                [up_file.name for up_file in files])
+            params['file_name'] = filenames
+
+        return json.dumps(params, ensure_ascii=False)

horizon/test/tests/middleware.py

@@ -12,10 +12,13 @@
 #    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
 #    License for the specific language governing permissions and limitations
 #    under the License.
+from mock import patch
 
 import django
 from django.conf import settings
+from django.core.exceptions import MiddlewareNotUsed
 from django.http import HttpResponseRedirect  # noqa
+from django.test.utils import override_settings
 from django.utils import timezone
 
 from horizon import exceptions
@@ -78,3 +81,115 @@ class MiddlewareTests(test.TestCase):
         request.session['django_timezone'] = 'UTC'
         mw.process_request(request)
         self.assertEqual(timezone.get_current_timezone_name(), 'UTC')
+
+
+class OperationLogMiddlewareTest(test.TestCase):
+
+    http_host = u'test_host'
+    http_referer = u'/dashboard/test_http_referer'
+
+    def test_middleware_not_used(self):
+        with self.assertRaises(MiddlewareNotUsed):
+            middleware.OperationLogMiddleware()
+
+    def _test_ready_for_post(self):
+        url = settings.LOGIN_URL
+        request = self.factory.post(url)
+        request.META['HTTP_HOST'] = self.http_host
+        request.META['HTTP_REFERER'] = self.http_referer
+        request.POST = {
+            "username": u"admin",
+            "password": u"pass"
+        }
+        request.user.username = u'test_user_name'
+        response = HttpResponseRedirect(url)
+        response.client = self.client
+
+        return request, response
+
+    def _test_ready_for_get(self):
+        url = '/dashboard/project/?start=2016-03-01&end=2016-03-11'
+        request = self.factory.get(url)
+        request.META['HTTP_HOST'] = self.http_host
+        request.META['HTTP_REFERER'] = self.http_referer
+        request.user.username = u'test_user_name'
+        response = HttpResponseRedirect(url)
+        response.client = self.client
+
+        return request, response
+
+    @override_settings(OPERATION_LOG_ENABLED=True)
+    @patch(('horizon.middleware.operation_log.OperationLogMiddleware.'
+            'OPERATION_LOG'))
+    def test_process_response_for_post(self, mock_logger):
+        olm = middleware.OperationLogMiddleware()
+        request, response = self._test_ready_for_post()
+
+        resp = olm.process_response(request, response)
+
+        self.assertTrue(mock_logger.info.called)
+        self.assertEqual(302, resp.status_code)
+        log_args = mock_logger.info.call_args[0]
+        logging_str = log_args[0] % log_args[1]
+        self.assertTrue(request.user.username in logging_str)
+        self.assertTrue(self.http_referer in logging_str)
+        self.assertTrue(settings.LOGIN_URL in logging_str)
+        self.assertTrue('POST' in logging_str)
+        self.assertTrue('302' in logging_str)
+        post_data = ['"username": "admin"', '"password": "********"']
+        for data in post_data:
+            self.assertTrue(data in logging_str)
+
+    @override_settings(OPERATION_LOG_ENABLED=True)
+    @override_settings(OPERATION_LOG_OPTIONS={'target_methods': ['GET']})
+    @patch(('horizon.middleware.operation_log.OperationLogMiddleware.'
+            'OPERATION_LOG'))
+    def test_process_response_for_get(self, mock_logger):
+        olm = middleware.OperationLogMiddleware()
+        request, response = self._test_ready_for_get()
+
+        resp = olm.process_response(request, response)
+
+        self.assertTrue(mock_logger.info.called)
+        self.assertEqual(302, resp.status_code)
+        log_args = mock_logger.info.call_args[0]
+        logging_str = log_args[0] % log_args[1]
+        self.assertTrue(request.user.username in logging_str)
+        self.assertTrue(self.http_referer in logging_str)
+        self.assertTrue(request.path in logging_str)
+        self.assertTrue('GET' in logging_str)
+        self.assertTrue('302' in logging_str)
+
+    @override_settings(OPERATION_LOG_ENABLED=True)
+    @patch(('horizon.middleware.operation_log.OperationLogMiddleware.'
+            'OPERATION_LOG'))
+    def test_process_response_for_get_no_target(self, mock_logger):
+        """In default setting, Get method is not logged"""
+        olm = middleware.OperationLogMiddleware()
+        request, response = self._test_ready_for_get()
+
+        resp = olm.process_response(request, response)
+
+        self.assertEqual(0, mock_logger.info.call_count)
+        self.assertEqual(302, resp.status_code)
+
+    @override_settings(OPERATION_LOG_ENABLED=True)
+    @patch(('horizon.middleware.operation_log.OperationLogMiddleware.'
+            'OPERATION_LOG'))
+    def test_process_exception(self, mock_logger):
+        olm = middleware.OperationLogMiddleware()
+        request, response = self._test_ready_for_post()
+        exception = Exception("Unexpected error occured.")
+
+        olm.process_exception(request, exception)
+
+        log_args = mock_logger.info.call_args[0]
+        logging_str = log_args[0] % log_args[1]
+        self.assertTrue(mock_logger.info.called)
+        self.assertTrue(request.user.username in logging_str)
+        self.assertTrue(self.http_referer in logging_str)
+        self.assertTrue(settings.LOGIN_URL in logging_str)
+        self.assertTrue('Unexpected error occured.' in logging_str)
+        post_data = ['"username": "admin"', '"password": "********"']
+        for data in post_data:
+            self.assertTrue(data in logging_str)

openstack_dashboard/local/local_settings.py.example

@@ -461,6 +461,13 @@ LOGGING = {
     # if nothing is specified here and disable_existing_loggers is True,
     # django.db.backends will still log unless it is disabled explicitly.
     'disable_existing_loggers': False,
+    'formatters': {
+        'operation': {
+            # The format of "%(message)s" is defined by
+            # OPERATION_LOG_OPTIONS['format']
+            'format': '%(asctime)s %(message)s'
+        },
+    },
     'handlers': {
         'null': {
             'level': 'DEBUG',
@@ -471,6 +478,11 @@ LOGGING = {
             'level': 'INFO',
             'class': 'logging.StreamHandler',
         },
+        'operation': {
+            'level': 'INFO',
+            'class': 'logging.StreamHandler',
+            'formatter': 'operation',
+        },
     },
     'loggers': {
         # Logging from django.db.backends is VERY verbose, send to null
@@ -488,6 +500,11 @@ LOGGING = {
             'level': 'DEBUG',
             'propagate': False,
         },
+        'horizon.operation_log': {
+            'handlers': ['operation'],
+            'level': 'INFO',
+            'propagate': False,
+        },
         'openstack_dashboard': {
             'handlers': ['console'],
             'level': 'DEBUG',
@@ -737,3 +754,20 @@ REST_API_REQUIRED_SETTINGS = ['OPENSTACK_HYPERVISOR_FEATURES',
 # Help URL can be made available for the client. To provide a help URL, edit the
 # following attribute to the URL of your choice.
 #HORIZON_CONFIG["help_url"] = "http://openstack.mycompany.org"
+
+# Settings for OperationLogMiddleware
+# OPERATION_LOG_ENABLED is flag to use the function to log an operation on
+# Horizon.
+# mask_targets is arrangement for appointing a target to mask.
+# method_targets is arrangement of HTTP method to output log.
+# format is the log contents.
+#OPERATION_LOG_ENABLED = False
+#OPERATION_LOG_OPTIONS = {
+#    'mask_fields': ['password'],
+#    'target_methods': ['POST'],
+#    'format': ("[%(domain_name)s] [%(domain_id)s] [%(project_name)s]"
+#        " [%(project_id)s] [%(user_name)s] [%(user_id)s] [%(request_scheme)s]"
+#        " [%(referer_url)s] [%(request_url)s] [%(message)s] [%(method)s]"
+#        " [%(http_status)s] [%(param)s]"),
+#}
+

openstack_dashboard/settings.py

@@ -106,6 +106,7 @@ MIDDLEWARE_CLASSES = (
     'django.middleware.csrf.CsrfViewMiddleware',
     'django.contrib.sessions.middleware.SessionMiddleware',
     'django.contrib.auth.middleware.AuthenticationMiddleware',
+    'horizon.middleware.OperationLogMiddleware',
     'django.contrib.messages.middleware.MessageMiddleware',
     'django.contrib.auth.middleware.SessionAuthenticationMiddleware',
     'horizon.middleware.HorizonMiddleware',

releasenotes/notes/operation-history-log-64354f66614cb1dd.yaml

@@ -0,0 +1,5 @@
+---
+features:
+  - >
+    [`blueprint operation-history-log <https://blueprints.launchpad.net/horizon/+spec/operation-history-log>`_]
+    Added a feature to log operation history of users.