Add default logging handler to web.run_app (#3243) (#3324)

CHANGES/3324.feature

@@ -0,0 +1,3 @@
+Add default logging handler to web.run_app
+
+If the `Application.debug` flag is set and the default logger `aiohttp.access` is used, access logs will now be output using a `stderr` `StreamHandler` if no handlers are attached. Furthermore, if the default logger has no log level set, the log level will be set to `DEBUG`.

CONTRIBUTORS.txt

@@ -31,6 +31,7 @@ Andrej Antonov
 Andrew Leech
 Andrew Lytvyn
 Andrew Svetlov
+Andrew Zhou
 Andrii Soldatenko
 Antoine Pietri
 Anton Kasyanov

aiohttp/web.py

@@ -75,6 +75,13 @@ def run_app(app: Union[Application, Awaitable[Application]], *,
 
     app = cast(Application, app)
 
+    # Configure if and only if in debugging mode and using the default logger
+    if app.debug and access_log.name == 'aiohttp.access':
+        if access_log.level == logging.NOTSET:
+            access_log.setLevel(logging.DEBUG)
+        if not access_log.hasHandlers():
+            access_log.addHandler(logging.StreamHandler())
+
     runner = AppRunner(app, handle_signals=handle_signals,
                        access_log_class=access_log_class,
                        access_log_format=access_log_format,

docs/logging.rst

@@ -28,24 +28,24 @@ configuring whole loggers in your application.
 Access logs
 -----------
 
-Access log by default is switched on and uses ``'aiohttp.access'``
-logger name.
+Access logs are enabled by default. If the `debug` flag is set, and the default
+logger ``'aiohttp.access'`` is used, access logs will be output to
+:obj:`~sys.stderr` if no handlers are attached.
+Furthermore, if the default logger has no log level set, the log level will be
+set to :obj:`logging.DEBUG`.
 
-The log may be controlled by :meth:`aiohttp.web.AppRunner` and
+This logging may be controlled by :meth:`aiohttp.web.AppRunner` and
 :func:`aiohttp.web.run_app`.
 
-
-Pass *access_log* parameter with value of :class:`logging.Logger`
-instance to override default logger.
+To override the default logger, pass an instance of :class:`logging.Logger` to
+override the default logger.
 
 .. note::
 
-   Use ``web.run_app(app, access_log=None)`` for disabling access logs.
-
+   Use ``web.run_app(app, access_log=None)`` to disable access logs.
 
-Other parameter called *access_log_format* may be used for specifying log
-format (see below).
 
+In addition, *access_log_format* may be used to specify the log format.
 
 .. _aiohttp-logging-access-log-format-spec:
 
@@ -85,15 +85,15 @@ request and response:
 | ``%{FOO}o``  | ``response.headers['FOO']``                             |
 +--------------+---------------------------------------------------------+
 
-Default access log format is::
+The default access log format is::
 
    '%a %t "%r" %s %b "%{Referer}i" "%{User-Agent}i"'
 
 .. versionadded:: 2.3.0
 
 *access_log_class* introduced.
 
-Example of drop-in replacement for :class:`aiohttp.helpers.AccessLogger`::
+Example of a drop-in replacement for :class:`aiohttp.helpers.AccessLogger`::
 
   from aiohttp.abc import AbstractAccessLogger
 
@@ -110,13 +110,13 @@ Example of drop-in replacement for :class:`aiohttp.helpers.AccessLogger`::
 Gunicorn access logs
 ^^^^^^^^^^^^^^^^^^^^
 When `Gunicorn <http://docs.gunicorn.org/en/latest/index.html>`_ is used for
-:ref:`deployment <aiohttp-deployment-gunicorn>` its default access log format
+:ref:`deployment <aiohttp-deployment-gunicorn>`, its default access log format
 will be automatically replaced with the default aiohttp's access log format.
 
 If Gunicorn's option access_logformat_ is
-specified explicitly it should use aiohttp's format specification.
+specified explicitly, it should use aiohttp's format specification.
 
-Gunicorn access log works only if accesslog_ is specified explicitly in your
+Gunicorn's access log works only if accesslog_ is specified explicitly in your
 config or as a command line option.
 This configuration can be either a path or ``'-'``. If the application uses
 a custom logging setup intercepting the ``'gunicorn.access'`` logger,
@@ -129,13 +129,13 @@ access log file upon every startup.
 Error logs
 ----------
 
-*aiohttp.web* uses logger named ``'aiohttp.server'`` to store errors
+:mod:`aiohttp.web` uses a logger named ``'aiohttp.server'`` to store errors
 given on web requests handling.
 
-The log is enabled by default.
+This log is enabled by default.
 
-To use different logger name please pass *logger* parameter
-(:class:`logging.Logger` instance) to :meth:`aiohttp.web.AppRunner` constructor.
+To use a different logger name, pass *logger* (:class:`logging.Logger`
+instance) to the :meth:`aiohttp.web.AppRunner` constructor.
 
 
 .. _access_logformat:

tests/test_run_app.py

@@ -1,5 +1,6 @@
 import asyncio
 import contextlib
+import logging
 import os
 import platform
 import signal
@@ -539,3 +540,80 @@ async def make_app():
                                                   reuse_port=None)
     startup_handler.assert_called_once_with(mock.ANY)
     cleanup_handler.assert_called_once_with(mock.ANY)
+
+
+def test_run_app_default_logger(monkeypatch, patched_loop):
+    logger = web.access_logger
+    attrs = {
+        'hasHandlers.return_value': False,
+        'level': logging.NOTSET,
+        'name': 'aiohttp.access',
+    }
+    mock_logger = mock.create_autospec(logger, name='mock_access_logger')
+    mock_logger.configure_mock(**attrs)
+
+    app = web.Application(debug=True)
+    web.run_app(app,
+                print=stopper(patched_loop),
+                access_log=mock_logger)
+    mock_logger.setLevel.assert_any_call(logging.DEBUG)
+    mock_logger.hasHandlers.assert_called_with()
+    assert isinstance(mock_logger.addHandler.call_args[0][0],
+                      logging.StreamHandler)
+
+
+def test_run_app_default_logger_setup_requires_debug(patched_loop):
+    logger = web.access_logger
+    attrs = {
+        'hasHandlers.return_value': False,
+        'level': logging.NOTSET,
+        'name': 'aiohttp.access',
+    }
+    mock_logger = mock.create_autospec(logger, name='mock_access_logger')
+    mock_logger.configure_mock(**attrs)
+
+    app = web.Application(debug=False)
+    web.run_app(app,
+                print=stopper(patched_loop),
+                access_log=mock_logger)
+    mock_logger.setLevel.assert_not_called()
+    mock_logger.hasHandlers.assert_not_called()
+    mock_logger.addHandler.assert_not_called()
+
+
+def test_run_app_default_logger_setup_requires_default_logger(patched_loop):
+    logger = web.access_logger
+    attrs = {
+        'hasHandlers.return_value': False,
+        'level': logging.NOTSET,
+        'name': None,
+    }
+    mock_logger = mock.create_autospec(logger, name='mock_access_logger')
+    mock_logger.configure_mock(**attrs)
+
+    app = web.Application()
+    web.run_app(app,
+                print=stopper(patched_loop),
+                access_log=mock_logger)
+    mock_logger.setLevel.assert_not_called()
+    mock_logger.hasHandlers.assert_not_called()
+    mock_logger.addHandler.assert_not_called()
+
+
+def test_run_app_default_logger_setup_only_if_unconfigured(patched_loop):
+    logger = web.access_logger
+    attrs = {
+        'hasHandlers.return_value': True,
+        'level': None,
+        'name': 'aiohttp.access',
+    }
+    mock_logger = mock.create_autospec(logger, name='mock_access_logger')
+    mock_logger.configure_mock(**attrs)
+
+    app = web.Application(debug=False)
+    web.run_app(app,
+                print=stopper(patched_loop),
+                access_log=mock_logger)
+    mock_logger.setLevel.assert_not_called()
+    mock_logger.hasHandlers.assert_not_called()
+    mock_logger.addHandler.assert_not_called()