search

neovim / pynvim

Python client and plugin host for Nvim
http://pynvim.readthedocs.io/en/latest/
Apache License 2.0
1.47k stars 118 forks source link

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

Closed michel-slm closed 9 months ago

michel-slm commented 11 months ago

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 commented 11 months ago

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

https://github.com/neovim/pynvim/pull/529

michel-slm commented 11 months ago

ah, the test_buffer issue is due to this https://github.com/neovim/pynvim/commit/82a2e14b96fbffa30caeefec6e86b668c96662eb

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

michel-slm commented 11 months ago

https://github.com/neovim/pynvim/pull/531 fixes test_buffer by not hardcoding the global value for 'default'

justinmk commented 11 months ago

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 commented 10 months ago

798dfc3fa67c566867715852edd440c6c9efe164 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 commented 9 months ago

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.