Skip to content

Commit

Permalink
aiohttp.wep.Application.make_handler access_log_class support (#2316)
Browse files Browse the repository at this point in the history
* Initial access_log_factory support.

* Added changes.

* abstraction level changes for AccessLogger.

* Added RequestHandler docstrings.

* Fix changes naming.

* Added access_log_class check for Application.make_handler

* Added basic tests for access_log_class.

* Added docs for access_log_class

* Fix typo request->response

* _log -> log

* Added more details to TypeError regarding access_log_class.
  • Loading branch information
hellysmile authored and asvetlov committed Oct 13, 2017
1 parent 4ffdb3a commit e11c82a
Show file tree
Hide file tree
Showing 10 changed files with 124 additions and 17 deletions.
11 changes: 11 additions & 0 deletions aiohttp/abc.py
Original file line number Diff line number Diff line change
Expand Up @@ -146,3 +146,14 @@ def write_eof(self, chunk=b''):
@abstractmethod
def drain(self):
"""Flush the write buffer."""


class AbstractAccessLogger(ABC):

def __init__(self, logger, log_format):
self.logger = logger
self.log_format = log_format

@abstractmethod
def log(self, request, response, time):
"""Emit log to logger"""
13 changes: 3 additions & 10 deletions aiohttp/helpers.py
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
from yarl import URL

from . import hdrs
from .abc import AbstractAccessLogger
from .log import client_logger


Expand Down Expand Up @@ -346,7 +347,7 @@ def content_disposition_header(disptype, quote_fields=True, **params):
return value


class AccessLogger:
class AccessLogger(AbstractAccessLogger):
"""Helper object to log access.
Usage:
Expand Down Expand Up @@ -400,7 +401,7 @@ def __init__(self, logger, log_format=LOG_FORMAT):
:param log_format: apache compatible log format
"""
self.logger = logger
super().__init__(logger, log_format=log_format)

_compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)
if not _compiled_format:
Expand Down Expand Up @@ -513,14 +514,6 @@ def _format_line(self, request, response, time):
for key, method in self._methods)

def log(self, request, response, time):
"""Log access.
:param message: Request object. May be None.
:param environ: Environment dict. May be None.
:param response: Response object.
:param transport: Tansport object. May be None
:param float time: Time taken to serve the request.
"""
try:
fmt_info = self._format_line(request, response, time)

Expand Down
16 changes: 14 additions & 2 deletions aiohttp/web.py
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,9 @@
from . import (hdrs, web_exceptions, web_fileresponse, web_middlewares,
web_protocol, web_request, web_response, web_server,
web_urldispatcher, web_ws)
from .abc import AbstractMatchInfo, AbstractRouter
from .abc import AbstractAccessLogger, AbstractMatchInfo, AbstractRouter
from .frozenlist import FrozenList
from .helpers import AccessLogger
from .http import HttpVersion # noqa
from .log import access_logger, web_logger
from .signals import FuncSignal, PostSignal, PreSignal, Signal
Expand Down Expand Up @@ -230,7 +231,17 @@ def router(self):
def middlewares(self):
return self._middlewares

def make_handler(self, *, loop=None, **kwargs):
def make_handler(self, *,
loop=None,
access_log_class=AccessLogger,
**kwargs):

if not issubclass(access_log_class, AbstractAccessLogger):
raise TypeError(
'access_log_class must be subclass of '
'aiohttp.abc.AbstractAccessLogger, got {}'.format(
access_log_class))

self._set_loop(loop)
self.freeze()

Expand All @@ -240,6 +251,7 @@ def make_handler(self, *, loop=None, **kwargs):
kwargs[k] = v

return Server(self._handle, request_factory=self._make_request,
access_log_class=access_log_class,
loop=self.loop, **kwargs)

@asyncio.coroutine
Expand Down
6 changes: 5 additions & 1 deletion aiohttp/web_protocol.py
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,9 @@ class RequestHandler(asyncio.streams.FlowControlMixin, asyncio.Protocol):
:param logger: custom logger object
:type logger: aiohttp.log.server_logger
:param access_log_class: custom class for access_logger
:type access_log_class: aiohttp.abc.AbstractAccessLogger
:param access_log: custom logging object
:type access_log: aiohttp.log.server_logger
Expand All @@ -83,6 +86,7 @@ def __init__(self, manager, *, loop=None,
tcp_keepalive=True,
slow_request_timeout=None,
logger=server_logger,
access_log_class=helpers.AccessLogger,
access_log=access_logger,
access_log_format=helpers.AccessLogger.LOG_FORMAT,
debug=False,
Expand Down Expand Up @@ -138,7 +142,7 @@ def __init__(self, manager, *, loop=None,
self.debug = debug
self.access_log = access_log
if access_log:
self.access_logger = helpers.AccessLogger(
self.access_logger = access_log_class(
access_log, access_log_format)
else:
self.access_logger = None
Expand Down
1 change: 1 addition & 0 deletions changes/2315.feature
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
aiohttp.wep.Application.make_handler support access_log_class
24 changes: 21 additions & 3 deletions docs/abc.rst
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ Not Allowed*. :meth:`AbstractMatchInfo.handler` raises
:attr:`~AbstractMatchInfo.http_exception` on call.


.. class:: AbstractRouter
.. class:: aiohttp.abc.AbstractRouter

Abstract router, :class:`aiohttp.web.Application` accepts it as
*router* parameter and returns as
Expand All @@ -54,7 +54,7 @@ Not Allowed*. :meth:`AbstractMatchInfo.handler` raises
:return: :class:`AbstractMatchInfo` instance.


.. class:: AbstractMatchInfo
.. class:: aiohttp.abc.AbstractMatchInfo

Abstract *match info*, returned by :meth:`AbstractRouter.resolve` call.

Expand Down Expand Up @@ -102,7 +102,7 @@ attribute.
Abstract Cookie Jar
-------------------

.. class:: AbstractCookieJar
.. class:: aiohttp.abc.AbstractCookieJar

The cookie jar instance is available as :attr:`ClientSession.cookie_jar`.

Expand Down Expand Up @@ -146,3 +146,21 @@ Abstract Cookie Jar

:return: :class:`http.cookies.SimpleCookie` with filtered
cookies for given URL.

Abstract Abstract Access Logger
-------------------------------

.. class:: aiohttp.abc.AbstractAccessLogger

An abstract class, base for all :class:`RequestHandler`
``access_logger`` implementations

Method ``log`` should be overridden.

.. method:: log(request, response, time)

:param request: :class:`aiohttp.web.Request` object.

:param response: :class:`aiohttp.web.Response` object.

:param float time: Time taken to serve the request.
14 changes: 14 additions & 0 deletions docs/logging.rst
Original file line number Diff line number Diff line change
Expand Up @@ -87,6 +87,20 @@ Default access log format is::

'%a %l %u %t "%r" %s %b "%{Referrer}i" "%{User-Agent}i"'

.. versionadded:: 2.3.0

*access_log_class* introduced.

Example of drop-in replacement for :class:`aiohttp.helpers.AccessLogger`::

from aiohttp.abc import AbstractAccessLogger

class AccessLogger(AbstractAccessLogger):

def log(self, request, response, time):
self.logger.info(f'{request.remote} '
f'"{request.method} {request.path} '
f'done in {time}s: {response.status}')

.. note::

Expand Down
3 changes: 3 additions & 0 deletions docs/web_reference.rst
Original file line number Diff line number Diff line change
Expand Up @@ -1347,6 +1347,9 @@ duplicated like one using :meth:`Application.copy`.
:data:`aiohttp.log.server_logger`.
:param access_log: Custom logging object. Default:
:data:`aiohttp.log.access_logger`.
:param access_log_class: class for `access_logger`. Default:
:data:`aiohttp.helpers.AccessLogger`.
Must to be a subclass of :class:`aiohttp.abc.AbstractAccessLogger`.
:param str access_log_format: Access log format string. Default:
:attr:`helpers.AccessLogger.LOG_FORMAT`.
:param bool debug: Switches debug mode. Default: ``False``.
Expand Down
26 changes: 26 additions & 0 deletions tests/test_helpers.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
from yarl import URL

from aiohttp import helpers
from aiohttp.abc import AbstractAccessLogger


# -------------------- coro guard --------------------------------
Expand Down Expand Up @@ -256,6 +257,31 @@ def test_logger_no_transport():
mock_logger.info.assert_called_with("-", extra={'remote_address': '-'})


def test_logger_abc():
class Logger(AbstractAccessLogger):
def log(self, request, response, time):
1 / 0

mock_logger = mock.Mock()
access_logger = Logger(mock_logger, None)

with pytest.raises(ZeroDivisionError):
access_logger.log(None, None, None)

class Logger(AbstractAccessLogger):
def log(self, request, response, time):
self.logger.info(self.log_format.format(
request=request,
response=response,
time=time
))

mock_logger = mock.Mock()
access_logger = Logger(mock_logger, '{request} {response} {time}')
access_logger.log('request', 'response', 1)
mock_logger.info.assert_called_with('request response 1')


class TestReify:

def test_reify(self):
Expand Down
27 changes: 26 additions & 1 deletion tests/test_web_application.py
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@
import pytest

from aiohttp import helpers, log, web
from aiohttp.abc import AbstractRouter
from aiohttp.abc import AbstractAccessLogger, AbstractRouter


def test_app_ctor(loop):
Expand Down Expand Up @@ -65,6 +65,7 @@ def test_app_make_handler_debug_exc(loop, mocker, debug):
app.make_handler(loop=loop)
srv.assert_called_with(app._handle,
request_factory=app._make_request,
access_log_class=mock.ANY,
loop=loop,
debug=debug)

Expand All @@ -76,9 +77,33 @@ def test_app_make_handler_args(loop, mocker):
app.make_handler(loop=loop)
srv.assert_called_with(app._handle,
request_factory=app._make_request,
access_log_class=mock.ANY,
loop=loop, debug=mock.ANY, test=True)


def test_app_make_handler_access_log_class(loop, mocker):
class Logger:
pass

app = web.Application()

with pytest.raises(TypeError):
app.make_handler(access_log_class=Logger, loop=loop)

class Logger(AbstractAccessLogger):

def log(self, request, response, time):
self.logger.info('msg')

srv = mocker.patch('aiohttp.web.Server')

app.make_handler(access_log_class=Logger, loop=loop)
srv.assert_called_with(app._handle,
access_log_class=Logger,
request_factory=app._make_request,
loop=loop, debug=mock.ANY)


@asyncio.coroutine
def test_app_register_on_finish():
app = web.Application()
Expand Down

6 comments on commit e11c82a

@argaen
Copy link
Member

@argaen argaen commented on e11c82a Dec 4, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why was the access_log_class only exposed in make_handler. What if as a user using web.run_app I want to overwrite the class being used for the access log? Any example on how to do that?

@asvetlov
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch.
Anyway run_app implementation is deeply refactored, see #2530
The PR is almost done but not merged yet.

@argaen
Copy link
Member

@argaen argaen commented on e11c82a Dec 4, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Anyway run_app implementation is deeply refactored, see #2530
The PR is almost done but not merged yet.

Woah those are quite big changes, will have a look :)

Good catch.

So, with the current implementation, there is no way to override the logger class? If so, is there an example? The documentation about logging is quite scarce.

@asvetlov
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

web.run_app has no access_log_class parameter , sorry.
AppRunner and family supports it but we need add a param to web.run_app anyway.

@argaen
Copy link
Member

@argaen argaen commented on e11c82a Dec 5, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does it make sense to do a PR adding this param and propagating it to make_handler?

@asvetlov
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If have no strong opinion, +0 from me.
Anyway new PR should be done after merging #2530 (I hope to do it today).

Please sign in to comment.