# HG changeset patch # User Mads Kiilerich # Date 2019-10-19 23:07:12 # Node ID b42ee1bdf0820e3dd5da2d0bbf624acb83d256b0 # Parent 5240fbde6ddb96a7d7992d105a2318be5b51f648 wsgi: make WSGI wrapper follow the result and log when it actually has finished The wrapper lost control after "%s responding after %.3fs" when it passed the iterator through. Now, wrap the iterator and keep track of its use and when it is closed and make an additional loging of "%s responded after %.3fs". 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,8 @@ kallithea.lib.middleware.wrapper ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ -Wrap app to measure request and response time ... until the response starts. +Wrap app to measure request and response time ... all the way to the response +WSGI iterator has been closed. This file was forked by the Kallithea project in July 2014. Original author and date, and relevant copyright and licensing information is below: @@ -44,6 +45,26 @@ class Meter: return time.time() - self._start +class ResultIter: + + def __init__(self, result, meter, description): + self._result_close = getattr(result, 'close', None) or (lambda: None) + self._next = iter(result).next + self._meter = meter + self._description = description + + def __iter__(self): + return self + + def next(self): + chunk = self._next() + return chunk + + def close(self): + self._result_close() + log.info("%s responded after %.3fs", self._description, self._meter.duration()) + + class RequestWrapper(object): def __init__(self, app, config): @@ -60,4 +81,4 @@ class RequestWrapper(object): result = self.application(environ, start_response) finally: log.info("%s responding after %.3fs", description, meter.duration()) - return result + return ResultIter(result, meter, description)