This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: test_subprocess.POSIXProcessTestCase fails in AMD64 Ubuntu 3.x
Type: Stage: resolved
Components: Tests Versions: Python 3.8
process
Status: closed Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: matrixise, pablogsal, vstinner, xtreak
Priority: normal Keywords: patch

Created on 2018-08-02 23:57 by pablogsal, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 8660 merged vstinner, 2018-08-03 20:45
Messages (13)
msg323001 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2018-08-02 23:57
test_subprocess.POSIXProcessTestCase fails in AMD64 Ubuntu 3.x buildbots:

https://buildbot.python.org/all/#/builders/154/builds/104

It seems that it has some problems with (unclosed?) file descriptors:

test_terminate_dead (test.test_subprocess.Win32ProcessTestCase) ... skipped 'Windows specific tests'
======================================================================
FAIL: test_close_fds (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.x.einat-ubuntu/build/Lib/test/test_subprocess.py", line 2378, in test_close_fds
    "Some fds were left open")
AssertionError: {3} is not false : Some fds were left open
======================================================================
FAIL: test_close_fds_after_preexec (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.x.einat-ubuntu/build/Lib/test/test_subprocess.py", line 2653, in test_close_fds_after_preexec
    self.assertNotIn(fd, remaining_fds)
AssertionError: 3 unexpectedly found in {0, 1, 2, 3}
======================================================================
FAIL: test_pass_fds (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.x.einat-ubuntu/build/Lib/test/support/__init__.py", line 615, in wrapper
    return func(*args, **kw)
  File "/home/buildbot/buildarea/3.x.einat-ubuntu/build/Lib/test/test_subprocess.py", line 2503, in test_pass_fds
    "fd to be closed passed")
AssertionError: {4} is not false : fd to be closed passed
----------------------------------------------------------------------
Ran 285 tests in 68.129s
FAILED (failures=3, skipped=28)
1 test failed again:
    test_subprocess
msg323002 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2018-08-03 00:02
This also happens on x86-64 High Sierra 3.x buildbot:

https://buildbot.python.org/all/#/builders/145/builds/265
msg323004 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2018-08-03 00:05
More failures on AMD64 Debian PGO 3.x:

https://buildbot.python.org/all/#/builders/47/builds/1362

test_terminate (test.test_subprocess.Win32ProcessTestCase) ... skipped 'Windows specific tests'
test test_subprocess failed
test_terminate_dead (test.test_subprocess.Win32ProcessTestCase) ... skipped 'Windows specific tests'
======================================================================
FAIL: test_close_fds (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/slaves/enable-optimizations-bot/3.x.gps-debian-profile-opt.nondebug/build/Lib/test/test_subprocess.py", line 2378, in test_close_fds
    "Some fds were left open")
AssertionError: {3} is not false : Some fds were left open
======================================================================
FAIL: test_close_fds_after_preexec (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/slaves/enable-optimizations-bot/3.x.gps-debian-profile-opt.nondebug/build/Lib/test/test_subprocess.py", line 2653, in test_close_fds_after_preexec
    self.assertNotIn(fd, remaining_fds)
AssertionError: 3 unexpectedly found in {0, 1, 2, 3}
======================================================================
FAIL: test_pass_fds (test.test_subprocess.POSIXProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/lib/buildbot/slaves/enable-optimizations-bot/3.x.gps-debian-profile-opt.nondebug/build/Lib/test/support/__init__.py", line 615, in wrapper
    return func(*args, **kw)
  File "/var/lib/buildbot/slaves/enable-optimizations-bot/3.x.gps-debian-profile-opt.nondebug/build/Lib/test/test_subprocess.py", line 2503, in test_pass_fds
    "fd to be closed passed")
AssertionError: {4} is not false : fd to be closed passed
----------------------------------------------------------------------
Ran 285 tests in 27.876s
FAILED (failures=3, skipped=28)
1 test failed again:
    test_subprocess
msg323019 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2018-08-03 04:44
Some of VSTS Mac OS and Linux builds also have the same failure 

Sample Linux : https://python.visualstudio.com/cpython/_build/results?buildId=21154&view=logs
Sample Mac OS : https://python.visualstudio.com/cpython/_build/results?buildId=21155&view=logs

Test case failure reported in Arch : https://bugs.python.org/issue34327

Thanks
msg323038 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 07:20
Same issue with my builds : 

* Linux -> https://python.visualstudio.com/cpython/_build/results?buildId=21273&view=logs
* macOS -> https://python.visualstudio.com/cpython/_build/results?buildId=21274&view=logs
msg323039 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 07:36
same problem here:
linux: https://python.visualstudio.com/8e426817-76c0-4b99-ba9e-a48a1e4bd5db/_build/index?buildId=21241
macOS: https://python.visualstudio.com/8e426817-76c0-4b99-ba9e-a48a1e4bd5db/_build/index?buildId=21242
msg323041 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 08:29
When I try to find the issue with git bisect, I have one commit.

72ec3193b5118a2ccc8be8bf03d7b74691c6a264 is the first bad commit
commit 72ec3193b5118a2ccc8be8bf03d7b74691c6a264
Author: Victor Stinner <vstinner@redhat.com>
Date:   Thu Aug 2 19:34:20 2018 +0200

    bpo-34170: Cleanup pymain_run_filename() (GH-8631)
    
    * Inline pymain_run_file() and pymain_open_filename() into
      pymain_run_filename()
    * Created pymain_run_stdin() which is pymain_run_filename() with
      filename=NULL
    * Rename pymain_run_filename() to pymain_run_file()

:040000 040000 6e49f5791bc63c3bf67a3674ccc00a412b5f089a 1b93e169af3afb07daaf06e2247a3eae6a88cac5 M	Modules

with ./python -m test test_subprocess -v
msg323043 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 10:01
I continue to work on this issue
msg323045 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 12:39
I think there is an issue with pymain_run_file, in the new code of Victor, a file descriptor is not closed but I don't know why.
msg323046 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2018-08-03 12:56
Maybe we can strace a failing test and cross check the opens and the closes to see which one is not being closed. Or monitor /proc/PID/fd while the test runs. I can investigate later today myself.
msg323047 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 13:02
Pablo, the main issue comes after this commit, you can strace the call 
for example 

./python -m unittest test.test_subprocess.POSIXProcessTestCase.test_pass_fds

on this test function and you will see than there is a opened file descriptor.

I tried to rewrite the patch of victor and see what was the difference, and there is no issue with pymain_run_stdin but I have the issue with pymain_run_file.

after that, I don't know how to find the leaked file.

Any idea?
msg323085 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-08-03 21:54
New changeset d8078626770a8d358eb83d7928c12d75ff4e821a by Victor Stinner in branch 'master':
bpo-34170: Fix pymain_run_file() (GH-8660)
https://github.com/python/cpython/commit/d8078626770a8d358eb83d7928c12d75ff4e821a
msg323092 - (view) Author: Stéphane Wirtel (matrixise) * (Python committer) Date: 2018-08-03 22:21
Thanks Victor, I don't know enough the API C-Python :/
History
Date User Action Args
2022-04-11 14:59:04adminsetgithub: 78507
2018-08-03 22:31:31matrixisesetstatus: open -> closed
stage: patch review -> resolved
2018-08-03 22:21:14matrixisesetmessages: + msg323092
2018-08-03 21:54:08vstinnersetmessages: + msg323085
2018-08-03 20:45:08vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request8155
2018-08-03 20:09:10berker.peksaglinkissue34327 superseder
2018-08-03 13:02:16matrixisesetmessages: + msg323047
2018-08-03 12:56:12pablogsalsetmessages: + msg323046
2018-08-03 12:39:34matrixisesetmessages: + msg323045
2018-08-03 10:01:47matrixisesetmessages: + msg323043
2018-08-03 08:29:59matrixisesetmessages: + msg323041
2018-08-03 07:36:22matrixisesetmessages: + msg323039
2018-08-03 07:20:34matrixisesetnosy: + vstinner, matrixise
messages: + msg323038
2018-08-03 04:44:52xtreaksetnosy: + xtreak
messages: + msg323019
2018-08-03 00:05:10pablogsalsetmessages: + msg323004
2018-08-03 00:02:22pablogsalsetmessages: + msg323002
2018-08-02 23:57:08pablogsalcreate