Python rq.worker not honoring Django's LOGGING config

Question

I am trying to run a standalone script outside of a Django app that interfaces with a Redis queue and uses the Python rq module. Everything is working fine but somewhere in either upgrading to Python 3.8 (from 2.7) or upgrading from Django 2.2 (from 1.11) or from rq to 1.2.2 (from 0.13) rq stopped honoring the Django LOGGING config. Here is what my Django settings.py file looks like:

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "verbose": {
            "format": "%(asctime)s [%(process)d] [%(levelname)s] pathname=%(pathname)s lineno=%(lineno)s %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S"
        },
        "simple": {
            "format": "%(asctime)s [%(name)s] %(levelname)s - %(message)s"
        }
    },
    "handlers": {
        "null": {
            "level": "DEBUG",
            "class": "logging.NullHandler"
        },
        "console": {
            "level": "DEBUG",
            "class": "logging.StreamHandler",
            "formatter": "simple"
        }
    },
    "loggers": {
        "django.request": {
          "handlers": ["console"],
          "level": "ERROR",
          "propagate": True
        },
        "api": {
          "handlers": ["console"],
          "level": "DEBUG",
          "propagate": True
        },
        "worker": {
          "handlers": ["console"],
          "level": "DEBUG",
          "propagate": True
        },
        "rq.worker": {
          "handlers": ["console"],
          "level": "ERROR",
          "propagate": True
         }
    }
}

And here is what my worker.py looks like:

import django
django.setup()

import os
import logging
import redis
import multiprocessing
from rq import Queue, Connection
from rq.worker import HerokuWorker

logger = logging.getLogger("worker")

if __name__ == "__main__":
    redis_url = os.getenv("REDISTOGO_URL", None)
    if redis_url:
        conn = redis.from_url(redis_url)
        listen = ["high", "default", "low"]
        thread_count = int(os.getenv("WORKER_THREAD_COUNT", "4"))
        logger.debug("Setting up worker script, threads=%d", thread_count)

        with Connection(conn):
            workers = []
            for i in range(thread_count):
                worker = HerokuWorker(map(Queue, listen))
                p = multiprocessing.Process(target=worker.work)
                workers.append(p)
                p.start()
    else:
        logger.error("Could not find REDISTOGO_URL environment variable")

You can see I have rq.worker set to an ERROR level, but I'm getting INFO messages out on the console. This used to work just fine, but unfortunately I didn't notice this until after I finished upgrading everything. I tried removing the rq.worker section out of settings.py and the messages still get printed, but not in the format I defined. So I know my settings.py file is getting read properly. Has anyone else come across this or have any suggestions? I really do not want to have to fork rq just to resolve this.

score 1 · Answer 1 · answered Feb 17 '20 at 02:51

1

Naturally, 5 minutes after posting this I decided to look at the python-rq source and I found that the work method takes in a logging_level. This is what the new work line looks like:

p = multiprocessing.Process(target=worker.work, kwargs={"logging_level": "ERROR"})

Everything seems to be working as expected now.

answered Feb 17 '20 at 02:51

themanatuf

2,880
2
25
39

A more generic answer is: `some_worker.work(logging_level=logging.WARNING)` rq seems to ignore logging.config.dictConfig loglevels too, so it's the only way to fix this. – nicbou Aug 21 '22 at 11:25

Python rq.worker not honoring Django's LOGGING config

1 Answers1