diff --git a/sanic/app.py b/sanic/app.py index 70d7b0b5..52892669 100644 --- a/sanic/app.py +++ b/sanic/app.py @@ -1573,8 +1573,9 @@ class Sanic(BaseSanic, RunnerMixin, metaclass=TouchUpMeta): "shutdown", ): raise SanicException(f"Invalid server event: {event}") - if self.state.verbosity >= 1: - logger.debug(f"Triggering server events: {event}") + logger.debug( + f"Triggering server events: {event}", extra={"verbosity": 1} + ) reverse = concern == "shutdown" if loop is None: loop = self.loop diff --git a/sanic/application/state.py b/sanic/application/state.py index 724ddcb5..5975c2a6 100644 --- a/sanic/application/state.py +++ b/sanic/application/state.py @@ -9,7 +9,7 @@ from socket import socket from ssl import SSLContext from typing import TYPE_CHECKING, Any, Dict, List, Optional, Set, Union -from sanic.log import logger +from sanic.log import VerbosityFilter, logger from sanic.server.async_server import AsyncioServer @@ -91,6 +91,9 @@ class ApplicationState: if getattr(self.app, "configure_logging", False) and self.app.debug: logger.setLevel(logging.DEBUG) + def set_verbosity(self, value: int): + VerbosityFilter.verbosity = value + @property def is_debug(self): return self.mode is Mode.DEBUG diff --git a/sanic/asgi.py b/sanic/asgi.py index 107e8931..3dbd95a7 100644 --- a/sanic/asgi.py +++ b/sanic/asgi.py @@ -25,27 +25,28 @@ class Lifespan: def __init__(self, asgi_app: ASGIApp) -> None: self.asgi_app = asgi_app - if self.asgi_app.sanic_app.state.verbosity > 0: - if ( - "server.init.before" - in self.asgi_app.sanic_app.signal_router.name_index - ): - logger.debug( - 'You have set a listener for "before_server_start" ' - "in ASGI mode. " - "It will be executed as early as possible, but not before " - "the ASGI server is started." - ) - if ( - "server.shutdown.after" - in self.asgi_app.sanic_app.signal_router.name_index - ): - logger.debug( - 'You have set a listener for "after_server_stop" ' - "in ASGI mode. " - "It will be executed as late as possible, but not after " - "the ASGI server is stopped." - ) + if ( + "server.init.before" + in self.asgi_app.sanic_app.signal_router.name_index + ): + logger.debug( + 'You have set a listener for "before_server_start" ' + "in ASGI mode. " + "It will be executed as early as possible, but not before " + "the ASGI server is started.", + extra={"verbosity": 1}, + ) + if ( + "server.shutdown.after" + in self.asgi_app.sanic_app.signal_router.name_index + ): + logger.debug( + 'You have set a listener for "after_server_stop" ' + "in ASGI mode. " + "It will be executed as late as possible, but not after " + "the ASGI server is stopped.", + extra={"verbosity": 1}, + ) async def startup(self) -> None: """ diff --git a/sanic/log.py b/sanic/log.py index 4b3b960c..5911e832 100644 --- a/sanic/log.py +++ b/sanic/log.py @@ -61,21 +61,36 @@ class Colors(str, Enum): # no cov END = "\033[0m" BLUE = "\033[01;34m" GREEN = "\033[01;32m" - YELLOW = "\033[01;33m" + PURPLE = "\033[01;35m" RED = "\033[01;31m" + SANIC = "\033[38;2;255;13;104m" + YELLOW = "\033[01;33m" +class VerbosityFilter(logging.Filter): + verbosity: int = 0 + + def filter(self, record: logging.LogRecord) -> bool: + verbosity = getattr(record, "verbosity", 0) + return verbosity <= self.verbosity + + +_verbosity_filter = VerbosityFilter() + logger = logging.getLogger("sanic.root") # no cov +logger.addFilter(_verbosity_filter) """ General Sanic logger """ error_logger = logging.getLogger("sanic.error") # no cov +error_logger.addFilter(_verbosity_filter) """ Logger used by Sanic for error logging """ access_logger = logging.getLogger("sanic.access") # no cov +access_logger.addFilter(_verbosity_filter) """ Logger used by Sanic for access logging """ diff --git a/sanic/touchup/schemes/ode.py b/sanic/touchup/schemes/ode.py index 7c6ed3d7..6303ed17 100644 --- a/sanic/touchup/schemes/ode.py +++ b/sanic/touchup/schemes/ode.py @@ -24,9 +24,7 @@ class OptionalDispatchEvent(BaseScheme): raw_source = getsource(method) src = dedent(raw_source) tree = parse(src) - node = RemoveDispatch( - self._registered_events, self.app.state.verbosity - ).visit(tree) + node = RemoveDispatch(self._registered_events).visit(tree) compiled_src = compile(node, method.__name__, "exec") exec_locals: Dict[str, Any] = {} exec(compiled_src, module_globals, exec_locals) # nosec @@ -64,9 +62,8 @@ class OptionalDispatchEvent(BaseScheme): class RemoveDispatch(NodeTransformer): - def __init__(self, registered_events, verbosity: int = 0) -> None: + def __init__(self, registered_events) -> None: self._registered_events = registered_events - self._verbosity = verbosity def visit_Expr(self, node: Expr) -> Any: call = node.value @@ -83,8 +80,10 @@ class RemoveDispatch(NodeTransformer): if hasattr(event, "s"): event_name = getattr(event, "value", event.s) if self._not_registered(event_name): - if self._verbosity >= 2: - logger.debug(f"Disabling event: {event_name}") + logger.debug( + f"Disabling event: {event_name}", + extra={"verbosity": 2}, + ) return None return node diff --git a/tests/test_asgi.py b/tests/test_asgi.py index d1be5ff2..61d36fa7 100644 --- a/tests/test_asgi.py +++ b/tests/test_asgi.py @@ -222,6 +222,7 @@ def test_listeners_triggered_async(app, caplog): assert after_server_stop app.state.mode = Mode.DEBUG + app.state.verbosity = 0 with caplog.at_level(logging.DEBUG): server.run() diff --git a/tests/test_logging.py b/tests/test_logging.py index c475b00b..274b407c 100644 --- a/tests/test_logging.py +++ b/tests/test_logging.py @@ -209,3 +209,42 @@ def test_access_log_client_ip_reqip(monkeypatch): "request": f"GET {request.scheme}://{request.host}/", }, ) + + +@pytest.mark.parametrize( + "app_verbosity,log_verbosity,exists", + ( + (0, 0, True), + (0, 1, False), + (0, 2, False), + (1, 0, True), + (1, 1, True), + (1, 2, False), + (2, 0, True), + (2, 1, True), + (2, 2, True), + ), +) +def test_verbosity(app, caplog, app_verbosity, log_verbosity, exists): + rand_string = str(uuid.uuid4()) + + @app.get("/") + def log_info(request): + logger.info("DEFAULT") + logger.info(rand_string, extra={"verbosity": log_verbosity}) + return text("hello") + + with caplog.at_level(logging.INFO): + _ = app.test_client.get( + "/", server_kwargs={"verbosity": app_verbosity} + ) + + record = ("sanic.root", logging.INFO, rand_string) + + if exists: + assert record in caplog.record_tuples + else: + assert record not in caplog.record_tuples + + if app_verbosity == 0: + assert ("sanic.root", logging.INFO, "DEFAULT") in caplog.record_tuples