rcarriga / vim-ultest

The ultimate testing plugin for (Neo)Vim
MIT License
385 stars 15 forks source link

[go test]: Incorrrect test results being reported #34

Closed awwalker closed 3 years ago

awwalker commented 3 years ago

I know from the debugging wiki there are some issues with go test due to it not returning 0/1 exit codes after completion but I'm filing an issue in the hopes that there is a way, like in the debug flow, to attach an output parser.

As an example if I run a go test file using a call to :Ultest it shows the test as failing even though the actual output shows success.

Screen Shot 2021-04-09 at 3 05 10 AM

I'm happy to help contribute if this doesn't already exist and isn't too deep in the weeds of what vim-test ultimately controls.

rcarriga commented 3 years ago

Hmm that is odd. Can you ULTEST_LOG_LEVEL=DEBUG ULTEST_LOG_FILE=ultest.log nvim <test_file>.go, run :Ultest and paste the contents of ultest.log here?

awwalker commented 3 years ago
12:30:08 | INFO | MainThread | logging.py:create_logger:74 | Logger created
12:30:08 | DEBUG | MainThread | __init__.py:__init__:40 | Handler created
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:08 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | MainThread | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | MainThread | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | MainThread | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | WARNING | Thread-1 | processes.py:run:135 | An exception was thrown when starting test TestUpsertCurrenciesTx6678823922465912131 with command: ['go', 'test', '-run', 'TestUpsertCurrenciesTx$', './services/secmaster/db']
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/processes.py", line 128, in run
    *cmd, stdin=in_handle, stderr=out_handle, stdout=out_handle
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/subprocess.py", line 217, in create_subprocess_exec
    stderr=stderr, **kwds)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/base_events.py", line 1516, in subprocess_exec
    bufsize, **kwargs)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 193, in _make_subprocess_transport
    self._child_watcher_callback, transp)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 924, in add_child_handler
    "Cannot add child handler, "
RuntimeError: Cannot add child handler, the child watcher does not have a loop attached
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | MainThread | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | WARNING | Thread-1 | processes.py:run:135 | An exception was thrown when starting test TestQueryCurrenciesTx2733261413546267579 with command: ['go', 'test', '-run', 'TestQueryCurrenciesTx$', './services/secmaster/db']
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/processes.py", line 128, in run
    *cmd, stdin=in_handle, stderr=out_handle, stdout=out_handle
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/subprocess.py", line 217, in create_subprocess_exec
    stderr=stderr, **kwds)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/base_events.py", line 1516, in subprocess_exec
    bufsize, **kwargs)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 193, in _make_subprocess_transport
    self._child_watcher_callback, transp)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 924, in add_child_handler
    "Cannot add child handler, "
RuntimeError: Cannot add child handler, the child watcher does not have a loop attached
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | Thread-1 | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
12:30:11 | ERROR | MainThread | logging.py:__deferred_flog:37 | Error converting args to str
Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/logging.py", line 34, in __deferred_flog
    level, eval(fstr, frame.f_globals, frame.f_locals), stacklevel=3
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/logging/__init__.py", line 1398, in log
    self._log(level, msg, args, **kwargs)
TypeError: _log() got an unexpected keyword argument 'stacklevel'
github-actions[bot] commented 3 years ago

:tada: This issue has been resolved in version 2.11.1 :tada:

The release is available on GitHub release

Your semantic-release bot :package::rocket:

rcarriga commented 3 years ago

Sorry for the noise in the logs, turns out you've uncovered a bug in the logging with python 3.7. All fixed now.

The actual issue you're having is here

Traceback (most recent call last):
  File "/Users/awalker/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/processes.py", line 128, in run
    *cmd, stdin=in_handle, stderr=out_handle, stdout=out_handle
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/subprocess.py", line 217, in create_subprocess_exec
    stderr=stderr, **kwds)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/base_events.py", line 1516, in subprocess_exec
    bufsize, **kwargs)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 193, in _make_subprocess_transport
    self._child_watcher_callback, transp)
  File "/Users/awalker/.pyenv/versions/3.7.0/lib/python3.7/asyncio/unix_events.py", line 924, in add_child_handler
    "Cannot add child handler, "
RuntimeError: Cannot add child handler, the child watcher does not have a loop attached

which was a fun one to track down :sweat_smile: Turns out there's a bug with asyncio.create_subprocess_exec in python 3.7 https://bugs.python.org/issue35621. I've gone by the suggested solution at the bottom and seems to be working perfeclty for me.

Let me know if you have any trouble!