Mercurial > kallithea

annotate kallithea/lib/middleware/wrapper.py @ 7907:b42ee1bdf082

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
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".
author Mads Kiilerich <mads@kiilerich.com>
date Sat, 19 Oct 2019 23:07:12 +0200
parents 5240fbde6ddb
children 19418a4c6c61
Ignore whitespace changes - Everywhere: Within whitespace: At end of lines:
rev   line source
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
1 # -*- coding: utf-8 -*-
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
2 # This program is free software: you can redistribute it and/or modify
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
3 # it under the terms of the GNU General Public License as published by
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
4 # the Free Software Foundation, either version 3 of the License, or
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
5 # (at your option) any later version.
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
6 #
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
7 # This program is distributed in the hope that it will be useful,
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
8 # but WITHOUT ANY WARRANTY; without even the implied warranty of
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
9 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
10 # GNU General Public License for more details.
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
11 #
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
12 # You should have received a copy of the GNU General Public License
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
13 # along with this program. If not, see <http://www.gnu.org/licenses/>.
4116
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
14 """
4186
7e5f8c12a3fc First step in two-part process to rename directories to kallithea.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4116
diff changeset
15 kallithea.lib.middleware.wrapper
4116
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
16 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
17
7907
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
18 Wrap app to measure request and response time ... all the way to the response
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
19 WSGI iterator has been closed.
4116
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
20
4211
1948ede028ef RhodeCode GmbH is not the sole author of this work
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4208
diff changeset
21 This file was forked by the Kallithea project in July 2014.
1948ede028ef RhodeCode GmbH is not the sole author of this work
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4208
diff changeset
22 Original author and date, and relevant copyright and licensing information is below:
4116
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
23 :created_on: May 23, 2013
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
24 :author: marcink
4211
1948ede028ef RhodeCode GmbH is not the sole author of this work
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4208
diff changeset
25 :copyright: (c) 2013 RhodeCode GmbH, and others.
4208
ad38f9f93b3b Correct licensing information in individual files.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4187
diff changeset
26 :license: GPLv3, see LICENSE.md for more details.
4116
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
27 """
ffd45b185016 Imported some of the GPLv3'd changes from RhodeCode v2.2.5.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 3500
diff changeset
28
7811
0a277465fddf scripts: initial run of import cleanup using isort
Mads Kiilerich <mads@kiilerich.com>
parents: 4918
diff changeset
29 import logging
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
30 import time
7811
0a277465fddf scripts: initial run of import cleanup using isort
Mads Kiilerich <mads@kiilerich.com>
parents: 4918
diff changeset
31
0a277465fddf scripts: initial run of import cleanup using isort
Mads Kiilerich <mads@kiilerich.com>
parents: 4918
diff changeset
32 from kallithea.lib.base import _get_access_path, _get_ip_addr
4186
7e5f8c12a3fc First step in two-part process to rename directories to kallithea.
Bradley M. Kuhn <bkuhn@sfconservancy.org>
parents: 4116
diff changeset
33 from kallithea.lib.utils2 import safe_unicode
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
34
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
35
7906
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
36 log = logging.getLogger(__name__)
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
37
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
38
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
39 class Meter:
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
40
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
41 def __init__(self):
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
42 self._start = time.time()
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
43
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
44 def duration(self):
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
45 return time.time() - self._start
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
46
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
47
7907
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
48 class ResultIter:
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
49
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
50 def __init__(self, result, meter, description):
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
51 self._result_close = getattr(result, 'close', None) or (lambda: None)
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
52 self._next = iter(result).next
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
53 self._meter = meter
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
54 self._description = description
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
55
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
56 def __iter__(self):
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
57 return self
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
58
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
59 def next(self):
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
60 chunk = self._next()
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
61 return chunk
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
62
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
63 def close(self):
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
64 self._result_close()
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
65 log.info("%s responded after %.3fs", self._description, self._meter.duration())
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
66
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
67
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
68 class RequestWrapper(object):
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
69
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
70 def __init__(self, app, config):
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
71 self.application = app
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
72 self.config = config
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
73
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
74 def __call__(self, environ, start_response):
7906
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
75 meter = Meter()
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
76 description = "Request from %s for %s" % (
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
77 _get_ip_addr(environ),
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
78 safe_unicode(_get_access_path(environ)),
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
79 )
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
80 try:
7906
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
81 result = self.application(environ, start_response)
3489
d997a314d18a moved time measure of request to separate middleware for better results (the last one in stack)
Marcin Kuzminski <marcin@python-works.com>
parents:
diff changeset
82 finally:
7906
5240fbde6ddb wsgi: reintroduce the "wrapper" middleware for logging request timing, but guarded by optional use_wsgi_wrapper=true
Mads Kiilerich <mads@kiilerich.com>
parents: 7811
diff changeset
83 log.info("%s responding after %.3fs", description, meter.duration())
7907
b42ee1bdf082 wsgi: make WSGI wrapper follow the result and log when it actually has finished
Mads Kiilerich <mads@kiilerich.com>
parents: 7906
diff changeset
84 return ResultIter(result, meter, description)