Refactor uvicorn logger setup

docs/index.md

@@ -205,8 +205,7 @@ There are several ways to run uvicorn directly from your application.
 
 If you're looking for a programmatic equivalent of the `uvicorn` command line interface, use `uvicorn.run()`:
 
-```python
-# main.py
+```py title="main.py"
 import uvicorn
 
 async def app(scope, receive, send):
@@ -275,9 +274,7 @@ For more information, see the [deployment documentation](deployment.md).
 
 The `--factory` flag allows loading the application from a factory function, rather than an application instance directly. The factory will be called with no arguments and should return an ASGI application.
 
-**example.py**:
-
-```python
+```py title="example.py"
 def create_app():
     app = ...
     return app

docs/logging.md

@@ -0,0 +1,40 @@
+# Logging
+
+Logging in Python is pretty complex, and there are many different ways to do it.
+This document is intended to provide an overview about the logger objects available in **Uvicorn**.
+
+### Loggers
+
+**Uvicorn** has many loggers available, each one with a different purpose.
+
+It contains an ancestor logger called `uvicorn`, and then multiple children loggers.
+
+#### Server Logger (`uvicorn.server`)
+
+This logger is used to log information about the core server functionality, such as startup and shutdown.
+
+#### WebSocket Logger (`uvicorn.websocket`)
+
+This logger is used to log server-side information about WebSocket protocol messages.
+
+#### HTTP Logger (`uvicorn.http`)
+
+This logger is used to log server-side information about HTTP protocol messages.
+
+#### Access Logger (`uvicorn.access`)
+
+This logger is used to log client-side information about each request/response cycle.
+
+#### ASGI Logger (`uvicorn.asgi`)
+
+This logger is used to log low-level server-side ASGI messages. Only available when `--log-level` is set to `trace`.
+
+### Configuration
+
+**Uvicorn** uses the standard Python `logging` module to handle logging.
+
+This section will be used to teach people how to configure uvicorn loggers.
+
+### Tutorials
+
+This section will be used to link tutorials.

mkdocs.yml

@@ -24,12 +24,18 @@ edit_uri: ""
 nav:
   - Introduction: "index.md"
   - Settings: "settings.md"
+  - Logging: "logging.md"
   - Deployment: "deployment.md"
   - Server Behavior: "server-behavior.md"
   - Contributing: "contributing.md"
 
 markdown_extensions:
   - admonition
+  - pymdownx.highlight:
+      anchor_linenums: true
+  - pymdownx.inlinehilite
+  - pymdownx.snippets
+  - pymdownx.superfences
   - codehilite:
       css_class: highlight
   - toc:

tests/middleware/test_logging.py

@@ -66,15 +66,13 @@ async def test_trace_logging_on_http_protocol(http_protocol, caplog, logging_con
         http=http_protocol,
         log_config=logging_config,
     )
-    with caplog_for_logger(caplog, "uvicorn.error"):
+    with caplog_for_logger(caplog, "uvicorn.http"):
         async with run_server(config):
             async with httpx.AsyncClient() as client:
                 response = await client.get("http://127.0.0.1:8000")
         assert response.status_code == 204
         messages = [
-            record.message
-            for record in caplog.records
-            if record.name == "uvicorn.error"
+            record.message for record in caplog.records if record.name == "uvicorn.http"
         ]
         assert any(" - HTTP connection made" in message for message in messages)
         assert any(" - HTTP connection lost" in message for message in messages)
@@ -102,16 +100,21 @@ async def open_connection(url):
         log_config=logging_config,
         ws=ws_protocol,
     )
-    with caplog_for_logger(caplog, "uvicorn.error"):
+    with caplog_for_logger(caplog, "uvicorn.http"), caplog_for_logger(
+        caplog, "uvicorn.websockets"
+    ):
         async with run_server(config):
             is_open = await open_connection("ws://127.0.0.1:8000")
         assert is_open
+        messages = [
+            record.message for record in caplog.records if record.name == "uvicorn.http"
+        ]
+        assert any(" - Upgrading to WebSocket" in message for message in messages)
         messages = [
             record.message
             for record in caplog.records
-            if record.name == "uvicorn.error"
+            if record.name == "uvicorn.websockets"
         ]
-        assert any(" - Upgrading to WebSocket" in message for message in messages)
         assert any(" - WebSocket connection made" in message for message in messages)
         assert any(" - WebSocket connection lost" in message for message in messages)
 

tests/protocols/test_http.py

@@ -808,8 +808,8 @@ async def test_invalid_http_request(request_line, protocol_cls, caplog):
     app = Response("Hello, world", media_type="text/plain")
     request = INVALID_REQUEST_TEMPLATE % request_line
 
-    caplog.set_level(logging.INFO, logger="uvicorn.error")
-    logging.getLogger("uvicorn.error").propagate = True
+    caplog.set_level(logging.INFO, logger="uvicorn.http")
+    logging.getLogger("uvicorn.http").propagate = True
 
     protocol = get_connected_protocol(app, protocol_cls)
     protocol.data_received(request)

tests/test_config.py

@@ -254,7 +254,7 @@ def test_app_unimportable_other(caplog: pytest.LogCaptureFixture) -> None:
     error_messages = [
         record.message
         for record in caplog.records
-        if record.name == "uvicorn.error" and record.levelname == "ERROR"
+        if record.name == "uvicorn.server" and record.levelname == "ERROR"
     ]
     assert (
         'Error loading ASGI app. Attribute "app" not found in module "tests.test_config".'  # noqa: E501
@@ -485,8 +485,10 @@ def test_config_log_level(log_level: int) -> None:
     config = Config(app=asgi_app, log_level=log_level)
     config.load()
 
-    assert logging.getLogger("uvicorn.error").level == log_level
+    assert logging.getLogger("uvicorn.server").level == log_level
     assert logging.getLogger("uvicorn.access").level == log_level
+    assert logging.getLogger("uvicorn.http").level == log_level
+    assert logging.getLogger("uvicorn.websockets").level == log_level
     assert logging.getLogger("uvicorn.asgi").level == log_level
     assert config.log_level == log_level
 

tests/test_lifespan.py

@@ -155,7 +155,7 @@ async def test():
     error_messages = [
         record.message
         for record in caplog.records
-        if record.name == "uvicorn.error" and record.levelname == "ERROR"
+        if record.name == "uvicorn.server" and record.levelname == "ERROR"
     ]
     assert "the lifespan event failed" in error_messages.pop(0)
     assert "Application startup failed. Exiting." in error_messages.pop(0)
@@ -240,7 +240,7 @@ async def test():
     error_messages = [
         record.message
         for record in caplog.records
-        if record.name == "uvicorn.error" and record.levelname == "ERROR"
+        if record.name == "uvicorn.server" and record.levelname == "ERROR"
     ]
     assert "the lifespan event failed" in error_messages.pop(0)
     assert "Application shutdown failed. Exiting." in error_messages.pop(0)

tests/test_main.py

@@ -90,7 +90,7 @@ def test_run_invalid_app_config_combination(caplog: pytest.LogCaptureFixture) ->
     with pytest.raises(SystemExit) as exit_exception:
         run(app, reload=True)
     assert exit_exception.value.code == 1
-    assert caplog.records[-1].name == "uvicorn.error"
+    assert caplog.records[-1].name == "uvicorn.server"
     assert caplog.records[-1].levelno == WARNING
     assert caplog.records[-1].message == (
         "You must pass the application as an import string to enable "

uvicorn/config.py

@@ -117,12 +117,14 @@
     },
     "loggers": {
         "uvicorn": {"handlers": ["default"], "level": "INFO", "propagate": False},
-        "uvicorn.error": {"level": "INFO"},
+        "uvicorn.server": {"level": "INFO"},
+        "uvicorn.websockets": {"level": "INFO"},
+        "uvicorn.http": {"level": "INFO"},
         "uvicorn.access": {"handlers": ["access"], "level": "INFO", "propagate": False},
     },
 }
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 def create_ssl_context(
@@ -422,8 +424,10 @@ def configure_logging(self) -> None:
                 log_level = LOG_LEVELS[self.log_level]
             else:
                 log_level = self.log_level
-            logging.getLogger("uvicorn.error").setLevel(log_level)
+            logging.getLogger("uvicorn.server").setLevel(log_level)
             logging.getLogger("uvicorn.access").setLevel(log_level)
+            logging.getLogger("uvicorn.http").setLevel(log_level)
+            logging.getLogger("uvicorn.websockets").setLevel(log_level)
             logging.getLogger("uvicorn.asgi").setLevel(log_level)
         if self.access_log is False:
             logging.getLogger("uvicorn.access").handlers = []

uvicorn/lifespan/on.py

@@ -34,7 +34,7 @@ def __init__(self, config: Config) -> None:
             config.load()
 
         self.config = config
-        self.logger = logging.getLogger("uvicorn.error")
+        self.logger = logging.getLogger("uvicorn.server")
         self.startup_event = asyncio.Event()
         self.shutdown_event = asyncio.Event()
         self.receive_queue: "Queue[LifespanReceiveMessage]" = asyncio.Queue()

uvicorn/loops/asyncio.py

@@ -2,7 +2,7 @@
 import logging
 import sys
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 def asyncio_setup(use_subprocess: bool = False) -> None:  # pragma: no cover

uvicorn/main.py

@@ -41,7 +41,7 @@
 
 STARTUP_FAILURE = 3
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 def print_version(ctx: click.Context, param: click.Parameter, value: bool) -> None:
@@ -552,7 +552,7 @@ def run(
     server = Server(config=config)
 
     if (config.reload or config.workers > 1) and not isinstance(app, str):
-        logger = logging.getLogger("uvicorn.error")
+        logger = logging.getLogger("uvicorn.server")
         logger.warning(
             "You must pass the application as an import string to enable 'reload' or "
             "'workers'."

uvicorn/protocols/http/h11_impl.py

@@ -76,7 +76,7 @@ def __init__(
         self.config = config
         self.app = config.loaded_app
         self.loop = _loop or asyncio.get_event_loop()
-        self.logger = logging.getLogger("uvicorn.error")
+        self.logger = logging.getLogger("uvicorn.http")
         self.access_logger = logging.getLogger("uvicorn.access")
         self.access_log = self.access_logger.hasHandlers()
         self.conn = h11.Connection(h11.SERVER, config.h11_max_incomplete_event_size)

uvicorn/protocols/http/httptools_impl.py

@@ -74,7 +74,7 @@ def __init__(
         self.config = config
         self.app = config.loaded_app
         self.loop = _loop or asyncio.get_event_loop()
-        self.logger = logging.getLogger("uvicorn.error")
+        self.logger = logging.getLogger("uvicorn.http")
         self.access_logger = logging.getLogger("uvicorn.access")
         self.access_log = self.access_logger.hasHandlers()
         self.parser = httptools.HttpRequestParser(self)

uvicorn/protocols/websockets/websockets_impl.py

@@ -104,7 +104,7 @@ def __init__(
             ping_interval=self.config.ws_ping_interval,
             ping_timeout=self.config.ws_ping_timeout,
             extensions=extensions,
-            logger=logging.getLogger("uvicorn.error"),
+            logger=logging.getLogger("uvicorn.websockets"),
             extra_headers=[],
         )
 

uvicorn/protocols/websockets/wsproto_impl.py

@@ -26,7 +26,7 @@ def __init__(self, config, server_state, _loop=None):
         self.config = config
         self.app = config.loaded_app
         self.loop = _loop or asyncio.get_event_loop()
-        self.logger = logging.getLogger("uvicorn.error")
+        self.logger = logging.getLogger("uvicorn.websockets")
         self.root_path = config.root_path
 
         # Shared server state

uvicorn/server.py

@@ -30,7 +30,7 @@
     signal.SIGTERM,  # Unix signal 15. Sent by `kill <pid>`.
 )
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 class ServerState:

uvicorn/supervisors/basereload.py

@@ -17,7 +17,7 @@
     signal.SIGTERM,  # Unix signal 15. Sent by `kill <pid>`.
 )
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 class BaseReload:

uvicorn/supervisors/multiprocess.py

@@ -17,7 +17,7 @@
     signal.SIGTERM,  # Unix signal 15. Sent by `kill <pid>`.
 )
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 class Multiprocess:

uvicorn/supervisors/statreload.py

@@ -6,7 +6,7 @@
 from uvicorn.config import Config
 from uvicorn.supervisors.basereload import BaseReload
 
-logger = logging.getLogger("uvicorn.error")
+logger = logging.getLogger("uvicorn.server")
 
 
 class StatReload(BaseReload):

uvicorn/supervisors/watchgodreload.py

@@ -14,7 +14,8 @@
 
     DirEntry = os.DirEntry[str]
 
-logger = logging.getLogger("uvicorn.error")
+
+logger = logging.getLogger("uvicorn.server")
 
 
 class CustomWatcher(DefaultWatcher):

uvicorn/workers.py

@@ -22,7 +22,7 @@ class UvicornWorker(Worker):
     def __init__(self, *args: Any, **kwargs: Any) -> None:
         super(UvicornWorker, self).__init__(*args, **kwargs)
 
-        logger = logging.getLogger("uvicorn.error")
+        logger = logging.getLogger("uvicorn.server")
         logger.handlers = self.log.error_log.handlers
         logger.setLevel(self.log.error_log.level)
         logger.propagate = False