Change logging "print" function to "tqdm.write" so logging doesn't interfere with progress bars

Question

I have a simple question: How do I change the built-in Python logger's print function to tqdm.write such that logging messages do not interfere with tqdm's progress bars?

Lupercalia

If you have to stick with tqdm, then @RolKau's answer is the way to go, but tqdm clears and redraws all of the progress bars on each write, so it's easy to overwhelm it if you have a lot of output. If you're not suck with tqdm, Enlighten does what you need out of the box and will hold up better under load since it doesn't rely on redrawing. – Intervention

Answer 1

You need a custom logging handler:

import logging
import tqdm

class TqdmLoggingHandler(logging.Handler):
    def __init__(self, level=logging.NOTSET):
        super().__init__(level)

    def emit(self, record):
        try:
            msg = self.format(record)
            tqdm.tqdm.write(msg)
            self.flush()
        except Exception:
            self.handleError(record)  

and then add this to the logging chain:

import time

log = logging.getLogger(__name__)
log.setLevel(logging.INFO)
log.addHandler(TqdmLoggingHandler())
for i in tqdm.tqdm(range(100)):
    if i == 50:
        log.info("Half-way there!")
    time.sleep(0.1)

Edit: Fixed a bug in the call to super TqdmLoggingHandler's init method, that was pointed out by diligent reader @BlaineRogers in the comments. (If anyone wants to read further about this murky area of Python, I recommend https://fuhm.net/super-harmful/)

Mussman

I needed something to use logging module for output, solved it like this: https://mcmap.net/q/408978/-python-progress-bar-through-logging-module. Output is like this: 2016-12-19 15:35:06 [INFO ] 16%|#####9 | 768/4928 [07:04<40:50, 1.70it/s] – Misleading

it is important to use import tqdm not from tqdm import tqdm else the IO will interrupt the progress bar – Nodababus

super(self.__class__, self).__init__(level) will cause a RecursionError if you ever try to instantiate a subclass of TqdmLoggingHandler. super(cls, self).__init__() calls the __init__ method of the class after cls in the method resolution order of self.__class__. Let MyTqdmLoggingHandler be a subclass of TqdmLoggingHandler. Then MyTqdmLoggingHandler() calls TqdmLoggingHandler.__init__(self), which calls super(MyTqdmLoggingHandler, self).__init__(), which calls TqdmLoggingHandler.__init__(self). – Adsorbent

@BlaineRogers You are absolutely right! Thank you for pointing this out. I must apparently have written this before I became familiar with the MRO. I will correct the answer, in case anyone wants to use the code. – Mussman

I don't think that reference to the ancient "Super considered harmful" does anyone any good. Please see Raymond Hettinger's talk "Super Considered Super!" for a thorough rebuttal. youtu.be/EiOglTERPEo – Vitrify

Since we are in Jupyter Notebook, it should be tqdm.notebook.tqdm.write instead of tqdm.tqdm.write – Pinite

Answer 2

tqdm now has a built-in contextmanager for redirecting the logger:

import logging
from tqdm import trange
from tqdm.contrib.logging import logging_redirect_tqdm

LOG = logging.getLogger(__name__)

if __name__ == '__main__':
    logging.basicConfig(level=logging.INFO)
    with logging_redirect_tqdm():
        for i in trange(9):
            if i == 4:
                LOG.info("console logging redirected to `tqdm.write()`")
    # logging restored

Copied from tqdm documentation

Tavey

out of all the above answers. only this worked. Should be marked as accepted. – Socrates

If you've set your own formatter for LOG, then you should do logging_redirect_tqdm(loggers=[LOG]). This will cause tqdm to use LOG's formatter. – Epigram

this answer is more up to date, works and is much more straightforward than the accepted one. – Ingunna

It does require a context manager wherever one wants to use tqdm.write though, whereas the other solution can be used to make the change globally. – Lupercalia

Answer 3

Based on RolKau's answer above, simplified:

import logging
from tqdm import tqdm


class TqdmLoggingHandler(logging.StreamHandler):
    """Avoid tqdm progress bar interruption by logger's output to console"""
    # see logging.StreamHandler.eval method:
    # https://github.com/python/cpython/blob/d2e2534751fd675c4d5d3adc208bf4fc984da7bf/Lib/logging/__init__.py#L1082-L1091
    # and tqdm.write method:
    # https://github.com/tqdm/tqdm/blob/f86104a1f30c38e6f80bfd8fb16d5fcde1e7749f/tqdm/std.py#L614-L620

    def emit(self, record):
        try:
            msg = self.format(record)
            tqdm.write(msg, end=self.terminator)
        except RecursionError:
            raise
        except Exception:
            self.handleError(record)

Testing:

import time

log = logging.getLogger(__name__)
log.setLevel(logging.INFO)
log.addHandler(TqdmLoggingHandler())
#   ^-- Assumes this will be the unique handler emitting messages to sys.stdout.
#       If other handlers output to sys.stdout (without tqdm.write),
#       progress bar will be interrupted by those outputs

for i in tqdm(range(20)):
    log.info(f"Looping {i}")
    time.sleep(0.1)

Caveat: if you're working in a Jupyter notebook, progress bar will be interrupted and AFAIK there's no way to avoid it.

Feathercut

Answer 4

One easy solution, not so elegant, is convert the tqdm object to string. After that yo can log the message (or handle it as you want). The "format_dict" attribute may be useful as well:

from tqdm import tqdm
import time

#loop with progressbar:
it=tqdm(total=10)
for i in range(10):
    time.sleep(0.1)
    it.update(1)

it.close()
print("\n","--"*10)

# Convert tdqm object last output to sting
str_bar_msg = str(it)
print(str_bar_msg)

# See attributes:
print(it.format_dict)

output:

100%|██████████| 10/10 [00:01<00:00,  8.99it/s]
 --------------------
100%|██████████| 10/10 [00:01<00:00,  8.98it/s]
{'n': 10, 'total': 10, 'elapsed': 1.1145293712615967, 'ncols': None, 'nrows': None, 'prefix': '', 'ascii': False, 'unit': 'it', 'unit_scale': False, 'rate': None, 'bar_format': None, 'postfix': None, 'unit_divisor': 1000, 'initial': 0, 'colour': None}

Best regards

Fessler

Use from tqdm.notebook import tqdm if you are in Jupyter Notebook – Pinite

actually use from tqdm.auto import tqdm to auto detect if you are in a jupyter notebook and use the appropriate bar – Gunther

Answer 5

the easiest way is change stream of StreamHandler object e.g.:

import logging
from tqdm import tqdm, trange
import time

log = logging.getLogger(__name__)
log.setLevel(logging.INFO)
handler = logging.StreamHandler()
handler.setStream(tqdm) # <-- important
handler = log.addHandler(handler)

for i in trange(100):
    if i == 50:
        log.info("Half-way there!")
    time.sleep(0.1)

Advocacy

Not working, a warning appears in log.info when executed directly in COLAB. – Connieconniption

replace log.info("Half-way there!") by tqdm.write("Half-way there!"). result is the same, wchich mean the problem is module tqdm itself, because .write(...) is official print method while using tqdm. – Advocacy

Answer 6

The new io handler is useful!

class TqdmToLogger(io.StringIO):
    logger = None
    level = None
    buf = ""

    def __init__(self, logger, level=None, mininterval=5):
        super(TqdmToLogger, self).__init__()
        self.logger = logger
        self.level = level or logging.INFO
        self.mininterval = mininterval
        self.last_time = 0

    def write(self, buf):
        self.buf = buf.strip("\r\n\t ")

    def flush(self):
        if len(self.buf) > 0 and time.time() - self.last_time > self.mininterval:
            self.logger.log(self.level, self.buf)
            self.last_time = time.time()```

# before this line, you need to create logger with file handler
tqdm_out = TqdmToLogger(logger)
tbar = tqdm(sample, total=len(sample), file=tqdm_out)

logger.info("Model Inference.")
for it, batch_data in enumerate(tbar):
   pass

```

Boehmite

As it’s currently written, your answer is unclear. Please edit to add additional details that will help others understand how this addresses the question asked. You can find more information on how to write good answers in the help center. – Swagman

Answer 7

I would add yet another option for these looking for a simple fix to avoid log messages being printed on the same line of the tqdm output. If logging messages start with "\n" then you have an extra blank line between each logging message, which is not best, but this way you end the tqdm text before continuing it.

So everything becomes perfectly readable again by simply adding "\n" at the start of the logging format string:

logging.basicConfig(format='\n... the rest of your format string ...')

I did't try the other answers because they rely on the internal working of tqdm, so I would have to check compatibility with current version.

The above solution is also safe for multiprocessing where it would not be trivial to coordinate logging as proposed by some solutions.

Also, for future visitors: take a look at the currently open issue of tqdm and also this merged contribution.

Acquaint