tqdm + logging, message containing line feed gets eaten after line feed

[Erawpalassalg]

tqdm v. 4.31.1
Python v. 3.7.0
Linux version : Debian stretch (this bug does not reproduce on MacOs or ArchLinux)

When using tqdm with logging, configured as @casperdcl suggests it in #313 BUT with a line feed in the message, tqdm eats the new line.

Test code:

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\nnew line" % x)
  log.info("done")

Now, several test cases:

• If a \n is added to the end of the message, the text now gets displayed properly (with the line feed at the end, but we asked for it)
• If we use end="\n" instead of end="", the message gets displayed properly but with two line feeds at the end.
• passing end="test" shows that tqdm seems to have an issue with stdout buffering, since it appends "test" to the next logging line (probably an issue on itself, not sure how it's related to this issue)

One might think that this is a flushing issue, but adding the following solves the 3rd test case (while breaking the progress bar though), while doing nothing for the 2nd one (not even breaking the progress bar).

import sys

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

  @classmethod
  def flush(_):
    sys.sdout.flush()

[evandrocoan]

BUT with a line feed in the message, tqdm eats the new line.

I did not understand this. I created simplified version of your example, reducing the time and loop range for fast results:

import tqdm
import sys
import logging
import time

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)()

if __name__ == "__main__":
    logging.basicConfig(level=logging.DEBUG, stream=DummyTqdmFile(sys.stderr))
    log = logging.getLogger(__name__)
    log.info("loop")

    for x in tqdm.trange(1, 16):
        time.sleep(.2)

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

    log.info("done")

When I run your example here under Cygwin mintty.exe, with Anaconda Python 3.7.2 and tqdm 4.23.4 I got this:

Is what is wrong with this results?

Running the same example inside Sublime Text, I got this:

Running the same example inside Windows cmd.exe, I got this:

[casperdcl]

yes well tqdm.write should be renamed tqdm.print. it tries to be perhaps a little too intelligent.

[aliaksandr-tsukanau]

Experiencing similar problems inside PyCharm on Ubuntu 18.04. Would love to see a fix :)

[golyalpha]

I have a slightly different issue, with tqdm progressbars getting reordered in an unusual way.

Here's an asciinema recording of the behaviour: https://asciinema.org/a/w2DZIs0uMov5VERFJrlk8nw6j (sorry for the relatively long downloads)