Repository: byllyfish/shellous (language: python)

Issue:
test_command_iterator_api_interrupted_sync: CRITICAL: process still running <Process 2796>
```
tests/test_shellous.py::test_command_iterator_api_interrupted_sync 
-------------------------------- live log setup --------------------------------
1635653744.273 DEBUG asyncio Using selector: EpollSelector
1635653744.274 DEBUG asyncio Using selector: EpollSelector
1635653744.274 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
-------------------------------- live log call ---------------------------------
1635653744.276 DEBUG asyncio Using selector: EpollSelector
1635653744.277 INFO shellous Runner.__aenter__ stepin <Runner 'echo' pid=None> (Linux-5.8.0-1042-azure-x86_64-with-glibc2.31 CPython 3.10.0 asyncio.unix_events._UnixSelectorEventLoop MainThread ThreadedChildWatcher)
1635653744.277 INFO shellous Runner._start stepin <Runner 'echo' pid=None>
1635653744.277 INFO shellous Runner._subprocess_spawn stepin <Runner 'echo' pid=None>
1635653744.278 INFO shellous Runner._subprocess_exec stepin <Runner 'echo' pid=None>
1635653744.279 DEBUG asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python' stdin=<pipe> stdout=<pipe> stderr=<_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>
1635653744.282 DEBUG asyncio process '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python' created: pid 2796
1635653744.284 DEBUG asyncio Write pipe 15 connected: (<_UnixWritePipeTransport fd=15 idle bufsize=0>, <WriteSubprocessPipeProto fd=0 pipe=<_UnixWritePipeTransport fd=15 idle bufsize=0>>)
1635653744.284 DEBUG asyncio Read pipe 16 connected: (<_UnixReadPipeTransport fd=16 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=16 polling>>)
1635653744.285 INFO asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python': <_UnixSubprocessTransport pid=2796 running stdin=<_UnixWritePipeTransport fd=15 idle bufsize=0> stdout=<_UnixReadPipeTransport fd=16 polling>>
1635653744.285 INFO shellous Runner._subprocess_exec stepout <Runner 'echo' pid=2796 exit_code=None> ex=None
1635653744.286 INFO shellous Runner._subprocess_spawn stepout <Runner 'echo' pid=2796 exit_code=None> ex=None
1635653744.287 INFO shellous Runner._start stepout <Runner 'echo' pid=2796 exit_code=None> ex=None
1635653744.287 INFO shellous Runner.__aenter__ stepout <Runner 'echo' pid=2796 exit_code=None> ex=None
1635653744.287 INFO shellous read_lines stepin
1635653744.287 INFO shellous write_stream stepin
1635653744.288 INFO shellous write_stream stepout ex=None
1635653744.288 INFO shellous Runner._waiter stepin <Runner 'echo' pid=2796 exit_code=None>
1635653744.316 INFO shellous Runner.__aexit__ stepin <Runner 'echo' pid=2796 exit_code=None> exc_value=CancelledError()
1635653744.317 INFO shellous Runner._finish stepin <Runner 'echo' pid=2796 exit_code=None>
1635653744.317 INFO shellous Runner._kill stepin <Runner 'echo' cancelled pid=2796 exit_code=None>
1635653744.317 INFO shellous Runner.signal <Runner 'echo' cancelled pid=2796 exit_code=None> signal=<Signals.SIGTERM: 15>
1635653744.318 INFO shellous Runner._waiter stepout <Runner 'echo' cancelled pid=2796 exit_code=None> ex=CancelledError()
1635653744.319 INFO asyncio <_UnixReadPipeTransport fd=16 polling> was closed by peer
1635653744.319 INFO shellous Runner._kill stepout <Runner 'echo' cancelled pid=2796 exit_code=None> ex=GeneratorExit()
1635653744.319 INFO shellous Runner._close stepin <Runner 'echo' cancelled pid=2796 exit_code=None>
1635653744.320 CRITICAL shellous Runner._close process still running <Process 2796>
1635653744.320 INFO shellous Runner._close stepout <Runner 'echo' cancelled pid=2796 exit_code=None> ex=GeneratorExit()
1635653744.320 INFO shellous Runner._finish stepout <Runner 'echo' cancelled pid=2796 exit_code=None> ex=GeneratorExit()
1635653744.320 INFO shellous Runner.__aexit__ stepout <Runner 'echo' cancelled pid=2796 exit_code=None> ex=GeneratorExit() exc_value=CancelledError()
1635653744.321 INFO shellous read_lines stepout ex=GeneratorExit()
1635653744.322 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
PASSED
------------------------------ live log teardown -------------------------------
1635653744.337 WARNING asyncio Unknown child process pid 2796, will report returncode 255
1635653744.337 WARNING asyncio Loop <_UnixSelectorEventLoop running=False closed=True debug=True> that handles pid 2796 is closed
1635653744.338 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
```


Discussion / hints:
```
tests/test_shellous.py::test_command_iterator_api_interrupted_sync 
-------------------------------- live log setup --------------------------------
1635655684.391 DEBUG asyncio Using selector: EpollSelector
1635655684.392 DEBUG asyncio Using selector: EpollSelector
1635655684.392 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
-------------------------------- live log call ---------------------------------
1635655684.393 DEBUG asyncio Using selector: EpollSelector
1635655684.394 INFO shellous Runner.__aenter__ stepin <Runner 'echo' pid=None> (Linux-5.8.0-1042-azure-x86_64-with-glibc2.31 CPython 3.10.0 asyncio.unix_events._UnixSelectorEventLoop MainThread ThreadedChildWatcher)
1635655684.394 INFO shellous Runner._start stepin <Runner 'echo' pid=None>
1635655684.394 INFO shellous Runner._subprocess_spawn stepin <Runner 'echo' pid=None>
1635655684.395 INFO shellous Runner._subprocess_exec stepin <Runner 'echo' pid=None>
1635655684.396 DEBUG asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python' stdin=<pipe> stdout=<pipe> stderr=<_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>
1635655684.398 DEBUG asyncio process '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python' created: pid 2348
1635655684.399 DEBUG asyncio Write pipe 15 connected: (<_UnixWritePipeTransport fd=15 idle bufsize=0>, <WriteSubprocessPipeProto fd=0 pipe=<_UnixWritePipeTransport fd=15 idle bufsize=0>>)
1635655684.400 DEBUG asyncio Read pipe 16 connected: (<_UnixReadPipeTransport fd=16 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=16 polling>>)
1635655684.401 INFO asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.10/bin/python': <_UnixSubprocessTransport pid=2348 running stdin=<_UnixWritePipeTransport fd=15 idle bufsize=0> stdout=<_UnixReadPipeTransport fd=16 polling>>
1635655684.401 INFO shellous Runner._subprocess_exec stepout <Runner 'echo' pid=2348 exit_code=None> ex=None
1635655684.401 INFO shellous Runner._subprocess_spawn stepout <Runner 'echo' pid=2348 exit_code=None> ex=None
1635655684.402 INFO shellous Runner._start stepout <Runner 'echo' pid=2348 exit_code=None> ex=None
1635655684.402 INFO shellous Runner.__aenter__ stepout <Runner 'echo' pid=2348 exit_code=None> ex=None
1635655684.402 INFO shellous read_lines stepin
1635655684.403 INFO shellous write_stream stepin
1635655684.403 INFO shellous write_stream stepout ex=None
1635655684.403 INFO shellous Runner._waiter stepin <Runner 'echo' pid=2348 exit_code=None>
1635655684.429 INFO shellous Runner.__aexit__ stepin <Runner 'echo' pid=2348 exit_code=None> exc_value=CancelledError()
1635655684.429 INFO shellous Runner._finish stepin <Runner 'echo' pid=2348 exit_code=None>
1635655684.429 INFO shellous Runner._kill stepin <Runner 'echo' cancelled pid=2348 exit_code=None>
1635655684.429 INFO shellous Runner.signal <Runner 'echo' cancelled pid=2348 exit_code=None> signal=<Signals.SIGTERM: 15>
1635655684.430 INFO shellous Runner._waiter stepout <Runner 'echo' cancelled pid=2348 exit_code=None> ex=CancelledError()
1635655684.430 DEBUG asyncio process 2348 exited with returncode -15
1635655684.431 INFO asyncio <_UnixReadPipeTransport fd=16 polling> was closed by peer
1635655684.431 INFO shellous Runner._kill stepout <Runner 'echo' cancelled pid=2348 exit_code=None> ex=GeneratorExit()
1635655684.432 INFO shellous Runner._close stepin <Runner 'echo' cancelled pid=2348 exit_code=None>
1635655684.432 CRITICAL shellous Runner._close process still running <Process 2348>
1635655684.432 INFO shellous Runner._close stepout <Runner 'echo' cancelled pid=2348 exit_code=None> ex=GeneratorExit()
1635655684.432 INFO shellous Runner._finish stepout <Runner 'echo' cancelled pid=2348 exit_code=None> ex=GeneratorExit()
1635655684.432 INFO shellous Runner.__aexit__ stepout <Runner 'echo' cancelled pid=2348 exit_code=None> ex=GeneratorExit() exc_value=CancelledError()
1635655684.432 INFO asyncio <_UnixSubprocessTransport closed pid=2348 running stdin=<_UnixWritePipeTransport closed fd=15 closed> stdout=<_UnixReadPipeTransport closed fd=16 closed>> exited with return code -15
1635655684.433 INFO shellous read_lines stepout ex=GeneratorExit()
1635655684.434 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
PASSED
------------------------------ live log teardown -------------------------------
1635655684.450 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
```
```
tests/test_shellous.py::test_command_iterator_api_interrupted_sync 
-------------------------------- live log setup --------------------------------
1635993134.324 DEBUG asyncio Using selector: EpollSelector
1635993134.325 DEBUG asyncio Using selector: EpollSelector
1635993134.325 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
-------------------------------- live log call ---------------------------------
1635993134.327 DEBUG asyncio Using selector: EpollSelector
1635993134.328 INFO shellous Runner.__aenter__ stepin <Runner 'echo' pid=None> (Linux-5.11.0-1020-azure-x86_64-with-glibc2.31 CPython 3.9.7 asyncio.unix_events._UnixSelectorEventLoop MainThread ThreadedChildWatcher)
1635993134.328 INFO shellous Runner._start stepin <Runner 'echo' pid=None>
1635993134.328 INFO shellous Runner._subprocess_spawn stepin <Runner 'echo' pid=None>
1635993134.329 INFO shellous Runner._subprocess_exec stepin <Runner 'echo' pid=None>
1635993134.330 DEBUG asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.9/bin/python' stdin=<pipe> stdout=<pipe> stderr=<_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>
1635993134.333 DEBUG asyncio process '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.9/bin/python' created: pid 2368
1635993134.336 DEBUG asyncio Write pipe 15 connected: (<_UnixWritePipeTransport fd=15 idle bufsize=0>, <WriteSubprocessPipeProto fd=0 pipe=<_UnixWritePipeTransport fd=15 idle bufsize=0>>)
1635993134.337 DEBUG asyncio Read pipe 16 connected: (<_UnixReadPipeTransport fd=16 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=16 polling>>)
1635993134.338 INFO asyncio execute program '/home/runner/.cache/pypoetry/virtualenvs/shellous-dySVFLnW-py3.9/bin/python': <_UnixSubprocessTransport pid=2368 running stdin=<_UnixWritePipeTransport fd=15 idle bufsize=0> stdout=<_UnixReadPipeTransport fd=16 polling>>
1635993134.338 INFO shellous Runner._subprocess_exec stepout <Runner 'echo' pid=2368 exit_code=None> ex=None
1635993134.338 INFO shellous Runner._subprocess_spawn stepout <Runner 'echo' pid=2368 exit_code=None> ex=None
1635993134.339 INFO shellous Runner._start stepout <Runner 'echo' pid=2368 exit_code=None> ex=None
1635993134.339 INFO shellous Runner.__aenter__ stepout <Runner 'echo' pid=2368 exit_code=None> ex=None
1635993134.340 INFO shellous read_lines stepin
1635993134.340 INFO shellous write_stream stepin
1635993134.340 INFO shellous write_stream stepout ex=None
1635993134.341 INFO shellous Runner._waiter stepin <Runner 'echo' pid=2368 exit_code=None>
1635993134.363 INFO shellous Runner.__aexit__ stepin <Runner 'echo' pid=2368 exit_code=None> exc_value=CancelledError()
1635993134.363 INFO shellous Runner._finish stepin <Runner 'echo' pid=2368 exit_code=None>
1635993134.364 INFO shellous Runner._kill stepin <Runner 'echo' cancelled pid=2368 exit_code=None>
1635993134.364 INFO shellous Runner.signal <Runner 'echo' cancelled pid=2368 exit_code=None> signal=<Signals.SIGTERM: 15>
1635993134.365 INFO shellous Runner._waiter stepout <Runner 'echo' cancelled pid=2368 exit_code=None> ex=CancelledError()
1635993134.367 INFO shellous harvest_wait cancelled trustee=<Runner 'echo' cancelled pid=2368 exit_code=None> cancel_finish=False ex=GeneratorExit()
1635993134.368 INFO shellous read_lines stepout ex=GeneratorExit()
1635993134.368 INFO shellous Runner._kill stepout <Runner 'echo' cancelled pid=2368 exit_code=None> ex=GeneratorExit()
1635993134.368 INFO shellous Runner._close stepin <Runner 'echo' cancelled pid=2368 exit_code=None>
1635993134.368 CRITICAL shellous Runner._close process still running <Process 2368>
1635993134.369 WARNING asyncio Close running child process: kill <_UnixSubprocessTransport closed pid=2368 running stdin=<_UnixWritePipeTransport closed fd=15 closed> stdout=<_UnixReadPipeTransport closing fd=16 idle>>
1635993134.369 INFO shellous Runner._close stepout <Runner 'echo' cancelled pid=2368 exit_code=None> ex=GeneratorExit()
1635993134.369 INFO shellous Runner._finish stepout <Runner 'echo' cancelled pid=2368 exit_code=None> ex=GeneratorExit()
1635993134.369 INFO shellous Runner.__aexit__ stepout <Runner 'echo' cancelled pid=2368 exit_code=None> ex=GeneratorExit() exc_value=CancelledError()
1635993134.370 DEBUG asyncio process 2368 exited with returncode -15
1635993134.371 INFO asyncio <_UnixSubprocessTransport closed pid=2368 running stdin=<_UnixWritePipeTransport closed fd=15 closed> stdout=<_UnixReadPipeTransport closed fd=16 closed>> exited with return code -15
1635993134.372 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
PASSED
------------------------------ live log teardown -------------------------------
1635993134.389 DEBUG asyncio Close <_UnixSelectorEventLoop running=False closed=False debug=True>
```

Fix patch:
diff --git a/.cirrus.yml b/.cirrus.yml
index f7ae29d9..b4f61757 100644
--- a/.cirrus.yml
+++ b/.cirrus.yml
@@ -3,6 +3,10 @@
 freebsd_task:
   name: CI / build
 
+  env:
+    # for lsof
+    PATH: ${PATH}:/usr/local/sbin
+
   matrix:
     - name: FreeBSD 13.0
       freebsd_instance:
diff --git a/shellous/runner.py b/shellous/runner.py
index 162684ff..e3e1f3a6 100644
--- a/shellous/runner.py
+++ b/shellous/runner.py
@@ -439,7 +439,7 @@ async def _kill(self):
             if self._proc.returncode is None:
                 await harvest(self._waiter(), timeout=cancel_timeout, trustee=self)
 
-        except (asyncio.CancelledError, asyncio.TimeoutError) as ex:
+        except (asyncio.CancelledError, asyncio.TimeoutError, GeneratorExit) as ex:
             LOGGER.warning("Runner.kill %r (ex)=%r", self, ex)
             if _is_cancelled(ex):
                 self._set_cancelled()


Test patch:
diff --git a/tests/unix/test_unix.py b/tests/unix/test_unix.py
index 1f50aae4..e781c5ca 100644
--- a/tests/unix/test_unix.py
+++ b/tests/unix/test_unix.py
@@ -1506,85 +1506,94 @@ async def test_timeout_and_wait_for(sh):
         await asyncio.wait_for(cmd, 1.0)
 
 
-# On macOS and FreeBSD build systems, ignore the file descriptor for
-# `_virtualenv.pth` if it's open.
+# Grab the FD(4), TYPE(5) and NAME(9) columns only where the FD starts with
+# an integer. Replace any integer /dev/tty numbers in NAME with `N`.
 _AWK_SCRIPT = """
-/_virtualenv\\.pth$/ { next }
 $4 ~ /^[0-9]+/ { sub(/[0-9]+/, "N", $9); print $4, $5, $9 }
 """
 
 
-@pytest.mark.skip(_is_codecov(), reason="codecov")
+@pytest.mark.skipif(_is_uvloop() or _is_codecov(), reason="codecov")
 async def test_open_file_descriptors(sh):
     "Test what file descriptors are open in the subprocess."
 
-    cmd = sh(sys.executable, "-c", 'input("a")').stdin(())
-
+    cmd = sh("cat").stdin(())
     lsof = sh("lsof", "-n", "-P", "-p").stderr(1)
     awk = sh("awk", _AWK_SCRIPT).stderr(1)
 
     async with cmd.set(close_fds=True) as run:
         result = await (lsof(run.pid) | awk)
-        run.stdin.write(b"b\n")
+        run.stdin.close()
 
     if sys.platform == "linux":
         assert result == "0u unix type=STREAM\n1w FIFO pipe\n2u CHR /dev/null\n"
+    elif sys.platform.startswith("freebsd"):
+        assert result == "0u unix \n1u PIPE \n2u VCHR /dev/null\n"
     else:
         assert result == "0u unix \n1 PIPE \n2u CHR /dev/null\n"
 
 
-@pytest.mark.skip(_is_codecov(), reason="codecov")
+@pytest.mark.skipif(_is_uvloop() or _is_codecov(), reason="codecov")
 async def test_open_file_descriptors_unclosed_fds(sh):
     "Test what file descriptors are open in the subprocess (close_fds=False)."
 
-    cmd = sh(sys.executable, "-c", 'input("a")').stdin(())
-
+    cmd = sh("cat").stdin(())
     lsof = sh("lsof", "-n", "-P", "-p").stderr(1)
     awk = sh("awk", _AWK_SCRIPT).stderr(1)
 
     async with cmd.set(close_fds=False) as run:
         result = await (lsof(run.pid) | awk)
-        run.stdin.write(b"b\n")
+        run.stdin.close()
 
     if sys.platform == "linux":
         assert result == "0u unix type=STREAM\n1w FIFO pipe\n2u CHR /dev/null\n"
+    elif sys.platform.startswith("freebsd"):
+        assert result == "0u unix \n1u PIPE \n2u VCHR /dev/null\n"
     else:
         assert result == "0u unix \n1 PIPE \n2u CHR /dev/null\n"
 
 
-@pytest.mark.skip(_is_codecov(), reason="codecov")
+@pytest.mark.skipif(_is_uvloop() or _is_codecov(), reason="uvloop,codecov")
 async def test_open_file_descriptors_pty(sh):
     "Test what file descriptors are open in the pty subprocess."
 
-    cmd = sh(sys.executable, "-c", 'input("a")').stdin(())
-
+    cmd = sh("cat").stdin(())
     lsof = sh("lsof", "-n", "-P", "-p").stderr(1)
     awk = sh("awk", _AWK_SCRIPT).stderr(1)
 
     async with cmd.set(close_fds=True, pty=True) as run:
         result = await (lsof(run.pid) | awk)
-        run.stdin.write(b"b\n")
+        run.stdin.close()
 
     if sys.platform == "linux":
         assert result == "0u CHR /dev/pts/N\n1u CHR /dev/pts/N\n2u CHR /dev/pts/N\n"
+    elif sys.platform.startswith("freebsd"):
+        assert result in (
+            "0u VCHR /dev/pts/N\n1u VCHR /dev/pts/N\n2u VCHR /dev/pts/N\n",
+            "0u VCHR /dev\n1u VCHR /dev\n2u VCHR /dev\n",
+        )
     else:
         assert result == "0u CHR /dev/ttysN\n1u CHR /dev/ttysN\n2u CHR /dev/ttysN\n"
 
 
-@pytest.mark.skip(_is_codecov(), reason="codecov")
+@pytest.mark.skipif(_is_uvloop() or _is_codecov(), reason="uvloop,codecov")
 async def test_open_file_descriptors_pty_unclosed_fds(sh):
     "Test what file descriptors are open in the pty (close_fds=False)."
 
-    cmd = sh(sys.executable, "-c", 'input("a")').stdin(())
-
+    cmd = sh("cat").stdin(())
     lsof = sh("lsof", "-n", "-P", "-p").stderr(1)
     awk = sh("awk", _AWK_SCRIPT).stderr(1)
 
     async with cmd.set(close_fds=False, pty=True) as run:
         result = await (lsof(run.pid) | awk)
-        run.stdin.write(b"b\n")
+        run.stdin.close()
 
     if sys.platform == "linux":
         assert result == "0u CHR /dev/pts/N\n1u CHR /dev/pts/N\n2u CHR /dev/pts/N\n"
+    elif sys.platform.startswith("freebsd"):
+        assert result in (
+            "0u VCHR /dev/pts/N\n1u VCHR /dev/pts/N\n2u VCHR /dev/pts/N\n",
+            "0u VCHR /dev\n1u VCHR /dev\n2u VCHR /dev\n",
+        )
     else:
         assert result == "0u CHR /dev/ttysN\n1u CHR /dev/ttysN\n2u CHR /dev/ttysN\n"