test_subprocess: test_check_output_timeout flaky

[colesbury]

Bug report

The test_check_output_timeout test sometimes times out before the "BDFL" string is printed to stdout.

https://github.com/python/cpython/actions/runs/8261299493/job/22598342550

 ======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCaseNoPoll.test_check_output_timeout)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/runner/work/cpython/cpython/Lib/test/test_subprocess.py", line 286, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
    ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: None != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.RunFuncTestCase.test_check_output_timeout)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/runner/work/cpython/cpython/Lib/test/test_subprocess.py", line 1694, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
    ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: None != b'BDFL'

----------------------------------------------------------------------

reported by @sobolevn in #116682 (comment)

Linked PRs

• gh-116742 : Fix assertIn check with [None, b'BDFL'] as values for stdout #116917
• gh-116742: Fix subprocess test_check_output_timeout() #130836
• [3.13] gh-116742: Fix subprocess test_check_output_timeout() (GH-130836) #130873
• [3.12] gh-116742: Fix subprocess test_check_output_timeout() (GH-130836) #130874

[colesbury]

Increasing the timeout further will slow down the test, so that's not a great solution. I think we should just get rid of the print("BDFL") and self.assertEqual(c.exception.output, b'BDFL') because those aren't reliable and instead only test that the TimeoutExpired exception is raised.

[Jitendra-GRL]

Hi @colesbury,
I'm excited about the opportunity to contribute to this project and help address the issue at hand. As a software engineer I have experience with Python and am confident in my ability to provide valuable contributions to this repository.
Could you please grant me permission to contribute to this issue? I'm eager to dive in and collaborate with the community to find a solution.

[sobolevn]

@Jitendra-GRL please, go ahead!

[Jitendra-GRL]

Thanks @sobolevn
Suggestion : self.assertIn(c.exception.output, [None, b'BDFL']) instead of self.assertEqual(c.exception.output, b'BDFL') should solve this issue

[sobolevn]

No :)
This issue is not about changing the assertion. This issue is rather complex, it shows that we have either a race or some unstable behavior in our subprocess module.

I will close #116917
But, if you want to dive deep into the subprocess module (which is one of the hardest modules, in my opinion), then - feel free to do so.

We would need:

• A repro that works 100% of times
• A root cause of the issue
• A plan on how to solve it and not break anything else
• A PR :)

This is hard, but interesting! 👍

[Jitendra-GRL]

@sobolevn, agreed👍. Then we should try checking if the TimeoutExpired exception is raised, as @colesbury mentioned in the above comment, using self.assertIsInstance(c.exception, subprocess.TimeoutExpired). This way, we can be sure if the correct exception is raised in case the test_check_output_timeout test times out before printing the "BDFL" string to stdout.

[Jitendra-GRL]

Also couldn't able to trace the output of this test_check_output_timeout test in the passing jobs.

[vstinner]

@colesbury:

Increasing the timeout further will slow down the test, so that's not a great solution. I think we should just get rid of the print("BDFL") and self.assertEqual(c.exception.output, b'BDFL') because those aren't reliable and instead only test that the TimeoutExpired exception is raised.

I agree. I wrote #130836 to fix the race condition: don't write into stdout anymore.