Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add example of logging config file #491

Open
Tracked by #1808
matrixise opened this issue Nov 17, 2019 · 29 comments
Open
Tracked by #1808

Add example of logging config file #491

matrixise opened this issue Nov 17, 2019 · 29 comments
Labels

Comments

@matrixise
Copy link

matrixise commented Nov 17, 2019

In the doc, there is the description of --log-config <path> for the configuration of a config file. I think an example of config file could be really awesome for the new comers.

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
@tomchristie
Copy link
Member

Agreed yup. As a starting point we could just link to this: https://docs.python.org/3/library/logging.config.html#logging-config-fileformat

Tho ideally a proper example that's relevant to uvicorn would be ace.

Any pull requests here would be most welcome (even if it's just linkig to the Python docs to start with.)

@ex-nerd
Copy link

ex-nerd commented Feb 6, 2020

It would also be worth mentioning that by enabling the custom log, other uvicorn loggers are likely to become disabled. See #511

@NightMachinery
Copy link

I found this helpful:

import sys
import uvicorn
from uvicorn.config import LOGGING_CONFIG

def main():
    root_path = ''
    if len(sys.argv) >= 2:
        root_path = sys.argv[1]
    ##
    # %(name)s : uvicorn, uvicorn.error, ... . Not insightful at all.
    LOGGING_CONFIG["formatters"]["access"]["fmt"] = '%(asctime)s %(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s'
    LOGGING_CONFIG["formatters"]["default"]["fmt"] = "%(asctime)s %(levelprefix)s %(message)s"

    date_fmt = "%Y-%m-%d %H:%M:%S"
    LOGGING_CONFIG["formatters"]["default"]["datefmt"] = date_fmt
    LOGGING_CONFIG["formatters"]["access"]["datefmt"] = date_fmt
    ##
    uvicorn.run("brishgarden.garden:app", host="127.0.0.1", port=7230, log_level="info", proxy_headers=True, root_path=root_path)

@ievgennaida
Copy link

ievgennaida commented Sep 23, 2020

I will appreciate good example for the uvicorn logging with other libs.
Currently I am configuring root logger and setting formatter to all the available

   for logger_name in logging.root.manager.loggerDict.keys():
        override_logger = logging.getLogger(logger_name)
        for handler in override_logger.handlers:
            handler.setFormatter(formatter)

@ievgennaida
Copy link

Do you use any config file by default when nothing is passed to the --log-config?

@florimondmanca florimondmanca added the docs Improve documentation label Sep 28, 2020
@mattiacampana
Copy link

mattiacampana commented Nov 18, 2020

I would like to specify the log configuration in a separate file and use it with the option --log-config.
In particular, I would like to add the timestamp to the logs. I've found this

LOGGING_CONFIG["formatters"]["default"]["fmt"] = "%(asctime)s [%(name)s] %(levelprefix)s %(message)s"

but I don't know how to specify it in a config file.

@euri10
Copy link
Member

euri10 commented Nov 18, 2020

I would like to specify the log configuration in a separate file and use it with the option --log-config.
In particular, I would like to add the timestamp to the logs. I've found this

LOGGING_CONFIG["formatters"]["default"]["fmt"] = "%(asctime)s [%(name)s] %(levelprefix)s %(message)s"

but I don't know how to specify it in a config file.

assuming you're passing a yaml file, something like the below should print the timestamp, this is well explained in python docs here

version: 1
formatters:
  simple:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console]
    propagate: no
root:
  level: DEBUG
  handlers: [console]

@mattiacampana
Copy link

mattiacampana commented Nov 18, 2020

Thank you @euri10. However, I got the following error when I try to run uvicorn with --log-config option:
configparser.MissingSectionHeaderError: File contains no section headers.
What kind of header should I use? Should I specify an additional option to use the .yaml config file?

Sorry, but this is my very first time with this problem and I'm a bit confused...

@euri10
Copy link
Member

euri10 commented Nov 18, 2020

dunno what you're doing, seems like you're using a ini logging format ?

you can use --log-config with :

  1. yaml or json, it will be detected according to the file extension (.yaml or .yml and .json) see here :

uvicorn/uvicorn/config.py

Lines 240 to 247 in bdab488

elif self.log_config.endswith(".json"):
with open(self.log_config) as file:
loaded_config = json.load(file)
logging.config.dictConfig(loaded_config)
elif self.log_config.endswith((".yaml", ".yml")):
with open(self.log_config) as file:
loaded_config = yaml.safe_load(file)
logging.config.dictConfig(loaded_config)

  1. a old ini file format, with any other file extentions, I think you ended up here, in that case it means your ini format is incorrect and I can just point you at the docs I already linked above for writing the correct format

  2. a dictionary, more to be use when running programmatically

for reference with the above simplest log.yaml and running ❯ uvicorn app:app --log-config=log.yaml you get the timestamp as asked:

2020-11-18 13:54:22,907 - uvicorn.access - INFO - 127.0.0.1:53346 - "GET / HTTP/1.1" 200
2020-11-18 13:54:23,238 - uvicorn.access - INFO - 127.0.0.1:53346 - "GET / HTTP/1.1" 200
2020-11-18 13:54:23,804 - uvicorn.access - INFO - 127.0.0.1:53346 - "GET / HTTP/1.1" 200

@nicoinn
Copy link

nicoinn commented Nov 23, 2020

I also had @mattiacampana 's issue --- fixed by updating to the latest uvicorn with pip install -U uvicorn

@romkazor
Copy link

romkazor commented Mar 24, 2021

How add custom header to access log? User-Agent or Authorization, etc.? Thanks.

@luca-drf
Copy link

Not sure if this is helpful but I had the same issue as @mattiacampana and I solved by defining a new formatter, a new handler and configuring the root logger to use them. Then setting disable_existing_loggers: False allows existing uvicorn loggers to inherit the custom configuration without having to modify them at "runtime":

version: 1
disable_existing_loggers: False
formatters:
  timestamped:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: INFO
    formatter: timestamped
    stream: ext://sys.stdout
root:
  level: INFO
  handlers: [console]

@luca-drf
Copy link

luca-drf commented Apr 6, 2021

Not sure if this is helpful but I had the same issue as @mattiacampana and I solved by defining a new formatter, a new handler and configuring the root logger to use them. Then setting disable_existing_loggers: False allows existing uvicorn loggers to inherit the custom configuration without having to modify them at "runtime":

version: 1
disable_existing_loggers: False
formatters:
  timestamped:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: INFO
    formatter: timestamped
    stream: ext://sys.stdout
root:
  level: INFO
  handlers: [console]

Another solution I found, in order to use uvicorn formatter classes (and not lose colors, for instance), is to re-define loggers like this:

version: 1
disable_existing_loggers: False
formatters:
  default:
    (): 'uvicorn.logging.DefaultFormatter'
    fmt: '%(asctime)s %(levelprefix)-9s %(name)s -: %(message)s'
  access:
    (): 'uvicorn.logging.AccessFormatter'
    fmt: '%(asctime)s %(levelprefix)-9s %(name)s -: %(client_addr)s - "%(request_line)s" %(status_code)s'
handlers:
  default:
    class: logging.StreamHandler
    formatter: default
    stream: ext://sys.stderr
  access:
    class: logging.StreamHandler
    formatter: access
    stream: ext://sys.stdout
loggers:
  uvicorn:
    level: INFO
    handlers:
      - default
  uvicorn.error:
    level: INFO
  uvicorn.access:
    level: INFO
    propagate: False
    handlers:
      - access

@houmie
Copy link

houmie commented May 31, 2021

I'm experiecing the same problem as @mattiacampana and @nicoinn. I already upgraded uvicorn to the latest version: uvicorn==0.13.4

Error:

May 31 10:10:40 api-stag gunicorn[21353]: Traceback (most recent call last):
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/venv/bin/gunicorn", line 8, in <module>
May 31 10:10:40 api-stag gunicorn[21353]:     sys.exit(run())
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/app/wsgiapp.py", line 67, in run
May 31 10:10:40 api-stag gunicorn[21353]:     WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/app/base.py", line 231, in run
May 31 10:10:40 api-stag gunicorn[21353]:     super().run()
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/app/base.py", line 72, in run
May 31 10:10:40 api-stag gunicorn[21353]:     Arbiter(self).run()
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/arbiter.py", line 58, in __init__
May 31 10:10:40 api-stag gunicorn[21353]:     self.setup(app)
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/arbiter.py", line 93, in setup
May 31 10:10:40 api-stag gunicorn[21353]:     self.log = self.cfg.logger_class(app.cfg)
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/glogging.py", line 195, in __init__
May 31 10:10:40 api-stag gunicorn[21353]:     self.setup(cfg)
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/glogging.py", line 248, in setup
May 31 10:10:40 api-stag gunicorn[21353]:     fileConfig(cfg.logconfig, defaults=defaults,
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/lib/python3.9/logging/config.py", line 69, in fileConfig
May 31 10:10:40 api-stag gunicorn[21353]:     cp.read(fname)
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/lib/python3.9/configparser.py", line 697, in read
May 31 10:10:40 api-stag gunicorn[21353]:     self._read(fp, filename)
May 31 10:10:40 api-stag gunicorn[21353]:   File "/home/admin/.pyenv/versions/3.9.5/lib/python3.9/configparser.py", line 1082, in _read
May 31 10:10:40 api-stag gunicorn[21353]:     raise MissingSectionHeaderError(fpname, lineno, line)
May 31 10:10:40 api-stag gunicorn[21353]: configparser.MissingSectionHeaderError: File contains no section headers.
May 31 10:10:40 api-stag gunicorn[21353]: file: '/etc/app/log_conf.yml', line: 1
May 31 10:10:40 api-stag gunicorn[21353]: 'version: 1\n'

Service:

...
ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn -c /etc/app/config.py main:app --log-config /etc/app/log_conf.yml

log_conf.yml

version: 1
disable_existing_loggers: False
formatters:
  default:
    (): 'uvicorn.logging.DefaultFormatter'
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
  access:
    (): 'uvicorn.logging.AccessFormatter'
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  default:
    formatter: default
    class: logging.StreamHandler
    stream: ext://sys.stderr
  access:
    formatter: access
    class: logging.StreamHandler
    stream: ext://sys.stdout
loggers:
  uvicorn.error:
    level: INFO
    handlers:
      - default
    propagate: no
  uvicorn.access:
    level: INFO
    handlers:
      - access
    propagate: no

@euri10
Copy link
Member

euri10 commented May 31, 2021

@houmie your error is in gunicron which tries to load a ini file, this is unrelated to uvicorn

@houmie
Copy link

houmie commented May 31, 2021

@euri10

That's strange. This only happens when I try to pass in --log-config /etc/app/log_conf.yml.

ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn -c /etc/app/config.py main:app --log-config /etc/app/log_conf.yml

If I don't do that it works fine.

ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn -c /etc/app/config.py main:app

I even tried to load everything without gunicorn config.

ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn main:app -w 1 -k uvicorn.workers.UvicornWorker --log-config /etc/app/log_conf.yml

It keeps complaining about the yml file:

May 31 11:12:41 api-stag gunicorn[22354]: configparser.MissingSectionHeaderError: File contains no section headers.
May 31 11:12:41 api-stag gunicorn[22354]: file: '/etc/app/log_conf.yml', line: 1
May 31 11:12:41 api-stag gunicorn[22354]: 'version: 1\n'

What could I be missing, please?

@euri10
Copy link
Member

euri10 commented May 31, 2021

again, this has nothing to do with uvicorn, you are passing a yaml log file to gunicorn while it expects a ini file:
https://docs.gunicorn.org/en/stable/settings.html#logconfig

@houmie
Copy link

houmie commented May 31, 2021

Sorry my bad. I'm trying to get my head around this.

So how would I pass in --log-config /etc/app/log_conf.yml to uvicorn, if uvicorn was driven through gunicorn in the first place, as I demonstrated above?

Based on the docs: https://www.uvicorn.org/#running-with-gunicorn I'm not seeing how to achieve that.

Thanks

@euri10
Copy link
Member

euri10 commented May 31, 2021

it's in the docs here https://www.uvicorn.org/deployment/#gunicorn

If you need to pass uvicorn's config arguments to gunicorn workers then you'll have to subclass UvicornWorker

@houmie
Copy link

houmie commented May 31, 2021

Ah Thanks. I see. So it should look like this?

/etc/app/config.py

from uvicorn.workers import UvicornWorker

bind = "127.0.0.1:8000"
workers = 4
worker_class = "MyUvicornWorker"
...

class MyUvicornWorker(UvicornWorker):
    CONFIG_KWARGS = {"loop": "asyncio", "http": "h11", "lifespan": "off"}

And then the gunicorn service loads it like this, correct?

ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn -c /etc/app/config.py main:app

Is there a way to load the uvicorn.yml file into the sub class without the pain of translating every line into CONFIG_KWARGS by hand?

@euri10
Copy link
Member

euri10 commented May 31, 2021

/trying to keep calm and not throw a RTFM...

what about that ?

class MyUvicornWorker(UvicornWorker):
    CONFIG_KWARGS = {"log_config": "yourloginggingfile.yaml"}

please try not to hijack unrelated issues and read the docs, thanks

@houmie
Copy link

houmie commented May 31, 2021

Please keep calm. Why are you so on the edge? I'm having a respectful and friendly conversation with you. Nobody is holding a gun against your head here.

The documentation is not very comprehensive.

May 31 13:18:34 api-stag gunicorn[25040]: Error: class uri 'MyUvicornWorker' invalid or not found:
May 31 13:18:34 api-stag gunicorn[25040]: [Traceback (most recent call last):
May 31 13:18:34 api-stag gunicorn[25040]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/util.py", line 88, in load_class
May 31 13:18:34 api-stag gunicorn[25040]:     return pkg_resources.load_entry_point(
May 31 13:18:34 api-stag gunicorn[25040]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/pkg_resources/__init__.py", line 474, in load_entry_point
May 31 13:18:34 api-stag gunicorn[25040]:     return get_distribution(dist).load_entry_point(group, name)
May 31 13:18:34 api-stag gunicorn[25040]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2845, in load_entry_point
May 31 13:18:34 api-stag gunicorn[25040]:     raise ImportError("Entry point %r not found" % ((group, name),))
May 31 13:18:34 api-stag gunicorn[25040]: ImportError: Entry point ('gunicorn.workers', 'MyUvicornWorker') not found

It seems pointing to the subclass in the same config.py is not enough. I have already set the Python Path to /etc/app. But it is still not able to find it. The documentation doesn't say anything about this.

@euri10
Copy link
Member

euri10 commented May 31, 2021

just run gunicorn -k MyUvicornWorker with the above subclassed UvicornWorker, everything is in the docs, just take the time to read, but I know :
https://twitter.com/jcsrb/status/1392459191353286656

@houmie
Copy link

houmie commented May 31, 2021

¯_(ツ)_/¯
I know you don't believe me that I have checked the docs. The issue is that the sub class can't be found.

I have followed what you have suggested:

/etc/systemd/system/app.service:

ExecStart=/home/admin/.pyenv/versions/venv/bin/gunicorn -w 1 -k MyUvicornWorker main:app

A friendly reminder the subclass of MyUvicornWorker is in /etc/app/config.py.
/etc/app is in PythonPath.

May 31 16:17:10 api-stag gunicorn[26055]: Error: class uri 'MyUvicornWorker' invalid or not found:
May 31 16:17:10 api-stag gunicorn[26055]: [Traceback (most recent call last):
May 31 16:17:10 api-stag gunicorn[26055]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/gunicorn/util.py", line 88, in load_class
May 31 16:17:10 api-stag gunicorn[26055]:     return pkg_resources.load_entry_point(
May 31 16:17:10 api-stag gunicorn[26055]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/pkg_resources/__init__.py", line 474, in load_entry_point
May 31 16:17:10 api-stag gunicorn[26055]:     return get_distribution(dist).load_entry_point(group, name)
May 31 16:17:10 api-stag gunicorn[26055]:   File "/home/admin/.pyenv/versions/3.9.5/envs/venv/lib/python3.9/site-packages/pkg_resources/__init__.py", line 2845, in load_entry_point
May 31 16:17:10 api-stag gunicorn[26055]:     raise ImportError("Entry point %r not found" % ((group, name),))
May 31 16:17:10 api-stag gunicorn[26055]: ImportError: Entry point ('gunicorn.workers', 'MyUvicornWorker') not found
May 31 16:17:10 api-stag gunicorn[26055]: ]
May 31 16:17:10 api-stag systemd[1]: app.service: Main process exited, code=exited, status=1/FAILURE
May 31 16:17:10 api-stag systemd[1]: app.service: Failed with result 'exit-code'.

@euri10
Copy link
Member

euri10 commented May 31, 2021

adapt your path @houmie -k MyUvicornWorker should be probably -k config.MyUvicornWorker given what you described, dunno what to tell you other than read the errors you get more carefully maybe, and ask questions on SO next time ?

@ronalddas
Copy link

ronalddas commented May 1, 2023

How add custom header to access log? User-Agent or Authorization, etc.? Thanks.

Any example for this? I want to log the request_id from nginx

@grillazz
Copy link

grillazz commented May 1, 2023

@ronalddas
Copy link

ronalddas commented May 1, 2023

@grillazz Thanks for the reference, but I just ended up using asgi-logger

@Aruelius
Copy link

adapt your path @houmie -k MyUvicornWorker should be probably -k config.MyUvicornWorker given what you described, dunno what to tell you other than read the errors you get more carefully maybe, and ask questions on SO next time ?

You are absolutely right.

I will show a complete case that how Gunicorn can use Uvicorn log:

  • app/
    • ...
  • deploy/
    • __init__.py
    • gunicorn.conf.py
  • mylogconfig.yaml

The FastAPI app dir: app/...

Deploy dir:

# deploy/__init__.py

from uvicorn_worker import UvicornWorker


class MyUvicornWorker(UvicornWorker):
    CONFIG_KWARGS = {
        "loop": "asyncio",
        "http": "auto",
        "lifespan": "off",
        "log_config": "mylogconfig.yaml"
    }
# deploy/gunicorn.conf.py

wsgi_app = "app.main:app"
bind = "127.0.0.1:3011"
timeout = 5
worker_class = "deploy.MyUvicornWorker"  # this is important
accesslog = "access.log"
errorlog = "debug.log"
...

The log config file: mylogconfig.yaml

version: 1
disable_existing_loggers: False
formatters:
  default:
    (): 'uvicorn.logging.DefaultFormatter'
    fmt: '%(levelprefix)s [%(asctime)s] %(message)s'
  access:
    (): 'uvicorn.logging.AccessFormatter'
    fmt: '%(levelprefix)s [%(asctime)s] %(client_addr)s - "%(request_line)s" %(status_code)s'
handlers:
  default:
    class: logging.StreamHandler
    formatter: default
    stream: ext://sys.stderr
  access:
    class: logging.StreamHandler
    formatter: access
    stream: ext://sys.stdout
loggers:
  uvicorn:
    level: INFO
    handlers:
      - default
  uvicorn.error:
    level: INFO
  uvicorn.access:
    level: INFO
    propagate: False
    handlers:
      - access

Run: gunicorn -c deploy/gunicorn.conf.py

Hope this can help you guys,

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.