Downgrade warnings to backwater debug messages (#2382)

sanic/asgi.py

@@ -1,14 +1,15 @@
+from __future__ import annotations
+
 import warnings
 
-from typing import Optional
+from typing import TYPE_CHECKING, Optional
 from urllib.parse import quote
 
-import sanic.app  # noqa
-
 from sanic.compat import Header
 from sanic.exceptions import ServerError
 from sanic.helpers import _default
 from sanic.http import Stage
+from sanic.log import logger
 from sanic.models.asgi import ASGIReceive, ASGIScope, ASGISend, MockTransport
 from sanic.request import Request
 from sanic.response import BaseHTTPResponse
@@ -16,30 +17,35 @@ from sanic.server import ConnInfo
 from sanic.server.websockets.connection import WebSocketConnection
 
 
+if TYPE_CHECKING:  # no cov
+    from sanic import Sanic
+
+
 class Lifespan:
-    def __init__(self, asgi_app: "ASGIApp") -> None:
+    def __init__(self, asgi_app: ASGIApp) -> None:
         self.asgi_app = asgi_app
 
-        if (
+        if self.asgi_app.sanic_app.state.verbosity > 0:
-            "server.init.before"
+            if (
-            in self.asgi_app.sanic_app.signal_router.name_index
+                "server.init.before"
-        ):
+                in self.asgi_app.sanic_app.signal_router.name_index
-            warnings.warn(
+            ):
-                'You have set a listener for "before_server_start" '
+                logger.debug(
-                "in ASGI mode. "
+                    'You have set a listener for "before_server_start" '
-                "It will be executed as early as possible, but not before "
+                    "in ASGI mode. "
-                "the ASGI server is started."
+                    "It will be executed as early as possible, but not before "
-            )
+                    "the ASGI server is started."
-        if (
+                )
-            "server.shutdown.after"
+            if (
-            in self.asgi_app.sanic_app.signal_router.name_index
+                "server.shutdown.after"
-        ):
+                in self.asgi_app.sanic_app.signal_router.name_index
-            warnings.warn(
+            ):
-                'You have set a listener for "after_server_stop" '
+                logger.debug(
-                "in ASGI mode. "
+                    'You have set a listener for "after_server_stop" '
-                "It will be executed as late as possible, but not after "
+                    "in ASGI mode. "
-                "the ASGI server is stopped."
+                    "It will be executed as late as possible, but not after "
-            )
+                    "the ASGI server is stopped."
+                )
 
     async def startup(self) -> None:
         """
@@ -88,7 +94,7 @@ class Lifespan:
 
 
 class ASGIApp:
-    sanic_app: "sanic.app.Sanic"
+    sanic_app: Sanic
     request: Request
     transport: MockTransport
     lifespan: Lifespan

tests/test_asgi.py

@@ -1,4 +1,5 @@
 import asyncio
+import logging
 
 from collections import deque, namedtuple
 
@@ -6,6 +7,7 @@ import pytest
 import uvicorn
 
 from sanic import Sanic
+from sanic.application.state import Mode
 from sanic.asgi import MockTransport
 from sanic.exceptions import Forbidden, InvalidUsage, ServiceUnavailable
 from sanic.request import Request
@@ -44,7 +46,7 @@ def protocol(transport):
     return transport.get_protocol()
 
 
-def test_listeners_triggered():
+def test_listeners_triggered(caplog):
     app = Sanic("app")
     before_server_start = False
     after_server_start = False
@@ -82,9 +84,31 @@ def test_listeners_triggered():
     config = uvicorn.Config(app=app, loop="asyncio", limit_max_requests=0)
     server = CustomServer(config=config)
 
-    with pytest.warns(UserWarning):
+    start_message = (
+        '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."
+    )
+    stop_message = (
+        '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."
+    )
+
+    with caplog.at_level(logging.DEBUG):
         server.run()
 
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) not in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) not in caplog.record_tuples
+
     all_tasks = asyncio.all_tasks(asyncio.get_event_loop())
     for task in all_tasks:
         task.cancel()
@@ -94,8 +118,38 @@ def test_listeners_triggered():
     assert before_server_stop
     assert after_server_stop
 
+    app.state.mode = Mode.DEBUG
+    with caplog.at_level(logging.DEBUG):
+        server.run()
 
-def test_listeners_triggered_async(app):
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) not in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) not in caplog.record_tuples
+
+    app.state.verbosity = 2
+    with caplog.at_level(logging.DEBUG):
+        server.run()
+
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) in caplog.record_tuples
+
+
+def test_listeners_triggered_async(app, caplog):
     before_server_start = False
     after_server_start = False
     before_server_stop = False
@@ -132,9 +186,31 @@ def test_listeners_triggered_async(app):
     config = uvicorn.Config(app=app, loop="asyncio", limit_max_requests=0)
     server = CustomServer(config=config)
 
-    with pytest.warns(UserWarning):
+    start_message = (
+        '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."
+    )
+    stop_message = (
+        '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."
+    )
+
+    with caplog.at_level(logging.DEBUG):
         server.run()
 
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) not in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) not in caplog.record_tuples
+
     all_tasks = asyncio.all_tasks(asyncio.get_event_loop())
     for task in all_tasks:
         task.cancel()
@@ -144,6 +220,36 @@ def test_listeners_triggered_async(app):
     assert before_server_stop
     assert after_server_stop
 
+    app.state.mode = Mode.DEBUG
+    with caplog.at_level(logging.DEBUG):
+        server.run()
+
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) not in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) not in caplog.record_tuples
+
+    app.state.verbosity = 2
+    with caplog.at_level(logging.DEBUG):
+        server.run()
+
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        start_message,
+    ) in caplog.record_tuples
+    assert (
+        "sanic.root",
+        logging.DEBUG,
+        stop_message,
+    ) in caplog.record_tuples
+
 
 def test_non_default_uvloop_config_raises_warning(app):
     app.config.USE_UVLOOP = True