Order of stdout and stderr is messed up

[mgeier]

Code:

import sys

print('stderr1', file=sys.stderr)
print('stdout1')
print('stderr2', file=sys.stderr)
print('stdout2')

Output:

stdout1
stdout2
stderr1
stderr2

Expected output:

stderr1
stdout1
stderr2
stdout2

This happens with:

python3 -m notebook
python3 -m jupyter_console

The error does not occur with:

python3 -m IPython

... where the order is as expected.

I've already reported this quite some time ago in jupyter/help#111, where there was some chit-chat and then I was sent here.

[takluyver]

The suggested solution is to make writing to either stream flush the other one - so a write to stderr flushes stdout.

[Carreau]

It might have been pointed out before, but that's (AFAIU) how stderr/out are supposed to work, even C is affected:

https://stackoverflow.com/questions/1242974/write-to-stdout-and-printf-output-not-interleaved

It's also consistent with what I get in my shell when I call a pure python script: (called many time to show the randomness or order).

 ~ $ python foo.py
stdout1
stdout2
stderr1
stderr2
 ~ $ python foo.py
stderr1
stderr2
stdout1
stdout2
 ~ $ cat foo.py
import sys

print('stderr1', file=sys.stderr)
print('stdout1')
print('stderr2', file=sys.stderr)
print('stdout2')

So I would like to be careful to not guaranty a behavior that happen to appear to work in IPython in some shells but not in Python.

[takluyver]

Yeah, the current behaviour is not actually wrong. But it can cause confusion (e.g. jupyter/notebook#3070), so if it's practical to make it behave more like people expect, I don't think there's much risk in doing so.

[Carreau]

I don't think there's much risk in doing so.

We should probably flush only if the stream that going to be flushed end with a \n otherwise the behavior will likely not be correct. It will also risk screwing up any \r.

[mgeier]

@Carreau Thanks for trying this out!

It's also consistent with what I get in my shell when I call a pure python script: (called many time to show the randomness or order).

How did you call this script?
I've tried calling it many times on the terminal, and I always got the same output:

stderr1
stdout1
stderr2
stdout2

that's (AFAIU) how stderr/out are supposed to work

I understand that stdout is typically buffered, and for good reasons.
And stderr is typically unbuffered, also for good reasons.

And that's why the current ipykernel behavior is so unexpected, because it consistently displays stdout before stderr.

So I'll have to update the expected case I mentioned above. In addition to one expected output (in the order of calls)

stderr1
stdout1
stderr2
stdout2

... I wouldn't be surprised if sometimes some stderr output is displayed before some stdout output, like e.g.

stderr1
stderr2
stdout1
stdout2

But I would never expect stdout to "overtake" stderr (and I'm wondering why this happened in @Carreau's example).

So why does ipykernel seem to consistently show stdout first and then stderr?
Wouldn't it be possible just to switch those?

I don't know how exactly the buffering works in ipykernel, but what about disabling the buffering for stderr while keeping it for stdout?

Regarding the "flushing" solution suggested by @takluyver: What about making it asymmetrical and only flush stderr when a stdout message comes in?

All of these solutions would probably to some extent emulate the behavior of stderr being somewhat unbuffered (I'm trying to be intentionally vague here).

[bartoszcichocki87]

Hi,
Any luck on finding a solution on this case?
I'm currently using time.sleep(0.1) just before and right after print to sys.stderr but it is not optimal solution for bigger projects.

[shredEngineer]

bump