very slow test execution when there are many (~thousands) of tests defined in a file

[devoncarew]

I'm working on a project where most of the tests are generated from a specification. There are tens of thousands of tests, and depending on the granularity of the source spec (the WASM specification) there can be several thousands tests in a single dart source file.

I see very slow test execution (from VS Code) when there are thousands of tests in a single dart source file. This is in comparison to running dart test for the same project from the command line - test execution there is on the order of a few seconds (6.90s for 7,590 tests). From VS code, just the tests in one file may take a few minutes to run.

I assume there's a quadratic / polynomial algorithm in there somewhere. I'm not sure if its in dart test (finding the locations for tess in the files?), in VS Code (displaying the locations?) or in the communication between the two (discovering tests and communicating it back to VS Code?). Or perhaps in the xml reporter for dart test - generally only used by IDEs?

In any case, I'm opening this issue to track the performance problem. The repo for the project demonstrating the issue is https://github.com/devoncarew/wasmd. The tests w/ perf issues are test/spec/f32/f32_test.dart and test/spec/f64/f64_test.dart. Let me know if there's any more digging you'd like me to do on my end.

[DanTup]

Thanks, I can repro this. The extension host seems to be eating a lot of CPU when this happens, so my guess is that it's in the extension and perhaps where we're trying to match up the tests in the results to those we already know about (we maintain an in-memory model of tests, merging those discovered at analysis time and runtime).

I'll d some profiling when back properly and see where the time is going.

While testing this, I also saw #4326 which seems to be something else eating a lot of CPU in the extension host for this project (before running any tests, so I think unrelated, but likely a similar thing - either slow and adds up, or scales badly).

[DanTup]

This shows up in the console while running that test file too. Seems we're blocking the extension host enough to start triggering an automatic profile, but then respond soon after such that it's cancelled. This would makes sense if it's the location of tests in the model as noted above.. it'll run on each test result and is probably just slow enough to trigger the profile, and then this happens repeatedly for each test.

[devoncarew]

Thanks for taking a look - much appreciated!

[DanTup]

I've made some reasonable improvements to this in #4328 (f32_test.dart is somewhere around 10s I think), but there are a few test failures and the "x/y Passed" labels aren't being updated correctly. I think that should all be fixable without adding much time back on though.

I did find an issue that might be in VS Code too - the editor seems to hang a bit when moving around that file - I've filed microsoft/vscode#170493 for investigation. I also found that the tests run are slower when the Test tree is visible, although I don't entirely understand why yet (the VS Code UI is in a different process to ours so I wouldn't expect it to be holding up the extension host). I'll dig more into that once the other issues are resolved.

[devoncarew]

Thanks again for taking a look!

I have some other large files now - some I'm not checking in - that show up perf issues in other places (general analysis, ...). I think these will be good for shaking out slowdowns in normal sized files.

[DanTup]

If you have any examples you can share (either by committing on a branch somewhere, or sending to me) I'd definitely be interested in taking a look after this. Performance is something that comes up now and then but often in private projects that can't be shared and profiling/optimising "remotely" can be tricky.

I have been thinking abut how maybe we could have something similar to Dart: Capture Logs for profiling information. It'd be neat if you could start profiling the analyzer by just running a command in VS Code, then reproduce your slow thing, then click a button to stop profiling and write a file that could be shared/examined.

Along similar lines, it'd be nice if users could maybe trigger profiling stop/starting from their code, similar to console.profile.

[DanTup]

I took some timings before/after the changes in #4328, and I'm quite surprised this hadn't come up sooner. With a small set of tests, rebuilding the whole tree was so fast that it was the easy thing to do, and it scaled incredibly badly (especially in the case of a large number of very small/fast tests).

Using current stable extension, running f32_test.dart with the file closed and the test tree visible but collapsed:

• Till "Exited" in Debug Console: 5:50 (350s)
• Till debug toolbar disappears: 5:50 (350s)

With the changes, timings are:

• Till "Exited" in Debug Console: 7s
• Till debug toolbar disappears: 8s

This is much better, however there are still some issues when the file is open and the tree is expanded:

• Till "Exited" in Debug Console: 15s
• Till debug toolbar disappears: 30s

I ran the profiler on both the extension host and VS Code for this case, and there's almost nothing happening in the extension host and lots of blocking in the VS Code UI, so I think once microsoft/vscode#170493 is resolved that will be better (but I'll re-test to be sure once it has).

I'm gonna do some more testing with your project to check for any other obvious perf issues in the extension, but otherwise I'll publish a pre-release version soon so you can update and confirm it's working (and hopefully give some more real world testing coverage before the next release 😄).

[DanTup]

@devoncarew I've pushed a pre-release version of the extension (v3.57.20230104) you can opt-in to if you aren't already on pre-releases:

It still has the caveat above (things are slower with the test file open), but otherwise should be much better. Please let me know if you see any other perf issues (or find any bugs in these changes).

[devoncarew]

A 50x perf improvement :) f32_test.dart takes ~4s to run on the command line, so your new numbers are likely ideal for testing through VS Code. I'll check out the pre-release dart code version - thanks!

[devoncarew]

however there are still some issues when the file is open and the tree is expanded

I do see the perf difference you describe, but the overall perf is night-and-day improved (unusable before for very large test files, and fine - if a little laggy - for the same w/ the updated extension).

[DanTup]

Cool - hopefully many of the remaining issues will go away if the VS Code issue above is fixed. As well as slowing things down, I see full editor hangs where I can't scroll/interact with the code 😞

That said, if you don't use those gutter icons for testing you could actually avoid the VS Code issue entirely by disabling them:

With that disabled, I see the same perf with the file open as when it was closed (and no hangs).

[DanTup]

microsoft/vscode#170493 was fixed and I tried this out in Insiders, and the editor is way more responsive now moving around these files.

It won't ship in a stable VS Code for almost 1 month (they just released and this wasn't in that version), but once it does, let me know if you still see any perf issues with this project (or others).