Honor gunicorn access log format

[ipmb]

When running under gunicorn, --access-logformat isn't honored.

There was some discussion of this in #389, but I didn't see an open issue for it.

Important

• We're using Polar.sh so you can upvote and help fund this issue.
• We receive the funding once the issue is completed & confirmed by you.
• Thank you in advance for helping prioritize & fund our backlog.

[danieltahara]

This is a pretty big loss for observability for us, and means we have to implement something out of band (and therefore less efficient). Any word on if it will be worked on?

[loudsquelch]

Any update on this?

[asgoel]

Any update on this one?

[tomchristie]

Hey folks - "Any update on this" is almost always not helpful. If there was an update on it, it'd be here on the ticket.
If anyone wants to put some work into progressing it that'd be welcome.

[asgoel]

@tomchristie I would be willing to take a stab. i've taken a look at the code and it seems like the UvicornWorker is fundamentally written in a different way than the rest of the gunicorn workers that come bundled by default.

We would basically need to thread through the Logger instance from gunicorn and call the access method when the request is complete in httptools_impl/h11_impl. We'd also need to record request time which the app currently does not do.

Does this approach sound somewhat correct to you?

[asgoel]

@tomchristie just following up to see if my above comment made sense.

[KlausGlueckert]

We have the same problem at the moment and are about to write a custom logging engine for this, because we must be able to alter the uvicorn log format when running it from gunicorn. Any update on this if there will be a fix? In addition, ideally it should also be configurable in a logging.conf:

[formatter_AccessFormatter]
format=|| %(levelname)s || %(message)s
datefmt=%Y-%m-%dT%H:%M:%S
class=logging.Formatter
access_log_format = %(h)s %(l)s %(u)s %(t)s %(r)s %(s)s %(b)s %(f)s %(a)s

[immerrr]

I have implemented the gunicorn logging in a very naive and straightforward way in my branch.

Would you be interested in a PR?

[euri10]

yes @immerrr !
can't promise a speedy speedy review though, pretty bysu

[immerrr]

@euri10 sure, np, here you go: #947

[chbndrhnns]

Now that there is a PR, what would be required to add this functionality? We'd like to match our existing aiohttp-created logs with some new logs created from a FastAPI -> uvicorn -> gunicorn stack.

[euri10]

Now that there is a PR, what would be required to add this functionality? We'd like to match our existing aiohttp-created logs with some new logs created from a FastAPI -> uvicorn -> gunicorn stack.

tl;dr : not a priority on my side at all

The longer version is I'm lacking time mostly, plus I dont use gunicorn nor am familiar enough with its internals to have a good idea if the implementation is correct or sensible. On top of that there are 0 tests for the feature which makes me very hesitant since this part of the code (UvicornWorker) is already weakly tested in our codebase.

[immerrr]

@euri10 the low priority thing is understandable. i asked it in the PR, but let me reiterate, is there anything that would help to get the ball rolling here?

i mean, if it's the gunicorn part, maybe we can ask nicely in the gunicorn community to have someone come over and have a look. if it's the tests, then i can write them risking that the test code will be thrown away if the approach is not solid enough, but it's fine, i guess. WDYT?

[euri10]

I answered in the PR @immerrr

[lambdaq]

Can we merge this PR? This is extremely useful for me.

[KaranTrivedi]

I just had my issue merged into this thread. Any updates on this?

[bhumkong]

While this is not implemented, asgi-logger might be useful to customize access log format.
It supports showing response time.

[suhcrates-web]

I got the answer.
see that gunicorn anyway writes log records, and it follows certain default format. And such default format is configured in somwhere. Then, you can modify that config.
then, where is the default config? it is in the /sitepackages/gunicorn/glogging.py where the gunicorn is installed. it is the 'access_fmt' variable in the 'Logger' class.

[pythonwood]

gunicorn support async base worker offically now. may be is time to rewrite UvicornWorker(AsyncWorker).

AsyncWorker source:

class AsyncWorker(base.Worker):
     ...
    def handle_request(self, listener_name, req, sock, addr):
                ...
                request_time = datetime.now() - request_start
                self.log.access(resp, req, environ, request_time)
     

it is so long to wait. #606
may be i will try it

[waketzheng]

I am using FastAPI, and this worked for me:
fastapi/fastapi#1508 (comment)