subprocess bufsize=1 docs are misleading

[raylu]

BPO	21332
Nosy	@gpshead, @pitrou, @vstinner, @jwilk, @4kir4, @vadmium
PRs	bpo-32236: Issue RuntimeWarning if buffering=1 for open() in binary mode #4842
Files	subprocess-line-buffering-issue21332.patch: update docs, add tests, pass line_buffering subprocess-line-buffering-issue21332-ps2.patch: modify test_universal_newlines to work with Python io implementation subprocess-line-buffering-issue21332-ps3.patch: avoid big timeout in the tests subprocess-line-buffering-issue21332-ps4.patch: remove no longer necessary changes to test_universal_newlines subprocess-line-buffering-issue21332-ps5.patch: move assertEqual() to the caller

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2014-09-21.19:16:25.948>
created_at = <Date 2014-04-22.23:35:45.245>
labels = ['type-bug', 'library']
title = 'subprocess bufsize=1 docs are misleading'
updated_at = <Date 2018-10-20.00:22:36.056>
user = 'https://bugs.python.org/raylu'

bugs.python.org fields:

activity = <Date 2018-10-20.00:22:36.056>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2014-09-21.19:16:25.948>
closer = 'pitrou'
components = ['Library (Lib)']
creation = <Date 2014-04-22.23:35:45.245>
creator = 'raylu'
dependencies = []
files = ['35109', '35124', '35129', '35189', '36679']
hgrepos = []
issue_num = 21332
keywords = ['patch']
message_count = 18.0
messages = ['217044', '217596', '217601', '217651', '217683', '217739', '217740', '217742', '217744', '217745', '218136', '218229', '219058', '220919', '227216', '227223', '227225', '328097']
nosy_count = 9.0
nosy_names = ['gregory.p.smith', 'pitrou', 'vstinner', 'jwilk', 'Arfrever', 'akira', 'python-dev', 'martin.panter', 'raylu']
pr_nums = ['4842']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue21332'
versions = ['Python 3.4', 'Python 3.5']

[raylu]

https://docs.python.org/3.3/library/subprocess.html says

"bufsize will be supplied as the corresponding argument to the open() function when creating the stdin/stdout/stderr pipe file objects: ... 1 means line buffered"

but it calls io.open with 'wb' and 'rb': http://hg.python.org/cpython/file/c9cb931b20f4/Lib/subprocess.py#l828

This puts the file in binary mode, and https://docs.python.org/3.3/library/functions.html#open says

"1 to select line buffering (only usable in text mode)"

Even with universal_newlines=True, the TextIOWrapper isn't passed line_buffering=True. There's actually no way to get line buffering any more.

[4kir4]

It looks like a bug in the subprocess module e.g., if child process does:

  sys.stdout.write(sys.stdin.readline())
  sys.stdout.flush()

and the parent:

   p.stdin.write(line) #NOTE: no flush
   line = p.stdout.readline()

then a deadlock may happen with bufsize=1 (because it is equivalent to bufsize=-1 in the current code)

Surprisingly, it works if universal_newlines=True but only for C implementation of io i.e., if C extension is disabled:

  import io, _pyio 
  io.TextIOWrapper = _pyio.TextIOWrapper

then it blocks forever even if universal_newlines=True with bufsize=1 that is clearly wrong (<-- bug) e.g., test_universal_newlines deadlocks with _pyio.TextIOWrapper

C implementation works because it sets needflush flag even if only write_through is provided 1:

if (self->write_through)
    needflush = 1;
else if (self->line_buffering &&
    (haslf ||
     PyUnicode_FindChar(text, '\r', 0, PyUnicode_GET_LENGTH(text), 1) != -1))
    needflush = 1;

Python io implementation doesn't flush with only write_through flag.

It doesn't deadlock if bufsize=0 whether universal_newlines=True or not.

Note: Python 2.7 doesn't deadlock with bufsize=0 and bufsize=1 in this case as expected.

What is not clear is whether it should work with universal_newline=False and bufsize=1: both current docs and Python 2.7 behaviour say that there should not be a deadlock.

I've updated the docs to mention that bufsize=1 works only with
universal_newlines=True and added corresponding tests. I've also updated the subprocess' code to pass line_buffering explicitly.

Patch is uploaded.

[4kir4]

Related issue bpo-21396

[gpshead]

Thanks for the report, diagnosis and patch! Your change looks good to me. I'll commit it soon.

[4kir4]

I've changed test_newlines to work also with Python io implementation.

I've updated the patch.

Note: tests use 10 seconds timeouts: I don't know how long it should take to read back a line from a subprocess so that the timeout would indicate a deadlock.

[vadmium]

Perhaps you can avoid the 10 s deadlock timeout and threading in your test by closing the underlying input pipe file descriptor (or raw file object), without flushing it.

Also, it seems to me that “line_buffering=True” is redundant with “write_through=True”. I’m not super familiar with the new write-through mode though, so I could be wrong. Perhaps the change in “subprocess.py” may not be needed at least once bpo-21396 is fixed.

[vadmium]

Sorry, it seems I was wrong on the second point. Looking closer, it seems write-through mode only flushes the TextIOWrapper layer, not the underlying binary file object, whereas line-buffering mode flushes everything to the OS, so the extra line_buffering=True flag would be needed.

[4kir4]

yes, line_buffering=(bufsize == 1) is necessary to support the current
Python io implementation or if C implementation is fixed to avoid
buffer.flush() on every write with write_through=True -- otherwise
bufsize is not respected in text mode (it would always mean bufsize=0).

Note: the current patch for issue bpo-21396 (making C and Python io do the
same thing) may break subprocess code with universal_newlines=True that
expects (incorrectly) bufsize=0 by default -- as test_universal_newlines
had (enabling universal_newlines shouldn't switch from bufsize=-1 to
bufsize=0). <-- XXX backward compatibility issue!

Perhaps you can avoid the 10 s deadlock timeout and threading in your
test by closing the underlying input pipe file descriptor (or raw file
object), without flushing it.

It is a good idea. There could be portability issues with the test: it
relies on the fact that os.close doesn't flush already buffered data -- I
don't know whether os.close causes flush on Windows (it doesn't on POSIX
1: the data shall be discarded).

I've uploaded a new patch with the updated tests. Please, review.

[vadmium]

On second thoughts maybe the idea of closing the input is not such a good idea in practice. Once you call os.close() on the file descriptor, that descriptor becomes unallocated, and I can’t see any way to prevent p.stdin.close(), Popen() context, destructors, etc from trying to close the file descriptor again. If the Python test suite is ever multithreaded (I’m not really familiar with it), that would be a real problem. In any case closing an unallocated file descriptor is a bad idea. Maybe the deadlocking version is more appropriate after all.

[4kir4]

to be clear: the test itself doesn't use threads, python -mtest -j0
runs tests using multiple processes, not threads. There is no issue.

If the test were to run in the presence of multiple threads then
the issue would be the explicit p.stdin.close() in the test (look
at the patch) that may close p.stdin.fileno() that might be opened
in another thread (unrelated to the current test) after it was
closed in the test the first time. I could call
getattr(p.stdin, 'buffer', p.stdin).raw.fd = -1 to avoid trying to
close the fd the second time but I don't think it is necessary.

I don't think tests are expected to run in the presence of multiple
threads unless they start them.

[4kir4]

I've updated the patch to remove changes to test_universal_newlines
test that was fixed in revision 37d0c41ed8ad that closes bpo-21396 issue

[4kir4]

I've asked about thread-safety of tests on python-dev mailing list:
https://mail.python.org/pipermail/python-dev/2014-May/134523.html