classification
Title: EBADF error on x86 Tiger 3.x buildbot
Type: Stage: resolved
Components: macOS, Tests Versions: Python 3.7, Python 3.6, Python 3.5
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: db3l, ned.deily, ronaldoussoren, vstinner
Priority: normal Keywords:

Created on 2017-05-02 08:12 by vstinner, last changed 2017-05-04 14:52 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 1443 merged vstinner, 2017-05-03 22:17
PR 1449 merged vstinner, 2017-05-04 10:22
PR 1450 merged vstinner, 2017-05-04 10:23
Messages (9)
msg292725 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-02 08:12
test_http_body_pipe() of test_urllib2 uses a subprocess, no idea if it's related:

        cmd = [sys.executable, "-c", r"pass"]
        for headers in {}, {"Content-Length": 30}:
            with subprocess.Popen(cmd, stdout=subprocess.PIPE) as proc:
                req = Request("http://example.com/", proc.stdout, headers)
                ...

See also my issue #29915 "Drop Mac OS X Tiger support in Python 3.7?" :-)

http://buildbot.python.org/all/builders/x86%20Tiger%203.x/builds/597/steps/test/logs/stdio

./python.exe -E -c 'import sys ; from sysconfig import get_platform ; print("%s-%d.%d" % (get_platform(), *sys.version_info[:2]))' >platform
/bin/sh: line 1: pybuildbot.identify: command not found
./python.exe  ./Tools/scripts/run_tests.py -j 1 -u all -W --slowest --timeout=900 -j2
make: [buildbottest] Error 127 (ignored)
== CPython 3.7.0a0 (heads/master:5d7a8d0, May 1 2017, 12:22:06) [GCC 4.0.1 (Apple Computer, Inc. build 5367)]
==   Darwin-8.11.1-i386-32bit little-endian
==   hash algorithm: siphash24 32bit
==  cwd: /Users/db3l/buildarea/3.x.bolen-tiger/build/build/test_python_12700
==  encodings: locale=UTF-8, FS=utf-8
Testing with flags: sys.flags(debug=0, inspect=0, interactive=0, optimize=0, dont_write_bytecode=0, no_user_site=0, no_site=0, ignore_environment=1, verbose=0, bytes_warning=2, quiet=0, hash_randomization=1, isolated=0)
Using random seed 2778758
Run tests in parallel using 2 child processes
0:00:12 [  1/405] test_deque passed
0:00:35 [  2/405] test_trace passed (34 sec)
0:00:56 [  3/405] test_capi passed -- running: test_socket (44 sec)
0:00:57 [  4/405] test_pkgimport passed -- running: test_socket (45 sec)
0:01:02 [  5/405] test_socket passed (49 sec)
0:01:07 [  6/405] test_imaplib passed
0:01:18 [  7/405] test_urllib2 passed
Fatal Python error: Py_Initialize: can't initialize sys standard streams
OSError: [Errno 9] Bad file descriptor

Current thread 0xa000d000 (most recent call first):
Fatal Python error: Py_Initialize: can't initialize sys standard streams
OSError: [Errno 9] Bad file descriptor

Current thread 0xa000d000 (most recent call first):
0:01:20 [  8/405] test_getargs2 passed
0:01:24 [  9/405] test_calendar passed
0:01:25 [ 10/405] test_unpack_ex passed
msg292878 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-03 10:08
@David Bolen: Would you mind to take a look? I don't have access to your x86 Tiger 3.x buildbot.
msg292935 - (view) Author: David Bolen (db3l) Date: 2017-05-03 19:25
Hmm, I wonder if this is another race condition similar to issue 8458?

I think that was thought to be related to the subprocess exiting quickly, in which case the question might be why that might happen more so than the actual descriptor error.

BTW, Victor, in case it would help, your account (vstinner, ssh key haypo@marge) still exists on this buildbot from past testing in 2011.  The only thing I'd need to re-enable is the port forwarding on my firewall.
msg292940 - (view) Author: David Bolen (db3l) Date: 2017-05-03 21:19
In running the test under a local build, the issue is very repeatable, but I believe it's actually due to slow process startup rather than a quick exit.

That is, adding a brief sleep after process creation and just before the Request() call seems to fix the problem.  I'm guessing the buildbot is sluggish enough that it just takes a bit longer for the process to start and be ready to be used.  

Whether or not that's purely a machine or test problem, or whether it means that perhaps subprocess.Popen() is returning sooner than it should with a process that isn't ready yet is unclear.  (Or even if subprocess can tell)

With the machine fairly idle, it looks like the minimum workable delay is about 200ms - probably something a bit longer would be safer under load, if looking for a quick workaround.
msg292942 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-03 21:42
initstdio() is supposed to handle EBADF: see issue #24891.
msg292943 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-03 22:45
New changeset 1c4670ea0cc3d208121af11b9b973e6bb268e570 by Victor Stinner in branch 'master':
bpo-30225: Fix is_valid_fd() on macOS Tiger (#1443)
https://github.com/python/cpython/commit/1c4670ea0cc3d208121af11b9b973e6bb268e570
msg292974 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-04 11:21
New changeset 31906b42fd71c6baaf80429005c720b40dfe8fae by Victor Stinner in branch '3.6':
bpo-30225: Fix is_valid_fd() on macOS Tiger (#1443) (#1449)
https://github.com/python/cpython/commit/31906b42fd71c6baaf80429005c720b40dfe8fae
msg292975 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-04 11:21
New changeset 8a1c71053139f20348ea487c0c464694ed3c88c5 by Victor Stinner in branch '3.5':
bpo-30225: Fix is_valid_fd() on macOS Tiger (#1443) (#1450)
https://github.com/python/cpython/commit/8a1c71053139f20348ea487c0c464694ed3c88c5
msg292984 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-04 14:52
Ok, the race condition causing EBADF is now handled correctly in 3.5, 3.6 and master (3.7).
History
Date User Action Args
2019-10-22 23:30:02vstinnerlinkissue33384 superseder
2017-05-04 14:52:07vstinnersetstatus: open -> closed
versions: + Python 3.5, Python 3.6
messages: + msg292984

resolution: fixed
stage: resolved
2017-05-04 11:21:18vstinnersetmessages: + msg292975
2017-05-04 11:21:13vstinnersetmessages: + msg292974
2017-05-04 10:23:09vstinnersetpull_requests: + pull_request1548
2017-05-04 10:22:10vstinnersetpull_requests: + pull_request1547
2017-05-03 22:45:58vstinnersetmessages: + msg292943
2017-05-03 22:17:59vstinnersetpull_requests: + pull_request1541
2017-05-03 21:42:10vstinnersetmessages: + msg292942
2017-05-03 21:19:51db3lsetmessages: + msg292940
2017-05-03 19:25:36db3lsetmessages: + msg292935
2017-05-03 10:08:54vstinnersetnosy: + db3l
messages: + msg292878
2017-05-02 08:12:52vstinnercreate