Nothing happens on Ultest* commands

[VVKot]

Very similar to #21.

Describe the bug
Nothing happens when running Ultest* commands. Tests are seemingly detected fine (they show up in UltestSummary tree), however, they are not actually running. I am in Typescript test file, using Jest. :TestFile from vim-test runs succesfully.

Logs should be created using ULTEST_LOG_LEVEL=DEBUG ULTEST_LOG_FILE=vim-ultest.log nvim <test-file> and added here as well:

21:33:00 | INFO | MainThread | logging.py:create_logger:98 | Logger created
21:33:00 | DEBUG | MainThread | init.py:init:41 | Handler created
21:33:01 | DEBUG | Thread-1 | init.py:_handle_coroutine:57 | Starting job with group update_positions
21:33:01 | INFO | Thread-1 | tracker.py:_async_update:52 | Updating positions in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | file.py:parse_file_structure:22 | Converted pattern {'test': ['\v^\s*%(it|test)\s*[( ]\s*%("|'|)(.*)%("|\'|)'], 'namespace': ['\v^\s*%(describe|suite|context)\s*[( ]\s*%("|'|)(.*)%("|\'|)']} to {'test': [re.compile('^\s*(?:it|test)\s*[( ]\s*(?:"|'|)(.*)(?:"|\'|)')], 'namespace': [re.compile('^\s*(?:describe|suite|context)\s*[( ]\s*(?:"|'|)(.*)(?:"|\'|)')]}
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test /path/to/bar.test.ts found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test bar5117784500479910972 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo0 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo1 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo2 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo3 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo4 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo5 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo6 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo7 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo8 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_remove_old_positions:122 | No tests removed
21:33:01 | DEBUG | Thread-1 | init.py:_handle_coroutine:77 | Finished job with group update_positions
21:33:17 | INFO | MainThread | init.py:run_nearest:125 | Running nearest test in bar.test.ts at line 0
21:33:17 | INFO | MainThread | init.py:run_nearest:129 | No tests found for bar.test.ts rerunning after processing positions

To Reproduce
See above

Expected behavior
Tests actually run

Screenshots
None

Additional context
:checkhealth does not show any problems, remote plugins are up-to-date, Python3 and pynvim are available (I am also using UltiSnips which need Python and are functioning fine).

[VVKot]

@rcarriga anything that you might be able to tell from this log? Happy to try to setup a repro otherwise.

[rcarriga]

Assuming you're reliably reproducing the logs, it looks like the file name is being inconsistently used /path/to/bar.test.ts vs bar.test.ts. Could you try with the latest commit to see if it works?

[VVKot]

Hmm, this sadly does not seem to change anything.

[rcarriga]

OK I can't really debug any further without something to reproduce. If you can replicate with a simple dummy file that'd be brilliant

[yacut]

I have a similar problem with junit test

The log for ULTEST_LOG_LEVEL=DEBUG ULTEST_LOG_FILE=vim-ultest.log nvim <test-file>:

21:16:59 | WARNING | Thread-1 | __init__.py:_handle_coroutine:73 | Traceback (most recent call last):

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 57, in _async_update
    positions = await self._parse_positions(file_name, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 107, in _parse_positions
    positions = await self._file_parser.parse_file_structure(file, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 24, in parse_file_structure
    patterns = self._convert_patterns(vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 39, in _convert_patterns
    tests = [

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 40, in <listcomp>
    self._convert_regex(pattern) for pattern in vim_patterns.get("test", "")

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 52, in _convert_regex
    return re.compile(regex)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 252, in compile
    return _compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 304, in _compile
    p = sre_compile.compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_compile.py", line 764, in compile
    p = sre_parse.parse(p, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 948, in parse
    p = _parse_sub(source, state, flags & SRE_FLAG_VERBOSE, 0)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 834, in _parse
    p = _parse_sub(source, state, sub_verbose, nested + 1)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 525, in _parse
    code = _escape(source, this, state)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 426, in _escape
    raise source.error("bad escape %s" % escape, len(escape))

re.error: bad escape \z at position 7

21:16:59 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:78 | Finished job with group update_positions
21:17:03 | INFO | MainThread | __init__.py:run_nearest:125 | Running nearest test in src/test/java/Test.java at line 1
21:17:03 | INFO | MainThread | __init__.py:run_nearest:129 | No tests found for src/test/java/Test.java, rerunning after processing positions
21:17:03 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:58 | Starting job with group update_positions
21:17:03 | INFO | Thread-1 | tracker.py:_async_update:55 | Updating positions in src/test/java/Test.java
21:17:03 | WARNING | Thread-1 | __init__.py:_handle_coroutine:72 | Exception throw in job: bad escape \z at position 7
21:17:03 | WARNING | Thread-1 | __init__.py:_handle_coroutine:73 | Traceback (most recent call last):

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 57, in _async_update
    positions = await self._parse_positions(file_name, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 107, in _parse_positions
    positions = await self._file_parser.parse_file_structure(file, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 24, in parse_file_structure
    patterns = self._convert_patterns(vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 39, in _convert_patterns
    tests = [

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 40, in <listcomp>
    self._convert_regex(pattern) for pattern in vim_patterns.get("test", "")

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 52, in _convert_regex
    return re.compile(regex)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 252, in compile
    return _compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 304, in _compile
    p = sre_compile.compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_compile.py", line 764, in compile
    p = sre_parse.parse(p, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 948, in parse
    p = _parse_sub(source, state, flags & SRE_FLAG_VERBOSE, 0)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 834, in _parse
    p = _parse_sub(source, state, sub_verbose, nested + 1)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 525, in _parse
    code = _escape(source, this, state)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 426, in _escape
    raise source.error("bad escape %s" % escape, len(escape))

re.error: bad escape \z at position 7

21:17:03 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:78 | Finished job with group update_positions
21:17:04 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:58 | Starting job with group update_positions
21:17:04 | INFO | Thread-1 | tracker.py:_async_update:55 | Updating positions in src/test/java/Test.java
21:17:04 | WARNING | Thread-1 | __init__.py:_handle_coroutine:72 | Exception throw in job: bad escape \z at position 7
21:17:04 | WARNING | Thread-1 | __init__.py:_handle_coroutine:73 | Traceback (most recent call last):

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 57, in _async_update
    positions = await self._parse_positions(file_name, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 107, in _parse_positions
    positions = await self._file_parser.parse_file_structure(file, vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 24, in parse_file_structure
    patterns = self._convert_patterns(vim_patterns)

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 39, in _convert_patterns
    tests = [

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 40, in <listcomp>
    self._convert_regex(pattern) for pattern in vim_patterns.get("test", "")

  File "/Users/xxx/.local/share/nvim/plugged/vim-ultest/rplugin/python3/ultest/handler/parsers/file.py", line 52, in _convert_regex
    return re.compile(regex)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 252, in compile
    return _compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/re.py", line 304, in _compile
    p = sre_compile.compile(pattern, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_compile.py", line 764, in compile
    p = sre_parse.parse(p, flags)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 948, in parse
    p = _parse_sub(source, state, flags & SRE_FLAG_VERBOSE, 0)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 834, in _parse
    p = _parse_sub(source, state, sub_verbose, nested + 1)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 443, in _parse_sub
    itemsappend(_parse(source, state, verbose, nested + 1,

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 525, in _parse
    code = _escape(source, this, state)

  File "/Users/xxx/.pyenv/versions/3.9.4/lib/python3.9/sre_parse.py", line 426, in _escape
    raise source.error("bad escape %s" % escape, len(escape))

re.error: bad escape \z at position 7

21:17:04 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:78 | Finished job with group update_positions

Additionally I have an error on nvim start:

But the :UpdateRemotePlugins command shows no problem:

[rcarriga]

@yacut This is a different problem. Try with the latest commit, I believe I have fixed the issue. If not, please open a separate issue.

[rcarriga]

@VVKot Following up, I've taken a look at your dotfiles and found these functions wrap vim-test commands

local call_with_test_directory_as_cwd = function(command)
  local cwd = vim.api.nvim_eval("getcwd()")
  vim.o.autochdir = true
  last_test_cwd = vim.api.nvim_eval("getcwd()")
  vim.api.nvim_command(command)
  vim.o.autochdir = false
  vim.api.nvim_command("cd " .. cwd)
end

local call_with_last_test_cwd = function(command)
  local cwd = vim.api.nvim_eval("getcwd()")
  vim.api.nvim_command("cd " .. last_test_cwd)
  vim.api.nvim_command(command)
  vim.api.nvim_command("cd " .. cwd)
end

Can you explain what these are for? As they're not standard vim-test functionality I would imagine this is why vim-ultest is not working

[VVKot]

@rcarriga sure, they basically set up correct cwd for tests to run. See longer explanation here: vim-test/vim-test#209 (comment).

However, even if I don't use this commands and just use raw vim-test commands instead, my tests do run (they'd fail at runtime because they will execute Typescript, not compiled Javascript). However, running Ultest commands directly does not do anything. It seems that discovery of the tests works correctly, however, then we don't find those tests relative to the current position in the file:

21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test /path/to/bar.test.ts found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test bar5117784500479910972 found in /path/to/bar.test.ts
21:33:01 | DEBUG | Thread-1 | tracker.py:_async_update:79 | New test foo0 found in /path/to/bar.test.ts

...

21:33:17 | INFO | MainThread | init.py:run_nearest:125 | Running nearest test in bar.test.ts at line 0
21:33:17 | INFO | MainThread | init.py:run_nearest:129 | No tests found for bar.test.ts rerunning after processing positions

Sorry, haven't gotten to setting up a repro yet.

[rcarriga]

Ah OK thanks for the info! I'll wait for a reproduction so 😄

[nathani-work]

I'm having the same issue, I can run vim-test commands but no Ultest commands
I'm running vim-ultest in https://www.lunarvim.org/, and I'm working with go files, using the standard go tests

here's my logs:

12:08:00 | INFO | MainThread | logging.py:create_logger:101 | Logger created
12:08:01 | INFO | MainThread | __init__.py:__init__:28 | Using local threaded child watcher
12:08:01 | DEBUG | MainThread | __init__.py:__init__:43 | Handler created
12:08:01 | ERROR | MainThread | tracker.py:_get_file_patterns:103 | Error while evaluating patterns for file test_file.go
Traceback (most recent call last):
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 101, in _get_file_patterns
    return self._vim.sync_call("ultest#adapter#get_patterns", file)
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/vim_client/__init__.py", line 121, in sync_call
    return self._eval(expr, sync=True)
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/vim_client/__init__.py", line 134, in _eval
    return self._vim.eval(expr, async_=not sync)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/api/nvim.py", line 295, in eval
    return self.request('nvim_eval', string, **kwargs)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/api/nvim.py", line 182, in request
    res = self._session.request(name, *args, **kwargs)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/msgpack_rpc/session.py", line 102, in request
    raise self.error_wrapper(err)
pynvim.api.common.NvimError: Vim(let):E117: Unknown function: test#determine_runner
12:08:01 | DEBUG | MainThread | tracker.py:update:34 | No patterns found for test_file.go
12:08:03 | INFO | MainThread | __init__.py:run_nearest:125 | Running nearest test in test_file.go at line 0
12:08:03 | INFO | MainThread | __init__.py:run_nearest:130 | No tests found for test_file.go, rerunning after processing positions
12:08:03 | ERROR | MainThread | tracker.py:_get_file_patterns:103 | Error while evaluating patterns for file test_file.go
Traceback (most recent call last):
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/handler/tracker.py", line 101, in _get_file_patterns
    return self._vim.sync_call("ultest#adapter#get_patterns", file)
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/vim_client/__init__.py", line 121, in sync_call
    return self._eval(expr, sync=True)
  File "/home/nathani/.local/share/lunarvim/site/pack/packer/start/vim-ultest/rplugin/python3/ultest/vim_client/__init__.py", line 134, in _eval
    return self._vim.eval(expr, async_=not sync)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/api/nvim.py", line 295, in eval
    return self.request('nvim_eval', string, **kwargs)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/api/nvim.py", line 182, in request
    res = self._session.request(name, *args, **kwargs)
  File "/home/nathani/.local/lib/python3.7/site-packages/pynvim/msgpack_rpc/session.py", line 102, in request
    raise self.error_wrapper(err)
pynvim.api.common.NvimError: Vim(let):E117: Unknown function: test#determine_runner
12:08:03 | DEBUG | MainThread | tracker.py:update:34 | No patterns found for test_file.go

[rcarriga]

@nathani-axis This looks like a separate issue. It looks like vim-test is either not installed or not loaded. Are you lazy loading it?

[nathani-work]

@nathani-axis This looks like a separate issue. It looks like vim-test is either not installed or not loaded. Are you lazy loading it?

You're right, this was my vim-test plugin installation

    {
        "vim-test/vim-test",
        cmd = { "TestNearest", "TestFile", "TestSuite", "TestLast", "TestVisit" },
        keys = { "<localleader>tf", "<localleader>tn", "<localleader>ts" },
        config = function()
            vim.cmd [[
                function! ToggleTermStrategy(cmd) abort
                    call luaeval("require('toggleterm').exec(_A[1])", [a:cmd])
                endfunction
                let g:test#custom_strategies = {'toggleterm': function('ToggleTermStrategy')}
            ]]
            vim.g["test#strategy"] = "toggleterm"
        end,
    },

:PackerStatus said (not loaded)

I've removed the cmd= and the keys= lines from the plugin installation config for vim-test, now it's loaded and :Ultest works