Эх сурвалжийг харах

HUE-7447 [core] Log access page return time

Romain Rigaux 8 жил өмнө
parent
commit
bc2956b

+ 10 - 10
desktop/core/src/desktop/log/access.py

@@ -59,6 +59,7 @@ last_access_map = { }
 # Max number of records per user per view to keep
 _USER_ACCESS_HISTORY_SIZE = desktop.conf.USER_ACCESS_HISTORY_SIZE.get()
 
+
 class AccessInfo(dict):
   """
   Represents details on a user access.
@@ -79,16 +80,16 @@ class AccessInfo(dict):
     self['proto'] = request.META.get('SERVER_PROTOCOL', '-')
     self['agent'] = request.META.get('HTTP_USER_AGENT', '-')
     self['time'] = time.time()
+    self['duration'] = None
+
+  def log(self, level, msg=None, start_time=None):
+    self['duration'] = ' returned in %dms' % ((time.time() - start_time) * 1000) if start_time is not None else ''
 
-  def log(self, level, msg=None):
     if msg is not None:
       self['msg'] = msg
-      ACCESS_LOG.log(level,
-                     '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s" -- %(msg)s' %
-                     self)
+      ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s -- %(msg)s' % self)
     else:
-      ACCESS_LOG.log(level,
-                     '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"' % self)
+      ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s' % self)
 
   def add_to_access_history(self, app):
     """Record this user access to the recent access map"""
@@ -130,20 +131,19 @@ class AccessInfo(dict):
         view_access_list.pop()
 
       # Update the IP address and last access time of the user
-      last_access_map[user] = {'ip':self['remote_ip'],
-                               'time':self['time']}
+      last_access_map[user] = {'ip': self['remote_ip'], 'time': self['time']}
     finally:
       user_lk.release()
 
 
 _MODULE_RE = re.compile('[^.]*')
 
-def log_page_hit(request, view_func, level=None):
+def log_page_hit(request, view_func, level=None, start_time=None):
   """Log the request to the access log"""
   if level is None:
     level = logging.INFO
   ai = AccessInfo(request)
-  ai.log(level)
+  ai.log(level, start_time=start_time)
   # Find the app
   app_re_match = _MODULE_RE.match(view_func.__module__)
   app = app_re_match and app_re_match.group(0) or '-'

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

@@ -273,6 +273,8 @@ class LoginAndPermissionMiddleware(object):
     which tells us the log level. The downside is that we don't have the status code,
     which isn't useful for status logging anyways.
     """
+    request.ts = time.time()
+    request.view_func = view_func
     access_log_level = getattr(view_func, 'access_log_level', None)
     # First, skip views not requiring login
 
@@ -330,6 +332,11 @@ class LoginAndPermissionMiddleware(object):
     else:
       return HttpResponseRedirect("%s?%s=%s" % (settings.LOGIN_URL, REDIRECT_FIELD_NAME, urlquote(request.get_full_path())))
 
+  def process_response(self, request, response):
+    if hasattr(request, 'ts') and hasattr(request, 'view_func'):
+      log_page_hit(request, request.view_func, level=logging.DEBUG, start_time=request.ts)
+    return response
+
 
 class JsonMessage(object):
   def __init__(self, **kwargs):