classification
Title: python -m test -jN: write stderr in stdout to get messages in order
Type: Stage: patch review
Components: Tests Versions: Python 3.11
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: vstinner
Priority: normal Keywords: patch

Created on 2021-10-08 11:15 by vstinner, last changed 2021-10-13 15:35 by vstinner.

Pull Requests
URL Status Linked Edit
PR 28819 merged vstinner, 2021-10-08 12:05
PR 28885 merged vstinner, 2021-10-11 20:21
PR 28908 merged vstinner, 2021-10-12 23:25
PR 28915 merged vstinner, 2021-10-13 02:29
PR 28926 merged vstinner, 2021-10-13 15:12
Messages (9)
msg403467 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-08 11:15
In buildbot logs, when a worker process is run, two pipes are created for stdout and stderr. The problem is that using two pipes produce an output which is hard to read.

Pseudo output:
---
stdout time 1
stdout time 2
stdout time 3
stderr time 1
stderr time 2
---

I would prefer:
---
stdout time 1
stderr time 1
stdout time 2
stderr time 2
stdout time 3
---

Real logs:
https://buildbot.python.org/all/#/builders/79/builds/870
---
0:01:10 load avg: 4.48 [236/427/1] test_ftplib failed (env changed) -- (...)
Warning -- Uncaught thread exception: Exception
Exception in thread Thread-67:
Traceback (most recent call last):
  (...)
Exception
test__all__ (test.test_ftplib.MiscTestCase) ... ok
test_abort (test.test_ftplib.TestFTPClass) ... ok
test_acct (test.test_ftplib.TestFTPClass) ... ok
test_all_errors (test.test_ftplib.TestFTPClass) ... ok
(...)
Ran 94 tests in 2.326s
---

The Warning is logged at the beginning, it's not possible to know which test emitted this warning.

I propose to write stdout and stderr of a worker process into a single pipe to keep messages order.

In the past, I saw buildbot logging stderr messages in a different color. But it no longer seems to be the case.

I'm working on a PR.
msg403480 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-08 15:14
New changeset b108db63e02797a795840152b82cab9792fd3ed2 by Victor Stinner in branch 'main':
bpo-45410: libregrtest -jN writes stderr into stdout (GH-28819)
https://github.com/python/cpython/commit/b108db63e02797a795840152b82cab9792fd3ed2
msg403677 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-11 20:11
Sadly, a recent build failure (at commit 560a79f94e94de66a18f2a5e4194c2fe51e2adf1) still write "Uncaught thread exception" at the top of logs:
---
0:00:11 load avg: 6.07 [315/427/1] test_ftplib failed (env changed)
Warning -- Uncaught thread exception: Exception
Exception in thread Thread-67:
(...)
Exception
test__all__ (test.test_ftplib.MiscTestCase) ... ok
test_abort (test.test_ftplib.TestFTPClass) ... ok
(...)
Ran 94 tests in 3.234s
OK (skipped=1)
---
msg403686 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-11 21:07
New changeset 1ebd798fddef51e1f6fd40a4860278a1851ac268 by Victor Stinner in branch 'main':
bpo-45410: Add test.support.flush_std_streams() (GH-28885)
https://github.com/python/cpython/commit/1ebd798fddef51e1f6fd40a4860278a1851ac268
msg403707 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-12 01:02
Calling sys.stdout doesn't help :-(

Fail at commit ce3489cfdb9f0e050bdc45ce5d3902c2577ea683:
https://buildbot.python.org/all/#/builders/73/builds/788
---
0:00:10 load avg: 7.59 [306/427/1] test_ftplib failed (env changed)
Warning -- Uncaught thread exception: Exception
Exception in thread Thread-67:
(...)
Exception
test__all__ (test.test_ftplib.MiscTestCase) ... ok
test_abort (test.test_ftplib.TestFTPClass) ... ok
test_acct (test.test_ftplib.TestFTPClass) ... ok
(...)
---

The warning cannot come from MiscTestCase.test__all__(), so the warning is still logged at the wrong place.
msg403766 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-12 23:52
New changeset dbe213de7ef28712bbfdb9d94a33abb9c33ef0c2 by Victor Stinner in branch 'main':
bpo-45410: Enhance libregrtest -W/--verbose3 option (GH-28908)
https://github.com/python/cpython/commit/dbe213de7ef28712bbfdb9d94a33abb9c33ef0c2
msg403781 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-13 02:05
> bpo-45410: Enhance libregrtest -W/--verbose3 option (GH-28908)

Oh. Sadly, with this change, faulthandler is no longer able to dump a traceback on a crash :-(
msg403827 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-13 12:08
New changeset 773330773968f211c77abc7b5b525faa7b3c35a2 by Victor Stinner in branch 'main':
bpo-45410: regrtest -W leaves stdout/err FD unchanged (GH-28915)
https://github.com/python/cpython/commit/773330773968f211c77abc7b5b525faa7b3c35a2
msg403844 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-10-13 15:35
New changeset 676201a59f90caace606d11d4172aa74c1cd4992 by Victor Stinner in branch 'main':
bpo-45410: regrtest replaces print_warning.orig_stderr (GH-28926)
https://github.com/python/cpython/commit/676201a59f90caace606d11d4172aa74c1cd4992
History
Date User Action Args
2021-10-13 15:35:28vstinnersetmessages: + msg403844
2021-10-13 15:12:07vstinnersetpull_requests: + pull_request27215
2021-10-13 12:08:48vstinnersetmessages: + msg403827
2021-10-13 02:29:02vstinnersetpull_requests: + pull_request27205
2021-10-13 02:05:20vstinnersetmessages: + msg403781
2021-10-12 23:52:29vstinnersetmessages: + msg403766
2021-10-12 23:25:50vstinnersetpull_requests: + pull_request27199
2021-10-12 01:02:55vstinnersetmessages: + msg403707
2021-10-11 21:07:28vstinnersetmessages: + msg403686
2021-10-11 20:21:48vstinnersetpull_requests: + pull_request27179
2021-10-11 20:11:15vstinnersetmessages: + msg403677
2021-10-08 15:14:49vstinnersetmessages: + msg403480
2021-10-08 12:05:59vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request27138
2021-10-08 11:15:36vstinnercreate