generic logging options

[benoitc]

beside the changein #1528 , I think we could introduce in a later release a more generic logging handling to prevent the addition of more options each time someone wants to introduce its own log handler. Smth like --access-log=syslog: .... and so on. Thoughts?

[Code0x58]

How about moving away from individual options all together and just having optional sane defaults, then only allowing the python logging to be configured through --logconfig=, or something like Django's LOGGING_CONFIG but in gunicorn.conf.py? edit: it looks like the last part is suggested in #1087

[tilgovi]

I think I like what @Code0x58 is saying.

• Only have one option to set the log config from a file, using the .ini support in Python
• Document our loggers (gunicorn.error and gunicorn.access)
• Document best practice for using dictConfig in a gunicorn.conf.py

[tilgovi]

If it's really necessary for people who love to 12factor these things and feel a strong need for it, we could treat some environment variable as a JSON dictConfig, if that's reasonable.

[Code0x58]

There also appears to be gunicorn.http and gunicorn.http.wsgi which are undocumented, although one was mentioned in a change log. I noticed them when running python -i gunicorn -- --workers=1 ...

[benoitc]

By default gunicorn already return the logs on stdout/stderr so it's already "compliant" with twelve-factor. Logging to logs/syslogs/other logger is a convenience offered to the users that want a minimal installation without having to pipe or capture them by using an external tool.

What I proposed is exactly about that, but instead of having different options, the command line arguments should be used to choose one or more logging routers with different handlers that can be used for it.

We already support the logconfig or dictconfig parameter for those who want to override the default logging. Gunicorn logging is about its own log, the application shouldn't try to override the `gunicorn." handlers and write to stdout or anything using ts own entry point, its own log file, its own syslog config.

I can understand anyway that some users want to log at the same place, so maybe we could provide a way to define the name of log endpoint that gunicorn should use for logging inside python? That should be optional though since some including myself are also using gunicorn with apps not in python.

[NicolasLM]

If I may give a tangible use case: the code bases I work on usually have many different entrypoints. Gunicorn for the API, Celery workers for background tasks, some standalone processes for statefull work and so on. Of course each of these processes need to log things.

In my dreams I would configure logging myself once before letting the rest of the code (Gunicorn, Celery, my own code) do its work. At this point I don't want anything to touch the logging configuration I set. (Of course libraries creating log records to their own loggers is completely fine)

Doing that is surprisingly difficult.

• There is no way of telling Gunicorn to not touch logging, as far as I know.
• For instance Celery requires you to subscribe to a signal in order to let it know that it should not touch logging.

It would be amazing it there was a way of completely bypassing the configuration that Gunicorn does to the logging module.

(Oh and by the way, Gunicorn only reads the kind of deprecated fileConfig, not the preferred dictConfig)

[Code0x58]

I have that exact same situation, after looking at it for too long I subclassed* gunicorn.glogging.Logger and overrode .setup(), then that class is given in logging_class. I also have accesslog = "/dev/null" so Logger.access() doesn't skip logging to gunicorn.access due to config.

I am not 100% on this approach yet, but it is better than what I have seen. I or one of my colleagues** may be willing to put in patches to change this, but only if it is released with Python2 support (considering it would likely just be adding things, it could still be in 19.x).

I think just disabling gunicorn's logging config all together would be a better option, then it could be configured wherever without concerns of the changes getting squashed.

* having your config file named gunicorn.conf.py is a bad idea (although that is what gunicorn looks for if you don't provide a file name), as you can't use it to supply a custom Logger class
** we are expecting to convert numerous apps from using Apache2 to gunicorn (assuming it is suitable), when gunicorn was chosen to go forward with we weren't aware of the plan to drop Python2 support in 20 - we are still a couple of years off Python3. Putting off the plan to drop support could lead to more patches

[benoitc]

actually there was a PR that was adding dictConfig: #1110

but it has been closed. I think we all agree we should support it.

Anyway Gunicorn is a server and will continue to provide its own way to use the logs. It can be improved and I would like to discuss more the way we can improve the interface to configure them as suggested in the issue introduction.

Maybe we could also have a way to remove any loging by configuring the logger class to NullLogger or a better name which would simply setup the loggers and not the handlers (if feasible) ? That would be the simplest way to fix it.

[Code0x58]

I suppose you could do something like accumulate --logging=log_name:handler:formatter_arg:handler_arg="value1",key2="value2"… for a consistent way of wrapping up some dictConfig functionality.

I think generic configuration like this is hindered by the current use of the glogging.Logger class and derived gunicorn.instrument.statsd.Statsd, if it was replaced with equivalent LoggingAdapters, Handlers, and Formatters then I am pretty sure it would be trivial.

I've been thinking about this recently as it would let the user configure logging entirely through dictConfig/fileConfig (at least because of access log formatting) and also leave the underlying application to decide what non-gunicorn derived logging class to use, helping make gunicorn more transparent.

[NicolasLM]

As @Code0x58, I also find this topic hard to follow because Gunicorn and Python Logging have very different definitions of what a Logger is. By reading comments in this issue I am never sure which one we are talking about.

That being said, we have to live with it, as there is no changing that without breaking things that Gunicorn users rely on.

Maybe we could also have a way to remove any loging by configuring the logger class to Gunicorn NullLogger or a better name which would simply setup the Python loggers and not the Python handlers (if feasible) ?

(quote edited to lift ambiguity) That sounds good to me. Gunicorn would only be responsible for creating its own Python Loggers and the user would then configure them the way he wants.

[dcosson]

Just wondering if any progress has been made on this?

I'm running into similar issues, my use case is that I want to log json formatted logs so I can pass them to something like kibana (or any other log aggregator service). I think this and most of the other stuff discussed in this thread can be solved by allowing a LoggerAdapter, which basically lets you bypass all the crazyness of the logging module formatter-that-can't-really-format. I.e. you set the format to just "%(message)s" and then the adapter can implement a function that can actually format a message however you want, including serializing as json and including any metadata you want.

I can't figure out how to use a LoggerAdapter with gunicorn though - as far as I can figure out, you can't specify it in any of the static log definition formats like ini config file or dict, and it's not a logger class I can give gunicorn the path to, because the constructor of a LoggerAdapter is different than a python Logger or glogger Logger. I can wrap the gunicorn logger via getLogger("gunicorn") in a LoggerAdapter, but I can't figure out how to give that back to gunicorn to log to it.

Is this possible? Or does it make sense to add a new option for specifying an already-configured logger object in a python gunicorn config file?

[dcosson]

In case it's useful to anyone else, I did get something working (though an easier & documented way to do this seems like it would still be useful).

# In gunicorn_config.py

accesslog = "-"  # need something like this to enable access logging at all
logger_class = "utils.logging.StubbedGunicornLogger"

# In utils/logging.py

import gunicorn.glogging

class StubbedGunicornLogger(gunicorn.glogging.Logger):
    def setup(self, cfg):
        handler = logging.StreamHandler()
        error_logger = logging.getLogger("gunicorn.error")
        error_logger.addHandler(handler)
        access_logger = logging.getLogger("gunicorn.access")
        access_logger.addHandler(handler)
        self.error_log = CustomLogAdapter(error_logger, extra={})
        self.access_log = CustomLogAdapter(access_logger, extra={})
        self.error_log.setLevel(logging.INFO)
        self.access_log.setLevel(logging.INFO)

# CustomLogAdapter can use whatever kind of logging logic you want,
# or use a library like pygogo.utils.StructuredAdapter

[pawamoy]

It is absolutely useful @dcosson. Thank you so much for sharing this. I've been banging my head for 10 full-focus hours trying to unify logging for a Gunicorn/Uvicorn/FastAPI application (and learning how Python logging works).

Your solution is... well, the solution!

I intercept everything in a loguru sink and every log line is now beautifully formatted 😄

And if I ever need to format the logs as JSON for Kibana or else, I now know how! (edit: loguru has a serialize option that does that just fine!)

Thanks again!

[pawamoy]

I wrote a short blog post about this at http://pawamoy.github.io/2020/06/02/unify-logging-for-a-gunicorn-uvicorn-app/

I setup everything in a single file:

import os
import logging
import sys

from gunicorn.app.base import BaseApplication
from gunicorn.glogging import Logger
from loguru import logger

from my_app.app import app


LOG_LEVEL = logging.getLevelName(os.environ.get("LOG_LEVEL", "DEBUG"))
JSON_LOGS = True if os.environ.get("JSON_LOGS", "0") == "1" else False
WORKERS = int(os.environ.get("GUNICORN_WORKERS", "5"))


class InterceptHandler(logging.Handler):
    def emit(self, record):
        # Get corresponding Loguru level if it exists
        try:
            level = logger.level(record.levelname).name
        except ValueError:
            level = record.levelno

        # Find caller from where originated the logged message
        frame, depth = logging.currentframe(), 2
        while frame.f_code.co_filename == logging.__file__:
            frame = frame.f_back
            depth += 1

        logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage())


class StubbedGunicornLogger(Logger):
    def setup(self, cfg):
        handler = logging.NullHandler()
        self.error_logger = logging.getLogger("gunicorn.error")
        self.error_logger.addHandler(handler)
        self.access_logger = logging.getLogger("gunicorn.access")
        self.access_logger.addHandler(handler)
        self.error_log.setLevel(LOG_LEVEL)
        self.access_log.setLevel(LOG_LEVEL)


class StandaloneApplication(BaseApplication):
    """Our Gunicorn application."""

    def __init__(self, app, options=None):
        self.options = options or {}
        self.application = app
        super().__init__()

    def load_config(self):
        config = {
            key: value for key, value in self.options.items()
            if key in self.cfg.settings and value is not None
        }
        for key, value in config.items():
            self.cfg.set(key.lower(), value)

    def load(self):
        return self.application


if __name__ == '__main__':
    intercept_handler = InterceptHandler()
    # logging.basicConfig(handlers=[intercept_handler], level=LOG_LEVEL)
    # logging.root.handlers = [intercept_handler]
    logging.root.setLevel(LOG_LEVEL)

    seen = set()
    for name in [
        *logging.root.manager.loggerDict.keys(),
        "gunicorn",
        "gunicorn.access",
        "gunicorn.error",
        "uvicorn",
        "uvicorn.access",
        "uvicorn.error",
    ]:
        if name not in seen:
            seen.add(name.split(".")[0])
            logging.getLogger(name).handlers = [intercept_handler]

    logger.configure(handlers=[{"sink": sys.stdout, "serialize": JSON_LOGS}])

    options = {
        "bind": "0.0.0.0",
        "workers": WORKERS,
        "accesslog": "-",
        "errorlog": "-",
        "worker_class": "uvicorn.workers.UvicornWorker",
        "logger_class": StubbedGunicornLogger
    }

    StandaloneApplication(app, options).run()

[benoitc]

In case it's useful to anyone else, I did get something working (though an easier & documented way to do this seems like it would still be useful).

# In gunicorn_config.py

accesslog = "-"  # need something like this to enable access logging at all
logger_class = "utils.logging.StubbedGunicornLogger"

# In utils/logging.py

import gunicorn.glogging

class StubbedGunicornLogger(gunicorn.glogging.Logger):
    def setup(self, cfg):
        handler = logging.StreamHandler()
        error_logger = logging.getLogger("gunicorn.error")
        error_logger.addHandler(handler)
        access_logger = logging.getLogger("gunicorn.access")
        access_logger.addHandler(handler)
        self.error_log = CustomLogAdapter(error_logger, extra={})
        self.access_log = CustomLogAdapter(access_logger, extra={})
        self.error_log.setLevel(logging.INFO)
        self.access_log.setLevel(logging.INFO)

# CustomLogAdapter can use whatever kind of logging logic you want,
# or use a library like pygogo.utils.StructuredAdapter

i agree this should be better documented. Can you open a ticket related to it?

[benoitc]

I wrote a short blog post about this at http://pawamoy.github.io/2020/06/02/unify-logging-for-a-gunicorn-uvicorn-app/

I setup everything in a single file:

import os
import logging
import sys

from gunicorn.app.base import BaseApplication
from gunicorn.glogging import Logger
from loguru import logger

from my_app.app import app


LOG_LEVEL = logging.getLevelName(os.environ.get("LOG_LEVEL", "DEBUG"))
JSON_LOGS = True if os.environ.get("JSON_LOGS", "0") == "1" else False
WORKERS = int(os.environ.get("GUNICORN_WORKERS", "5"))


class InterceptHandler(logging.Handler):
    def emit(self, record):
        # Get corresponding Loguru level if it exists
        try:
            level = logger.level(record.levelname).name
        except ValueError:
            level = record.levelno

        # Find caller from where originated the logged message
        frame, depth = logging.currentframe(), 2
        while frame.f_code.co_filename == logging.__file__:
            frame = frame.f_back
            depth += 1

        logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage())


class StubbedGunicornLogger(Logger):
    def setup(self, cfg):
        handler = logging.NullHandler()
        self.error_logger = logging.getLogger("gunicorn.error")
        self.error_logger.addHandler(handler)
        self.access_logger = logging.getLogger("gunicorn.access")
        self.access_logger.addHandler(handler)
        self.error_log.setLevel(LOG_LEVEL)
        self.access_log.setLevel(LOG_LEVEL)


class StandaloneApplication(BaseApplication):
    """Our Gunicorn application."""

    def __init__(self, app, options=None):
        self.options = options or {}
        self.application = app
        super().__init__()

    def load_config(self):
        config = {
            key: value for key, value in self.options.items()
            if key in self.cfg.settings and value is not None
        }
        for key, value in config.items():
            self.cfg.set(key.lower(), value)

    def load(self):
        return self.application


if __name__ == '__main__':
    intercept_handler = InterceptHandler()
    # logging.basicConfig(handlers=[intercept_handler], level=LOG_LEVEL)
    # logging.root.handlers = [intercept_handler]
    logging.root.setLevel(LOG_LEVEL)

    seen = set()
    for name in [
        *logging.root.manager.loggerDict.keys(),
        "gunicorn",
        "gunicorn.access",
        "gunicorn.error",
        "uvicorn",
        "uvicorn.access",
        "uvicorn.error",
    ]:
        if name not in seen:
            seen.add(name.split(".")[0])
            logging.getLogger(name).handlers = [intercept_handler]

    logger.configure(handlers=[{"sink": sys.stdout, "serialize": JSON_LOGS}])

    options = {
        "bind": "0.0.0.0",
        "workers": WORKERS,
        "accesslog": "-",
        "errorlog": "-",
        "worker_class": "uvicorn.workers.UvicornWorker",
        "logger_class": StubbedGunicornLogger
    }

    StandaloneApplication(app, options).run()

thanks for the blog. It’s useful :)