Slide 1
Slide 1 text
Public
Write your own Java Profiler
in 240 lines of pure Java
Johannes Bechberger
The best
JDKTM
Slide 2
Slide 2 text
Public
Slide 3
Slide 3 text
Public
Client
Admin
Server
Question?
Set Question
JSON
Slide 4
Slide 4 text
Public
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
Public
So the event came...
... and the server was overwhelmed
Slide 6
Slide 6 text
Public
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
Public
Profilers to the rescue
Slide 8
Slide 8 text
Public
Slide 9
Slide 9 text
Public Source: Photoshot/Getty Images
Slide 10
Slide 10 text
Public
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
Public
Slide 12
Slide 12 text
Public
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
Public
Debugging
Testing
Profiling
Toolbox
Slide 14
Slide 14 text
Public
Slide 15
Slide 15 text
Public
Slide 16
Slide 16 text
Public
Who of you used a
profiler?
Slide 17
Slide 17 text
Public
yes
no
JetBrains 2022 survey
Slide 18
Slide 18 text
Public
Slide 19
Slide 19 text
Public
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
Public
Different Profilers
Slide 21
Slide 21 text
Public
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
Public
Sampling Profilers
fun serverLoop() {
while (true) {
req = ...
if (req.isQuestionRequest)
handleQuestionRequest(req)
...
}
}
Profiled Code
=
Production Code
Slide 23
Slide 23 text
Public
Profilers aren’t
rocket science
Slide 24
Slide 24 text
Public
So let’s write our own
https://mostlynerdless.de
Slide 25
Slide 25 text
Public
Main
agentmain(args)
premain(args)
Profiler
sample
sleep
Store
start store
Slide 26
Slide 26 text
Public
Main
agentmain(args)
premain(args)
Slide 27
Slide 27 text
Public
Main Class
java -javaagent:./target/tiny_profiler.jar=agentArgs ...
Slide 28
Slide 28 text
Public
Main Class
java -javaagent:./target/tiny_profiler.jar=agentArgs ...
public static void agentmain(String agentArgs) {
premain(agentArgs);
}
JVM start later
attach
attach
public static void premain(String agentArgs) {
Main main = new Main();
main.run(new Options(agentArgs));
}
Slide 29
Slide 29 text
Public
Main class
private void run(Options options) {
Thread t = new Thread(
Profiler.newInstance(options));
t.setDaemon(true);
t.setName("Profiler");
t.start();
}
public class Options {
Duration interval;
Optional flamePath;
boolean printMethodTable;
}
Slide 30
Slide 30 text
Public
Profiler
sample
sleep
Slide 31
Slide 31 text
Public
Profiler
public static Profiler newInstance(Options options) {
Profiler profiler = new Profiler(options);
Runtime.getRuntime()
.addShutdownHook(
new Thread(profiler::onEnd));
return profiler;
}
Slide 32
Slide 32 text
Public
Profiler
private void sample() {
Thread.getAllStackTraces()
.forEach(
(thread, st) -> {
if (thread.isDaemon()) {
return;
}
store.addSample(st);
}
});
}
Slide 33
Slide 33 text
Public
StackTraceElement
class StackTraceElement {
Class> declaringClassObject;
String classLoaderName;
String moduleName;
String moduleVersion;
String declaringClass;
String methodName;
String fileName;
int lineNumber;
}
Slide 34
Slide 34 text
Public
Store
Slide 35
Slide 35 text
Public
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 36
Slide 36 text
Public
Turning traces into flamegraphs
parseJSON
currentQuestion
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
1
1
1
1
1
handleQuestionRequest
Slide 37
Slide 37 text
Public
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 38
Slide 38 text
Public
Turning traces into flamegraphs
parseJSON
currentQuestion
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
2
2
2
2
2
handleQuestionRequest
Slide 39
Slide 39 text
Public
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 40
Slide 40 text
Public
Turning traces into flamegraphs
currentQuestion
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
3
3
3
3
2
handleQuestionRequest
Slide 41
Slide 41 text
Public
Flamegraphs would be great
main
serverLoop
handleQuestionRequest
currentQuestion isQuestionEnabled
parseJSON parseJSON
Slide 42
Slide 42 text
Public
Turning traces into flamegraphs
isQuestionEnabled
serverLoop
main main
serverLoop
handleQR
currentQuestion
parseJSON
4
4
4
3
2
parseJSON
isQuestionEnabled
parseJSON
1
1
handleQuestionRequest
Slide 43
Slide 43 text
Public
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 44
Slide 44 text
Public
With the power of d3-flame-graph
Slide 45
Slide 45 text
Public
Write your own Java Profiler
in 240 lines of pure Java
Johannes Bechberger
The best
JDKTM
251
Slide 46
Slide 46 text
Public
Demo
Slide 47
Slide 47 text
Public
Reality
Slide 48
Slide 48 text
Public
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 49
Slide 49 text
Public
Take profiles with a
grain of salt
Slide 50
Slide 50 text
Public
Obtaining a profile
Slide 51
Slide 51 text
Public
Async-Profiler
java \
-agentpath:libasyncProfiler.so=start,\
event=cpu,\
file=flame.html,flamegraph \
arguments
Download from GitHub
file=file.jfr,jfr,jfrsync,alloc \
Slide 52
Slide 52 text
Public
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 53
Slide 53 text
Public
https://sapmachine.io/jfrevents
Slide 54
Slide 54 text
Public
https://sapmachine.io/jfrevents
Slide 55
Slide 55 text
Public
Fibonacci Server
maas.com/fib/{n}
Slide 56
Slide 56 text
Public
Custom JFR Events
class SessionEvent extends jdk.jfr.Event {
int sessionId;
int n;
// ... // constructor
}
var event = new SessionEvent(sessionId, n);
event.begin();
ctx.result("fibonacci: " + fib(n));
event.commit();
Slide 57
Slide 57 text
Public
Slide 58
Slide 58 text
Public
Inspecting a profile
Slide 59
Slide 59 text
Public
JDK Mission Control
Slide 60
Slide 60 text
Public
Slide 61
Slide 61 text
Public
Slide 62
Slide 62 text
Public
Slide 63
Slide 63 text
Public
Slide 64
Slide 64 text
Public
JFR Plugin for IntelliJ Still a prototype
Slide 65
Slide 65 text
Public
Slide 66
Slide 66 text
Public
Slide 67
Slide 67 text
Public
Slide 68
Slide 68 text
Public
Slide 69
Slide 69 text
Public
Slide 70
Slide 70 text
Public
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 71
Slide 71 text
Public
Continuous Profiling
Slide 72
Slide 72 text
Public
asprof -e wall \
--loop 1m -f profile-%t.jfr
Slide 73
Slide 73 text
Public
Pyroscope
Slide 74
Slide 74 text
Public
Slide 75
Slide 75 text
Public
... and many more
Slide 76
Slide 76 text
Public
Debugging
Testing
Profiling
Toolbox
Slide 77
Slide 77 text
Public
@parttimen3rd on Twitter
parttimenerd on GitHub
mostlynerdless.de
@SweetSapMachine
sapmachine.io