jepsen-io / knossos

Verifies the linearizability of experimentally accessible histories.
398 stars 31 forks source link

Add Tufte profiling instrumentation #9

Closed johanatan closed 7 years ago

johanatan commented 7 years ago

Adds Tufte profiling instrumentation on linearizability analysis.

aphyr commented 7 years ago

Hey! I strongly recommend using JMC for profiling knossos instead of a wrapper like Tufte, or even bytecode instrumentation like Yourkit. Knossos does a lot of its work with primitives, is v sensitive to inlining, and profilers that can't see past safepoints will give misleading results. --Kyle

aphyr commented 7 years ago

Sooo... I think it's great that you're working on profiling, and you're welcome to do this in a branch! I'm happy to see performance improvements! But I thiiink I'm gonna close this unless we can demonstrate concrete benefits over JMC. Thoughts?

johanatan commented 7 years ago

Does JMC play well with Clojure stack traces/method names/lambdas etc?

The one advantage I can see to this approach is that it lets you pick very specific targets of interest (instead of having to navigate/parse huge stack traces etc) and the summary it prints is quite nice (showing total number of calls, percent of time spent and elapsed time spent in each trace point). And I think in my testing that safe points were not a factor (as GC doesn't happen within the 200ms or so that the analysis phase takes to run and we have plenty of memory [128 GB]). :)

If JMC is as great as you are saying it is, then yea, I would agree that there is little utility to this patch.

johanatan commented 7 years ago

[comment updated]

aphyr commented 7 years ago

Yep! I used JMC extensively for optimizing Knossos--remember safepoints aren't just for GC, but are inserted at various points--typically method boundaries. Profiling Knossos with Yourkit worked for a while, but didn't provide much benefit after the first few passes--dramatically undersamples hot inlined methods. You'll also find my code generally names inline fns to make profiling easier. Finally, you generally want to see Clojure fn overhead (instead of hiding it) because function calls can involve surprisingly expensive hidden calls at the fn boundary, particularly around varargs and array seqs.

johanatan commented 7 years ago

So there seems to be a disconnect here re: the operation of Tufte. Tufte is not a sampling profiler. Tufte merely calls getSystemTimeNano before and after executing the form it wraps and subtracts the difference. Thus, it will in fact account for any "expensive hidden Clojure calls" and it will not matter if there is either inlining or safepointing inside, outside, or at the wrapper/instrument insertion points (as long as said safepointing is cheap [and if it isn't doing GC, it should be]).

And I was asking if JMC can pretty-print Clojure function names (including lambdas) in a easily human-intelligible fashion (not whether it would account for "hidden calls" or not).

aphyr commented 7 years ago

I understand how Tufte works; my comments above may prove useful as you proceed. You're welcome to use Tufte if you think it's useful, and I'll gladly accept perf patches with demonstrable improvement. Try stress-test for a representative benchmark.