Multiprocessing: How to write separate log files for each instance while using pool.map?

Question

I want to create a class where each instance writes its own log file. This works fine when I use a function instead of a class (or when I don´t use multiprocessing):

import multiprocessing, logging

def setup_logger(name_logfile, path_logfile):
        logger = logging.getLogger(name_logfile)
        formatter = logging.Formatter('%(asctime)s:   %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
        fileHandler = logging.FileHandler(path_logfile, mode='w')
        fileHandler.setFormatter(formatter)
        streamHandler = logging.StreamHandler()
        streamHandler.setFormatter(formatter)

        logger.setLevel(logging.DEBUG)
        logger.addHandler(fileHandler)
        logger.addHandler(streamHandler)
        return logger

    def MyFunc(A):
        print A
        logger = setup_logger('Logfile%s' %A, '/dev/shm/Logfile%s.log' %A)
        logger.info('text to be written to logfile')


    pool = multiprocessing.Pool(2)
    pool.map(MyFunc,[1,2])
    pool.close()
    pool.join()

But when I use a class, I get pickling errors:

import multiprocessing, logging

class MyClass(object):
    def __init__(self,A):
        print A
        self.logger = self.setup_logger('Logfile%s' %A, '/dev/shm/Logfile%s.log' %A)
        self.logger.info('text to be written to logfile')

    def setup_logger(self,name_logfile, path_logfile):
        logger = logging.getLogger(name_logfile)
        formatter = logging.Formatter('%(asctime)s:   %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
        fileHandler = logging.FileHandler(path_logfile, mode='w')
        fileHandler.setFormatter(formatter)
        streamHandler = logging.StreamHandler()
        streamHandler.setFormatter(formatter)

        logger.setLevel(logging.DEBUG)
        logger.addHandler(fileHandler)
        logger.addHandler(streamHandler)
        return logger

pool = multiprocessing.Pool(2)
pool.map(MyClass,[1,2])
pool.close()
pool.join()

OUT:

1
2
2015/02/12 14:05:09:   text to be written to logfile
2015/02/12 14:05:09:   text to be written to logfile
Process PoolWorker-1:
Traceback (most recent call last):
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    self.run()
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 114, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python2.7/multiprocessing/pool.py", line 99, in worker
Process PoolWorker-2:
    put((job, i, result))
  File "/usr/lib64/python2.7/multiprocessing/queues.py", line 392, in put
Traceback (most recent call last):
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    return send(obj)
PicklingError: Can't pickle <type 'thread.lock'>: attribute lookup thread.lock failed
    self.run()
  File "/usr/lib64/python2.7/multiprocessing/process.py", line 114, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python2.7/multiprocessing/pool.py", line 99, in worker
    put((job, i, result))
  File "/usr/lib64/python2.7/multiprocessing/queues.py", line 392, in put
    return send(obj)
PicklingError: Can't pickle <type 'thread.lock'>: attribute lookup thread.lock failed

I can´t figure out what is the reason for this error since every logfile has its own output path. I need the logger as an attribute of the object, so how can I work around this pickling error?

Answer 1

You cannot pickle loggers. What you can do instead is to remove and reset the loggers when the objects get pickled and unpickled:

import multiprocessing, logging


class MyClass(object):

   def __init__(self,A):
        print A
        self.A = A # we need to keep the name!
        self.logger = self.setup_logger('Logfile%s' %A, '/misc/hy5/scheffler/Skripte_Models/python/Tests/Logfile%s.log' %A)
        self.logger.info('text to be written to logfile')

    def setup_logger(self,name_logfile, path_logfile):
        logger = logging.getLogger(name_logfile)
        formatter = logging.Formatter('%(asctime)s:   %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
        fileHandler = logging.FileHandler(path_logfile, mode='w')
        fileHandler.setFormatter(formatter)
        streamHandler = logging.StreamHandler()
        streamHandler.setFormatter(formatter)

        logger.setLevel(logging.DEBUG)
        logger.addHandler(fileHandler)
        logger.addHandler(streamHandler)
        return logger

    def __getstate__(self):
        """Called for pickling.

        Removes the logger to allow pickling and returns a copy of `__dict__`.

        """
        statedict = self.__dict__.copy()
        if 'logger' in statedict:
            # Pickling does not work with loggers objects, so we just keep the logger's name:
            del statedict['logger']
        return statedict

    def __setstate__(self, statedict):
        """Called after loading a pickle dump.

        Restores `__dict__` from `statedict` and adds a new logger.

        """
        self.__dict__.update(statedict)
        process_name = multiprocessing.current_process().name
        self.logger = self.setup_logger('Logfile%s' % self.A, 
                       '/dev/shm/Logfile%s_%s.log' % (self.A, process_name)

Note that we add the process name to the log file to avoid multiple processes manipulating the very same file! You probably also want to make sure that the logging handlers and the corresponding files are closed at some point.

EDIT:

There is a multiprocessing aware logger in the multiprocessing module. However, I always find this one too limiting.