Logging is blocked when log file is compressing

[lizheng2018CC]

Here is my code: logger.add(sink=filename, level=min_level, colorize=True, rotation='50 MB', retention=10, compression='tar.xz', enqueue=True, backtrace=False, diagnose=True, format=fmt, catch=True, encoding='utf8') When a log file reaches 50MB, logging is blocked, which takes about 10 seconds. I was wondering, can the compression process be made into a separate thread?

[Delgan]

Compression is done in a separate thread when enqueue=True.

Do you have a fully reproducible example? Your thread might be blocked for another reason.

[Delgan]

Re-reading the question, I see you talk about logging being blocked, not the main thread, sorry.

In this case, it's not possible to keep logging to a new file while the old one is compressed, indeed. I'm not sure I want to change that behavior, it might have undesirable side effects (the order in which the rotation, compression and retention steps are executed is very important, and it becomes even more complicated when you take into account that each parameter can be a custom function).

Is it a big problem? All messages will be logged once the compression is done. Also, sinks like sys.stderr should not be blocked thus logs will still be logged on terminal without interruption.

[lizheng2018CC]

Here is my test demo:

def log_test():
    from loguru import logger
    fmt = "<green>{time:YY-MM-DD HH:mm:ss}</green> |<level>{level: <7}</level>| <cyan>{name}</cyan>:<cyan>{" \
          "function}</cyan>:<cyan>{line}</cyan> - <level>{message}</level> "
    logger.add(sink=sys.stdout, level='INFO', colorize=True, backtrace=False, diagnose=True,
               format=fmt, catch=True)
    logger.add(sink='/home/lz/test.log', level='INFO', colorize=True, rotation='50 MB', retention=20, compression='tar.xz',
               enqueue=True, backtrace=False, diagnose=True,
               format=fmt, catch=True, encoding='utf8')
    while True:
        logger.info('fadsfdsffdsaffffdsfsfdfsdafdafdfadfdfadffffff{}fdasfdsfadfdsf{}', time.time(), time.time())

The problem I'm having here is that when the log file reaches 50MB, the whole thread blocks at logger.info() and the terminal doesn't have any prints. Is this platform-related? My computer using an ARM architecture processor.

[Delgan]

Thanks for the example.

It's not related to the processor architecture, actually it's a flaw in the internal design of enqueue=True.

Basically, when enqeue=True, log messages are serialized into a queue and processed in a background thread (including the compression step). However, this queue size is limited to 65,536 bytes. When this limit is reached, calling queue.put() will block until some space is made available. Because the background thread can't empty the queue when compression is in progress, the main thread can hang if too many messages are logged during this time.

This is a bug I was aware of and for which I have a fix in progress on a local branch. I'll try to publish it as soon as possible.

In the meantime, I can suggest to implement your own threaded compression function like this:

import os
import tarfile
import threading

from loguru import logger

def compression(filepath):
    filename = os.path.basename(filepath)
    with tarfile.open(filepath + ".tar.xz", mode="w:xz") as f:
        f.add(filepath, filename)

def threaded_compression(filepath):
    thread = threading.Thread(target=compression, args=(filepath, ), daemon=True)
    thread.start()

if __name__ == "__main__":
    fmt = "<green>{time:YY-MM-DD HH:mm:ss}</green> |<level>{level: <7}</level>| <cyan>{name}</cyan>:<cyan>{" \
          "function}</cyan>:<cyan>{line}</cyan> - <level>{message}</level> "
    logger.add(sink='/home/lz/test.log', level='INFO', colorize=True, rotation='50 MB', retention=20,
               compression=threaded_compression, enqueue=True, backtrace=False, diagnose=True,
               format=fmt, catch=True, encoding='utf8')

[mberdyshev]

Hello, @Delgan! Have you had time to fix this bug? Is it available on some branch?

[Delgan]

@mberdyshev I have a fix for this, but right now it's not merged because there is a bug with PyPy I struggle to understand.

[mberdyshev]

@Delgan Is it possible to help you with the PyPy bug?

[Delgan]

@mberdyshev I'm in the process of producing a minimal reproducible example that I could share with the Pypy team (assuming it's not a Loguru bug), but I'm cruelly lacking free time at the moment.

The problem can be observed on this branch which causes Pypy tests to hang forever.