[issue38323] asyncio: MultiLoopWatcher has a race condition (test_asyncio: test_close_kill_running() hangs on AMD64 RHEL7 Refleaks 3.x)

[Chris Jerdonek]

Chris Jerdonek <chris.jerdonek at gmail.com> added the comment:

I'm attaching a stand-alone script that can reproduce the issue. It doesn't use unittest or even MultiLoopChildWatcher.

It starts an event loop and then repeatedly calls loop.subprocess_exec() with 0.2 seconds in between until the "hang" happens (which shows up as a timeout). I recommend running the script for about 15 seconds, and if it doesn't happen, re-run it again. You might need to run it a half-dozen or dozen times to see the hang, but it can also happen right away.

I'm sure the script can be cleaned up and simplified a lot more. This is just a start. I wanted to see how much of the cruft I could strip out quickly.

This is what the output looks like after one of the hangs:

[81]: 16.77
/.../cpython/Lib/subprocess.py:1048: ResourceWarning: subprocess 3282 is still running
  _warn("subprocess %s is still running" % self.pid,
ResourceWarning: Enable tracemalloc to get the object allocation traceback
killing pid: 3283
BaseSubprocessTransport: awaiting in _wait
_sig_child: started
releasing waiter: okay
okay
[82]: 16.99
/.../cpython/Lib/subprocess.py:1048: ResourceWarning: subprocess 3283 is still running
  _warn("subprocess %s is still running" % self.pid,
ResourceWarning: Enable tracemalloc to get the object allocation traceback
killing pid: 3284
BaseSubprocessTransport: awaiting in _wait
_sig_child: started
releasing waiter: **TIMEOUT**
not okay: **TIMEOUT**

You can ignore the ResourceWarnings. You can also see at the end that the _sig_child() handler was called even in the timeout case (right before the loop.call_later(TIMEOUT, ...) callback began).

----------
Added file: https://bugs.python.org/file49144/test-kill.py

_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue38323>
_______________________________________