fix bug in access logging when error happens

This commit is contained in:
zenix 2017-04-12 17:39:17 +09:00
parent bf46bcf376
commit f872ceb0d9
2 changed files with 47 additions and 14 deletions

View File

@ -501,13 +501,6 @@ class Sanic:
log.exception( log.exception(
'Exception occured in one of response middleware handlers' 'Exception occured in one of response middleware handlers'
) )
if self.log_config_path:
netlog.info('', extra={
"host": "%s:%d" % request.ip,
"request": "%s %s" % (request.method, request.query_string),
"status": response.status,
"byte": len(response.body)
})
# pass the response to the correct callback # pass the response to the correct callback
if isinstance(response, StreamingHTTPResponse): if isinstance(response, StreamingHTTPResponse):
@ -576,7 +569,8 @@ class Sanic:
after_start=after_start, before_stop=before_stop, after_start=after_start, before_stop=before_stop,
after_stop=after_stop, ssl=ssl, sock=sock, workers=workers, after_stop=after_stop, ssl=ssl, sock=sock, workers=workers,
loop=loop, protocol=protocol, backlog=backlog, loop=loop, protocol=protocol, backlog=backlog,
register_sys_signals=register_sys_signals) register_sys_signals=register_sys_signals,
has_log_file=log_config_path != None)
try: try:
self.is_running = True self.is_running = True
@ -629,7 +623,8 @@ class Sanic:
after_start=after_start, before_stop=before_stop, after_start=after_start, before_stop=before_stop,
after_stop=after_stop, ssl=ssl, sock=sock, after_stop=after_stop, ssl=ssl, sock=sock,
loop=loop or get_event_loop(), protocol=protocol, loop=loop or get_event_loop(), protocol=protocol,
backlog=backlog, run_async=True) backlog=backlog, run_async=True,
has_log_file=log_config_path != None)
return await serve(**server_settings) return await serve(**server_settings)
@ -659,7 +654,7 @@ class Sanic:
before_start=None, after_start=None, before_stop=None, before_start=None, after_start=None, before_stop=None,
after_stop=None, ssl=None, sock=None, workers=1, loop=None, after_stop=None, ssl=None, sock=None, workers=1, loop=None,
protocol=HttpProtocol, backlog=100, stop_event=None, protocol=HttpProtocol, backlog=100, stop_event=None,
register_sys_signals=True, run_async=False): register_sys_signals=True, run_async=False, has_log_file=True):
"""Helper function used by `run` and `create_server`.""" """Helper function used by `run` and `create_server`."""
if isinstance(ssl, dict): if isinstance(ssl, dict):
@ -710,7 +705,8 @@ class Sanic:
'request_max_size': self.config.REQUEST_MAX_SIZE, 'request_max_size': self.config.REQUEST_MAX_SIZE,
'loop': loop, 'loop': loop,
'register_sys_signals': register_sys_signals, 'register_sys_signals': register_sys_signals,
'backlog': backlog 'backlog': backlog,
'has_log_file': has_log_file
} }
# -------------------------------------------- # # -------------------------------------------- #

View File

@ -25,7 +25,8 @@ try:
except ImportError: except ImportError:
async_loop = asyncio async_loop = asyncio
from sanic.log import log from sanic.log import log, netlog
from sanic.response import HTTPResponse
from sanic.request import Request from sanic.request import Request
from sanic.exceptions import ( from sanic.exceptions import (
RequestTimeout, PayloadTooLarge, InvalidUsage, ServerError) RequestTimeout, PayloadTooLarge, InvalidUsage, ServerError)
@ -64,12 +65,14 @@ class HttpProtocol(asyncio.Protocol):
'parser', 'request', 'url', 'headers', 'parser', 'request', 'url', 'headers',
# request config # request config
'request_handler', 'request_timeout', 'request_max_size', 'request_handler', 'request_timeout', 'request_max_size',
# enable or disable access log / error log purpose
'has_log_file',
# connection management # connection management
'_total_request_size', '_timeout_handler', '_last_communication_time') '_total_request_size', '_timeout_handler', '_last_communication_time')
def __init__(self, *, loop, request_handler, error_handler, def __init__(self, *, loop, request_handler, error_handler,
signal=Signal(), connections=set(), request_timeout=60, signal=Signal(), connections=set(), request_timeout=60,
request_max_size=None): request_max_size=None, has_log_file=True):
self.loop = loop self.loop = loop
self.transport = None self.transport = None
self.request = None self.request = None
@ -77,6 +80,7 @@ class HttpProtocol(asyncio.Protocol):
self.url = None self.url = None
self.headers = None self.headers = None
self.signal = signal self.signal = signal
self.has_log_file = has_log_file
self.connections = connections self.connections = connections
self.request_handler = request_handler self.request_handler = request_handler
self.error_handler = error_handler self.error_handler = error_handler
@ -187,6 +191,14 @@ class HttpProtocol(asyncio.Protocol):
response.output( response.output(
self.request.version, keep_alive, self.request.version, keep_alive,
self.request_timeout)) self.request_timeout))
if self.has_log_file:
netlog.info('', extra={
'status': response.status,
'byte': len(response.body),
'host': '%s:%d' % self.request.ip,
'request': '%s %s' % (self.request.method,
self.request.url)
})
except AttributeError: except AttributeError:
log.error( log.error(
('Invalid response object for url {}, ' ('Invalid response object for url {}, '
@ -222,6 +234,14 @@ class HttpProtocol(asyncio.Protocol):
response.transport = self.transport response.transport = self.transport
await response.stream( await response.stream(
self.request.version, keep_alive, self.request_timeout) self.request.version, keep_alive, self.request_timeout)
if self.has_log_file:
netlog.info('', extra={
'status': response.status,
'byte': -1,
'host': '%s:%d' % self.request.ip,
'request': '%s %s' % (self.request.method,
self.request.url)
})
except AttributeError: except AttributeError:
log.error( log.error(
('Invalid response object for url {}, ' ('Invalid response object for url {}, '
@ -257,6 +277,21 @@ class HttpProtocol(asyncio.Protocol):
"Writing error failed, connection closed {}".format(repr(e)), "Writing error failed, connection closed {}".format(repr(e)),
from_error=True) from_error=True)
finally: finally:
if self.has_log_file:
extra = {
'status': response.status,
'host': '',
'request': str(self.request) + str(self.url)
}
if response and isinstance(response, HTTPResponse):
extra['byte'] = len(response.body)
else:
extra['byte'] = -1
if self.request:
extra['host'] = '%s:%d' % self.request.ip,
extra['request'] = '%s %s' % (self.request.method,
self.url)
netlog.info('', extra=extra)
self.transport.close() self.transport.close()
def bail_out(self, message, from_error=False): def bail_out(self, message, from_error=False):
@ -320,7 +355,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
request_timeout=60, ssl=None, sock=None, request_max_size=None, request_timeout=60, ssl=None, sock=None, request_max_size=None,
reuse_port=False, loop=None, protocol=HttpProtocol, backlog=100, reuse_port=False, loop=None, protocol=HttpProtocol, backlog=100,
register_sys_signals=True, run_async=False, connections=None, register_sys_signals=True, run_async=False, connections=None,
signal=Signal()): signal=Signal(), has_log_file=True):
"""Start asynchronous HTTP Server on an individual process. """Start asynchronous HTTP Server on an individual process.
:param host: Address to host on :param host: Address to host on
@ -345,6 +380,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
:param reuse_port: `True` for multiple workers :param reuse_port: `True` for multiple workers
:param loop: asyncio compatible event loop :param loop: asyncio compatible event loop
:param protocol: subclass of asyncio protocol class :param protocol: subclass of asyncio protocol class
:param has_log_file: disable/enable access log and error log
:return: Nothing :return: Nothing
""" """
if not run_async: if not run_async:
@ -366,6 +402,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
error_handler=error_handler, error_handler=error_handler,
request_timeout=request_timeout, request_timeout=request_timeout,
request_max_size=request_max_size, request_max_size=request_max_size,
has_log_file=has_log_file
) )
server_coroutine = loop.create_server( server_coroutine = loop.create_server(