Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

record output is completely broken #42

Closed
ChrisBr opened this issue Aug 30, 2018 · 5 comments
Closed

record output is completely broken #42

ChrisBr opened this issue Aug 30, 2018 · 5 comments

Comments

@ChrisBr
Copy link
Contributor

ChrisBr commented Aug 30, 2018 •
edited

I tried to record a benchmark and then use the different output formats. However, the output format is completely wrong. Example from the readme:

example.yml

prelude: |
  a = 'a' * 100
  b = 'b' * 100
benchmark:
  join: '[a, b].join'
  str-interp: '"#{a}#{b}"'
~

Commands:

./exe/benchmark-driver example.yml --rbenv "system;jruby-9.2.0.0" -o record
./exe/benchmark-driver benchmark_driver.record.yml

Actual output:

Calculating -------------------------------------
                join     1.263M         6.147M i/s -      3.674M times in 2.910045s 0.597724s
          str-interp     1.390M         6.170M i/s -      4.043M times in 2.908356s 0.655217s

Comparison:
          str-interp:   6169780.0 i/s 
                join:   6146784.0 i/s - 1.00x  slower
          str-interp:   1389976.6 i/s - 4.44x  slower
                join:   1262550.3 i/s - 4.89x  slower

Expected output:

Warming up --------------------------------------
                join     1.216M i/s -      1.247M times in 1.024951s (822.17ns/i)
          str-interp     1.236M i/s -      1.287M times in 1.040920s (808.89ns/i)
Calculating -------------------------------------
                         system  jruby-9.2.0.0 
                join     1.204M         6.315M i/s -      3.649M times in 3.031806s 0.577790s
          str-interp     1.493M         5.765M i/s -      3.709M times in 2.484574s 0.643288s

Comparison:
                             join
       jruby-9.2.0.0:   6315263.4 i/s 
              system:   1203539.5 i/s - 5.25x  slower

                       str-interp
       jruby-9.2.0.0:   5765360.9 i/s 
              system:   1492725.2 i/s - 3.86x  slower

More information:

When looking at the output file, I found already one issue, although I don't think this is the major problem here:

---
type: recorded
job_warmup_context_result:
  ? !ruby/struct:BenchmarkDriver::Job
    name: join
  : true:
      ? !ruby/struct:BenchmarkDriver::Context
        name: system
        executable: &1 !ruby/struct:BenchmarkDriver::Config::Executable
          name: system
          command:
          - "/usr/bin/ruby"
          cache: {}
        gems: &2 {}
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          ? &3 !ruby/struct:BenchmarkDriver::Metric
            name: Iteration per second
            unit: i/s
            larger_better: true
            worse_word: slower
          : 1224692.9059707068
        duration: 1.042432755
        loop_count: 1276660
        environment: {}
    false:
      ? !ruby/struct:BenchmarkDriver::Context
        name: system
        executable: *1
        gems: *2
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          *3: 1262550.2866748516
        duration: 2.910044881995418
        loop_count: 3674078
        environment: {}
      ? !ruby/struct:BenchmarkDriver::Context
        name: jruby-9.2.0.0
        executable: &4 !ruby/struct:BenchmarkDriver::Config::Executable
          name: jruby-9.2.0.0
          command:
          - "/home/cbruckmayer/.rbenv/versions/jruby-9.2.0.0/bin/ruby"
          cache: {}
        gems: &5 {}
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          *3: 6146783.99638361
        duration: 0.5977236229809932
        loop_count: 3674078
        environment: {}
  ? !ruby/struct:BenchmarkDriver::Job
    name: str-interp
  : true:
      ? !ruby/struct:BenchmarkDriver::Context
        name: system
        executable: *1
        gems: *2
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          *3: 1347515.9225639598
        duration: 1.019698526
        loop_count: 1374060
        environment: {}
    false:
      ? !ruby/struct:BenchmarkDriver::Context
        name: system
        executable: *1
        gems: *2
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          *3: 1389976.630139554
        duration: 2.9083560919971205
        loop_count: 4042547
        environment: {}
      ? !ruby/struct:BenchmarkDriver::Context
        name: jruby-9.2.0.0
        executable: *4
        gems: *5
        prelude: ''
      : !ruby/struct:BenchmarkDriver::Result
        values:
          *3: 6169780.046371228
        duration: 0.6552173610107275
        loop_count: 4042547
        environment: {}
metrics:
- *3

The metrics section does not correctly serialize the metrics but only a *3.

Another problem seems to be here:
https://github.com/benchmark-driver/benchmark-driver/blob/master/lib/benchmark_driver/runner.rb#L49

The executables are taken from the config and therefore the formatting is wrong. It can be worked around with:

./exe/benchmark-driver benchmark_driver.record.yml --rbenv "system;jruby-9.2.0.0"

However, I think calling the rbenv here shouldn't be necessary as they are already synchronized, no? Or would it be necessary to synchronize the config as well?

Edit: removed the part about markdown, seems to be fine, my mistake!
@k0kubun
Copy link
Member

k0kubun commented Aug 31, 2018

Hmm, that's something unexpected. I'll take a look after I go home.

@ChrisBr
Copy link
Contributor Author

ChrisBr commented Aug 31, 2018

Seems like the gruff output is also broken because of that:

benchmark_1  | results/result_100_aref.yml
benchmark_1  | /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-output-gruff-0.3.1/lib/benchmark_driver/output/gruff.rb:44:in `block (2 levels) in bulk_output': undefined method `values' for nil:NilClass (NoMethodError)
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-output-gruff-0.3.1/lib/benchmark_driver/output/gruff.rb:43:in `map'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-output-gruff-0.3.1/lib/benchmark_driver/output/gruff.rb:43:in `block in bulk_output'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-output-gruff-0.3.1/lib/benchmark_driver/output/gruff.rb:42:in `each'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-output-gruff-0.3.1/lib/benchmark_driver/output/gruff.rb:42:in `bulk_output'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/bulk_output.rb:37:in `with_benchmark'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/output.rb:55:in `with_benchmark'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner/recorded.rb:49:in `run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:40:in `block (4 levels) in run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:95:in `rescue in with_clean_env'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:90:in `with_clean_env'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:39:in `block (3 levels) in run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:30:in `each'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:30:in `block (2 levels) in run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:29:in `each'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:29:in `block in run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:28:in `each'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/lib/benchmark_driver/runner.rb:28:in `run'
benchmark_1  | 	from /usr/lib64/ruby/gems/2.4.0/gems/benchmark_driver-0.14.6/exe/benchmark-driver:118:in `<top (required)>'

Thanks for your work 👍 Let me know if I can help. I looked yesterday briefly into it but the structure of the results looked rather complicated so I didn't find the issue quickly ...

@k0kubun
Copy link
Member

k0kubun commented Aug 31, 2018

Btw, your example.yml includes

~

but it's not intentional, right?

@k0kubun
Copy link
Member

k0kubun commented Aug 31, 2018

I assume I fixed the original issue correctly in v0.14.8. I still don't understand the issue on gruff output, so please file another issue with more details if the error persists.

@ChrisBr
Copy link
Contributor Author

ChrisBr commented Aug 31, 2018

but it's not intentional, right?

Yeah, sorry! Wrong c&p from vim ...

I assume I fixed the original issue correctly in v0.14.8. I still don't understand the issue on gruff output, so please file another issue with more details if the error persists.

Confirmed, original issue is fixed! Thanks a lot ❤️

@ChrisBr ChrisBr mentioned this issue Sep 1, 2018
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@k0kubun @ChrisBr