Pass progress bar to logger

[dr-costas]

Hi,

Can the tqdm.tqdm progress bar to be passed into a logger?

[lrq3000]

Yes, please see this and this. And if you like the solution, please give us a like here!

[ddofborg]

I solved it like this:

import logging
import time
from tqdm import tqdm
import io

class TqdmToLogger(io.StringIO):
    """
        Output stream for TQDM which will output to logger module instead of
        the StdOut.
    """
    logger = None
    level = None
    buf = ''
    def __init__(self,logger,level=None):
        super(TqdmToLogger, self).__init__()
        self.logger = logger
        self.level = level or logging.INFO
    def write(self,buf):
        self.buf = buf.strip('\r\n\t ')
    def flush(self):
        self.logger.log(self.level, self.buf)

if __name__ == "__main__":
    logging.basicConfig(format='%(asctime)s [%(levelname)-8s] %(message)s')
    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)

    tqdm_out = TqdmToLogger(logger,level=logging.INFO)
    for x in tqdm(range(100),file=tqdm_out,mininterval=30,):
        time.sleep(.5)

[clbarnes]

This could be tidied up even further if tqdm had a built-in class looking something like this:

from tqdm import tqdm

class stream(object):
    def write(self, s):
        tqdm.write(s)
    
    def flush():
        pass

NB: edited

Then, instead of having to define your own class with a special emit method, you could just do

import logging
from tqdm import stream

logger = logging.getLogger()
logger.addHandler(logging.StreamHandler(stream))

If we wanted to be really cheeky about it, the only thing which actually needs doing is for the tqdm class to get a flush(cls): pass classmethod - then it can be passed in directly. But then maybe it's doing too many things.

It would be great if either a TqdmStream (for use with a StreamHandler) or a TqdmLogHandler could be added to the library - saves users digging through old StackOverflow posts which are all confusing variations on the same theme!

EDIT: It turns out the python docs may be lying about the fact that StreamHandler only needs an object with write and flush members. It's also looked for fp and pos while I've been playing around with it.

Therefore, I think the best course of action is to have a single TqdmHandler for use with logging. Would it need its own buffering scheme?

[casperdcl]

Just a quick update on this. Currently I'm using:

import tqdm
import logging
import time


class TqdmStream(object):
  @classmethod
  def write(_, msg):
    tqdm.tqdm.write(msg, end='')

  # is this required?
  # @classmethod
  # def flush(_):
  #   pass


if __name__ == "__main__":
  logging.basicConfig(level=logging.DEBUG, stream=TqdmStream)

  log = logging.getLogger(__name__)
  log.info("loop")
  # for x in tqdm.trange(1, 101, mininterval=10):
  for x in tqdm.trange(1, 101):
    time.sleep(.2)
    if not x % 20:
      log.debug("in loop %d" % x)
  log.info("done")

does anyone have any objections to adding this version of TqdmStream?

[clbarnes]

@casperdcl - does that work for you, even with threading/ multiprocessing? When I tried that, the StreamHandler was also looking for flush, fp and pos as well as write. The discussion on #383 suggests there might be a race condition here.

It would be nice to have a TqdmStream instead of a TqdmHandler so that it can be used with basicConfig as you demonstrate, but it might be safer use use a TqdmHandler: I'm using this

from tqdm import tqdm

class TqdmHandler(logging.Handler):
    def emit(self, record):
        try:
            msg = self.format(record)
            tqdm.write(msg)  # , file=sys.stderr)
            self.flush()
        except (KeyboardInterrupt, SystemExit):
            raise
        except:
            self.handleError(record)

from a logutils.QueueListener in my use case. I don't have a concrete failing case, though.

[casperdcl]

Are you certain? There's no way a StreamHandler should know to look for fp or pos. Also AFAIK the flush method is optional for both tqdm and logging.

[gpakosz]

Is there an updated and recommended way to interface tqdm with logging please?

[jinyu121]

So, how tqdm work with the logging model, to put the log both in Screen and File?

I tried #313 (comment) , but it only supports screen. And use stream and handler at the same time is not allowed.

[Erawpalassalg]

@casperdcl example of TqdmStream breaks if the message contains a line feed (not printing anything after the line feed). Related issue is #724

Leaving the end arg (or setting it to end="\n", which are the same) fixes it but adds 2 line feeds instead of one (same with doing tqdm.tqdm.write(f"{msg}\n", end="").

Best way I've found to fix it is by adding a line feed at the end of every message. But that's kind of an aweful solution and we still got an unwanted line feed.

[evandrocoan]

I used this for my custom logging module:

import tqdm
import time
import contextlib

from debug_tools import getLogger
log = getLogger()


class DummyTqdmFile(object):
    """ Dummy file-like that will write to tqdm
    https://github.com/tqdm/tqdm/issues/313
    """
    file = None

    def __init__(self, file):
        self.file = file

    def write(self, x):
        # Avoid print() second call (useless \n)
        if len(x.rstrip()) > 0:
            tqdm.tqdm.write(x, file=self.file, end='')

    def flush(self):
        return getattr(self.file, "flush", lambda: None)()


@contextlib.contextmanager
def std_out_err_redirect_tqdm(log):

    try:
        if log._file:
            original_file = log._file.stream
            log._file.stream = DummyTqdmFile( original_file )
            yield original_file

        elif log._stream:
            original_stream = log._stream.stream
            log._stream.stream = DummyTqdmFile( original_stream )
            yield original_stream

    except Exception as exc:
        raise exc

    finally:
        if log._file:
            log._file.stream = original_file
        elif log._stream:
            log._stream.stream = original_stream


if __name__ == "__main__":
    log.info("loop")

    with std_out_err_redirect_tqdm( log ) as outputstream:
        for x in tqdm.trange( 1, 16, file=outputstream, dynamic_ncols=True ):
            time.sleep(.2)

            if not x % 5:
                log.debug("in loop %d\nnew line" % x)

        log.info("done")

Results:

[casperdcl]

yes tqdm.write should be renamed tqdm.print as it tries to be a little too clever.

[timothymugayi]

Might anyone have any insights on how we can ensure when outputting to logging we can print the progress bar on single line.

node-v12.13.1-darwin-x64.tar.gz: 0%| | 8.19k/18.4M [00:00<17:45, 17.3kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:Downloadnode-v12.13.1-darwin-x64.tar.gz: 0%| | 90.1k/18.4M [00:00<12:32, 24.3kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:Downloadnode-v12.13.1-darwin-x64.tar.gz: 1%|1 | 188k/18.4M [00:00<08:50, 34.3kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:DownloadFnode-v12.13.1-darwin-x64.tar.gz: 2%|1 | 311k/18.4M [00:00<06:13, 48.4kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:DownloadFnode-v12.13.1-darwin-x64.tar.gz: 2%|2 | 410k/18.4M [00:00<04:26, 67.4kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:DownloadFnode-v12.13.1-darwin-x64.tar.gz: 3%|2 | 508k/18.4M [00:01<03:11, 93.3kB/s] (24-11-2019T13:51:51+0800; logger.py:62)WARNING:DownloadF

Below seems to work in pycharm but not via the terminal on mac

class TqdmSystemLogger(io.StringIO):

    def __init__(self, logger, suppress_new_line=True):
        super(TqdmSystemLogger, self).__init__()
        self.logger = logger
        self.buf = ''
        if suppress_new_line:
            for handler in self.logger.handlers:
                if isinstance(handler, logging.StreamHandler):
                    handler.terminator = ""

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

    def flush(self):
        self.logger.log(self.logger.level, '\r' + self.buf)

was also exploring perhaps printing on the same line using logger formatter this partially works on the terminal but feels hacky. There's absolutely nothing wrong printing on a newline, for my use-case just looks better to load the progress bar in a single line using the python logger.

formatter = logging.Formatter('\x1b[80D\x1b[1A\x1b[K%(message)s')

[de-code]

Not sure if it is helpful, what I have done in the past is to extend tqdm:

import logging

from tqdm import tqdm


LOGGER = logging.getLogger(__name__)


class logging_tqdm(tqdm):
    def __init__(
            self,
            *args,
            logger: logging.Logger = None,
            mininterval: float = 1,
            bar_format: str = '{desc}{percentage:3.0f}%{r_bar}',
            desc: str = 'progress: ',
            **kwargs):
        self._logger = logger
        super().__init__(
            *args,
            mininterval=mininterval,
            bar_format=bar_format,
            desc=desc,
            **kwargs
        )

    @property
    def logger(self):
        if self._logger is not None:
            return self._logger
        return LOGGER

    def display(self, msg=None, pos=None):
        if not self.n:
            # skip progress bar before having processed anything
            return
        if not msg:
            msg = self.__str__()
        self.logger.info('%s', msg)

It has some different more log-friendly defaults.
(Redirecting to logging instead, seems to be in particular useful for environments like Kubernetes.)

[brtasavpatel]

import logging

from tqdm import tqdm


LOGGER = logging.getLogger(__name__)


class logging_tqdm(tqdm):
    def __init__(
            self,
            *args,
            logger: logging.Logger = None,
            mininterval: float = 1,
            bar_format: str = '{desc}{percentage:3.0f}%{r_bar}',
            desc: str = 'progress: ',
            **kwargs):
        self._logger = logger
        super().__init__(
            *args,
            mininterval=mininterval,
            bar_format=bar_format,
            desc=desc,
            **kwargs
        )

    @property
    def logger(self):
        if self._logger is not None:
            return self._logger
        return LOGGER

    def display(self, msg=None, pos=None):
        if not self.n:
            # skip progress bar before having processed anything
            return
        if not msg:
            msg = self.__str__()
        self.logger.info('%s', msg)

@de-code how to actually use this?

 with logging_tqdm(total=10) as pbar:
     for i in range(10):
         pbar.update()

doesn't show anything.

[casperdcl]

fixed by #1155 (tqdm>=4.60.0); please see https://github.com/tqdm/tqdm#redirecting-logging

[de-code]

fixed by #1155; please see https://github.com/tqdm/tqdm#redirecting-logging

@casperdcl I believe this issue is to do the opposite, send the tqdm output to logging (#1155 was about sending the logging to tqdm)

Happy to also create a PR with the #313 (comment)

[casperdcl]

Ah srry, right 🤦 - please do!

[de-code]

@de-code how to actually use this?

 with logging_tqdm(total=10) as pbar:
     for i in range(10):
         pbar.update()

doesn't show anything.

@brtasavpatel you need to configure logging first. e.g.

import logging

logging.basicConfig(level='INFO')

Then you could also add some delay (sleep) to see the effect more (otherwise a single line will be shown), e.g.:

from time import sleep

for item in logging_tqdm(range(10)):
    sleep(0.3)

[rostepifanov]

I use this variant for tqdm 4.61.0

import logging as log

from tqdm import tqdm
from io import StringIO

class TqdmLogFormatter(object):
    def __init__(self, logger):
        self._logger = logger

    def __enter__(self):
        self.__original_formatters = list()

        for handler in self._logger.handlers:
            self.__original_formatters.append(handler.formatter)

            handler.terminator = ''
            formatter = log.Formatter( '%(message)s')
            handler.setFormatter(formatter)

        return self._logger

    def __exit__(self, exc_type, exc_value, exc_traceback):
        for handler, formatter in zip(self._logger.handlers, self.__original_formatters):
            handler.terminator = '\n'
            handler.setFormatter(formatter)

class TqdmLogger(StringIO):
    def __init__(self, logger):
        super().__init__()

        self._logger = logger

    def write(self, buffer):
        with TqdmLogFormatter(self._logger) as logger:
            logger.info(buffer)

    def flush(self):
        pass

[zzeitt]

Sorry to bother, but I wonder has this issue been addressed?

[Shellcat-Zero]

Not sure if it is helpful, what I have done in the past is to extend tqdm:

import logging

from tqdm import tqdm


LOGGER = logging.getLogger(__name__)


class logging_tqdm(tqdm):
    def __init__(
            self,
            *args,
            logger: logging.Logger = None,
            mininterval: float = 1,
            bar_format: str = '{desc}{percentage:3.0f}%{r_bar}',
            desc: str = 'progress: ',
            **kwargs):
        self._logger = logger
        super().__init__(
            *args,
            mininterval=mininterval,
            bar_format=bar_format,
            desc=desc,
            **kwargs
        )

    @property
    def logger(self):
        if self._logger is not None:
            return self._logger
        return LOGGER

    def display(self, msg=None, pos=None):
        if not self.n:
            # skip progress bar before having processed anything
            return
        if not msg:
            msg = self.__str__()
        self.logger.info('%s', msg)

It has some different more log-friendly defaults. (Redirecting to logging instead, seems to be in particular useful for environments like Kubernetes.)

@de-code I was wondering if you could tell me how to log other info while using this, and also how to use a handler with it that has specified formatting. So far, my attempts are getting duplicated output, and lines which do not keep my specified formatting:

handler = WatchedFileHandler('example.log')
formatter = logging.Formatter('%(asctime)s %(levelname)s %(name)s %(lineno)d: %(message)s')
handler.setFormatter(formatter)
LOGGER.addHandler(handler)
...
LOGGER.info('outputting other important program info')

[Shellcat-Zero]

Ah, sorry to bother you, I just realized that handlers are mutually exclusive with basicConfig, so using them at the same time causes the errors I described.

[thawro]

It is also possible to send tqdm progress bar to log file via its __str__ representation. My solution is to create separate logger for cmd logging and separate for file logging (there is a need for two to not duplicate the tqdm output). Here is the code:

import logging
import colorlog
from tqdm.auto import tqdm
from tqdm.asyncio import tqdm_asyncio
import time
import sys
import io
from typing import Callable


def get_cmd_pylogger(name: str = __name__) -> logging.Logger:
    """Initialize command line logger"""
    formatter = colorlog.ColoredFormatter(
        fmt="%(asctime)s - %(log_color)s%(levelname)s%(reset)s - %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S",
        log_colors={
            "DEBUG": "cyan",
            "INFO": "green",
            "WARNING": "yellow",
            "ERROR": "red",
            "CRITICAL": "bold_red",
        },
    )
    logger = logging.getLogger(name)
    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(formatter)
    logger.addHandler(stream_handler)
    logger.setLevel(logging.DEBUG)
    return logger


def get_file_pylogger(filepath: str, name: str = __name__) -> logging.Logger:
    """Initialize .log file logger"""
    formatter = logging.Formatter(
        fmt="%(asctime)s - %(levelname)s - %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S",
    )
    logger = logging.getLogger(name)
    file_handler = logging.FileHandler(filepath, "a+")
    file_handler.setFormatter(formatter)
    logger.addHandler(file_handler)
    logger.setLevel(logging.DEBUG)
    return logger



class StdOutLogger(object):
    """Saves stdout outputs to log file."""
    def __init__(self, file_log: logging.Logger):
        self.terminal = sys.stdout
        self.log = file_log.handlers[0].stream
    
    def write(self, message: str):
        self.terminal.write(message)
        self.log.write(message)  
        
    def flush(self):
        # needed for python 3 compatibility.
        pass    
    

def remove_last_line(file_log: logging.Logger):
    """Remove the last line of log file"""
    file: io.TextIOWrapper = file_log.handlers[0].stream
    file.seek(0)
    lines = file.readlines()
    file.seek(0)
    file.truncate()
    file.writelines(lines[:-1])
    file.seek(0, 2)


def logged_tqdm(file_log: logging.Logger, tqdm_iter: tqdm_asyncio, fn: Callable):
    """Pass tqdm progressbar to log file and shot it in cmd.
    tqdm output is passed to stdout or stderr, so there is a need to pass its str form to the log file aswell,
    however logging by default appends to log files so there was a need to remove last line at each iteration, so
    the progress bar seems to be updated in the same line.
    """
    idx = 0
    for sample in tqdm_iter:
        file_log.info(str(tqdm_iter))
        fn(sample)
        if idx < tqdm_iter.total:
            remove_last_line(file_log) 
        idx += 1
    file_log.info(str(tqdm_iter))


if __name__ == "__main__":
    log = get_cmd_pylogger(__name__)
    file_log = get_file_pylogger("test.log", "log_file")
    log.handlers.append(file_log.handlers[0])
    sys.stdout = StdOutLogger(file_log)
    
    # test command line logger
    log.info("logger output (1) [ registered by cmd logger]")
    
    # test StdOutLogger
    print("Print output (1) [registered by file logger]")
    
    fn = lambda x: time.sleep(x/5)
    
    logged_tqdm(file_log, tqdm([1] * 10, ncols=100), fn)
    log.info("===========")
    print("++++++++++")
    logged_tqdm(file_log, tqdm([1] * 10, ncols=100), fn)
    
    print("End")

and here is how it works:

[cykac04]

class TqdmLogger(tqdm):
    def __init__(self, logger: logging.Logger, **kwargs):
        self._logger = logger
        self._logger.debug('Enter class')

        self._orig_terminator = list()

        for handler in self._logger.handlers:
            self._orig_terminator.append(handler.terminator)
            handler.terminator = '\r'

        self.kwargs = kwargs
        self.kwargs['file'] = TqdmLoggerIO(self._logger)
        super().__init__(**self.kwargs)

    def close(self):
        super().close()
        if self._orig_terminator:
            for handler in self._logger.handlers:
                handler.terminator = self._orig_terminator.pop(0)
            self._logger.debug('Exit class')

class TqdmLoggerIO(StringIO):
    def __init__(self, logger: logging.Logger):
        super().__init__()
        self._logger = logger

    def write(self, s):
        self._logger.log(self._logger.level, s.strip('\r'))

    def flush(self):
        pass

def tqdm_test(logger: logging.Logger):
    pbar = TqdmLogger(total=100, logger=logger)
    for x in range(0, 110, 10):
        if (d := x - pbar.n) > 0:
            pbar.update(d)
        time.sleep(.1)
    pbar.close()
    logger.debug('End of function!')

I have optimize the solution from rostepifanov above.

DEBUG:__main__:Enter class
DEBUG:__main__:100%|##########| 100/100 [00:01<00:00, 90.18it/s]
DEBUG:__main__:Exit class
DEBUG:__main__:End of function!

[clbarnes]

Just to clarify - these last couple of comments are about writing your tqdm output to a logger, rather than writing your log output using tqdm?

That's a separate concern and should be in a different issue. The original issue was motivated by a case like

import logging
from tqdm import tqdm

logger = logging.getLogger(__name__)

for item in tqdm([1,2,3,4,5])
    logger.info("processing %s", item)

logging.basicConfig(level=logging.INFO)

Which, by default, disrupts the progress bar by printing out in the middle of it.

Discussion not relevant to this issue should be taken elsewhere.

[rostepifanov]

I use this variant for tqdm 4.61.0

import logging as log

from tqdm import tqdm
from io import StringIO

class TqdmLogFormatter(object):
    def __init__(self, logger):
        self._logger = logger

    def __enter__(self):
        self.__original_formatters = list()

        for handler in self._logger.handlers:
            self.__original_formatters.append(handler.formatter)

            handler.terminator = ''
            formatter = log.Formatter( '%(message)s')
            handler.setFormatter(formatter)

        return self._logger

    def __exit__(self, exc_type, exc_value, exc_traceback):
        for handler, formatter in zip(self._logger.handlers, self.__original_formatters):
            handler.terminator = '\n'
            handler.setFormatter(formatter)

class TqdmLogger(StringIO):
    def __init__(self, logger):
        super().__init__()

        self._logger = logger

    def write(self, buffer):
        with TqdmLogFormatter(self._logger) as logger:
            logger.info(buffer)

    def flush(self):
        pass

Extension of previously posted code to minimal workable snippet :

import logging as log

from tqdm import tqdm as tqdm_
from io import StringIO

class TqdmLogFormatter(object):
    def __init__(self, logger):
        self._logger = logger

    def __enter__(self):
        self.__original_formatters = list()

        for handler in self._logger.handlers:
            self.__original_formatters.append(handler.formatter)

            handler.terminator = ''
            formatter = log.Formatter( '%(message)s')
            handler.setFormatter(formatter)

        return self._logger

    def __exit__(self, exc_type, exc_value, exc_traceback):
        for handler, formatter in zip(self._logger.handlers, self.__original_formatters):
            handler.terminator = '\n'
            handler.setFormatter(formatter)

class TqdmLogger(StringIO):
    def __init__(self, logger):
        super().__init__()

        self._logger = logger

    def write(self, buffer):
        with TqdmLogFormatter(self._logger) as logger:
            logger.info(buffer)

    def flush(self):
        pass

file_ = TqdmLogger(logger)
tqdm = lambda x, **lkwargs: tqdm_(x, file=file_, **lkwargs)

logger = log.Logger('test')
logger.setLevel(log.INFO)

handler = log.FileHandler( 'test.log',
                           mode='a',
                           encoding='utf-8' )

logger.addHandler(handler)

for _ in tqdm(range(100)):
    pass