access logging refactoring

[asvetlov]

Long story short

Now access_log_class, access_log and access_log_format are used by public API to control access logger settings.

It is a design mistake, sorry.

The proposal is:

1. deprecate access_log_class and access_log_format parameters
2. deprecate logging.Logger value for access_log
3. accept AbstractAsyncAccessLogger as access_log parameter.
4. process access_log=None as default, keep the default behavior as is now
5. move access logger creation logic from web_protocol.py to web_runner.py
6. explicitly deprecate access logging params in web_server as well.

The API uses too much kwargs now, backward-compatible changes are possible but need very careful review. All existing public API for access log setup should work in aiohttp 4.0 and can be removed in 5.0

The issue requires a lot of work. I'm happy to review it but have no capacity to do it myself in a few months. We are looking for a champion :)

See also #3777 and #3767

[samuelcolvin]

as mentioned in #3767, personally I think logging should be accomplished by a simple coroutine, not classes no other options, just:

async def request_logger(request, response, start_time):
    ...

If users need to setup logging in some way, they can do that in on_startup or before creating the app, then access that setup object via request.app[...].

We can work to make this compatible (include a deprecation warning) with the current behaviour, but I think if we're redesigning the component of aiohttp we should work to make it as simple and easy to use as possible while remaining powerful.

[asvetlov]

Well, a simple async function is an option to consider. Defending the class approach I would mention that:

1. If access logger needs a context (underlying logging.Logger instance, log string format etc) -- you need to keep it somewhere. There is a possibility to write a factory that returns an async function and store all logger state in local closure variables but I don't sure if this approach is simplier than providing a class
2. Generic logger can not rely on request.app because the app attribute doesn't exist for low-level server
3. For introspection (repr(access_logger) etc) the class provides more info than just an async function.

Changing logger in on_startup is an interesting idea. Fundamental access logging support should work for low-level server too. Application helpers can be built on top of it.

[samuelcolvin]

I guess "simple coroutine" really means "something awaitable", so in fact you could create a class with async def __await__(self): implemented and pass that, or have a class with a public coroutine and pass that, eg. my_logger_class.log.

That way you support the simplest approach but also allow for more unusual/complex scenarios.

[asvetlov]

Minor note: Did you mean async def __call__(self, request, response, start_time) maybe? AFAIK __await__ should be a regular function that returns iterator object. I see no big difference between async def __call__() and async def log().

A dedicated abstract class allows detecting errors early by isinstance() check. Analyzing passed async function signature is cumbersome and not robust.

[asvetlov]

How often do you want to override access logger? If the answer is "sometimes, for reasonable big projects only" the class doesn't add a lot of work

[samuelcolvin]

sorry, yes I meant __call__, the whole point is you wouldn't need any class detection. aiohttp would just call await self.access_logger(request, response, time).

How often do you want to override access logger? If the answer is "sometimes, for reasonable big projects only" the class doesn't add a lot of work

The main use case I'm thinking of is a custom access logger for aiohttp-devtools, this would be better than middleware as it wouldn't involve modifying the app to add middleware.

Also to replace this middleware.

So basically for tools that are agnostic about the project (but might be configured by setting attributes of app).

[asvetlov]

Middleware replacement is a good point. The type check argument still remains valid: isinstance(logger, AbstractAsyncAccessLogger) works pretty well. inspect.iscoroutinefunction() doesn't work for a class with async def __call__. A check for async function signature (mis)match cannot be good enough. I would like to fail fast on application initialization stage, not on handling the first incoming request. I believe that fail-fast strategy is very important here.

[samuelcolvin]

We could deprecate AbstractAccessLogger completely and just tell people to always use AbstractAsyncAccessLogger then we don't have to do any tricky argument checking.

This is the plan.

accept an instance of Abstract*AccessLogger to run_app and AppRunner and deprecate passing a class?

Yes.

AbstractAsyncAccessLogger should have some kind of hook for async initialisation with, something like async def on_startup(self, app)? what about shutdown too? Maybe best to not do this here, but rather let users do this themselves with app.on_startup and app.on_shutdown

Maybe, not sure.

The first step is for supporting access logger object in runners. Application-level API can be considered as the second step.