mgr/dashboard: HTTP request logging

Signed-off-by: Ricardo Dias <rdias@suse.com>

src/pybind/mgr/dashboard_v2/module.py

@@ -23,7 +23,7 @@ if 'COVERAGE_ENABLED' in os.environ:
 from . import logger, mgr
 from .controllers.auth import Auth
 from .tools import load_controllers, json_error_page, SessionExpireAtBrowserCloseTool, \
-                   NotificationQueue
+                   NotificationQueue, RequestLoggingTool
 from .settings import options_command_list, handle_option_command
 
 
@@ -93,13 +93,15 @@ class Module(MgrModule):
         # Initialize custom handlers.
         cherrypy.tools.authenticate = cherrypy.Tool('before_handler', Auth.check_auth)
         cherrypy.tools.session_expire_at_browser_close = SessionExpireAtBrowserCloseTool()
+        cherrypy.tools.request_logging = RequestLoggingTool()
 
         # Apply the 'global' CherryPy configuration.
         config = {
             'engine.autoreload.on': False,
             'server.socket_host': server_addr,
             'server.socket_port': int(server_port),
-            'error_page.default': json_error_page
+            'error_page.default': json_error_page,
+            'tools.request_logging.on': True
         }
         cherrypy.config.update(config)
 

src/pybind/mgr/dashboard_v2/tools.py

@@ -90,6 +90,82 @@ class BaseController(object):
     }
 
 
+class RequestLoggingTool(cherrypy.Tool):
+    def __init__(self):
+        cherrypy.Tool.__init__(self, 'before_handler', self.request_begin,
+                               priority=95)
+
+    def _setup(self):
+        cherrypy.Tool._setup(self)
+        cherrypy.request.hooks.attach('on_end_request', self.request_end,
+                                      priority=5)
+        cherrypy.request.hooks.attach('after_error_response', self.request_error,
+                                      priority=5)
+
+    def _get_user(self):
+        if hasattr(cherrypy.serving, 'session'):
+            return cherrypy.session.get(Session.USERNAME)
+        return None
+
+    def request_begin(self):
+        req = cherrypy.request
+        user = self._get_user()
+        if user:
+            logger.debug("[%s:%s] [%s] [%s] %s", req.remote.ip,
+                         req.remote.port, req.method, user, req.path_info)
+        else:
+            logger.debug("[%s:%s] [%s] %s", req.remote.ip,
+                         req.remote.port, req.method, req.path_info)
+
+    def request_error(self):
+        self._request_log(logger.error)
+        logger.error(cherrypy.response.body)
+
+    def request_end(self):
+        status = cherrypy.response.status[:3]
+        if status in ["401"]:
+            # log unauthorized accesses
+            self._request_log(logger.warning)
+        else:
+            self._request_log(logger.info)
+
+    def _format_bytes(self, num):
+        units = ['B', 'K', 'M', 'G']
+
+        format_str = "{:.0f}{}"
+        for i, unit in enumerate(units):
+            div = 2**(10*i)
+            if num < 2**(10*(i+1)):
+                if num % div == 0:
+                    format_str = "{}{}"
+                else:
+                    div = float(div)
+                    format_str = "{:.1f}{}"
+                return format_str.format(num/div, unit[0])
+
+        # content-length bigger than 1T!! return value in bytes
+        return "{}B".format(num)
+
+    def _request_log(self, logger_fn):
+        req = cherrypy.request
+        res = cherrypy.response
+        lat = time.time() - res.time
+        user = self._get_user()
+        status = res.status[:3] if isinstance(res.status, str) else res.status
+        if 'Content-Length' in res.headers:
+            length = self._format_bytes(res.headers['Content-Length'])
+        else:
+            length = self._format_bytes(0)
+        if user:
+            logger_fn("[%s:%s] [%s] [%s] [%s] [%s] [%s] %s", req.remote.ip,
+                      req.remote.port, req.method, status,
+                      "{0:.3f}s".format(lat), user, length, req.path_info)
+        else:
+            logger_fn("[%s:%s] [%s] [%s] [%s] [%s] %s", req.remote.ip,
+                      req.remote.port, req.method, status,
+                      "{0:.3f}s".format(lat), length, req.path_info)
+
+
 # pylint: disable=too-many-instance-attributes
 class ViewCache(object):
     VALUE_OK = 0