uvicorn icon indicating copy to clipboard operation
uvicorn copied to clipboard

Honor gunicorn access log format

Open ipmb opened this issue 4 years ago • 20 comments

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.
Fund with Polar

ipmb avatar Dec 13 '19 17:12 ipmb

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?

danieltahara avatar Jan 27 '20 22:01 danieltahara

Any update on this?

loudsquelch avatar May 20 '20 16:05 loudsquelch

Any update on this one?

asgoel avatar Jun 08 '20 20:06 asgoel

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.

tomchristie avatar Jun 09 '20 09:06 tomchristie

@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 avatar Jun 09 '20 17:06 asgoel

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

asgoel avatar Jul 09 '20 17:07 asgoel

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

KlausGlueckert avatar Jul 17 '20 10:07 KlausGlueckert

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

Would you be interested in a PR?

immerrr avatar Feb 03 '21 09:02 immerrr

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

euri10 avatar Feb 03 '21 15:02 euri10

@euri10 sure, np, here you go: https://github.com/encode/uvicorn/pull/947

immerrr avatar Feb 03 '21 15:02 immerrr

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.

chbndrhnns avatar May 27 '21 11:05 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.

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.

euri10 avatar May 27 '21 11:05 euri10

@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?

immerrr avatar May 27 '21 17:05 immerrr

I answered in the PR @immerrr

euri10 avatar May 28 '21 07:05 euri10

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

lambdaq avatar Dec 22 '21 03:12 lambdaq

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

KaranTrivedi avatar Feb 09 '22 18:02 KaranTrivedi

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

bhumkong avatar Jul 19 '22 09:07 bhumkong

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.

suhcrates-web avatar Apr 01 '23 05:04 suhcrates-web

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

pythonwood avatar Oct 14 '23 19:10 pythonwood

I am using FastAPI, and this worked for me: https://github.com/tiangolo/fastapi/issues/1508#issuecomment-638365277

waketzheng avatar Feb 25 '24 08:02 waketzheng