[PATCH] base: add request time to footer

[Mads Kiilerich]

On 03/31/2015 07:46 PM, Thomas De Schampheleire wrote:
> On March 31, 2015 5:05:01 PM CEST, Mads Kiilerich <mads at kiilerich.com> wrote:
>> On 03/31/2015 05:00 PM, Thomas De Schampheleire wrote:
>>> # HG changeset patch
>>> # User Thomas De Schampheleire <thomas.de.schampheleire at gmail.com>
>>> # Date 1427813112 -7200
>>> #      Tue Mar 31 16:45:12 2015 +0200
>>> # Node ID 66accc3fb9a93d6e704177c80ea7500f1a34f02b
>>> # Parent  de5eaaad471f2c746a1b1fed0022a483284d243c
>>> base: add request time to footer
>>>
>>> Currently, the time to handle a request is only shown in the log,
>> while it is
>>> more readily useful when part of the page itself. Use a simple string
>>> substitution to replace the time before finalizing the request.
>>>
>>> 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
>>> @@ -40,10 +40,12 @@ class RequestWrapper(object):
>>>        def __call__(self, environ, start_response):
>>>            start = time.time()
>>>            try:
>>> -            return self.application(environ, start_response)
>>> +            response = self.application(environ, start_response)
>>>            finally:
>>>                log = logging.getLogger('kallithea.' +
>> self.__class__.__name__)
>>> +            total = time.time() - start
>>>                log.info('IP: %s Request to %s time: %.3fs' % (
>>>                    _get_ip_addr(environ),
>>> -                safe_unicode(_get_access_path(environ)), time.time()
>> - start)
>>> +                safe_unicode(_get_access_path(environ)), total)
>>>                )
>>> +            return
>> ''.join(response).replace('%##kallithea_request_time##%', '%.3fs' %
>> total)
>>
>> Response is an iterator that can stream the content without buffering
>> everything in memory. Joining it together into one string would lose
>> that nice property.
> I took that part from the existing profiling code.

The existing profile code is opt-in. This feature could perhaps be done 
the same way.

It could probably even be done with .ini filter-with and thus be 
configuration of completely independent WSGI middleware.

(Note also that some other optional middleware (static_files) also 
introduce full buffering and can have huge influence on the server 
performance.)

> What about doing the replacement on each piece individually? Could it be done with a generator?
> Do you see another solution?

I guess the templater could be tricked into inserting the current time 
when it is yielding the footer.

> What do you think about the general idea of adding the request time to the page?

I don't think it would have any value at all. It would not add any value 
to the user. If I want profiling on the client side, I would use a 
browser feature/plugin that can tell me much more and be much closer to 
the truth. If I want profiling on the server side, I already have it.

/Mads