Slide 1
Slide 1 text
Unleash the Power of Open
Source Java Profilers
Johannes Bechberger
The best
JDKTM
Krzysztof Ślusarski
Slide 2
Slide 2 text
No content
Slide 3
Slide 3 text
Client
Admin
Server
Question?
Set Question
JSON
Slide 4
Slide 4 text
Premature Optimization
We should forget about small efficiencies,
say about 97% of the time: premature
optimization is the root of all evil.
Yet we should not pass up our
opportunities in that critical 3%. A good
programmer will not be lulled into
complacency by such reasoning, he will be
wise to look carefully at the critical code;
but only after that code has been
identified.
— Donald Knuth
“
Source: Jacob Appelbaum, Wikipedia
Slide 5
Slide 5 text
So the event came...
... and the server was overwhelmed
Slide 6
Slide 6 text
Premature Optimization
We should forget about small efficiencies,
say about 97% of the time: premature
optimization is the root of all evil.
Yet we should not pass up our
opportunities in that critical 3%.
A good programmer will not be lulled into
complacency by such reasoning, he will be
wise to look carefully at the critical code;
but only after that code has been
identified.
— Donald Knuth
“
Source: Jacob Appelbaum, Wikipedia
Slide 7
Slide 7 text
Profilers to the rescue
Slide 8
Slide 8 text
No content
Slide 9
Slide 9 text
Source: ARD Degeto/WistingSesong/Viaplay
Slide 10
Slide 10 text
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
fun main() {
...
serverLoop()
}
fun serverLoop() {
while (true) {
req = ...
if (req.isQuestionRequest)
handleQuestionRequest(req)
...
}
}
fun handleQuestionRequest(req) {
if (isQuestionEnabled()) {
emit(currentQuestion().json)
} else {
emit({})
}
}
parseJSON parseJSON
Slide 11
Slide 11 text
No content
Slide 12
Slide 12 text
main
serverLoop
handleQuestionRequest
fun main() {
...
serverLoop()
}
fun serverLoop() {
while (true) {
req = ...
if (req.isQuestionRequest)
handleQuestionRequest(req)
...
}
}
fun handleQuestionRequest(req) {
if (isQuestionEnabled()) {
emit(currentQuestion().json)
} else {
emit({})
}
}
Slide 13
Slide 13 text
Debugging
Testing
Profiling
Toolbox
Slide 14
Slide 14 text
No content
Slide 15
Slide 15 text
No content
Slide 16
Slide 16 text
Who of you used a
profiler?
Slide 17
Slide 17 text
yes
no
JetBrains 2022 survey
Slide 18
Slide 18 text
No content
Slide 19
Slide 19 text
What is profiling?
A report on the amounts of time spent in
each routine of a program, used to find
and tune away the hot spots in it.
— The Jargon File
“
Slide 20
Slide 20 text
Different Profilers
Slide 21
Slide 21 text
Instrumenting Profilers Inserting instructions into the code automatically
fun serverLoop() {
logEntry(“serverLoop”)
while (true) {
req = ...
if (req.isQuestionRequest)
handleQuestionRequest(req)
...
}
logExit(“serverLoop”)
}
Profiled Code
≠
Production Code
long time = time();
println(“serverLoop: “ + (time() – start))
on class load
Slide 22
Slide 22 text
Sampling Profilers
fun serverLoop() {
while (true) {
req = ...
if (req.isQuestionRequest)
handleQuestionRequest(req)
...
}
}
Profiled Code
=
Production Code
Slide 23
Slide 23 text
Profilers aren’t
rocket science
Slide 24
Slide 24 text
So let’s write our own
https://mostlynerdless.de
Slide 25
Slide 25 text
Main
agentmain(args)
premain(args)
Profiler
sample
sleep
Store
start store
Slide 26
Slide 26 text
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 27
Slide 27 text
Turning traces into flamegraphs
parseJSON
currentQuestion
handleQR
serverLoop
main
private static class Node {
final String method;
final Map children;
long samples = 0;
void addTrace(List trace)
}
Slide 28
Slide 28 text
Turning traces into flamegraphs
parseJSON
currentQuestion
handleQR
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
1
1
1
1
1
Slide 29
Slide 29 text
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 30
Slide 30 text
Turning traces into flamegraphs
parseJSON
currentQuestion
handleQR
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
2
2
2
2
2
Slide 31
Slide 31 text
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 32
Slide 32 text
Turning traces into flamegraphs
currentQuestion
handleQR
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
3
3
3
3
2
Slide 33
Slide 33 text
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 34
Slide 34 text
Turning traces into flamegraphs
isQuestionEnabled
handleQR
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
4
4
4
3
2
parseJSON
isQuestionEnabled
parseJSON
1
1
Slide 35
Slide 35 text
Turning traces into flamegraphs
main
serverLoop
handleQR
currentQuestion
parseJSON
4
4
4
3
2
isQuestionEnabled
parseJSON
1
1
main
serverLoop
handleQuestionRequest
currentQuestion isQEnabled
parseJSON
parseJSON
Slide 36
Slide 36 text
With the power of d3-flame-graph
Slide 37
Slide 37 text
Reality
Slide 38
Slide 38 text
Java/JDK
Mission Control
Application Performance
Monitors, ...
Sampling Profiler
External
VisualVM
Netbeans
async-profiler
Sync Async
Forte Analyzer
Built-In
Java/JDK Flight Recorder
2016
1991
ASGCT 2002
2012
2018 Open Source
2010
Slide 39
Slide 39 text
Don’t trust them
Slide 40
Slide 40 text
No content
Slide 41
Slide 41 text
AsyncGetCallTrace
Slide 42
Slide 42 text
Tests in the OpenJDK?
Slide 43
Slide 43 text
1
Slide 44
Slide 44 text
That’s my work
Slide 45
Slide 45 text
Take profiles with a
grain of salt
Slide 46
Slide 46 text
Profiling Loop
Model Hypothesis Evaluation
Slide 47
Slide 47 text
Obtaining a profile
Slide 48
Slide 48 text
Async-Profiler
java \
-agentpath:libasyncProfiler.so=start,\
event=cpu,\
file=flame.html,flamegraph \
arguments
java –jar ap-loader.jar profiler PID ...
Download from GitHub
file=file.jfr,jfr,jfrsync,alloc \
Slide 49
Slide 49 text
Some of its features
• Many events can trigger sampling
• locks
• perf-events like cache-misses
• methods (via instrumentation)
• Embeddable
• via ap-loader
• Hackable
Async-profiler - manual by use cases
by Krzysztof Ślusarski
Slide 50
Slide 50 text
JDK Flight Recorder (JFR)
java \
-XX:+UnlockDiagnosticVMOptions \
-XX:+DebugNonSafepoints \
-XX:+FlightRecorder \
-XX:StartFlightRecording=filename=file.jfr \
arguments
jcmd PID JFR.start
jcmd PID JFR.dump filename=file.jfr
jcmd PID JFR.stop
Already included in your JDK 8+
Slide 51
Slide 51 text
https://sapmachine.io/jfrevents
Slide 52
Slide 52 text
Fibonacci Server
maas.com/fib/{n}
Slide 53
Slide 53 text
Custom JFR Events
class SessionEvent extends jdk.jfr.Event {
int sessionId;
int n;
....
}
var event = new SessionEvent(sessionId, n);
event.begin();
ctx.result("fibonacci: " + fib(n));
event.commit();
Slide 54
Slide 54 text
No content
Slide 55
Slide 55 text
No content
Slide 56
Slide 56 text
Inspecting a profile
Slide 57
Slide 57 text
JDK Mission Control
Slide 58
Slide 58 text
No content
Slide 59
Slide 59 text
No content
Slide 60
Slide 60 text
No content
Slide 61
Slide 61 text
No content
Slide 62
Slide 62 text
JFR Plugin for IntelliJ Still a prototype
Slide 63
Slide 63 text
No content
Slide 64
Slide 64 text
No content
Slide 65
Slide 65 text
No content
Slide 66
Slide 66 text
No content
Slide 67
Slide 67 text
No content
Slide 68
Slide 68 text
Impact on performance
in some benchmark, 48s, 8 cores, 4% standard deviation
Overhead
JFR (reduced setting) 0 - 5%, typically < 2%
JFR (profiling setting) 1 - 8%, typically < 5%
async-profiler 3 - 6%, typically < 2%
async-profiler with jfrsync 3 - 10%
Slide 69
Slide 69 text
Continuous Profiling
Slide 70
Slide 70 text
asprof -e wall \
--loop 1m -f profile-%t.jfr
Slide 71
Slide 71 text
Pyroscope
Slide 72
Slide 72 text
No content
Slide 73
Slide 73 text
No content
Slide 74
Slide 74 text
Parca
Slide 75
Slide 75 text
No content
Slide 76
Slide 76 text
... and many more
Slide 77
Slide 77 text
Debugging
Testing
Profiling
Toolbox
Slide 78
Slide 78 text
@parttimen3rd on Twitter
parttimenerd on GitHub
mostlynerdless.de
@SweetSapMachine
sapmachine.io