Response time in WSGIRequestHandler.log_request

[Andrei Fokau]

It's often useful to know how much time it takes for runserver to respond without setting up a middleware or using the debug toolbar. Currently, one could monkeypatch WSGIRequestHandler (e.g. in manage.py) in order to get the time:

from django.core.servers.basehttp import WSGIRequestHandler
_handle = WSGIRequestHandler.handle

def handle(self):
    self.request_started = time.time()
    _handle(self)

def log_request(self, code='-', size='-'):
    self.log_message('"%s" %s %s %dms',
                     self.requestline, str(code), str(size),
                     (time.time() - self.request_started) * 1e3)

WSGIRequestHandler.handle = handle
WSGIRequestHandler.log_request = log_request

or via middleware

class ResponseTimeMiddleware(object):
    def process_view(self, request, view_func, view_args, view_kwargs):
        start = time.time()
        response = view_func(request, *view_args, **view_kwargs)

        if response and getattr(response, 'is_rendered', True) is False:
            response.rendered_content

        logging.getLogger('response_time').debug(
            'Response time %dms', (time.time() - start) * 1000)
        return response

It seems easy to add it in the WSGIRequestHandler e.g. ​https://github.com/django/django/pull/5606. The response time is slightly longer than actual response time due to late measuring but think an easy implementation is better than the exact duration.

This feature is blocked by https://code.djangoproject.com/ticket/25684

[Simon Charette]

I'm not sure this should be part of the actual output of runserver but it would make sense to at least provide it as a kwarg to the logger calls to allow third party and users to refer to it in a formater or filter.

e.g. one could write a formatter that turns the text bold if request take more than X ms to complete.