# HG changeset patch
# User Mads Kiilerich <mads@kiilerich.com>
# Date 2019-10-19 22:53:21
# Node ID 5240fbde6ddb96a7d7992d105a2318be5b51f648
# Parent  948db4f4254fc8ea0fa9cdfe663d9ff6a327e04d

wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true

diff --git a/kallithea/config/app_cfg.py b/kallithea/config/app_cfg.py
--- a/kallithea/config/app_cfg.py
+++ b/kallithea/config/app_cfg.py
@@ -39,6 +39,7 @@ from kallithea.lib.middleware.https_fixu
 from kallithea.lib.middleware.permanent_repo_url import PermanentRepoUrl
 from kallithea.lib.middleware.simplegit import SimpleGit
 from kallithea.lib.middleware.simplehg import SimpleHg
+from kallithea.lib.middleware.wrapper import RequestWrapper
 from kallithea.lib.utils import check_git_version, load_rcextensions, make_ui, set_app_settings, set_indexer_config, set_vcs_config
 from kallithea.lib.utils2 import str2bool
 
@@ -199,6 +200,11 @@ def setup_application(app):
         app = HttpsFixup(app, config)
 
     app = PermanentRepoUrl(app, config)
+
+    # Optional and undocumented wrapper - gives more verbose request/response logging, but has a slight overhead
+    if str2bool(config.get('use_wsgi_wrapper')):
+        app = RequestWrapper(app, config)
+
     return app
 
 
diff --git a/kallithea/lib/middleware/wrapper.py b/kallithea/lib/middleware/wrapper.py
--- a/kallithea/lib/middleware/wrapper.py
+++ b/kallithea/lib/middleware/wrapper.py
@@ -15,7 +15,7 @@
 kallithea.lib.middleware.wrapper
 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 
-request time measuring app
+Wrap app to measure request and response time ... until the response starts.
 
 This file was forked by the Kallithea project in July 2014.
 Original author and date, and relevant copyright and licensing information is below:
@@ -32,6 +32,18 @@ from kallithea.lib.base import _get_acce
 from kallithea.lib.utils2 import safe_unicode
 
 
+log = logging.getLogger(__name__)
+
+
+class Meter:
+
+    def __init__(self):
+        self._start = time.time()
+
+    def duration(self):
+        return time.time() - self._start
+
+
 class RequestWrapper(object):
 
     def __init__(self, app, config):
@@ -39,12 +51,13 @@ class RequestWrapper(object):
         self.config = config
 
     def __call__(self, environ, start_response):
-        start = time.time()
+        meter = Meter()
+        description = "Request from %s for %s" % (
+            _get_ip_addr(environ),
+            safe_unicode(_get_access_path(environ)),
+        )
         try:
-            return self.application(environ, start_response)
+            result = self.application(environ, start_response)
         finally:
-            log = logging.getLogger('kallithea.' + self.__class__.__name__)
-            log.info('IP: %s Request to %s time: %.3fs' % (
-                _get_ip_addr(environ),
-                safe_unicode(_get_access_path(environ)), time.time() - start)
-            )
+            log.info("%s responding after %.3fs", description, meter.duration())
+        return result