search

evanphx / benchmark-ips

Provides iteration per second benchmarking for Ruby
MIT License
1.72k stars 97 forks source link

Slow Tests #114

Closed allcentury closed 9 months ago

allcentury commented 3 years ago

While working on #113 I noticed the test suite here is really slow:

Has anyone looked into this? 

ruby -Ilib:test:. -w -e 'require "minitest/autorun"; require "test/test_benchmark_ips.rb"' -- --profile
Run options: --profile --seed 51810

# Running:

...............

Finished in 59.705193s, 0.2512 runs/s, 0.7035 assertions/s.

15 runs, 42 assertions, 0 failures, 0 errors, 0 skips

================================================================================
Your 10 Slowest Tests
================================================================================

17.0485ms - TestBenchmarkIPS#test_quiet
 7.0211ms - TestBenchmarkIPS#test_json_output
 7.0170ms - TestBenchmarkIPS#test_ips_report_using_symbol
 7.0169ms - TestBenchmarkIPS#test_ips_defaults
 7.0166ms - TestBenchmarkIPS#test_ips_default_data
 3.9220ms - TestBenchmarkIPS#test_ips
 3.0117ms - TestBenchmarkIPS#test_output
 2.0114ms - TestBenchmarkIPS#test_kwargs
 2.0114ms - TestBenchmarkIPS#test_ips_alternate_config
 2.0113ms - TestBenchmarkIPS#test_ips_old_config

When I profile it, it seems like it's waiting on a thread but I can't seem to figure out where that's coming from

ruby -r profile test/test_benchmark_ips.rb -n test_quiet
Run options: -n test_quiet --seed 55234

# Running:

.

Finished in 10.115211s, 0.0989 runs/s, 0.0000 assertions/s.

1 runs, 0 assertions, 0 failures, 0 errors, 0 skips
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
197.30    16.22     16.22        2  8107.71  8107.71  Thread::Queue#pop
 34.78    19.07      2.86       77    37.12    73.40  #<Benchmark::IPS::Job::Entry:0x0000556a0dda3140>.call_times
 26.24    21.23      2.16   386597     0.01     0.03  TestBenchmarkIPS#test_quiet
 14.94    22.46      1.23       37    33.19    65.53  #<Benchmark::IPS::Job::Entry:0x0000556a0dc2cd70>.call_times
  7.61    23.08      0.63   386708     0.00     0.00  Integer#<

I opened up https://github.com/ruby/profile/issues/3 to see if there's a way to track that down.

kbrock commented 1 year ago

So the test suite is testing the iterations of methods. And it is trying to run them enough times to get a reasonable statistics.

I suppose we could try passing in warmup times and runtimes to cut down on each run. The only other way I can think is to stub these methods with return values