Dramatiq dont boot in Django environnement if LOGGING are used.

[LucSIGIER-LIAL]

Hello everyone.

In my Django application i used Dramatiq and i found out using LOGGING and Dramatiq in the same time make dramatiq fail to boot. My configuration :

DRAMATIQ_BROKER = {
    "BROKER": "dramatiq.brokers.redis.RedisBroker",
    "OPTIONS": {
        "url": "redis://localhost:6379",
    },
    "MIDDLEWARE": [
        "dramatiq.middleware.AgeLimit",
        "dramatiq.middleware.TimeLimit",
        "dramatiq.middleware.Callbacks",
        "dramatiq.middleware.Retries",
        "dramatiq.middleware.Pipelines",
        "django_dramatiq.middleware.AdminMiddleware",
        "django_dramatiq.middleware.DbConnectionsMiddleware",
    ]
}
DRAMATIQ_RESULT_BACKEND = {
    "BACKEND": "dramatiq.results.backends.redis.RedisBackend",
    "BACKEND_OPTIONS": {
        "url": "redis://localhost:6379",
    },
    "MIDDLEWARE_OPTIONS": {
        "result_ttl": 60000
    }
}

### LOGGING CONFIGURATION
LOGGING = {
    'version': 1,

    'handlers': {
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'foobar.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'ERROR',
            'propagate': True,
        },
    },
}

When i run the command > python .\manage.py rundramatiq That the results i have :

 * Discovered tasks module: 'django_dramatiq.tasks'
 * Discovered tasks module: 'APPLICATION.A13.A13_LOG_0005.tasks'
 * Running dramatiq: "dramatiq --path . --processes 8 --threads 8 --worker-shutdown-timeout 600000 django_dramatiq.setup django_dramatiq.tasks APPLICATION.A13.A13_LOG_0005.tasks"

[2024-05-27 10:51:57,250] [PID 22840] [MainThread] [dramatiq.MainProcess] [INFO] Dramatiq '1.17.0' is booting up.

If i erase my LOGGING configuration dramatiq boot well :

python .\manage.py rundramatiq
 * Discovered tasks module: 'django_dramatiq.tasks'
 * Discovered tasks module: 'APPLICATION.A13.A13_LOG_0005.tasks'
 * Running dramatiq: "dramatiq --path . --processes 8 --threads 8 --worker-shutdown-timeout 600000 django_dramatiq.setup django_dramatiq.tasks APPLICATION.A13.A13_LOG_0005.tasks"

[2024-05-27 10:54:27,089] [PID 27008] [MainThread] [dramatiq.MainProcess] [INFO] Dramatiq '1.17.0' is booting up.
[2024-05-27 10:54:25,697] [PID 25540] [MainThread] [dramatiq.WorkerProcess(0)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,033] [PID 23476] [MainThread] [dramatiq.WorkerProcess(1)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,452] [PID 17960] [MainThread] [dramatiq.WorkerProcess(2)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,481] [PID 27636] [MainThread] [dramatiq.WorkerProcess(3)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,571] [PID 20408] [MainThread] [dramatiq.WorkerProcess(4)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,678] [PID 11428] [MainThread] [dramatiq.WorkerProcess(5)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:26,904] [PID 26192] [MainThread] [dramatiq.WorkerProcess(6)] [INFO] Worker process is ready for action.
[2024-05-27 10:54:27,089] [PID 25200] [MainThread] [dramatiq.WorkerProcess(7)] [INFO] Worker process is ready for action.

It's a know issue ? If yes what can i do to fix this ?

[amureki]

Greetings @LucSIGIER-LIAL !

django_dramatiq and dramatiq libraries loading is not affected by Django's logging module.

Let's me try to clarify a couple of things to make sure we are on the same page.

In your LOGGING configuration I see that you are setting django logger (the only logger) to level ERROR. That means logging messages under ERROR level (so, INFO for example) are not tracked.

And since there is no explicit custom dramatiq logger set, it uses here the django one. Thus, you are not seeing all WorkerProcess messages, as you are excluding them.

To validate this, try to update your django logger level to INFO and boot it again. You will see WorkerProcess messages as you are expecting them.

Best, Rust