[Python] Is there a reason not to replace the default logging.Handler lock with a...

I've got some code that, for reasons not germane to the problem at hand:

1. Must write very large log messages
2. Must write them from multiple multiprocessing worker processes
3. Must not interleave the logs at all

Performance of logging is a secondary consideration; I'm not writing very many logs.

The problem we've encountered is that our logs are so big (a single log can be up to 1 GB in size) that they appear to be written via multiple underlying write calls, and if another process emits a small log in the middle of the larger log being written, the log is broken up (and can't be parsed by the tooling we use to upload events). This is possible because the logging module is only thread-safe, not multiprocess-safe; the lock it takes when emiting a log is a threading.RLock and therefore two worker processes can be emiting to the same file at the same time, and if the log is large enough to not be handled atomically, oops, they can interleave.

We can't use a QueueHandler, because we need to be able to block on an os.fsync call in certain circumstances (we're logging to a FUSE-based file system that parses what we send and uploads it to RabbitMQ with publisher_confirms enabled, but only blocks the writing process if the calling process fsyncs the file, so important messages can be blocked on until all prior messages are confirmed, while simple logs can be allowed to occur in the background).

My idea is to have our existing (already custom, to enable the conditional fsync) log StreamHandler subclass redefine Handler.create_lock (and .acquire and .release for good measure, since the name of the attribute, .lock, doesn't appear to be a documented guarantee) to return a multiprocessing.RLock instead of a threading.RLock.

The downside would be that when a huge log message is being written, nothing else can emit logs, but I don't see any other downsides. But I'm a little concerned, because I see no one else who has even considered doing this, and I'm worried I'm missing something obvious. It's possible no one else does it because performance trumps blocking behavior in most such cases, but I want to make sure I haven't missed anything else.

TL;DR: Will defining a StreamHandler subclass like:

import logging
import multiprocessing

class FuseHandler(logging.StreamHandler):

def create_lock(self):
self.lock = multiprocessing.RLock()

def acquire(self):
self.lock.acquire()

def release(self):
self.lock.release()

def emit(self):
# Custom code that sometimes os.fsync's the file after the write here


cause any problems I'm not foreseeing (beyond the slightly slower locking performance, and the pile-up effect if a big message takes a few seconds to be written and other logs are waiting on it)?

Continue reading...