Jupyter mixes stdout and stderr output in non-deterministic order

[Guzzii]

Description

A dummy progress bar would be created after finishing each outer iteration, looking like below. The code to reproduce the issue is attached. It works fine without print though. Is there any way to avoid this behavior?

100% (100 of 100) |######################| Elapsed Time: 0:00:01 Time:  0:00:01
 16% (16 of 100) |###                    | Elapsed Time: 0:00:00 ETA:   0:00:01
0
100% (100 of 100) |######################| Elapsed Time: 0:00:01 Time:  0:00:01
 16% (16 of 100) |###                    | Elapsed Time: 0:00:00 ETA:   0:00:00
1
100% (100 of 100) |######################| Elapsed Time: 0:00:01 Time:  0:00:01
2

Code

import time
import progressbar

for i in range(3):
    for j in progressbar.progressbar(range(0, 100)):
        time.sleep(0.01)
    print(i)

Versions

• Python version: 3.6
• Python distribution/environment: Anaconda
• Operating System: macOS 10.13
• Package version: 3.37.1

[wolph]

I cannot reproduce it in either the normal Python console or Anaconda. Can you try in a regular Python console just to make sure it's not related to Anaconda?

[Guzzii]

Hi @wolph. Sorry for the confusion. You are right. It works in python/ipython console. It only seems to have issue in Jupiter notebook.

[aaronjohnson92]

I reproduced this on python 3.7 in windows cmd, as well as on arch linux.

[wolph]

It seems like a bug in Jupyter outside of my control.

When running this code:

import time
import progressbar


for i in range(3):
    bar = progressbar.ProgressBar()
    
    for j in bar(range(10)):
        if j == 0:
            bar.widgets = ['bar i: %d :: ' % i] + bar.widgets
    
        time.sleep(0.1)
    print('print i: %d' % i)

The result is:

bar i: 0 :: 100% (10 of 10) |############| Elapsed Time: 0:00:01 Time:  0:00:01
bar i: 1 ::  10% (1 of 10) |#            | Elapsed Time: 0:00:00 ETA:   0:00:00
print i: 0
bar i: 1 :: 100% (10 of 10) |############| Elapsed Time: 0:00:01 Time:  0:00:01
bar i: 2 ::  10% (1 of 10) |#            | Elapsed Time: 0:00:00 ETA:   0:00:00
print i: 1
bar i: 2 :: 100% (10 of 10) |############| Elapsed Time: 0:00:01 Time:  0:00:01
print i: 2

That means that the stdout output is being buffered and printed at the wrong time. This is very similar to a bug in the Jetbrains editors (Pycharm specifically, but they all have it): #115

The good news is, as opposed to the bug in Pycharm, this bug can easily be circumvented. Simply add a sys.stdout.flush() between the print() and the start of the next bar and you're done :)

import sys
import time
import progressbar


for i in range(3):
    sys.stdout.flush()
    for j in progressbar.progressbar(range(10)):
        time.sleep(0.1)
    print('print i: %d' % i)

[Guzzii]

Thanks for looking into the issue @wolph . The trick works for me. It is a lot cleaner now

[HDembinski]

@wolph I just stumbled over the same issue. Why can't progressbar.progressbar call stdout.flush before it is starting to print, to avoid this issue?

[wolph]

@HDembinski when stdout redirection is enabled it would do at. If stdout redirection is not enabled the progressbar assumes that it's under your control and won't touch it.

Instead of manually flushing that might be a better solution :)

[HDembinski]

Instead of manually flushing that might be a better solution :)

Sorry, I don't follow what you mean.

I am generally very happy with progressbar, it is well designed and I can see that you care about the details and that things "just work". Perhaps as a workaround for the Jupyter notebook bug progressbar could check sys.stdout, which is an instance of ipykernel.iostream.OutStream in a notebook, and in that case flush automatically?

[wolph]

I was replying from my phone so I couldn't post an example. I mean the output redirection: https://github.com/WoLpH/python-progressbar#combining-progressbars-with-print-output

import time
import progressbar

for i in progressbar.progressbar(range(100), redirect_stdout=True):
    print('Some text', i)
    time.sleep(0.1)

Although I suppose detecting for that specific stream would be an option too, I'm not entirely sure which implementation would be best here. Automatically enabling the stdout redirection as mentioned above would be the easiest and probably works well in all cases but I'm a bit worried it can break things for people that also do iostream detection.

At the very least I'll need to make sure people can still disable the behaviour just in case they're somehow dependent on it. Wouldn't be the first time ;)

XKCD springs to mind: https://xkcd.com/1172/

[HDembinski]

Right, as a fellow maintainer I know. Thanks for reopening.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.