Feature request: Create a config option for Celery to not touch logging config anywhere ever

[jdelic]

Working with Celery in a more complex environment, like ours, is very frustrating because it seems to remove handlers and then seemingly sets up arbitrary loggers (like a kombu.log.NullHandler for the 'celery' logger). This is done even when we set CELERYD_HIJACK_ROOT_LOGGER and CELERY_REDIRECT_STDOUTS to False.

At my company we have a default config for the logging module which we want all services to use all the time with no exceptions (because these messages get picked up and reformatted by logstash/logstash-forwarder and put into elasticsearch). The only way to use this with Celery currently seems to bring Celery up then iterate through all loggers and remove them forcefully and then set up a sane logging configuration. Which means we set logging up twice in our environment, with the alternative being to patch Celery or monkey-patch Celery.

So my feature request is this: I'd like to set CELERY_I_HUMBLY_REQUEST_YOU_STOP_EFFING_WITH_MY_LOGGING = True and then Celery should just not do anything to logging at all aside from writing log messages.

I apologize if this is already possible and I just missed the adequate settings in the docs.

[ionelmc]

You can use the setup_logging signal to have your own setup (or just disable celery's): http://docs.celeryproject.org/en/latest/userguide/signals.html#setup-logging

[jdelic]

Ok, hooking into setup_logging works for us like this (for future reference by other people):

from celery.signals import setup_logging
from lpconfig.logging import DJANGO_LOGGING  # this is our logging dictConfig used everywhere.
@setup_logging.connect
def jobinator_setup_logging(loglevel, logfile, format, colorize, **kwargs):
    import logging.config
    logging.config.dictConfigClass(DJANGO_LOGGING).configure()
    logging.info('LaterPay logging configured')

Now, I would still maintain that the more complex software the community writes in Python and the more complex these systems become (with Sentry now being deployed everywhere etc.). it would be great if any sufficiently complex project like Celery would at least make its default logging config adhere to best practices like 12factor/logs or just accept a dictConfig, like Django does, instead of the absurd mix of configuration variables that Celery provides.

But that's for you Celery devs to discuss 😃. Anyway @ionelmc thanks for your help! I'm closing this since my original feature request is invalid.

[ionelmc]

Well I guess we could at least add something about this in http://docs.celeryproject.org/en/latest/django/index.html

[jdelic]

Actually, I'd rather see a simple "make Celery conform to 12factor" documentation entry in the main documentation. That would go a long way.

[ionelmc]

It's already 12factor - it output to stderr by default :-)

[ask]

There are too many misbehaving libraries out there so we have to hijack everything to make sure we have actual output. Logging for python is the wild west but maybe some day...

[ask]

Also dictConfig? Do you seriously want to expose your users to that? :)

[jdelic]

@ionelmc sorry, 12factor mandates complete logging to stdout, not stderr, so it's not (see 12factor.net/logs).

@ask imho if your library touches the root logger at all, it's a bug. That I have to set a config variable to stop Celery from redirecting stdout is imho a bug, too. It's not Celery's job to destroy every other libraries logging "to make sure that it can output logs in an arbitrary location". However much other libraries are misbehaving... depending on the load order, Celery will just make it worse. I don't think the answer to Python's logging woes can be "hey, for each app and dependency in your requirements.txt/setup.py figure out the proprietary way to stop it from reconfiguring logging.root". The docs should say: "All Celery subsystems are under the "celery" logger. If you want to set that up: here is a valid config file" and then Celery should log whereever.

Also, "our users" in this case is the Ops team and they can handle a dictConfig just fine 😉, but they filed a bug against our codebase because we had to figure out why including Celery broke our logging in the first place.

Finally, sorry for the wall of text.

[ask]

I agree that it shouldn't work like that, but we don't have any choice when other libraries configures the logger. The most important part is that we have output as we had problems with some users complaining about how celery would just hang at startup not doing anything, when in reality the system worked fine but a library they imported called dictConfig.

The number of users who actually use logging in depth is thankfully very small, so it's not a big problem for the majority of users. Being simple to get started with is more important, and we don't want users to need a deep investigation into finding out how to get output from the worker. Also note
that if a 3rd party library messes up logging it's Celery who gets the blame, not the misbehaving library.

There are no best practices for logging in Python and no one knows how to use it properly. A better choice for Celery could be to use raw syslog instead.

[ask]

Btw, I'm not sure how the 12factor manifesto(?) applies here, as Celery is not a web app service.
And what is stdout and stderr in this context exactly? It's fd 1 and 2, and in the foreground these are redirected to the terminal, but the celery worker is foremost a daemon where fd 1 and 2 does not exist, so there is no stdout or stderr to log to, and neither is there any established convention: some use syslog, others use one or more logfiles.

[jdelic]

Celery is a frequently used building block of web apps. The default behavior of Celery seems to be to:

• delete all existing handlers from logging.root
• set up two different formats for tasks and "other things"
• redirect stderr and stdout to celery.redirected (the docs say "the current logger" in configuration.rst#L1664 btw, which seems to be wrong)
• Overwrite a couple of environment variables as another side effect of setting up logging

Btw, the only reference I can find to CELERY_REDIRECT_STDOUTS is in configuration.rst#L1658. So that should be removed, I guess?

Celery's documentation states:

"Celery does not daemonize itself, please use one of the following daemonization tools."

So I'd argue that since Celery does not close fds 1 and 2 and does not connect them to /dev/null, because it does not daemonize itself, it's not a daemon. Instead it typically runs in the foreground and probably shouldn't redirect stdout and stderr .

So as a frequent building block of web apps and not being a daemon by itself, my argument is that if such a library/service has any kind of default behavior, that behavior should be oriented towards best practices and I gave 12factor as an example, because forcing it's own output to stdout imho would be better behavior then redirecting all the things' output to Celery's log.

Aside from all this, Python logging and Celery's behavior is log4j in early 2000 all over again. Everybody ships their own "I shall consume everything" configuration 😢

[ionelmc]

I'm not sure I'm following here. You're saying celery redirects stdout/stderr output to Celery's log. My thoughts here (and I didn't design or contribute to this, I'm just an user):

• It's not celery's log in the first place, it's python's logging system
• It's a exceptionally good default: you will get timestamps, and process ids by default in the output.

And there's a bit of confusion in this discussion, celery can work in 2 ways:

• Do self-daemonization (it's used in the init scripts), close fd1/fd2 and log to a file
• Run as-is (the default, mind you) and just dump everything on stderr. You can use this mode with a process supervisor like supervisord, foreman, whatever - and this adheres to the lousy specified 12factor "standard". stderr is equivalent to stdout in the 12factor spec IMHO because it's not mentioned at all in it.

[ask]

stderr is equivalent to stdout in the 12factor spec IMHO because it's not mentioned at all in it.

Right, and also if all output should go to stdout then by inference stderr is left unused and you can easily redirect everything to stdout:

$ celery -A proj worker -l info 2>&1

Using stdout for logging instead of stderr is an option that can be considered.