[Bug] Incorrect PASS sign indicator when using dynamic string in suite description

[joeveiga]

Describe the bug

Hey @rcarriga 👋 !
First of all, great plugin! It's making it real easy to use vim-test. I'm using it with jest in an Angular project and it's working great so far. I did run into an issue though: When trying to use dynamic values in the string describing my test suite/case, the plugin fails to mark a failed test as failed. My guess is there is some sort of namespacing issue there. Please see the following snippet, and the attached screenshots bellow showing the faulty behavior. Thanks!

// src/test.spec.ts

export class MyComponent {
  // ...
}

describe(MyComponent.name, () => {
  test('this shows as OK even tho it fails...', () => {
    expect(false).toBeTruthy();
  });
});

describe('MyComponent_NameString', () => {
  test('this works as expected', () => {
    expect(false).toBeTruthy();
  });
});

vim-ultest.log

13:58:40 | INFO | MainThread | logging.py:create_logger:101 | Logger created
13:58:40 | DEBUG | MainThread | __init__.py:__init__:43 | Handler created
13:58:40 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:58 | Starting job with group update_positions
13:58:40 | INFO | Thread-1 | tracker.py:_async_update:55 | Updating positions in src/test.spec.ts
13:58:40 | DEBUG | Thread-1 | file.py:parse_file_structure:25 | 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*(?:"|\'|`)(.*)(?:"|\'|`)')]}
13:58:40 | DEBUG | Thread-1 | tracker.py:_async_update:82 | New test src/test.spec.ts found in src/test.spec.ts
13:58:40 | DEBUG | Thread-1 | tracker.py:_async_update:82 | New test this_shows_as_OK_even_tho_it_fails___4051083889056447564 found in src/test.spec.ts
13:58:40 | DEBUG | Thread-1 | tracker.py:_async_update:82 | New test MyComponent_NameString4051083889056447564 found in src/test.spec.ts
13:58:40 | DEBUG | Thread-1 | tracker.py:_async_update:82 | New test this_works_as_expected6682587002160702406 found in src/test.spec.ts
13:58:40 | DEBUG | Thread-1 | tracker.py:_remove_old_positions:125 | No tests removed
13:58:40 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:78 | Finished job with group update_positions
13:58:54 | INFO | MainThread | __init__.py:run_nearest:125 | Running nearest test in src/test.spec.ts at line 0
13:58:54 | DEBUG | MainThread | __init__.py:_register_started:281 | Registering src/test.spec.ts as started
13:58:54 | DEBUG | MainThread | __init__.py:_register_started:281 | Registering this_shows_as_OK_even_tho_it_fails___4051083889056447564 as started
13:58:54 | DEBUG | MainThread | __init__.py:_register_started:281 | Registering MyComponent_NameString4051083889056447564 as started
13:58:54 | DEBUG | MainThread | __init__.py:_register_started:281 | Registering this_works_as_expected6682587002160702406 as started
13:58:54 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:58 | Starting job with group src/test.spec.ts
13:58:54 | DEBUG | Thread-1 | processes.py:run:50 | Starting test process src/test.spec.ts with command ['node_modules/.bin/jest', '--noStackTrace', '--no-coverage', '--', 'src/test.spec.ts'], cwd = None, env = None
13:58:57 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:57 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:57 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:57 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:57 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-3 | handle.py:forward:85 | Writing data to output file
13:58:59 | DEBUG | Thread-1 | processes.py:run:76 | Process src/test.spec.ts complete with exit code: 1
13:58:59 | INFO | Thread-1 | output.py:parse_failed:66 | Found failed test in output this shows as OK even tho it fails... in namespaces MyComponent ›  of runner javascript#jest
13:58:59 | INFO | Thread-1 | output.py:parse_failed:66 | Found failed test in output this works as expected in namespaces MyComponent_NameString ›  of runner javascript#jest
13:58:59 | DEBUG | Thread-1 | __init__.py:_register_result:292 | Registering src/test.spec.ts as exited with result {"id": "src/test.spec.ts", "file": "src/test.spec.ts", "code": 1, "output": "/var/folders/g2/bt7vcjrn0v30vvnxnvs2p3qc0000gp/T/ultestu6s6l2ee/src__test_spec_ts/src__test_spec_ts_out"}
13:58:59 | DEBUG | Thread-1 | __init__.py:_register_result:292 | Registering this_shows_as_OK_even_tho_it_fails___4051083889056447564 as exited with result {"id": "this_shows_as_OK_even_tho_it_fails___4051083889056447564", "file": "src/test.spec.ts", "code": 0, "output": "/var/folders/g2/bt7vcjrn0v30vvnxnvs2p3qc0000gp/T/ultestu6s6l2ee/src__test_spec_ts/src__test_spec_ts_out"}
13:58:59 | DEBUG | Thread-1 | __init__.py:_register_result:292 | Registering MyComponent_NameString4051083889056447564 as exited with result {"id": "MyComponent_NameString4051083889056447564", "file": "src/test.spec.ts", "code": 1, "output": "/var/folders/g2/bt7vcjrn0v30vvnxnvs2p3qc0000gp/T/ultestu6s6l2ee/src__test_spec_ts/src__test_spec_ts_out"}
13:58:59 | DEBUG | Thread-1 | __init__.py:_register_result:292 | Registering this_works_as_expected6682587002160702406 as exited with result {"id": "this_works_as_expected6682587002160702406", "file": "src/test.spec.ts", "code": 1, "output": "/var/folders/g2/bt7vcjrn0v30vvnxnvs2p3qc0000gp/T/ultestu6s6l2ee/src__test_spec_ts/src__test_spec_ts_out"}
13:58:59 | DEBUG | MainThread | __init__.py:_present_output:109 | Showing src/test.spec.ts output
13:58:59 | DEBUG | Thread-1 | __init__.py:_handle_coroutine:78 | Finished job with group src/test.spec.ts
13:58:59 | DEBUG | MainThread | __init__.py:_present_output:109 | Showing MyComponent_NameString4051083889056447564 output
13:58:59 | DEBUG | MainThread | __init__.py:_present_output:109 | Showing this_works_as_expected6682587002160702406 output

To Reproduce
Copy the provided code snippet and run :Ultest on it.

Expected behavior
Plugin should handle dynamic values in suite/test descriptions correctly.

Screenshots

Additional context

$ vim -v
NVIM v0.5.0
Build type: Release
LuaJIT 2.1.0-beta3
Compilation: clang -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=1 -DNVIM_TS_HAS_SET_MATCH_LIMIT -O2 -DNDEBUG -Wall -Wextra -pedantic -Wno-unused-parameter -Wstrict-prototypes -std=gnu99 -Wshadow -Wconversion -Wmissing-prototypes -Wimplicit-fallthrough -Wvla -fstack-protector-strong -fno-common -fdiagnostics-color=auto -DINCLUDE_GENERATED_DECLARATIONS -D_GNU_SOURCE -DNVIM_MSGPACK_HAS_FLOAT32 -DNVIM_UNIBI_HAS_VAR_FROM -DMIN_LOG_LEVEL=3 -I/tmp/neovim-20210702-21950-fs4dxz/neovim-0.5.0/build/config -I/tmp/neovim-20210702-21950-fs4dxz/neovim-0.5.0/src -I/usr/local/include -I/Library/Developer/CommandLineTools/SDKs/MacOSX10.15.sdk/usr/include -I/usr/local/opt/gettext/include -I/tmp/neovim-20210702-21950-fs4dxz/neovim-0.5.0/build/src/nvim/auto -I/tmp/neovim-20210702-21950-fs4dxz/neovim-0.5.0/build/include
Compiled by brew@iMac-Pro

[rcarriga]

Thanks for the great report! I believe your guess is exactly correct, there is a feature that allows for running all tests together but only if the output can be parsed to get the individual results. I've added the ability to opt of this (g:ultest_disable_grouping). It'll mean that all tests run as separate processes but unfortunately there is no way for the plugin to know the namespace structure to run together.

[joeveiga]

@rcarriga Thanks for the quick response! I had an issue with the config option but it looks like it's working as expected now. Although, I'm curious about what the issue is with dynamic names. Do you use the source files for something, or just parse the output of the test runner (or vim-test)? If it's the later, both outputs look identical to me so I don't see what the issue is there. For example, this is the output from running :TestFile on that file:

[rcarriga]

vim-test (and thus vim-ultest) is built entirely on matching regex expressions against source files to discover namespaces and tests. vim-ultest uses these matches to display the correct results by matching the names in the output. If the static file doesn't match to the output then there is no way (that I'm aware of) to figure out which tests fail. If the tests are run individually then the exit code of the process is enough to know the result, meaning the output doesn't have to match.