Log request duration at wsgi_app level instead of with_pool
This gives more accurate duration as other decorators may take time to execute. Closes #13650
This commit is contained in:
@@ -196,34 +196,18 @@ def with_pool(func):
|
||||
with Transaction().start(database_name, 0, readonly=True):
|
||||
pool.init()
|
||||
|
||||
log_message = '%s in %i ms'
|
||||
|
||||
def duration():
|
||||
return (time.monotonic() - started) * 1000
|
||||
started = time.monotonic()
|
||||
|
||||
try:
|
||||
result = func(request, pool, *args, **kwargs)
|
||||
except exceptions.HTTPException:
|
||||
logger.info(
|
||||
log_message, request, duration(),
|
||||
exc_info=logger.isEnabledFor(logging.DEBUG))
|
||||
raise
|
||||
except (UserError, UserWarning) as e:
|
||||
logger.info(
|
||||
log_message, request, duration(),
|
||||
exc_info=logger.isEnabledFor(logging.DEBUG))
|
||||
if request.rpc_method:
|
||||
raise
|
||||
else:
|
||||
abort(HTTPStatus.BAD_REQUEST, e)
|
||||
except Exception as e:
|
||||
logger.exception(log_message, request, duration())
|
||||
if request.rpc_method:
|
||||
raise
|
||||
else:
|
||||
abort(HTTPStatus.INTERNAL_SERVER_ERROR, e)
|
||||
logger.info(log_message, request, duration())
|
||||
return result
|
||||
return wrapper
|
||||
|
||||
|
||||
+50
-42
@@ -6,6 +6,7 @@ import logging
|
||||
import os
|
||||
import posixpath
|
||||
import sys
|
||||
import time
|
||||
import traceback
|
||||
import urllib.parse
|
||||
from functools import wraps
|
||||
@@ -142,51 +143,58 @@ class TrytondWSGI(object):
|
||||
return response
|
||||
|
||||
def wsgi_app(self, environ, start_response):
|
||||
for cls in self.protocols:
|
||||
if cls.content_type in environ.get('CONTENT_TYPE', ''):
|
||||
request = cls.request(environ)
|
||||
break
|
||||
else:
|
||||
request = Request(environ)
|
||||
logger.info('%s', request)
|
||||
def duration():
|
||||
return (time.monotonic() - started) * 1000
|
||||
started, request = time.monotonic(), None
|
||||
try:
|
||||
|
||||
origin = request.headers.get('Origin')
|
||||
origin_host = urllib.parse.urlparse(origin).netloc if origin else ''
|
||||
host = request.headers.get('Host')
|
||||
if origin and origin != 'null' and origin_host != host:
|
||||
cors = filter(
|
||||
None, config.get('web', 'cors', default='').splitlines())
|
||||
if origin not in cors:
|
||||
if (origin.startswith('moz-extension://')
|
||||
or origin.startswith('chrome-extension://')):
|
||||
origin = 'null'
|
||||
else:
|
||||
abort(HTTPStatus.FORBIDDEN)
|
||||
if origin == 'null':
|
||||
adapter = self.url_map.bind_to_environ(request.environ)
|
||||
endpoint = adapter.match()[0]
|
||||
if not getattr(endpoint, 'allow_null_origin', False):
|
||||
abort(HTTPStatus.FORBIDDEN)
|
||||
|
||||
with processing(request):
|
||||
data = self.dispatch_request(request)
|
||||
if not isinstance(data, (Response, exceptions.HTTPException)):
|
||||
response = self.make_response(request, data)
|
||||
for cls in self.protocols:
|
||||
if cls.content_type in environ.get('CONTENT_TYPE', ''):
|
||||
request = cls.request(environ)
|
||||
break
|
||||
else:
|
||||
response = data
|
||||
request = Request(environ)
|
||||
|
||||
if origin and isinstance(response, Response):
|
||||
response.headers['Access-Control-Allow-Origin'] = origin
|
||||
response.headers['Vary'] = 'Origin'
|
||||
method = request.headers.get('Access-Control-Request-Method')
|
||||
if method:
|
||||
response.headers['Access-Control-Allow-Methods'] = method
|
||||
headers = request.headers.get('Access-Control-Request-Headers')
|
||||
if headers:
|
||||
response.headers['Access-Control-Allow-Headers'] = headers
|
||||
response.headers['Access-Control-Max-Age'] = config.getint(
|
||||
'web', 'cache_timeout')
|
||||
return response(environ, start_response)
|
||||
origin = request.headers.get('Origin')
|
||||
origin_host = (
|
||||
urllib.parse.urlparse(origin).netloc if origin else '')
|
||||
host = request.headers.get('Host')
|
||||
if origin and origin != 'null' and origin_host != host:
|
||||
cors = filter(
|
||||
None, config.get('web', 'cors', default='').splitlines())
|
||||
if origin not in cors:
|
||||
if (origin.startswith('moz-extension://')
|
||||
or origin.startswith('chrome-extension://')):
|
||||
origin = 'null'
|
||||
else:
|
||||
abort(HTTPStatus.FORBIDDEN)
|
||||
if origin == 'null':
|
||||
adapter = self.url_map.bind_to_environ(request.environ)
|
||||
endpoint = adapter.match()[0]
|
||||
if not getattr(endpoint, 'allow_null_origin', False):
|
||||
abort(HTTPStatus.FORBIDDEN)
|
||||
|
||||
with processing(request):
|
||||
data = self.dispatch_request(request)
|
||||
if not isinstance(data, (Response, exceptions.HTTPException)):
|
||||
response = self.make_response(request, data)
|
||||
else:
|
||||
response = data
|
||||
|
||||
if origin and isinstance(response, Response):
|
||||
response.headers['Access-Control-Allow-Origin'] = origin
|
||||
response.headers['Vary'] = 'Origin'
|
||||
method = request.headers.get('Access-Control-Request-Method')
|
||||
if method:
|
||||
response.headers['Access-Control-Allow-Methods'] = method
|
||||
headers = request.headers.get('Access-Control-Request-Headers')
|
||||
if headers:
|
||||
response.headers['Access-Control-Allow-Headers'] = headers
|
||||
response.headers['Access-Control-Max-Age'] = config.getint(
|
||||
'web', 'cache_timeout')
|
||||
return response(environ, start_response)
|
||||
finally:
|
||||
logger.info('%s in %i ms', request, duration())
|
||||
|
||||
def __call__(self, environ, start_response):
|
||||
return self.wsgi_app(environ, start_response)
|
||||
|
||||
Reference in New Issue
Block a user