Slide 1

Slide 1 text

Does My Profiler Tell The Truth? Fabian Lange - codecentric AG

Slide 2

Slide 2 text

Profilers are Measurement Tools

Slide 3

Slide 3 text

–Grady Booch “A fool with a tool is still a fool”

Slide 4

Slide 4 text

Available Tools AppDynamics Dynatrace JProfiler YourKit VisualVM Mission Control JProbe NetBeans Profiler New Relic Honest Profiler

Slide 5

Slide 5 text

Java Virtual Machine Tool Interface

Slide 6

Slide 6 text

JSR-163 • Java Platform Profiling Architecture • defines following APIs • JVMTI (C API) as successor to JVMPI • java.lang.instrument • ClassFileTransformer • java.lang.management • MemoryMXBean • ThreadMXBean

Slide 7

Slide 7 text

How To Measure? • Native Agent • written in C • Inserted into the JVM using -agentpath • Java Agent • using java.lang.instrument package • loaded using -javaagent • External • Logs, DTrace, JMX

Slide 8

Slide 8 text

No content

Slide 9

Slide 9 text

–Werner Heisenberg, 1927 “One cannot measure Java code without interfering with the JVM.”

Slide 10

Slide 10 text

No content

Slide 11

Slide 11 text

Error Sources

Slide 12

Slide 12 text

Overhead

Slide 13

Slide 13 text

Overhead • Runtime Delay • CPU Consumption • Thread Scheduling • Memory Consumption • Network Saturation • Diskspace Usage

Slide 14

Slide 14 text

Accuracy

Slide 15

Slide 15 text

No content

Slide 16

Slide 16 text

Accuracy • System.currentTimeMillis() !    /**        *  Returns  the  current  time  in  milliseconds.  Note  that  while  the  unit  of  time  of  the  return  value  is  a  millisecond,        *  the  granularity  of  the  value  depends  on  the  underlying  operating  system  and  may  be  larger.  For  example,  many        *  operating  systems  measure  time  in  units  of  tens  of  milliseconds.        *        *  See  the  description  of  the  class  Date  for  a  discussion  of  slight  discrepancies  that  may  arise  between        *  "computer  time"  and  coordinated  universal  time  (UTC).        */   • System.nanoTime() !    /**        *  Returns  the  current  value  of  the  running  Java  Virtual  Machine's  high-­‐resolution  time  source,  in  nanoseconds.        *        *  This  method  can  only  be  used  to  measure  elapsed  time  and  is  not  related  to  any  other  notion  of  system  or  wall-­‐clock        *  time.  The  value  returned  represents  nanoseconds  since  some  fixed  but  arbitrary  origin  time  (perhaps  in  the        *  future,  so  values  may  be  negative).  The  same  origin  is  used  by  all  invocations  of  this  method  in  an  instance  of  a        *  Java  virtual  machine;  other  virtual  machine  instances  are  likely  to  use  a  different  origin.        *        *  This  method  provides  nanosecond  precision,  but  not  necessarily  nanosecond  resolution  (that  is,  how  frequently  the        *  value  changes)  -­‐  no  guarantees  are  made  except  that  the  resolution  is  at  least  as  good  as  that  of        *  {@link  #currentTimeMillis()}.        *        *  The  values  returned  by  this  method  become  meaningful  only  when  the  difference  between  two  such  values,  obtained        *  within  the  same  instance  of  a  Java  virtual  machine,  is  computed.        */

Slide 17

Slide 17 text

Time

Slide 18

Slide 18 text

Time • Wall-Clock Time • “real” Time which has passed since start. • Measurable with a clock on the wall. • CPU Time • Time the CPU was busy. • Measurable but questionable.

Slide 19

Slide 19 text

Lots of Data

Slide 20

Slide 20 text

Data Collection

Slide 21

Slide 21 text

Data Collection • (Stack) Sampling • Checking JVM activity in regular intervals. • Instrumentation • Injection of measurement code. • Sampling II • Reducing data by omission.

Slide 22

Slide 22 text

Sampling t main() foo() bar() baz()

Slide 23

Slide 23 text

Sampling - Great t main() foo() bar() baz()

Slide 24

Slide 24 text

Sampling - Oh Well… t main() foo() bar()

Slide 25

Slide 25 text

No content

Slide 26

Slide 26 text

Instrumentation

Slide 27

Slide 27 text

Instrumentation t main() foo() bar() baz()

Slide 28

Slide 28 text

Sampling
 vs
 Instrumentation DEMO

Slide 29

Slide 29 text

Code on Github https://github.com/CodingFabian/SamplingVsInstrumentation

Slide 30

Slide 30 text

Using JProfiler DEMO

Slide 31

Slide 31 text

Using HProf DEMO

Slide 32

Slide 32 text

Using Honest Profiler DEMO

Slide 33

Slide 33 text

Safepoints

Slide 34

Slide 34 text

Safepoints • Sampling thread has to wait for steady state to interrogate other threads • Safepoints are in-between code, so conceptually sampling never sees running code • Honest Profiler uses JVMTI AsyncGetCallTrace which does not wait for safepoints • github.com/RichardWarburton/honest-profiler • jeremymanson.blogspot.co.uk/2013/07/lightweight-asynchronous- sampling.html

Slide 35

Slide 35 text

From My Daily Work

Slide 36

Slide 36 text

Performance Tuning Guide • Start off with Sampling • Do not take results to serious • Look for bottlenecks • < 10 ms is most of the time irrelevant when profiling • Get better results from benchmarking • Check code, bytecode, assembly

Slide 37

Slide 37 text

How Much Influence has Instrumentation Code? DEMO

Slide 38

Slide 38 text

SEPA DEMO

Slide 39

Slide 39 text

Does My Profiler Tell The Truth? NO

Slide 40

Slide 40 text

Use JMH for Benchmarks

Slide 41

Slide 41 text

Further Reading • Dapper, a Large-Scale Distributed Systems Tracing Infrastructure • static.googleusercontent.com/media/research.google.com/de//pubs/archive/36356.pdf • Evaluating the Accuracy of Java Profilers • www-plan.cs.colorado.edu/klipto/mytkowicz-pldi10.pdf • How to Measure Java Performance • blog.codecentric.de/en/2011/10/measure-java-performance-sampling-or-instrumentation/ • Java Microbenchmark Harness • openjdk.java.net/projects/code-tools/jmh/ • Richard Warbutons Honest Profiler • github.com/RichardWarburton/honest-profiler

Slide 42

Slide 42 text

Want to know more? ! @CodingFabian [email protected] lj speakerdeck.com/CodingFabian github.com/CodingFabian