0

Problem

I pass a logging (logger) object, supposed to add lines to test.log, to a function background_task() that is run by the rq utility (task queues manager). logger has a FileHandler assigned to it to allow logging to test.log. Until background_task() is run, you can see the file handler present in logger.handlers, but when the logger is passed to background_task() and background_task() is run by rq worker, logger.handlers gets empty.

But if I ditch rq (and Redis) and just run background_task right away, the content of logger.handlers is preserved. So, it has something to do with rq (and, probably, task queuing in general, it's a new topic for me).

Steps to reproduce

  1. Run add_job.py: python3 add_job.py. You'll see the output of print(logger.handlers) called from within add_job(): there will be a handlers list containing FileHandler added in get_job_logger().
  2. Run command rq worker to start executing the queued task. You'll see the output of print(logger.handlers) once again but this time called from within background_task() and the list will be empty! Handlers of the logging (logger) object somehow get lost when the function that accepts a logger as an argument is run by rq (rq worker). What gives?

Here's how it looks like in the terminal:

$ python3 add_job.py
[<FileHandler /home/user/project/test.log (INFO)>]

$ rq worker
17:44:45 Worker rq:worker:2bbad3623e95438f81396c662cb01284: started, version 1.10.1
17:44:45 Subscribing to channel rq:pubsub:2bbad3623e95438f81396c662cb01284
17:44:45 *** Listening on default...
17:44:45 default: tasks.background_task(<RootLogger root (INFO)>) (5a5301be-efc3-49a7-ab0c-f7cf0a4bd3e5)
[]

Source code

add_job.py

import logging
from logging import FileHandler
from redis import Redis
from rq import Queue

from tasks import background_task


def add_job():
    r = Redis()
    qu = Queue(connection=r)
    logger = get_job_logger()

    print(logger.handlers)

    job = qu.enqueue(background_task, logger)


def get_job_logger():
    logger = logging.getLogger()
    logger.setLevel(logging.INFO)

    logger_file_handler = FileHandler('test.log')
    logger_file_handler.setLevel(logging.INFO)
    logger.addHandler(logger_file_handler)

    return logger


if __name__ == '__main__':
    add_job()

tasks.py

def background_task(logger):
    print(logger.handlers)
m_ocean
  • 327
  • 3
  • 11

1 Answers1

0

Answered here.

FileHandler does not get carried over into other threads. You start the FileHandler in the main thread and rq worker starts other threads. Memory is not shared like that.

Hm, I see... Thanks!

I assumed the FileHandler was being serialized or whatnot when written to Redis as a part of the whole logger object and then reinitialized when popping out of the queue.

Anyway, I'll try passing a file path to the function and initialize a logger from within. That way, keeping the FileHandler object to one thread.

EDIT: yeah, it works

m_ocean
  • 327
  • 3
  • 11