Slide 1

Slide 1 text

Hitchhiker’s Guide to Java Mission Control Alexey Ragozin alexey.ragozin@gmail.com

Slide 2

Slide 2 text

Profilers are Different Instrumentation built into JVM Java Visual VM JVMTI Instrumentation JMX

Slide 3

Slide 3 text

Java Mission Control • Session Profiling – classic • JVM Startup Profiling • Continuous Profiling

Slide 4

Slide 4 text

Java Mission Control

Slide 5

Slide 5 text

Java Mission Control Do not Panic!

Slide 6

Slide 6 text

Java Mission Control Most useful views  Method Profiling  Allocation Profiling  Contention & Monitors Information  Thread Execution Timeline  Exception Log  GC Events  JVM Configuration Details  IO Events

Slide 7

Slide 7 text

Method Profiling

Slide 8

Slide 8 text

Allocation Profiling

Slide 9

Slide 9 text

Contention & Monitors

Slide 10

Slide 10 text

Contention & Monitors

Slide 11

Slide 11 text

Thread & GC Timeline

Slide 12

Slide 12 text

Exception Log

Slide 13

Slide 13 text

Garbage Collection Log

Slide 14

Slide 14 text

Garbage Collection Log

Slide 15

Slide 15 text

JVM Configuration Details

Slide 16

Slide 16 text

JVM Configuration Details

Slide 17

Slide 17 text

IO Events

Slide 18

Slide 18 text

Profiling Session Configuration  Garbage Collector  Complier  Method Sampling  Thread Dump  Exceptions  Synchronization Threshold  File I/O Threshold  Socket I/O Threshold  Heap Statistics  Class Loading  Allocation Profiling Enforces Safepoints May be slow if there are many exceptions Set low threshold for profiling Enforces Full GC

Slide 19

Slide 19 text

Startup Profiling Prepare & Export configuration

Slide 20

Slide 20 text

Startup Profiling Start JVM with options -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording= delay=1s,duration=60s,name=MyRecording, filename=myrecording.jfr, settings=C:\PathTo\MyProfiling.jfc

Slide 21

Slide 21 text

Method Sampling Tracing  Instrument and record every interesting change in observed system Sampling  Capture periodic snapshots of observed system Task.run() wait() process() getBody() read() parse() handle() load() read() Time encode() wait() process() getBody() read() parse() handle() load() read() encode() wait() process() getBody() read() parse() handle() encode()

Slide 22

Slide 22 text

Method Sampling Task.run() wait() process() getBody() read() parse() handle() load() read() Time encode() wait() process() getBody() read() parse() handle() load() read() encode() wait() process() getBody() read() parse() handle() encode() 10 Task.run 7 3 process() 4 handle() 3 encode() 2 ... 1 ... 1 load() geBody() 2 1 read() parse() 1 ... 3 wait()

Slide 23

Slide 23 text

Flame Graph Task.run() wait() process() getBody() read() parse() handle() load() read() Time encode() wait() process() getBody() read() parse() handle() load() read() encode() wait() process() getBody() read() parse() handle() encode() Task.run() process() wait() getBody() handle() read() parse() load() encode() SJK - https://github.com/aragozin/jvm-tools

Slide 24

Slide 24 text

Method Sampling Traditional Profilers  Dump all threads periodically – Stop The World  JVM can suspend thread on in discrete points of execution Flight Recorder  Threads sampled during execution of Java code  No Safepoints / No Stop The World  No samples is thread is not running!

Slide 25

Slide 25 text

Method Sampling

Slide 26

Slide 26 text

Method Sampling Bias Problem – Frequent JNI calls into InflaterInputStream Java Flight Recorder SJK (JMX sampling) perf * * https://github.com/jvm-profiling-tools/perf-map-agent Total samples 5653 100.00% ZIP 2659 47.04% Other 2994 52.96% Total samples 2905 100.00% ZIP 2870 98.80% Other 35 1.20% Total samples 59896 100.00% ZIP 54771 91.44% Other 5125 8.56%

Slide 27

Slide 27 text

Method Sampling Bias Problem – Frequent JNI calls into InflaterInputStream Fix - 92% (565ms -> 45ms) Java Flight Recorder SJK (JMX sampling) perf * * https://github.com/jvm-profiling-tools/perf-map-agent Total samples 5653 100.00% ZIP 2659 47.04% Other 2994 52.96% Total samples 2905 100.00% ZIP 2870 98.80% Other 35 1.20% Total samples 59896 100.00% ZIP 54771 91.44% Other 5125 8.56%

Slide 28

Slide 28 text

Method Sampling Bias Sampling via JMX Flight Recorder Sampling Unsafe.park()

Slide 29

Slide 29 text

Method Sampling Bias Sampling via JMX Filter out Unsafe.park() Flight Recorder Sampling

Slide 30

Slide 30 text

Method Sampling Bias Flight Recorder Sampling Flight Recorder Sampling -XX:+UnlockDiagnosticVMOptions - XX:+DebugNonSafepoints

Slide 31

Slide 31 text

Execution Time Optimization  Prove what you spend time in code not in wait  Double check with Visual VM or other profiler  Use contention, events and thread timeline views  Set thresholds to 0

Slide 32

Slide 32 text

Allocation Sampling Instrumentation – Normal Profilers  Instrument every new instruction  Expensive!  Interfere JVM optimizations Flight Recorder  Fast path – Object allocated from TLAB  Slow path – new TLAB have to be allocated  Sample on slow path (every few hundreds of kB)  Non uniform sampling (TLAB size is dynamic) Sampled

Slide 33

Slide 33 text

Summary Method sampling Method tracing  Generic  IO Allocation sampling Heap dump inspection Startup profiling Continuous profiling Flight Recorder Only Java code Low overhead No Built-in events Low overhead No Yes May require license Classic Java Profiler On Safepoints High overhead Yes - High overhead Yes ? ?

Slide 34

Slide 34 text

KEEP CALM AND MAKE YOUR JAVA FAST AGAIN Alexey Ragozin alexey.ragozin@gmail.com http://blog.ragozin.info