Write your own Java Profiler in 240 lines of pure Java

Profilers help to analyze performance bottlenecks of your application if you know how to use them. Getting to grips with profilers helps to understand how they work: Profilers aren't rocket science. A usable Java profiler can be written in 240 lines of pure Java code, allowing you to fix performance issues and add custom features quickly.

This talk will give the fundamentals of Java profiling and how Java profilers typically work, followed by a detailed explanation of how to develop a functioning profiler in a few lines of Java code. This talk will also explain how you can use it in production to analyze performance issues and show briefly how to work with a widely used open-source profiler based on the same principles.

Recording from Devoxx Belgium 2023: https://www.youtube.com/watch?v=Mxcp2khJ4fw

Transcript

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