Test failures: "Event loop is closed" with Python 3.12, Fedora Linux

[michel-slm]

As tested using a scratch build on the Fedora build system: https://koji.fedoraproject.org/koji/taskinfo?taskID=103367353

I'm uploading the logs as otherwise they will get garbage collected within a couple of weeks.

build.log
root.log

Note: one error - the AssertionError in test_buffer - is introduced somewhere between 0.4.3 and the current master, it also fails when building for Fedora 38 which has Python 3.11, while building 0.4.3 succeeds and building 0.4.3 with the patches for handling imp removal passes tests on Fedora 38 and fails with the same test_vim event loop issue but passes test_buffer.

[michel-slm]

Linking this here - not worth an issue of its own: this PR fixes warnings when using pytest 6+

#529

[michel-slm]

ah, the test_buffer issue is due to this 82a2e14

I guess unless using neovim nightly this will not work. I wonder if we can make it conditional on neovim version

[michel-slm]

#531 fixes test_buffer by not hardcoding the global value for 'default'

[justinmk]

• Event loop is closed was also reported in OSError: EOF when trying to run example code on Windows #505
  • Are we using asyncio correctly?
• fwiw, I notice /usr/lib/python3.11/ in your logs but the issue mentions python 3.12?

From your build.log file:

Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f4818b78400>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
...
error: Bad exit status from /var/tmp/rpm-tmp.TJnuqo (%check)
    Bad exit status from /var/tmp/rpm-tmp.TJnuqo (%check)
RPM build errors:
Child return code was: 1
EXCEPTION: [Error('Command failed: \n # /usr/bin/systemd-nspawn -q -M c739984eca5f486591a9a603529cec53 -D /var/lib/mock/f39-build-44158357-5266102/root -a -u mockbuild --capability=cap_ipc_lock --bind=/tmp/mock-resolv.6mkqabk8:/etc/resolv.conf --bind=/dev/btrfs-control --bind=/dev/mapper/control --bind=/dev/loop-control --bind=/dev/loop0 --bind=/dev/loop1 --bind=/dev/loop2 --bind=/dev/loop3 --bind=/dev/loop4 --bind=/dev/loop5 --bind=/dev/loop6 --bind=/dev/loop7 --bind=/dev/loop8 --bind=/dev/loop9 --bind=/dev/loop10 --bind=/dev/loop11 --console=pipe --setenv=TERM=vt100 --setenv=SHELL=/bin/bash --setenv=HOME=/builddir --setenv=HOSTNAME=mock --setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin --setenv=PROMPT_COMMAND=printf "\\033]0;<mock-chroot>\\007" --setenv=PS1=<mock-chroot> \\s-\\v\\$  --setenv=LANG=C.UTF-8 --resolv-conf=off bash --login -c /usr/bin/rpmbuild -bb --noclean --target noarch --nodeps /builddir/build/SPECS/python-neovim.spec\n', 1)]
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/mockbuild/trace_decorator.py", line 93, in trace
    result = func(*args, **kw)
             ^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/mockbuild/util.py", line 597, in do_with_status
    raise exception.Error("Command failed: \n # %s\n%s" % (command, output), child.returncode)
mockbuild.exception.Error: Command failed: 
 # /usr/bin/systemd-nspawn -q -M c739984eca5f486591a9a603529cec53 -D /var/lib/mock/f39-build-44158357-5266102/root -a -u mockbuild --capability=cap_ipc_lock --bind=/tmp/mock-resolv.6mkqabk8:/etc/resolv.conf --bind=/dev/btrfs-control --bind=/dev/mapper/control --bind=/dev/loop-control --bind=/dev/loop0 --bind=/dev/loop1 --bind=/dev/loop2 --bind=/dev/loop3 --bind=/dev/loop4 --bind=/dev/loop5 --bind=/dev/loop6 --bind=/dev/loop7 --bind=/dev/loop8 --bind=/dev/loop9 --bind=/dev/loop10 --bind=/dev/loop11 --console=pipe --setenv=TERM=vt100 --setenv=SHELL=/bin/bash --setenv=HOME=/builddir --setenv=HOSTNAME=mock --setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin --setenv=PROMPT_COMMAND=printf "\033]0;<mock-chroot>\007" --setenv=PS1=<mock-chroot> \s-\v\$  --setenv=LANG=C.UTF-8 --resolv-conf=off bash --login -c /usr/bin/rpmbuild -bb --noclean --target noarch --nodeps /builddir/build/SPECS/python-neovim.spec

[cryptomilk]

798dfc3 with Python 3.12 still fails:

============================= test session starts ==============================
platform linux -- Python 3.12.0rc1, pytest-7.3.2, pluggy-1.2.0
cachedir: .tox/py312/.pytest_cache
rootdir: /builddir/build/BUILD/pynvim-0.4.3
configfile: setup.cfg
testpaths: test
plugins: timeout-2.1.0, asyncio-0.21.0
asyncio: mode=Mode.STRICT
collected 70 items
test/test_buffer.py .................                                    [ 24%]
test/test_client_rpc.py ....                                             [ 30%]
test/test_concurrency.py ..                                              [ 32%]
test/test_decorators.py .                                                [ 34%]
test/test_events.py ....                                                 [ 40%]
test/test_host.py ....                                                   [ 45%]
test/test_logging.py .                                                   [ 47%]
test/test_tabpage.py .....                                               [ 54%]
test/test_vim.py ..................F.                                    [ 82%]
test/test_window.py ............                                         [100%]
=================================== FAILURES ===================================
___________________________________ test_cwd ___________________________________
vim = <pynvim.api.nvim.Nvim object at 0x7f92c0ccd850>
tmpdir = local('/tmp/pytest-of-mockbuild/pytest-5/test_cwd0')
    def test_cwd(vim: Nvim, tmpdir: Any) -> None:
>       vim.command('python3 import os')
test/test_vim.py:201: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
pynvim/api/nvim.py:311: in command
    return self.request('nvim_command', string, **kwargs)
pynvim/api/nvim.py:199: in request
    res = self._session.request(name, *args, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <pynvim.msgpack_rpc.session.Session object at 0x7f92c0cce210>
method = 'nvim_command', args = ('python3 import os',), kwargs = {}
async_ = False
v = ([0, 'Vim(python3):E319: No "python3" provider found. Run ":checkhealth provider"'], None)
err = [0, 'Vim(python3):E319: No "python3" provider found. Run ":checkhealth provider"']
rv = None
    def request(self, method: AnyStr, *args: Any, **kwargs: Any) -> Any:
        """Send a msgpack-rpc request and block until as response is received.
    
        If the event loop is running, this method must have been called by a
        request or notification handler running on a greenlet. In that case,
        send the quest and yield to the parent greenlet until a response is
        available.
    
        When the event loop is not running, it will perform a blocking request
        like this:
        - Send the request
        - Run the loop until the response is available
        - Put requests/notifications received while waiting into a queue
    
        If the `async_` flag is present and True, a asynchronous notification
        is sent instead. This will never block, and the return value or error
        is ignored.
        """
        async_ = check_async(kwargs.pop('async_', None), kwargs, False)
        if async_:
            self._async_session.notify(method, args)
            return
    
        if kwargs:
            raise ValueError("request got unsupported keyword argument(s): {}"
                             .format(', '.join(kwargs.keys())))
    
        if self._is_running:
            v = self._yielding_request(method, args)
        else:
            v = self._blocking_request(method, args)
        if not v:
            # EOF
            raise OSError('EOF')
        err, rv = v
        if err:
            info("'Received error: %s", err)
>           raise self.error_wrapper(err)
E           pynvim.api.common.NvimError: Vim(python3):E319: No "python3" provider found. Run ":checkhealth provider"
pynvim/msgpack_rpc/session.py:137: NvimError
------------------------------ Captured log call -------------------------------
INFO     pynvim.msgpack_rpc.session:session.py:136 'Received error: [0, 'Vim(python3):E319: No "python3" provider found. Run ":checkhealth provider"']
=============================== warnings summary ===============================
test/test_buffer.py: 17 warnings
test/test_client_rpc.py: 4 warnings
test/test_concurrency.py: 2 warnings
test/test_events.py: 4 warnings
test/test_host.py: 4 warnings
test/test_tabpage.py: 5 warnings
test/test_vim.py: 20 warnings
test/test_window.py: 12 warnings
  /usr/lib64/python3.12/asyncio/events.py:824: DeprecationWarning: 'get_child_watcher' is deprecated as of Python 3.12 and will be removed in Python 3.14.
    return get_event_loop_policy().get_child_watcher()
test/test_buffer.py: 2 warnings
test/test_client_rpc.py: 1 warning
test/test_events.py: 1 warning
test/test_host.py: 1 warning
test/test_tabpage.py: 1 warning
test/test_vim.py: 3 warnings
test/test_window.py: 2 warnings
  /usr/lib/python3.12/site-packages/_pytest/unraisableexception.py:78: PytestUnraisableExceptionWarning: Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
  
  Traceback (most recent call last):
    File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
      self.close()
    File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
      proto.pipe.close()
    File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
      self.write_eof()
    File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
      self._loop.call_soon(self._call_connection_lost, None)
    File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
      self._check_closed()
    File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
      raise RuntimeError('Event loop is closed')
  RuntimeError: Event loop is closed
  
    warnings.warn(pytest.PytestUnraisableExceptionWarning(msg))
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================== short test summary info ============================
FAILED test/test_vim.py::test_cwd - pynvim.api.common.NvimError: Vim(python3)...
================== 1 failed, 69 passed, 79 warnings in 3.04s ===================
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
    self.write_eof()
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f92c10b1b20>
Traceback (most recent call last):
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 126, in __del__
  File "/usr/lib64/python3.12/asyncio/base_subprocess.py", line 104, in close
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 768, in close
  File "/usr/lib64/python3.12/asyncio/unix_events.py", line 754, in write_eof
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 772, in call_soon
  File "/usr/lib64/python3.12/asyncio/base_events.py", line 519, in _check_closed
RuntimeError: Event loop is closed
py312: exit 1 (3.54 seconds) /builddir/build/BUILD/pynvim-0.4.3> python -m pytest pid=458
  py312: FAIL code 1 (3.56=setup[0.01]+cmd[3.54] seconds)
  evaluation failed :( (3.63 seconds)

[wookayin]

The actual error is "Failed to load python3 host.".

The reason CI fails is neovim/neovim#25316 -- unless g:python3_host_prog is set explicitly, python3.12 cannot be automatically detected by neovim as the python3 provider.