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

No one assigned

    Labels

    help-wantedExtra attention is needed

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions