Selaa lähdekoodia

[core] Pluggable auditing logger

Provides a cleaner way to log requests to Hue.

e.g. of events:
{"1393901417":
 {"status": 200, "impersonator": null, "service": "useradmin", "url": "/useradmin/",
  "user": "test", "ip_address": "127.0.0.1", "authorization_failure": false},
"1393901418":
 {"status": 200, "impersonator": null, "service": "useradmin", "url": "/beeswax/",
  "user": "test2", "ip_address": "127.0.0.2", "authorization_failure": false}
}

Config:
  # The directory where to store the auditing logs. Auditing is disable if the value is empty.
  # e.g. /var/log/hue/audit.log
  ## audit_event_log_dir=

  # Size in KB/MB/GB for audit log to rollover.
  ## audit_log_max_file_size=100MB
Romain Rigaux 11 vuotta sitten
vanhempi
commit
ecfcb4c640

+ 10 - 2
desktop/conf.dist/hue.ini

@@ -83,6 +83,13 @@
   # e.g.: pig,zookeeper
   ## app_blacklist=
 
+  # The directory where to store the auditing logs. Auditing is disable if the value is empty.
+  # e.g. /var/log/hue/audit.log
+  ## audit_event_log_dir=
+
+  # Size in KB/MB/GB for audit log to rollover.
+  ## audit_log_max_file_size=100MB
+
   # Administrators
   # ----------------
   [[django_admins]]
@@ -94,8 +101,9 @@
   # -------------------
   [[custom]]
 
-  # Top banner HTML code
-  ## banner_top_html=
+    # Top banner HTML code
+    # e.g. <H2>Test Lab A2 Hue Services</H2>
+    ## banner_top_html=
 
   # Configuration options for user authentication into the web application
   # ------------------------------------------------------------------------

+ 7 - 0
desktop/conf/pseudo-distributed.ini.tmpl

@@ -92,6 +92,13 @@
   # e.g.: pig,zookeeper
   ## app_blacklist=
 
+  # The directory where to store the auditing logs. Auditing is disable if the value is empty.
+  # e.g. /var/log/hue/audit.log
+  ## audit_event_log_dir=
+
+  # Size in KB/MB/GB for audit log to rollover.
+  ## audit_log_max_file_size=100MB
+
   # Administrators
   # ----------------
   [[django_admins]]

+ 14 - 0
desktop/core/src/desktop/conf.py

@@ -591,6 +591,20 @@ HTTP_500_DEBUG_MODE = Config(
   default=True
 )
 
+AUDIT_EVENT_LOG_DIR = Config(
+  key="audit_event_log_dir",
+  help=_("The directory where to store the auditing logs. Auditing is disable if the value is empty."),
+  type=str,
+  default=""
+)
+
+AUDIT_LOG_MAX_FILE_SIZE = Config(
+  key="audit_log_max_file_size",
+  help=_("Size in KB/MB/GB for audit log to rollover."),
+  type=str,
+  default="100MB"
+)
+
 DJANGO_SERVER_EMAIL = Config(
   key='django_server_email',
   help=_('Email address that internal error messages should send as.'),

+ 1 - 0
desktop/core/src/desktop/lib/exceptions_renderable.py

@@ -27,6 +27,7 @@ from django.utils.encoding import force_unicode
 # Need full import statement
 import desktop.lib.django_util
 
+
 class PopupException(Exception):
   """
   Middleware will render this exception; and the template

+ 28 - 7
desktop/core/src/desktop/log/__init__.py

@@ -15,11 +15,6 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-"""
-Desktop logging configuration and library package that is independent from Django.
-This module contains basic setup functions for logging.
-"""
-
 import logging
 import logging.config
 import os
@@ -28,9 +23,12 @@ import re
 import sys
 
 from cStringIO import StringIO
+from logging.handlers import RotatingFileHandler
 
 from desktop.lib.paths import get_desktop_root
 from desktop.log import formatter
+from desktop.log.formatter import MessageOnlyFormatter
+
 
 DEFAULT_LOG_DIR = 'logs'
 LOG_FORMAT = '[%(asctime)s] %(module)-12s %(levelname)-8s %(message)s'
@@ -40,6 +38,7 @@ CONF_RE = re.compile('%LOG_DIR%|%PROC_NAME%')
 
 _log_dir = None
 
+
 def _read_log_conf(proc_name, log_dir):
   """
   _read_log_conf(proc_name, log_dir) -> StringIO or None
@@ -69,12 +68,30 @@ def _read_log_conf(proc_name, log_dir):
 def _find_console_stream_handler(logger):
   """Find a StreamHandler that is attached to the logger that prints to the console."""
   for handler in logger.handlers:
-    if isinstance(handler, logging.StreamHandler) and \
-            handler.stream in (sys.stderr, sys.stdout):
+    if isinstance(handler, logging.StreamHandler) and handler.stream in (sys.stderr, sys.stdout):
       return logger
   return None
 
 
+class AuditHandler(RotatingFileHandler):
+  pass
+
+
+def get_audit_logger():
+  from desktop.conf import AUDIT_EVENT_LOG_DIR, AUDIT_LOG_MAX_FILE_SIZE
+
+  audit_logger = logging.getLogger('audit')
+  if not filter(lambda hclass: isinstance(hclass, AuditHandler), audit_logger.handlers): # Don't add handler twice
+    size, unit = int(AUDIT_LOG_MAX_FILE_SIZE.get()[:-2]), AUDIT_LOG_MAX_FILE_SIZE.get()[-2:]
+    maxBytes = size * 1024 ** (1 if unit == 'KB' else 2 if unit == 'MB' else 3)
+
+    audit_handler = AuditHandler(AUDIT_EVENT_LOG_DIR.get(), maxBytes=maxBytes, backupCount=50)
+    audit_handler.setFormatter(MessageOnlyFormatter())
+    audit_logger.addHandler(audit_handler)
+
+  return audit_logger
+
+
 def chown_log_dir(uid, gid):
   """
   chown all files in the log dir to this user and group.
@@ -83,6 +100,7 @@ def chown_log_dir(uid, gid):
   """
   if _log_dir is None:
     return False
+
   try:
     os.chown(_log_dir, uid, gid)
     for entry in os.listdir(_log_dir):
@@ -123,6 +141,7 @@ def basic_logging(proc_name, log_dir=None):
   _log_dir = log_dir
 
   log_conf = _read_log_conf(proc_name, log_dir)
+
   if log_conf is not None:
     logging.config.fileConfig(log_conf)
     root_logger = logging.getLogger()
@@ -161,9 +180,11 @@ def basic_logging(proc_name, log_dir=None):
 def fancy_logging():
   """Configure logging into a buffer for /logs endpoint."""
   from log_buffer import FixedBufferHandler
+
   BUFFER_SIZE = 10 * 1024 * 1024 # This is the size in characters, not bytes
   buffer_handler = FixedBufferHandler(BUFFER_SIZE)
   _formatter = formatter.Formatter(LOG_FORMAT, DATE_FORMAT)
+
   # We always want to catch all messages in our error report buffer
   buffer_handler.setLevel(logging.DEBUG)
   buffer_handler.setFormatter(_formatter)

+ 26 - 0
desktop/core/src/desktop/log/formatter.py

@@ -1,3 +1,20 @@
+#!/usr/bin/env python
+# Licensed to Cloudera, Inc. under one
+# or more contributor license agreements.  See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership.  Cloudera, Inc. licenses this file
+# to you 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 logging
 import os
 
@@ -22,3 +39,12 @@ class Formatter(logging.Formatter):
       t = ct.strftime("%Y-%m-%d %H:%M:%S")
       s = "%s,%03d" % (t, record.msecs)
     return s
+
+
+class MessageOnlyFormatter(logging.Formatter):
+  def formatTime(self, record, datefmt=None):
+    return ''
+
+  def format(self, record):
+    return record.getMessage()
+

+ 94 - 0
desktop/core/src/desktop/log/tests.py

@@ -0,0 +1,94 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+# Licensed to Cloudera, Inc. under one
+# or more contributor license agreements.  See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership.  Cloudera, Inc. licenses this file
+# to you 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 tempfile
+
+from nose.tools import assert_true, assert_false, assert_equal, assert_not_equal
+
+from desktop.log import get_audit_logger, AuditHandler
+from desktop.conf import AUDIT_EVENT_LOG_DIR, AUDIT_LOG_MAX_FILE_SIZE
+
+
+def test_one_audit():
+  log_tmp = tempfile.NamedTemporaryFile("w+t")
+
+  # KB
+  reset = [
+      AUDIT_EVENT_LOG_DIR.set_for_testing(log_tmp),
+      AUDIT_LOG_MAX_FILE_SIZE.set_for_testing('25KB')
+  ]
+
+  audit_logger = get_audit_logger()
+  audit_handler = audit_logger.handlers[0]
+
+  assert_equal(25 * 1024 ** 1, audit_handler.maxBytes)
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers)
+  assert_true(isinstance(audit_handler, AuditHandler), audit_logger.handlers)
+
+  audit_logger = get_audit_logger()
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers) # Not adding handler twice
+
+  # Cleanup
+  audit_logger.removeHandler(audit_handler)
+
+  for r in reset:
+    r()
+
+  # MB
+  reset = [
+      AUDIT_EVENT_LOG_DIR.set_for_testing(log_tmp),
+      AUDIT_LOG_MAX_FILE_SIZE.set_for_testing('25MB')
+  ]
+
+  audit_logger = get_audit_logger()
+  audit_handler = audit_logger.handlers[0]
+
+  assert_equal(25 * 1024 ** 2, audit_handler.maxBytes)
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers)
+  assert_true(isinstance(audit_handler, AuditHandler), audit_logger.handlers)
+
+  audit_logger = get_audit_logger()
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers) # Not adding handler twice
+
+  # Cleanup
+  audit_logger.removeHandler(audit_handler)
+
+  for r in reset:
+    r()
+
+  # GB
+  reset = [
+      AUDIT_EVENT_LOG_DIR.set_for_testing(log_tmp),
+      AUDIT_LOG_MAX_FILE_SIZE.set_for_testing('25GB')
+  ]
+
+  audit_logger = get_audit_logger()
+  audit_handler = audit_logger.handlers[0]
+
+  assert_equal(25 * 1024 ** 3, audit_handler.maxBytes)
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers)
+  assert_true(isinstance(audit_handler, AuditHandler), audit_logger.handlers)
+
+  audit_logger = get_audit_logger()
+  assert_equal(len(audit_logger.handlers), 1, audit_logger.handlers) # Not adding handler twice
+
+  # Cleanup
+  audit_logger.removeHandler(audit_handler)
+
+  for r in reset:
+    r()

+ 42 - 0
desktop/core/src/desktop/middleware.py

@@ -22,6 +22,8 @@ import re
 import tempfile
 import kerberos
 
+from datetime import datetime
+
 from django.conf import settings
 from django.contrib import messages
 from django.contrib.auth import REDIRECT_FIELD_NAME, BACKEND_SESSION_KEY, authenticate, load_backend, login
@@ -46,6 +48,7 @@ from desktop.lib.exceptions_renderable import PopupException
 from desktop.log.access import access_log, log_page_hit
 from desktop import appmanager
 from hadoop import cluster
+from desktop.log import get_audit_logger
 
 
 LOG = logging.getLogger(__name__)
@@ -343,6 +346,43 @@ class LoginAndPermissionMiddleware(object):
       return HttpResponseRedirect("%s?%s=%s" % (settings.LOGIN_URL, REDIRECT_FIELD_NAME, urlquote(request.get_full_path())))
 
 
+class JsonMessage(object):
+  def __init__(self, **kwargs):
+    self.kwargs = kwargs
+
+  def __str__(self):
+    return json.dumps(self.kwargs)
+
+
+class AuditLoggingMiddleware(object):
+
+  def __init__(self):
+    from desktop.conf import AUDIT_EVENT_LOG_DIR
+
+    if not AUDIT_EVENT_LOG_DIR.get():
+      LOG.info('Unloading AuditLoggingMiddleware')
+      raise exceptions.MiddlewareNotUsed
+
+  def process_response(self, request, response):
+    try:
+      audit_logger = get_audit_logger()
+      audit_logger.debug(JsonMessage(**{
+          datetime.utcnow().strftime('%s'): {
+            'user': request.user.username  if hasattr(request, 'user') else 'anonymous',
+            "status": response.status_code,
+            "impersonator": None,
+            "ip_address": request.META.get('REMOTE_ADDR'),
+            "authorization_failure": response.status_code == 401,
+            "service": get_app_name(request),
+            "url": request.path,
+          }
+      }))
+      response['audited'] = True
+    except Exception, e:
+      LOG.error('Could not audit the request: %s' % e)
+    return response
+
+
 class SessionOverPostMiddleware(object):
   """
   Django puts session info in cookies, which is reasonable.
@@ -600,6 +640,7 @@ class SpnegoMiddleware(object):
       pass
     return username
 
+
 class HueRemoteUserMiddleware(RemoteUserMiddleware):
   """
   Middleware to delegate authentication to a proxy server. The proxy server
@@ -616,6 +657,7 @@ class HueRemoteUserMiddleware(RemoteUserMiddleware):
       LOG.info('Unloading HueRemoteUserMiddleware')
       raise exceptions.MiddlewareNotUsed
 
+
 class EnsureSafeMethodMiddleware(object):
   """
   Middleware to white list configured HTTP request methods.

+ 51 - 3
desktop/core/src/desktop/middleware_test.py

@@ -15,12 +15,18 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-from desktop.lib.django_test_util import make_logged_in_client
-from desktop.lib.test_utils import add_permission
+import json
+import os
+import tempfile
+
 from django.conf import settings
+from nose.tools import assert_equal, assert_false, assert_true
+
 import desktop.conf
 
-from nose.tools import assert_equal
+from desktop.conf import AUDIT_EVENT_LOG_DIR
+from desktop.lib.django_test_util import make_logged_in_client
+from desktop.lib.test_utils import add_permission
 
 
 def test_jframe_middleware():
@@ -88,6 +94,48 @@ def test_ensure_safe_method_middleware():
     done()
 
 
+def test_audit_logging_middleware_enable():
+  c = make_logged_in_client(username='test_audit_logging_middleware_enable', is_superuser=False)
+
+  # Make sure we enable it with a file path
+  log_tmp = tempfile.NamedTemporaryFile("w+t") # Get a tempfile path
+  log_path = log_tmp.name
+  log_tmp.close()
+  reset = AUDIT_EVENT_LOG_DIR.set_for_testing(log_path)
+  settings.MIDDLEWARE_CLASSES.append('desktop.middleware.AuditLoggingMiddleware') # Re-add middleware
+
+  try:
+    # Check if we audit correctly
+    response = c.get("/beeswax/")
+    assert_true('audited' in response, response)
+
+    audit = open(log_path).readlines()
+    for line in audit:
+      audit_json = json.loads(line)
+      audit_record = audit_json.values()[0]
+      assert_equal('test_audit_logging_middleware_enable', audit_record['user'], audit_record)
+      assert_equal('/beeswax/', audit_record['url'], audit_record)
+
+  finally:
+    settings.MIDDLEWARE_CLASSES.pop()
+    reset()
+    try:
+      os.remove(log_tmp)
+    except:
+      pass
+
+def test_audit_logging_middleware_disable():
+  c = make_logged_in_client(username='test_audit_logging_middleware_disable', is_superuser=False)
+
+  reset = AUDIT_EVENT_LOG_DIR.set_for_testing('')
+  try:
+    # No middleware yet
+    response = c.get("/oozie/")
+    assert_false('audited' in response, response)
+  finally:
+    reset()
+
+
 def test_ensure_safe_redirect_middleware():
   done = []
   settings.MIDDLEWARE_CLASSES.append('desktop.middleware.EnsureSafeRedirectURLMiddleware')

+ 2 - 1
desktop/core/src/desktop/settings.py

@@ -106,11 +106,12 @@ MIDDLEWARE_CLASSES = [
     # The order matters
     'desktop.middleware.EnsureSafeMethodMiddleware',
     'desktop.middleware.DatabaseLoggingMiddleware',
+    'desktop.middleware.AuditLoggingMiddleware',
     'django.middleware.common.CommonMiddleware',
     'desktop.middleware.SessionOverPostMiddleware',
     'django.contrib.sessions.middleware.SessionMiddleware',
     'django.contrib.auth.middleware.AuthenticationMiddleware',
-    'desktop.middleware.SpnegoMiddleware',
+    'desktop.middleware.SpnegoMiddleware',    
     'desktop.middleware.HueRemoteUserMiddleware',
     'django.middleware.locale.LocaleMiddleware',
     'babeldjango.middleware.LocaleMiddleware',