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

Function call overhead #229

Merged
merged 12 commits into from Jul 15, 2018

Conversation

Projects
None yet
2 participants
@PragTob
Copy link
Owner

PragTob commented Jun 23, 2018

Quite some drive by fixes in here :)

Had to add the configuration option so that it doesn't drive up our test times - these 0.02 seconds add up when you do it a hundred times!

Idea as a follow up: Show the measured overhead in the printed out configuration. That improves discoverability but also adds a place to show that someone has it intentionally turned off (it's opt out). However, that requires moving code around: Either move the printing into the runner (not really the right place) or move the inner part of the runner somewhere else so that it can be called from Benchmark and already displayed there and then passed into the runner.

Here it is in action, making it visible that a lot of the function are just optimized by the compiler to return a constant (which is great):

tobi@speedy:~/github/benchee(function-call-overhead)$ mix run samples/fast_functions.exs 
Operating System: Linux"
CPU Information: Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz
Number of Available Cores: 8
Available memory: 15.61 GB
Elixir 1.6.4
Erlang 20.3

Benchmark suite executing with the following configuration:
warmup: 1 s
time: 1 s
memory time: 1 s
parallel: 1
inputs: none specified
Estimated total run time: 21 s


Benchmarking ++ array concat (wrong)...
Benchmarking Enum.map(10)...
Benchmarking Integer addition...
Benchmarking Integer addition (wrong)...
Benchmarking String concatention (wrong)...
Benchmarking adding a head to an array (wrong)...
Benchmarking noop...

Name                                        ips        average  deviation         median         99th %
Integer addition (wrong)               358.83 M        2.79 ns  ±1551.16%           0 ns          36 ns
noop                                   334.28 M        2.99 ns  ±1397.50%           0 ns          41 ns
adding a head to an array (wrong)      316.02 M        3.16 ns  ±1198.18%           0 ns          37 ns
++ array concat (wrong)                307.24 M        3.25 ns   ±939.38%           0 ns          45 ns
String concatention (wrong)            268.45 M        3.73 ns   ±845.54%           1 ns          39 ns
Integer addition                        61.74 M       16.20 ns   ±235.69%          18 ns          59 ns
Enum.map(10)                             2.26 M      442.05 ns  ±2153.23%         364 ns         813 ns

Comparison: 
Integer addition (wrong)               358.83 M
noop                                   334.28 M - 1.07x slower
adding a head to an array (wrong)      316.02 M - 1.14x slower
++ array concat (wrong)                307.24 M - 1.17x slower
String concatention (wrong)            268.45 M - 1.34x slower
Integer addition                        61.74 M - 5.81x slower
Enum.map(10)                             2.26 M - 158.62x slower

Memory usage statistics:

Name                                 Memory usage
Integer addition (wrong)                    616 B
noop                                        616 B - 1.00x memory usage
adding a head to an array (wrong)           616 B - 1.00x memory usage
++ array concat (wrong)                     616 B - 1.00x memory usage
String concatention (wrong)                 616 B - 1.00x memory usage
Integer addition                            616 B - 1.00x memory usage
Enum.map(10)                                424 B - 0.69x memory usage
@devonestes
Copy link
Collaborator

devonestes left a comment

Works for me (with one small typo fix)! I guess this makes it a much more accurate benchmarking tool even for _nano_benchmarks!

@@ -9,6 +9,12 @@ guard("credo", run_on_start: true)
|> ignore(deps)
|> notification(:auto)

guard("mix format", run_on_start: true)
|> command("mix format --check-formatted")

This comment has been minimized.

@devonestes

devonestes Jun 26, 2018

Collaborator

This is good - letting us know it's not formatted on save, but not actually formatting on save. I like it!

README.md Outdated
@@ -193,6 +193,7 @@ The available options are the following (also documented in [hexdocs](https://he
in microseconds, and counts will be displayed in ones (this is
equivalent to the behaviour Benchee had pre 0.5.0)
* `:before_scenario`/`after_scenario`/`before_each`/`after_each` - read up on them in the [hooks section](#hooks-setup-teardown-etc)
* `:measure_function_call_overhead` - Measure how long an empty function call takes and deduct this from each measure tun time. Defaults to true.

This comment has been minimized.

@devonestes

devonestes Jun 26, 2018

Collaborator

Just a typo - "from each measure s/tun/run/ time".

@PragTob

This comment has been minimized.

Copy link
Owner Author

PragTob commented Jun 27, 2018

Thanks for taking a look @devonestes ! :)

Yes, actually wanted the headline of the new version to be: Microbenchmarks? Pah, how about Nano benchmarks! 😁

@PragTob PragTob merged commit 5cb18ae into master Jul 15, 2018

5 checks passed

continuous-integration/appveyor/branch AppVeyor build succeeded
Details
continuous-integration/appveyor/pr AppVeyor build succeeded
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
continuous-integration/travis-ci/push The Travis CI build passed
Details
coverage/coveralls Coverage decreased (-1.7%) to 94.845%
Details

@PragTob PragTob deleted the function-call-overhead branch Jul 15, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment