aiohttp.wep.Application.make_handler access_log_class support #2316

hellysmile · 2017-10-12T00:06:30Z

What do these changes do?

Adds support pluggable aiohttp.helpers.AccessLogger for aiohttp.wep.Application.make_handler

Are there changes in behavior for the user?

No breaking changes.

Related issue number

#2315

Checklist

I think the code is well written
Unit tests for the changes exist
Documentation reflects the changes
If you provide code modification, please add yourself to CONTRIBUTORS.txt
- The format is <Name> <Surname>.
- Please keep alphabetical order, the file is sorted by names.
Add a new news fragment into the changes folder
- name it <issue_id>.<type> for example (588.bug)
- if you don't have an issue_id change it to the pr id after creating the pr
- ensure type is one of the following:
  - .feature: Signifying a new feature.
  - .bugfix: Signifying a bug fix.
  - .doc: Signifying a documentation improvement.
  - .removal: Signifying a deprecation or removal of public API.
  - .misc: A ticket has been closed, but it is not of interest to users.
- Make sure to use full sentences with correct case and punctuation, for example: "Fix issue with non-ascii contents in doctest text files."

hellysmile · 2017-10-12T00:18:35Z

Here is example of AccessLogger which produces messages exactly same like current aiohttp.helpers.AccessLogger with default log_format

class AccessLogger(AbstractAccessLogger):

    def log(self, request, response, time):
        msg = '{request.remote} - - {t} "{r}" {response.status} {response.body_length} "{referrer}" "{user_agent}"'

        r = '%s %s HTTP/%s.%s' % tuple((request.method,
                                        request.path_qs) + request.version)

        t = datetime.datetime.utcnow().strftime('[%d/%b/%Y:%H:%M:%S +0000]')

        self.logger.info(msg.format(
            t=t,
            r=r,
            referrer=request.headers.get('Referrer', '-'),
            user_agent=request.headers.get('User-Agent', '-'),
            request=request,
            response=response,
            time=time,
        ))

I've played a bit with this AccessLogger, and server can be speeded up to 5% in comparison to the default aiohttp.helpers.AccessLogger, but it is not big deal.

Most useful example is something like:

class AccessLogger(AbstractAccessLogger):

    def log(self, request, response, time):
        self.logger.info(f'{request.remote} "{request.method}" -> {response.status}')

If proposal at least makes some sense, I'll do full test coverage/docs/etc

codecov-io · 2017-10-12T00:24:57Z

Codecov Report

Merging #2316 into master will increase coverage by <.01%.
The diff coverage is 100%.

@@            Coverage Diff             @@
##           master    #2316      +/-   ##
==========================================
+ Coverage   97.24%   97.24%   +<.01%     
==========================================
  Files          39       39              
  Lines        8195     8204       +9     
  Branches     1435     1436       +1     
==========================================
+ Hits         7969     7978       +9     
  Misses         98       98              
  Partials      128      128

Impacted Files	Coverage Δ
aiohttp/helpers.py	`97.27% <100%> (ø)`	⬆️
aiohttp/web.py	`99.66% <100%> (ø)`	⬆️
aiohttp/web_protocol.py	`88.27% <100%> (ø)`	⬆️
aiohttp/abc.py	`100% <100%> (ø)`	⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4ffdb3a...db02580. Read the comment docs.

asvetlov · 2017-10-12T08:21:43Z

Please make the feature well documented

kxepal · 2017-10-12T10:34:21Z

aiohttp/web_protocol.py

@@ -83,6 +83,7 @@ def __init__(self, manager, *, loop=None,
                 tcp_keepalive=True,
                 slow_request_timeout=None,
                 logger=server_logger,
+                 access_log_factory=helpers.AccessLogger,


It's not a factory, but a class. Otherwise need to document what factory should return - I think, that's abstraction level is redundant.

What about access_log_cls or access_log_class ?

access_log_class is good one.

kxepal · 2017-10-12T10:35:27Z

aiohttp/abc.py

+class AbstractAccessLogger(ABC):
+
+    def __init__(self, logger, log_format):
+        self.logger = logger


log_format seems to be lost.

Yes, but it is exactly how current AccessLogger works, as well default log_format is AccessLogger.LOG_FORMAT not sure is it needs to be stored as self.log_format. My idea was that, logger itself is only one required attribute, log_format is actually optional

So, if I'm making own AccessLogger I should keep in mind, that super requires two arguments, one of which it will set to attributes and one that it will ignore? A bit not friendly behavior. The AccessLogger may have overloaded __init__ to accept log_format, but if the AbstractAccessLogger doesn't uses it in anyway there is no point to keep it there.

kxepal · 2017-10-12T10:37:15Z

aiohttp/abc.py

+        self.logger = logger
+
+    @abstractmethod
+    def log(self, request, response, time):


Need to document which objects and types that method accepts.

Sure, it will be documented

hellysmile · 2017-10-12T10:51:32Z

@kxepal What do You think to make self._log @abstractmethod and self.log will be:

def log(self, request, response, time):
    try:
        self._log(request, response, time)
    except Exception as e:
        self.logger.exception("Error in logging", exc_info=e)

kxepal · 2017-10-12T11:00:01Z

@hellysmile
Good idea if we don't want to let logger crash the request. Though, it may hide errors for awhile. Also, no need to pass exc_info for logger.exception - it already catches it by default.

hellysmile · 2017-10-12T11:56:43Z

There is one more question, it will be nice to place somewhere

assert issubclass(access_log_class, AbstractAccessLogger), access_log_class

but where to place is, actually access_logger will be created lazy on first request

asvetlov · 2017-10-12T12:05:31Z

@hellysmile push the check into app.make_handler().

asvetlov · 2017-10-13T10:26:56Z

aiohttp/web.py

@@ -231,6 +231,14 @@ def middlewares(self):
        return self._middlewares

    def make_handler(self, *, loop=None, **kwargs):
+        if 'access_log_class' in kwargs:


Just add access_log_class=helpers.AccessLogger into method signature.

asvetlov · 2017-10-13T10:27:32Z

aiohttp/web.py

+        if 'access_log_class' in kwargs:
+            access_log_class = kwargs['access_log_class']
+
+            assert issubclass(access_log_class, AbstractAccessLogger), (


Should be TypeError, not AssertionError.

asvetlov · 2017-10-13T10:33:10Z

aiohttp/abc.py

+        """Emit log to logger"""
+
+        try:
+            self._log(request, response, time)


Let's drop _log() and make log() abstract method.
On one hand formatting logic always should be wrapped by catching exception obviously.
On other -- let's not make any decision about implementation details.
Implementor might want to do other things than just registering caught exception.
Let's keep ABC very abstract, my guts feel that there are many contradictory might occur if we will bake a code in abstract class.

asvetlov · 2017-10-13T10:35:24Z

aiohttp/abc.py

+    def _log(self, request, response, time):
+        """
+
+        :param request: Request object.


Please don't use sphinx formatting in docstrings -- it is a text for readers.
I'd like to rip it out everywhere and use only hand written documentation.

asvetlov

LGTM
@kxepal ?

kxepal

One little bit about error message. The rest looks fine.

kxepal · 2017-10-13T13:56:59Z

aiohttp/web.py

+
+        if not issubclass(access_log_class, AbstractAccessLogger):
+            raise TypeError('access_log_class must be subclass of '
+                            'aiohttp.abc.AbstractAccessLogger')


Would be nice to add got {} to error message to simplify understanding what's wrong with the logger.

kxepal

Cool, thanks!

lock · 2019-10-28T17:04:07Z

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a [new issue] for related bugs.
If you feel like there's important points made in this discussion, please include those exceprts into that [new issue].
[new issue]: https://github.com/aio-libs/aiohttp/issues/new

hellysmile added 2 commits October 12, 2017 03:03

Initial access_log_factory support.

17364dc

Added changes.

9dcb69d

kxepal reviewed Oct 12, 2017

View reviewed changes

kxepal requested changes Oct 12, 2017

View reviewed changes

abstraction level changes for AccessLogger.

bff0c8e

hellysmile added 2 commits October 12, 2017 14:58

Added RequestHandler docstrings.

07dd227

Fix changes naming.

9a6e28b

hellysmile added 2 commits October 12, 2017 16:25

Added access_log_class check for Application.make_handler

bbd6383

Added basic tests for access_log_class.

8f19815

hellysmile changed the title ~~aiohttp.wep.Application.make_handler access_log_factory support~~ aiohttp.wep.Application.make_handler access_log_class support Oct 12, 2017

hellysmile and others added 4 commits October 12, 2017 22:14

Merge branch 'master' into access_log_factory

d825c4b

Added docs for access_log_class

ced7bad

Fix typo request->response

fc75be3

Merge branch 'master' into access_log_factory

a9246ad

asvetlov requested changes Oct 13, 2017

View reviewed changes

_log -> log

f0ac3e3

asvetlov previously approved these changes Oct 13, 2017

View reviewed changes

kxepal requested changes Oct 13, 2017

View reviewed changes

Added more details to TypeError regarding access_log_class.

db02580

hellysmile dismissed asvetlov’s stale review via db02580 October 13, 2017 14:02

kxepal approved these changes Oct 13, 2017

View reviewed changes

asvetlov merged commit e11c82a into aio-libs:master Oct 13, 2017

asvetlov mentioned this pull request Oct 13, 2017

aiohttp.wep.Application.make_handler should support pluggable AccessLogger #2315

Closed

lock bot added the outdated label Oct 28, 2019

lock bot locked as resolved and limited conversation to collaborators Oct 28, 2019

psf-chronographer bot added the bot:chronographer:provided There is a change note present in this PR label Oct 28, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

aiohttp.wep.Application.make_handler access_log_class support #2316

aiohttp.wep.Application.make_handler access_log_class support #2316

hellysmile commented Oct 12, 2017 •

edited

Loading

hellysmile commented Oct 12, 2017 •

edited

Loading

codecov-io commented Oct 12, 2017 •

edited

Loading

asvetlov commented Oct 12, 2017

kxepal Oct 12, 2017

hellysmile Oct 12, 2017 •

edited

Loading

kxepal Oct 12, 2017

kxepal Oct 12, 2017

hellysmile Oct 12, 2017 •

edited

Loading

kxepal Oct 12, 2017

kxepal Oct 12, 2017

hellysmile Oct 12, 2017

hellysmile commented Oct 12, 2017 •

edited

Loading

kxepal commented Oct 12, 2017

hellysmile commented Oct 12, 2017 •

edited

Loading

asvetlov commented Oct 12, 2017

asvetlov Oct 13, 2017

asvetlov Oct 13, 2017

asvetlov Oct 13, 2017

asvetlov Oct 13, 2017

asvetlov left a comment

kxepal left a comment

kxepal Oct 13, 2017

kxepal left a comment

lock bot commented Oct 28, 2019

aiohttp.wep.Application.make_handler access_log_class support #2316

aiohttp.wep.Application.make_handler access_log_class support #2316

Conversation

hellysmile commented Oct 12, 2017 • edited Loading

What do these changes do?

Are there changes in behavior for the user?

Related issue number

Checklist

hellysmile commented Oct 12, 2017 • edited Loading

codecov-io commented Oct 12, 2017 • edited Loading

Codecov Report

asvetlov commented Oct 12, 2017

Choose a reason for hiding this comment

hellysmile Oct 12, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hellysmile Oct 12, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hellysmile commented Oct 12, 2017 • edited Loading

kxepal commented Oct 12, 2017

hellysmile commented Oct 12, 2017 • edited Loading

asvetlov commented Oct 12, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

asvetlov left a comment

Choose a reason for hiding this comment

kxepal left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

kxepal left a comment

Choose a reason for hiding this comment

lock bot commented Oct 28, 2019

hellysmile commented Oct 12, 2017 •

edited

Loading

hellysmile commented Oct 12, 2017 •

edited

Loading

codecov-io commented Oct 12, 2017 •

edited

Loading

hellysmile Oct 12, 2017 •

edited

Loading

hellysmile Oct 12, 2017 •

edited

Loading

hellysmile commented Oct 12, 2017 •

edited

Loading

hellysmile commented Oct 12, 2017 •

edited

Loading