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

Slf dtrace take1 #174

Merged
merged 3 commits into from
Jun 10, 2012
Merged

Slf dtrace take1 #174

merged 3 commits into from
Jun 10, 2012

Conversation

slfritchie
Copy link
Contributor

Add basic infrastructure Erlang-triggerable probes to Riak Core apps.

In an ideal world, this module would live in a repo that would be
easily sharable across multiple Basho projects. The tricky bit for
this would be trying to make generic the
application:get_env(riak_core, dtrace_support)' call that's currently in theriak_kv_dtrace:dtrace/1' function. But we'll
wait for another day, I think.

The purpose of this module is to reduce the overhead of DTrace (and
SystemTap) probes when those probes are: 1. not supported by the VM,
or 2. disabled by application configuration. #1 is the bigger
problem: a single call to the code loader can take several
milliseconds. #2 is useful in the case that we want to try to reduce
the overhead of adding these probes even further by avoiding the NIF
call entirely.

SLF's MacBook Pro tests

without cover, with R14B04 + DTrace:

timeit_naive                 average  2236.306 usec/call over     500.0 calls
timeit_mochiglobal           average     0.509 usec/call over  225000.0 calls
timeit_best OFF (fastest)    average     0.051 usec/call over  225000.0 calls
timeit_best ON -init         average     1.027 usec/call over  225000.0 calls
timeit_best ON +init         average     0.202 usec/call over  225000.0 calls

with cover, with R14B04 + DTrace:

timeit_naive                 average  2286.202 usec/call over     500.0 calls
timeit_mochiglobal           average     1.255 usec/call over  225000.0 calls
timeit_best OFF (fastest)    average     1.162 usec/call over  225000.0 calls
timeit_best ON -init         average     2.207 usec/call over  225000.0 calls
timeit_best ON +init         average     1.303 usec/call over  225000.0 calls

@ghost ghost assigned bookshelfdave Jun 4, 2012
@beerriot
Copy link
Contributor

beerriot commented Jun 6, 2012

The best time for me on OS X 10.6.8, R14B04+Dtrace without cover was "timeit_best ON +init":

timeit_naive                 average  6441.864 usec/call over     500.0 calls
timeit_mochiglobal           average     2.110 usec/call over  225000.0 calls
timeit_best OFF (fastest)    average     1.244 usec/call over  225000.0 calls
timeit_best ON -init         average     1.185 usec/call over  225000.0 calls
timeit_best ON +init         average     0.229 usec/call over  225000.0 calls

Same with cover (though I also don't see the difference your results showed when enabling cover, so maybe I have these confused):

timeit_naive                 average  6412.970 usec/call over     500.0 calls
timeit_mochiglobal           average     2.048 usec/call over  225000.0 calls
timeit_best OFF (fastest)    average     1.225 usec/call over  225000.0 calls
timeit_best ON -init         average     1.212 usec/call over  225000.0 calls
timeit_best ON +init         average     0.231 usec/call over  225000.0 calls

In case this helps:

Erlang R14B04 (erts-5.8.5) [source] [64-bit] [smp:4:4] [rq:4] [async-threads:64] [hipe] [kernel-poll:true] [dtrace]

@beerriot
Copy link
Contributor

beerriot commented Jun 6, 2012

Ooops. Nope, ignore that. The timeit…on tests explicitly set {dtrace_support, true} but timeit…off doesn't explicitly set {dtrace_support, false}. I had set true in the app.config, so the test was invalid. My numbers now mirror yours.

@slfritchie
Copy link
Contributor Author

The ordering of the runtime based on the env settings, etc. isn't ideal. Sorry!

dtrace([Int0, Int1] ++ Ints ++ [S0, String1] ++ Strings)
end.

enabled() ->
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

enabled/0 looks very similar to dtrace/1. Is there any chance the redundancies could be merged for maintainability?

@ghost ghost assigned beerriot Jun 8, 2012
@beerriot
Copy link
Contributor

beerriot commented Jun 8, 2012

Other than maybe DRYing up enabled/0, I am +1 on this PR. Great work, Scott & Ryan!

@slfritchie
Copy link
Contributor Author

Bryan, did you want to re-examine commit e70bc2c? It looks like my fear of extra overhead isn't justified, looking at the rebar eunit skip_deps=true suite=riak_core_dtrace timing report before & after that commit.

@beerriot
Copy link
Contributor

beerriot commented Jun 8, 2012

I see no appreciable change in the timings before an after e70bc2cbut enabled/0 is returning ok instead of true, which means that put_tag/1' doesn't work.s/ok;/true;/' and it's all set.

@slfritchie slfritchie merged commit c33a48e into master Jun 10, 2012
@ghost ghost assigned slfritchie Jun 10, 2012
@seancribbs seancribbs deleted the slf-dtrace-take1 branch April 1, 2015 22:59
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants