Skip to content

test-unit reporter causes large performance degradation #3843

@Earlopain

Description

@Earlopain

When I run a test class via "Run in Terminal", I can see how long these tests take. With a normal invocation, the tests finish in ~5 seconds, if the test-unit is reported the duration doubles to about 10 seconds.

I guess this does not happen so extremely in every scenario, just when the test file contains many tests. Specifically I encounter this in the prism snapshots test which creates about 3000 individual test methods. https://github.com/ruby/prism/blob/main/test/prism/snapshots_test.rb

$ bundle exec ruby -r/home/user/.rbenv/versions/3.4.6/lib/ruby/gems/3.4.0/gems/ruby-lsp-0.26.4/lib/ruby_lsp/test_reporters/test_unit_reporter.rb -Itest /home/user/code/ruby-prism/test/prism/snapshots_test.rb --testcase "/^Prism::SnapshotsTest\$/" --name "/\$/"
Loaded suite /home/user/code/ruby-prism/test/prism/snapshots_test
Started
Finished in 10.048171088 seconds.
--------------------------------------------------------------------------------------------------------------------------
2894 tests, 5788 assertions, 0 failures, 0 errors, 0 pendings, 0 omissions, 0 notifications
100% passed
--------------------------------------------------------------------------------------------------------------------------
288.01 tests/s, 576.03 assertions/s

$ bundle exec ruby  -Itest /home/user/code/ruby-prism/test/prism/snapshots_test.rb --testcase "/^Prism::SnapshotsTest\$/" --name "/\$/"
Loaded suite /home/user/code/ruby-prism/test/prism/snapshots_test
Started
Finished in 5.454402877 seconds.
--------------------------------------------------------------------------------------------------------------------------
2894 tests, 5788 assertions, 0 failures, 0 errors, 0 pendings, 0 omissions, 0 notifications
100% passed
--------------------------------------------------------------------------------------------------------------------------
530.58 tests/s, 1061.16 assertions/s

Attached there is a vernier profile. I see the custom reporter at about 18% runtime. That's not quite the 50% I would be expecting based on runtime but still quite a lot:

Image

time_profile.json (view on https://vernier.prof)

Metadata

Metadata

Assignees

Labels

help-wantedExtra attention is neededpinnedThis issue or pull request is pinned and won't be marked as stale

Type

No type
No fields configured for issues without a type.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions