Merge branch 'master' into refactor_server_access_log

This commit is contained in:
Piotr Buliński 2017-10-05 09:26:19 +02:00 committed by GitHub
commit 752ddfa7fc
10 changed files with 162 additions and 244 deletions

View File

@ -9,12 +9,6 @@ A simple example using default settings would be like this:
```python ```python
from sanic import Sanic from sanic import Sanic
from sanic.config import LOGGING
# The default logging handlers are ['accessStream', 'errorStream']
# but we change it to use other handlers here for demo purpose
LOGGING['loggers']['network']['handlers'] = [
'accessSysLog', 'errorSysLog']
app = Sanic('test') app = Sanic('test')
@ -23,14 +17,21 @@ async def test(request):
return response.text('Hello World!') return response.text('Hello World!')
if __name__ == "__main__": if __name__ == "__main__":
app.run(log_config=LOGGING) app.run(debug=True, access_log=True)
``` ```
And to close logging, simply assign log_config=None: To use your own logging config, simply use `logging.config.dictConfig`, or
pass `log_config` when you initialize `Sanic` app:
```python
app = Sanic('test', log_config=LOGGING_CONFIG)
```
And to close logging, simply assign access_log=False:
```python ```python
if __name__ == "__main__": if __name__ == "__main__":
app.run(log_config=None) app.run(access_log=False)
``` ```
This would skip calling logging functions when handling requests. This would skip calling logging functions when handling requests.
@ -38,64 +39,29 @@ And you could even do further in production to gain extra speed:
```python ```python
if __name__ == "__main__": if __name__ == "__main__":
# disable internal messages # disable debug messages
app.run(debug=False, log_config=None) app.run(debug=False, access_log=False)
``` ```
### Configuration ### Configuration
By default, log_config parameter is set to use sanic.config.LOGGING dictionary for configuration. The default configuration provides several predefined `handlers`: By default, log_config parameter is set to use sanic.log.LOGGING_CONFIG_DEFAULTS dictionary for configuration.
- internal (using [logging.StreamHandler](https://docs.python.org/3/library/logging.handlers.html#logging.StreamHandler))<br> There are three `loggers` used in sanic, and **must be defined if you want to create your own logging configuration**:
For internal information console outputs.
- root:<br>
- accessStream (using [logging.StreamHandler](https://docs.python.org/3/library/logging.handlers.html#logging.StreamHandler))<br>
For requests information logging in console
- errorStream (using [logging.StreamHandler](https://docs.python.org/3/library/logging.handlers.html#logging.StreamHandler))<br>
For error message and traceback logging in console.
- accessSysLog (using [logging.handlers.SysLogHandler](https://docs.python.org/3/library/logging.handlers.html#logging.handlers.SysLogHandler))<br>
For requests information logging to syslog.
Currently supports Windows (via localhost:514), Darwin (/var/run/syslog),
Linux (/dev/log) and FreeBSD (/dev/log).<br>
You would not be able to access this property if the directory doesn't exist.
(Notice that in Docker you have to enable everything by yourself)
- errorSysLog (using [logging.handlers.SysLogHandler](https://docs.python.org/3/library/logging.handlers.html#logging.handlers.SysLogHandler))<br>
For error message and traceback logging to syslog.
Currently supports Windows (via localhost:514), Darwin (/var/run/syslog),
Linux (/dev/log) and FreeBSD (/dev/log).<br>
You would not be able to access this property if the directory doesn't exist.
(Notice that in Docker you have to enable everything by yourself)
And `filters`:
- accessFilter (using sanic.log.DefaultFilter)<br>
The filter that allows only levels in `DEBUG`, `INFO`, and `NONE(0)`
- errorFilter (using sanic.log.DefaultFilter)<br>
The filter that allows only levels in `WARNING`, `ERROR`, and `CRITICAL`
There are two `loggers` used in sanic, and **must be defined if you want to create your own logging configuration**:
- sanic:<br>
Used to log internal messages. Used to log internal messages.
- sanic.error:<br>
Used to log error logs.
- network:<br> - sanic.access:<br>
Used to log requests from network, and any information from those requests. Used to log access logs.
#### Log format: #### Log format:
In addition to default parameters provided by python (asctime, levelname, message), In addition to default parameters provided by python (asctime, levelname, message),
Sanic provides additional parameters for network logger with accessFilter: Sanic provides additional parameters for access logger with:
- host (str)<br> - host (str)<br>
request.ip request.ip

View File

@ -1,7 +1,7 @@
from argparse import ArgumentParser from argparse import ArgumentParser
from importlib import import_module from importlib import import_module
from sanic.log import log from sanic.log import logger
from sanic.app import Sanic from sanic.app import Sanic
if __name__ == "__main__": if __name__ == "__main__":
@ -36,9 +36,9 @@ if __name__ == "__main__":
app.run(host=args.host, port=args.port, app.run(host=args.host, port=args.port,
workers=args.workers, debug=args.debug, ssl=ssl) workers=args.workers, debug=args.debug, ssl=ssl)
except ImportError as e: except ImportError as e:
log.error("No module named {} found.\n" logger.error("No module named {} found.\n"
" Example File: project/sanic_server.py -> app\n" " Example File: project/sanic_server.py -> app\n"
" Example Module: project.sanic_server.app" " Example Module: project.sanic_server.app"
.format(e.name)) .format(e.name))
except ValueError as e: except ValueError as e:
log.error("{}".format(e)) logger.error("{}".format(e))

View File

@ -10,11 +10,11 @@ from traceback import format_exc
from urllib.parse import urlencode, urlunparse from urllib.parse import urlencode, urlunparse
from ssl import create_default_context, Purpose from ssl import create_default_context, Purpose
from sanic.config import Config, LOGGING from sanic.config import Config
from sanic.constants import HTTP_METHODS from sanic.constants import HTTP_METHODS
from sanic.exceptions import ServerError, URLBuildError, SanicException from sanic.exceptions import ServerError, URLBuildError, SanicException
from sanic.handlers import ErrorHandler from sanic.handlers import ErrorHandler
from sanic.log import log from sanic.log import logger, error_logger, LOGGING_CONFIG_DEFAULTS
from sanic.response import HTTPResponse, StreamingHTTPResponse from sanic.response import HTTPResponse, StreamingHTTPResponse
from sanic.router import Router from sanic.router import Router
from sanic.server import serve, serve_multiple, HttpProtocol, Signal from sanic.server import serve, serve_multiple, HttpProtocol, Signal
@ -28,30 +28,21 @@ class Sanic:
def __init__(self, name=None, router=None, error_handler=None, def __init__(self, name=None, router=None, error_handler=None,
load_env=True, request_class=None, load_env=True, request_class=None,
log_config=LOGGING, strict_slashes=False): strict_slashes=False, log_config=None):
if log_config:
logging.config.dictConfig(log_config)
# Only set up a default log handler if the
# end-user application didn't set anything up.
if not logging.root.handlers and log.level == logging.NOTSET:
formatter = logging.Formatter(
"%(asctime)s: %(levelname)s: %(message)s")
handler = logging.StreamHandler()
handler.setFormatter(formatter)
log.addHandler(handler)
log.setLevel(logging.INFO)
# Get name from previous stack frame # Get name from previous stack frame
if name is None: if name is None:
frame_records = stack()[1] frame_records = stack()[1]
name = getmodulename(frame_records[1]) name = getmodulename(frame_records[1])
# logging
logging.config.dictConfig(log_config or LOGGING_CONFIG_DEFAULTS)
self.name = name self.name = name
self.router = router or Router() self.router = router or Router()
self.request_class = request_class self.request_class = request_class
self.error_handler = error_handler or ErrorHandler() self.error_handler = error_handler or ErrorHandler()
self.config = Config(load_env=load_env) self.config = Config(load_env=load_env)
self.log_config = log_config
self.request_middleware = deque() self.request_middleware = deque()
self.response_middleware = deque() self.response_middleware = deque()
self.blueprints = {} self.blueprints = {}
@ -584,7 +575,7 @@ class Sanic:
response = await self._run_response_middleware(request, response = await self._run_response_middleware(request,
response) response)
except: except:
log.exception( error_logger.exception(
'Exception occured in one of response middleware handlers' 'Exception occured in one of response middleware handlers'
) )
@ -609,7 +600,7 @@ class Sanic:
def run(self, host=None, port=None, debug=False, ssl=None, def run(self, host=None, port=None, debug=False, ssl=None,
sock=None, workers=1, protocol=None, sock=None, workers=1, protocol=None,
backlog=100, stop_event=None, register_sys_signals=True, backlog=100, stop_event=None, register_sys_signals=True,
log_config=None): access_log=True):
"""Run the HTTP Server and listen until keyboard interrupt or term """Run the HTTP Server and listen until keyboard interrupt or term
signal. On termination, drain connections before closing. signal. On termination, drain connections before closing.
@ -627,12 +618,10 @@ class Sanic:
:param protocol: Subclass of asyncio protocol class :param protocol: Subclass of asyncio protocol class
:return: Nothing :return: Nothing
""" """
if sock is None: if sock is None:
host, port = host or "127.0.0.1", port or 8000 host, port = host or "127.0.0.1", port or 8000
if log_config:
self.log_config = log_config
logging.config.dictConfig(log_config)
if protocol is None: if protocol is None:
protocol = (WebSocketProtocol if self.websocket_enabled protocol = (WebSocketProtocol if self.websocket_enabled
else HttpProtocol) else HttpProtocol)
@ -645,7 +634,7 @@ class Sanic:
host=host, port=port, debug=debug, ssl=ssl, sock=sock, host=host, port=port, debug=debug, ssl=ssl, sock=sock,
workers=workers, protocol=protocol, backlog=backlog, workers=workers, protocol=protocol, backlog=backlog,
register_sys_signals=register_sys_signals, register_sys_signals=register_sys_signals,
has_log=self.log_config is not None) access_log=access_log)
try: try:
self.is_running = True self.is_running = True
@ -654,12 +643,12 @@ class Sanic:
else: else:
serve_multiple(server_settings, workers) serve_multiple(server_settings, workers)
except: except:
log.exception( error_logger.exception(
'Experienced exception while trying to serve') 'Experienced exception while trying to serve')
raise raise
finally: finally:
self.is_running = False self.is_running = False
log.info("Server Stopped") logger.info("Server Stopped")
def stop(self): def stop(self):
"""This kills the Sanic""" """This kills the Sanic"""
@ -672,17 +661,16 @@ class Sanic:
async def create_server(self, host=None, port=None, debug=False, async def create_server(self, host=None, port=None, debug=False,
ssl=None, sock=None, protocol=None, ssl=None, sock=None, protocol=None,
backlog=100, stop_event=None, backlog=100, stop_event=None,
log_config=LOGGING): access_log=True):
"""Asynchronous version of `run`. """Asynchronous version of `run`.
NOTE: This does not support multiprocessing and is not the preferred NOTE: This does not support multiprocessing and is not the preferred
way to run a Sanic application. way to run a Sanic application.
""" """
if sock is None: if sock is None:
host, port = host or "127.0.0.1", port or 8000 host, port = host or "127.0.0.1", port or 8000
if log_config:
logging.config.dictConfig(log_config)
if protocol is None: if protocol is None:
protocol = (WebSocketProtocol if self.websocket_enabled protocol = (WebSocketProtocol if self.websocket_enabled
else HttpProtocol) else HttpProtocol)
@ -696,7 +684,7 @@ class Sanic:
host=host, port=port, debug=debug, ssl=ssl, sock=sock, host=host, port=port, debug=debug, ssl=ssl, sock=sock,
loop=get_event_loop(), protocol=protocol, loop=get_event_loop(), protocol=protocol,
backlog=backlog, run_async=True, backlog=backlog, run_async=True,
has_log=log_config is not None) access_log=access_log)
# Trigger before_start events # Trigger before_start events
await self.trigger_events( await self.trigger_events(
@ -741,7 +729,7 @@ class Sanic:
def _helper(self, host=None, port=None, debug=False, def _helper(self, host=None, port=None, debug=False,
ssl=None, sock=None, workers=1, loop=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, has_log=True): register_sys_signals=True, run_async=False, access_log=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):
# try common aliaseses # try common aliaseses
@ -782,7 +770,7 @@ class Sanic:
'loop': loop, 'loop': loop,
'register_sys_signals': register_sys_signals, 'register_sys_signals': register_sys_signals,
'backlog': backlog, 'backlog': backlog,
'has_log': has_log, 'access_log': access_log,
'websocket_max_size': self.config.WEBSOCKET_MAX_SIZE, 'websocket_max_size': self.config.WEBSOCKET_MAX_SIZE,
'websocket_max_queue': self.config.WEBSOCKET_MAX_QUEUE, 'websocket_max_queue': self.config.WEBSOCKET_MAX_QUEUE,
'graceful_shutdown_timeout': self.config.GRACEFUL_SHUTDOWN_TIMEOUT 'graceful_shutdown_timeout': self.config.GRACEFUL_SHUTDOWN_TIMEOUT
@ -806,9 +794,9 @@ class Sanic:
server_settings[settings_name] = listeners server_settings[settings_name] = listeners
if debug: if debug:
log.setLevel(logging.DEBUG) logger.setLevel(logging.DEBUG)
if self.config.LOGO is not None: if self.config.LOGO is not None:
log.debug(self.config.LOGO) logger.debug(self.config.LOGO)
if run_async: if run_async:
server_settings['run_async'] = True server_settings['run_async'] = True
@ -818,6 +806,6 @@ class Sanic:
proto = "http" proto = "http"
if ssl is not None: if ssl is not None:
proto = "https" proto = "https"
log.info('Goin\' Fast @ {}://{}:{}'.format(proto, host, port)) logger.info('Goin\' Fast @ {}://{}:{}'.format(proto, host, port))
return server_settings return server_settings

View File

@ -1,107 +1,9 @@
import os import os
import sys
import platform
import types import types
from sanic.log import DefaultFilter
SANIC_PREFIX = 'SANIC_' SANIC_PREFIX = 'SANIC_'
try:
from syslog import LOG_DAEMON
except ImportError:
LOG_DAEMON = 24
_address_dict = {
'Windows': ('localhost', 514),
'Darwin': '/var/run/syslog',
'Linux': '/dev/log',
'FreeBSD': '/var/run/log'
}
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'filters': {
'accessFilter': {
'()': DefaultFilter,
'param': [0, 10, 20]
},
'errorFilter': {
'()': DefaultFilter,
'param': [30, 40, 50]
}
},
'formatters': {
'simple': {
'format': '%(asctime)s - (%(name)s)[%(levelname)s]: %(message)s',
'datefmt': '%Y-%m-%d %H:%M:%S'
},
'access': {
'format': '%(asctime)s - (%(name)s)[%(levelname)s][%(host)s]: ' +
'%(request)s %(message)s %(status)d %(byte)d',
'datefmt': '%Y-%m-%d %H:%M:%S'
}
},
'handlers': {
'internal': {
'class': 'logging.StreamHandler',
'filters': ['accessFilter'],
'formatter': 'simple',
'stream': sys.stderr
},
'accessStream': {
'class': 'logging.StreamHandler',
'filters': ['accessFilter'],
'formatter': 'access',
'stream': sys.stderr
},
'errorStream': {
'class': 'logging.StreamHandler',
'filters': ['errorFilter'],
'formatter': 'simple',
'stream': sys.stderr
},
# before you use accessSysLog, be sure that log levels
# 0, 10, 20 have been enabled in you syslog configuration
# otherwise you won't be able to see the output in syslog
# logging file.
'accessSysLog': {
'class': 'logging.handlers.SysLogHandler',
'address': _address_dict.get(platform.system(),
('localhost', 514)),
'facility': LOG_DAEMON,
'filters': ['accessFilter'],
'formatter': 'access'
},
'errorSysLog': {
'class': 'logging.handlers.SysLogHandler',
'address': _address_dict.get(platform.system(),
('localhost', 514)),
'facility': LOG_DAEMON,
'filters': ['errorFilter'],
'formatter': 'simple'
},
},
'loggers': {
'sanic': {
'level': 'INFO',
'handlers': ['internal', 'errorStream']
},
'network': {
'level': 'INFO',
'handlers': ['accessStream', 'errorStream']
}
}
}
# this happens when using container or systems without syslog
# keep things in config would cause file not exists error
_addr = LOGGING['handlers']['accessSysLog']['address']
if type(_addr) is str and not os.path.exists(_addr):
LOGGING['handlers'].pop('accessSysLog')
LOGGING['handlers'].pop('errorSysLog')
class Config(dict): class Config(dict):
def __init__(self, defaults=None, load_env=True, keep_alive=True): def __init__(self, defaults=None, load_env=True, keep_alive=True):

View File

@ -12,7 +12,7 @@ from sanic.exceptions import (
TRACEBACK_WRAPPER_HTML, TRACEBACK_WRAPPER_HTML,
TRACEBACK_WRAPPER_INNER_HTML, TRACEBACK_WRAPPER_INNER_HTML,
TRACEBACK_BORDER) TRACEBACK_BORDER)
from sanic.log import log from sanic.log import logger
from sanic.response import text, html from sanic.response import text, html
@ -90,7 +90,7 @@ class ErrorHandler:
'Exception raised in exception handler "{}" ' 'Exception raised in exception handler "{}" '
'for uri: "{}"\n{}').format( 'for uri: "{}"\n{}').format(
handler.__name__, url, format_exc()) handler.__name__, url, format_exc())
log.error(response_message) logger.error(response_message)
return text(response_message, 500) return text(response_message, 500)
else: else:
return text('An error occurred while handling an error', 500) return text('An error occurred while handling an error', 500)
@ -101,7 +101,7 @@ class ErrorHandler:
Override this method in an ErrorHandler subclass to prevent Override this method in an ErrorHandler subclass to prevent
logging exceptions. logging exceptions.
""" """
getattr(log, level)(message) getattr(logger, level)(message)
def default(self, request, exception): def default(self, request, exception):
self.log(format_exc()) self.log(format_exc())
@ -117,7 +117,7 @@ class ErrorHandler:
response_message = ( response_message = (
'Exception occurred while handling uri: "{}"\n{}'.format( 'Exception occurred while handling uri: "{}"\n{}'.format(
request.url, format_exc())) request.url, format_exc()))
log.error(response_message) logger.error(response_message)
return html(html_output, status=500) return html(html_output, status=500)
else: else:
return html(INTERNAL_SERVER_ERROR_HTML, status=500) return html(INTERNAL_SERVER_ERROR_HTML, status=500)

View File

@ -1,18 +1,63 @@
import logging import logging
import sys
class DefaultFilter(logging.Filter): LOGGING_CONFIG_DEFAULTS = dict(
version=1,
disable_existing_loggers=False,
def __init__(self, param=None): loggers={
self.param = param "root": {
"level": "INFO",
"handlers": ["console"]
},
"sanic.error": {
"level": "INFO",
"handlers": ["error_console"],
"propagate": True,
"qualname": "sanic.error"
},
def filter(self, record): "sanic.access": {
if self.param is None: "level": "INFO",
return True "handlers": ["access_console"],
if record.levelno in self.param: "propagate": True,
return True "qualname": "sanic.access"
return False }
},
handlers={
"console": {
"class": "logging.StreamHandler",
"formatter": "generic",
"stream": sys.stdout
},
"error_console": {
"class": "logging.StreamHandler",
"formatter": "generic",
"stream": sys.stderr
},
"access_console": {
"class": "logging.StreamHandler",
"formatter": "access",
"stream": sys.stdout
},
},
formatters={
"generic": {
"format": "%(asctime)s [%(process)d] [%(levelname)s] %(message)s",
"datefmt": "[%Y-%m-%d %H:%M:%S %z]",
"class": "logging.Formatter"
},
"access": {
"format": "%(asctime)s - (%(name)s)[%(levelname)s][%(host)s]: " +
"%(request)s %(message)s %(status)d %(byte)d",
"datefmt": "[%Y-%m-%d %H:%M:%S %z]",
"class": "logging.Formatter"
},
}
)
log = logging.getLogger('sanic') logger = logging.getLogger('root')
netlog = logging.getLogger('network') error_logger = logging.getLogger('sanic.error')
access_logger = logging.getLogger('sanic.access')

View File

@ -17,7 +17,7 @@ except ImportError:
json_loads = json.loads json_loads = json.loads
from sanic.exceptions import InvalidUsage from sanic.exceptions import InvalidUsage
from sanic.log import log from sanic.log import error_logger
DEFAULT_HTTP_CONTENT_TYPE = "application/octet-stream" DEFAULT_HTTP_CONTENT_TYPE = "application/octet-stream"
@ -127,7 +127,7 @@ class Request(dict):
self.parsed_form, self.parsed_files = ( self.parsed_form, self.parsed_files = (
parse_multipart_form(self.body, boundary)) parse_multipart_form(self.body, boundary))
except Exception: except Exception:
log.exception("Failed when parsing form") error_logger.exception("Failed when parsing form")
return self.parsed_form return self.parsed_form

View File

@ -24,7 +24,7 @@ try:
except ImportError: except ImportError:
async_loop = asyncio async_loop = asyncio
from sanic.log import log, netlog from sanic.log import logger, access_logger
from sanic.response import HTTPResponse from sanic.response import HTTPResponse
from sanic.request import Request from sanic.request import Request
from sanic.exceptions import ( from sanic.exceptions import (
@ -67,8 +67,8 @@ class HttpProtocol(asyncio.Protocol):
'request_handler', 'request_timeout', 'response_timeout', 'request_handler', 'request_timeout', 'response_timeout',
'keep_alive_timeout', 'request_max_size', 'request_class', 'keep_alive_timeout', 'request_max_size', 'request_class',
'is_request_stream', 'router', 'is_request_stream', 'router',
# enable or disable access log / error log purpose # enable or disable access log purpose
'has_log', 'access_log',
# connection management # connection management
'_total_request_size', '_request_timeout_handler', '_total_request_size', '_request_timeout_handler',
'_response_timeout_handler', '_keep_alive_timeout_handler', '_response_timeout_handler', '_keep_alive_timeout_handler',
@ -77,7 +77,7 @@ class HttpProtocol(asyncio.Protocol):
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,
response_timeout=60, keep_alive_timeout=15, response_timeout=60, keep_alive_timeout=15,
request_max_size=None, request_class=None, has_log=True, request_max_size=None, request_class=None, access_log=True,
keep_alive=True, is_request_stream=False, router=None, keep_alive=True, is_request_stream=False, router=None,
state=None, debug=False, **kwargs): state=None, debug=False, **kwargs):
self.loop = loop self.loop = loop
@ -88,7 +88,7 @@ class HttpProtocol(asyncio.Protocol):
self.headers = None self.headers = None
self.router = router self.router = router
self.signal = signal self.signal = signal
self.has_log = has_log self.access_log = access_log
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
@ -190,7 +190,7 @@ class HttpProtocol(asyncio.Protocol):
self.keep_alive_timeout_callback) self.keep_alive_timeout_callback)
) )
else: else:
log.info('KeepAlive Timeout. Closing connection.') logger.info('KeepAlive Timeout. Closing connection.')
self.transport.close() self.transport.close()
# -------------------------------------------- # # -------------------------------------------- #
@ -337,13 +337,13 @@ class HttpProtocol(asyncio.Protocol):
self.keep_alive_timeout)) self.keep_alive_timeout))
self.log_response(response) self.log_response(response)
except AttributeError: except AttributeError:
log.error( logger.error(
('Invalid response object for url {}, ' ('Invalid response object for url {}, '
'Expected Type: HTTPResponse, Actual Type: {}').format( 'Expected Type: HTTPResponse, Actual Type: {}').format(
self.url, type(response))) self.url, type(response)))
self.write_error(ServerError('Invalid response type')) self.write_error(ServerError('Invalid response type'))
except RuntimeError: except RuntimeError:
log.error( logger.error(
'Connection lost before response written @ {}'.format( 'Connection lost before response written @ {}'.format(
self.request.ip)) self.request.ip))
except Exception as e: except Exception as e:
@ -376,13 +376,13 @@ class HttpProtocol(asyncio.Protocol):
self.request.version, keep_alive, self.keep_alive_timeout) self.request.version, keep_alive, self.keep_alive_timeout)
self.log_response(response) self.log_response(response)
except AttributeError: except AttributeError:
log.error( logger.error(
('Invalid response object for url {}, ' ('Invalid response object for url {}, '
'Expected Type: HTTPResponse, Actual Type: {}').format( 'Expected Type: HTTPResponse, Actual Type: {}').format(
self.url, type(response))) self.url, type(response)))
self.write_error(ServerError('Invalid response type')) self.write_error(ServerError('Invalid response type'))
except RuntimeError: except RuntimeError:
log.error( logger.error(
'Connection lost before response written @ {}'.format( 'Connection lost before response written @ {}'.format(
self.request.ip)) self.request.ip))
except Exception as e: except Exception as e:
@ -411,7 +411,7 @@ class HttpProtocol(asyncio.Protocol):
version = self.request.version if self.request else '1.1' version = self.request.version if self.request else '1.1'
self.transport.write(response.output(version)) self.transport.write(response.output(version))
except RuntimeError: except RuntimeError:
log.error( logger.error(
'Connection lost before error written @ {}'.format( 'Connection lost before error written @ {}'.format(
self.request.ip if self.request else 'Unknown')) self.request.ip if self.request else 'Unknown'))
except Exception as e: except Exception as e:
@ -427,16 +427,16 @@ class HttpProtocol(asyncio.Protocol):
def bail_out(self, message, from_error=False): def bail_out(self, message, from_error=False):
if from_error or self.transport.is_closing(): if from_error or self.transport.is_closing():
log.error( logger.error(
("Transport closed @ {} and exception " ("Transport closed @ {} and exception "
"experienced during error handling").format( "experienced during error handling").format(
self.transport.get_extra_info('peername'))) self.transport.get_extra_info('peername')))
log.debug( logger.debug(
'Exception:\n{}'.format(traceback.format_exc())) 'Exception:\n{}'.format(traceback.format_exc()))
else: else:
exception = ServerError(message) exception = ServerError(message)
self.write_error(exception) self.write_error(exception)
log.error(message) logger.error(message)
def cleanup(self): def cleanup(self):
"""This is called when KeepAlive feature is used, """This is called when KeepAlive feature is used,
@ -500,7 +500,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
ssl=None, sock=None, request_max_size=None, reuse_port=False, ssl=None, sock=None, request_max_size=None, reuse_port=False,
loop=None, protocol=HttpProtocol, backlog=100, 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(), request_class=None, has_log=True, signal=Signal(), request_class=None, access_log=True,
keep_alive=True, is_request_stream=False, router=None, keep_alive=True, is_request_stream=False, router=None,
websocket_max_size=None, websocket_max_queue=None, state=None, websocket_max_size=None, websocket_max_queue=None, state=None,
graceful_shutdown_timeout=15.0): graceful_shutdown_timeout=15.0):
@ -529,7 +529,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
: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 request_class: Request class to use :param request_class: Request class to use
:param has_log: disable/enable access log and error log :param access_log: disable/enable access log
:param is_request_stream: disable/enable Request.stream :param is_request_stream: disable/enable Request.stream
:param router: Router object :param router: Router object
:return: Nothing :return: Nothing
@ -554,7 +554,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
keep_alive_timeout=keep_alive_timeout, keep_alive_timeout=keep_alive_timeout,
request_max_size=request_max_size, request_max_size=request_max_size,
request_class=request_class, request_class=request_class,
has_log=has_log, access_log=access_log,
keep_alive=keep_alive, keep_alive=keep_alive,
is_request_stream=is_request_stream, is_request_stream=is_request_stream,
router=router, router=router,
@ -586,7 +586,7 @@ def serve(host, port, request_handler, error_handler, before_start=None,
try: try:
http_server = loop.run_until_complete(server_coroutine) http_server = loop.run_until_complete(server_coroutine)
except: except:
log.exception("Unable to start server") logger.exception("Unable to start server")
return return
trigger_events(after_start, loop) trigger_events(after_start, loop)
@ -597,14 +597,15 @@ def serve(host, port, request_handler, error_handler, before_start=None,
try: try:
loop.add_signal_handler(_signal, loop.stop) loop.add_signal_handler(_signal, loop.stop)
except NotImplementedError: except NotImplementedError:
log.warn('Sanic tried to use loop.add_signal_handler but it is' logger.warn(
'Sanic tried to use loop.add_signal_handler but it is'
' not implemented on this platform.') ' not implemented on this platform.')
pid = os.getpid() pid = os.getpid()
try: try:
log.info('Starting worker [{}]'.format(pid)) logger.info('Starting worker [{}]'.format(pid))
loop.run_forever() loop.run_forever()
finally: finally:
log.info("Stopping worker [{}]".format(pid)) logger.info("Stopping worker [{}]".format(pid))
# Run the on_stop function if provided # Run the on_stop function if provided
trigger_events(before_stop, loop) trigger_events(before_stop, loop)
@ -666,7 +667,7 @@ def serve_multiple(server_settings, workers):
server_settings['port'] = None server_settings['port'] = None
def sig_handler(signal, frame): def sig_handler(signal, frame):
log.info("Received signal {}. Shutting down.".format( logger.info("Received signal {}. Shutting down.".format(
Signals(signal).name)) Signals(signal).name))
for process in processes: for process in processes:
os.kill(process.pid, SIGINT) os.kill(process.pid, SIGINT)

View File

@ -1,7 +1,7 @@
import traceback import traceback
from json import JSONDecodeError from json import JSONDecodeError
from sanic.log import log from sanic.log import logger
HOST = '127.0.0.1' HOST = '127.0.0.1'
PORT = 42101 PORT = 42101
@ -19,7 +19,7 @@ class SanicTestClient:
url = 'http://{host}:{port}{uri}'.format( url = 'http://{host}:{port}{uri}'.format(
host=HOST, port=PORT, uri=uri) host=HOST, port=PORT, uri=uri)
log.info(url) logger.info(url)
conn = aiohttp.TCPConnector(verify_ssl=False) conn = aiohttp.TCPConnector(verify_ssl=False)
async with aiohttp.ClientSession( async with aiohttp.ClientSession(
cookies=cookies, connector=conn) as session: cookies=cookies, connector=conn) as session:
@ -61,7 +61,7 @@ class SanicTestClient:
**request_kwargs) **request_kwargs)
results[-1] = response results[-1] = response
except Exception as e: except Exception as e:
log.error( logger.error(
'Exception:\n{}'.format(traceback.format_exc())) 'Exception:\n{}'.format(traceback.format_exc()))
exceptions.append(e) exceptions.append(e)
self.app.stop() self.app.stop()

View File

@ -1,8 +1,8 @@
import uuid import uuid
from importlib import reload from importlib import reload
from sanic.config import LOGGING
from sanic.response import text from sanic.response import text
from sanic.log import LOGGING_CONFIG_DEFAULTS
from sanic import Sanic from sanic import Sanic
from io import StringIO from io import StringIO
import logging import logging
@ -40,18 +40,34 @@ def test_log():
assert rand_string in log_text assert rand_string in log_text
def test_default_log_fmt(): def test_logging_defaults():
reset_logging() reset_logging()
Sanic() app = Sanic("test_logging")
for fmt in [h.formatter for h in logging.getLogger('sanic').handlers]:
assert fmt._fmt == LOGGING['formatters']['simple']['format']
for fmt in [h.formatter for h in logging.getLogger('root').handlers]:
assert fmt._fmt == LOGGING_CONFIG_DEFAULTS['formatters']['generic']['format']
for fmt in [h.formatter for h in logging.getLogger('sanic.error').handlers]:
assert fmt._fmt == LOGGING_CONFIG_DEFAULTS['formatters']['generic']['format']
for fmt in [h.formatter for h in logging.getLogger('sanic.access').handlers]:
assert fmt._fmt == LOGGING_CONFIG_DEFAULTS['formatters']['access']['format']
def test_logging_pass_customer_logconfig():
reset_logging() reset_logging()
Sanic(log_config=None)
for fmt in [h.formatter for h in logging.getLogger('sanic').handlers]:
assert fmt._fmt == "%(asctime)s: %(levelname)s: %(message)s"
modified_config = LOGGING_CONFIG_DEFAULTS
modified_config['formatters']['generic']['format'] = '%(asctime)s - (%(name)s)[%(levelname)s]: %(message)s'
modified_config['formatters']['access']['format'] = '%(asctime)s - (%(name)s)[%(levelname)s]: %(message)s'
if __name__ == "__main__": app = Sanic("test_logging", log_config=modified_config)
test_log()
for fmt in [h.formatter for h in logging.getLogger('root').handlers]:
assert fmt._fmt == modified_config['formatters']['generic']['format']
for fmt in [h.formatter for h in logging.getLogger('sanic.error').handlers]:
assert fmt._fmt == modified_config['formatters']['generic']['format']
for fmt in [h.formatter for h in logging.getLogger('sanic.access').handlers]:
assert fmt._fmt == modified_config['formatters']['access']['format']