Profiler la JVM avec async-profiler
La plupart des profilers Java historiques (VisualVM, les vieux modes par échantillonnage de JProfiler, le sampler CPU intégré à la JVM) ne capturent les stacks qu’aux safepoints. Le souci, c’est que les threads ne sont pas répartis uniformément dans le code au moment où ils atteignent un safepoint. Certaines méthodes en contiennent beaucoup, d’autres aucune. Le profil obtenu est donc biaisé, et on finit parfois par optimiser du code qui n’est pas le vrai coupable. C’est ce qu’on appelle le safepoint bias.
async-profiler ne souffre pas de ce problème. Il s’appuie sur les perf_events du noyau (ou sur un timer interne) pour interrompre les threads à n’importe quel endroit, puis récupère la stack via AsyncGetCallTrace. Son overhead reste de l’ordre de quelques pour-cent, ce qui le rend utilisable directement en production.
Démarrer en une commande
Depuis la 3.x le binaire s’appelle asprof. Pour profiler le CPU d’un process déjà lancé pendant 30 secondes et en sortir un flamegraph :
asprof -d 30 -f profile.html <pid>
L’événement par défaut est cpu. Le format de sortie est déduit de l’extension du fichier : un .html donne un flamegraph interactif. Pour un premier diagnostic, ça suffit.
Choisir ce qu’on mesure
Le vrai intérêt de l’outil, c’est qu’on couvre plusieurs dimensions avec le même binaire via -e :
asprof -d 30 -e cpu -f cpu.html <pid> # temps CPU
asprof -d 30 -e alloc -f alloc.html <pid> # allocations sur la heap
asprof -d 30 -e lock -f lock.html <pid> # contention sur les locks
asprof -d 30 -e wall -f wall.html <pid> # wall-clock (temps réel)
La distinction qui compte vraiment au quotidien, c’est CPU contre wall-clock. Le mode cpu ne compte que le temps pendant lequel les threads tournent effectivement sur un cœur. Un thread bloqué sur une I/O ou en attente d’un lock, il ne le voit pas. Si votre latence vient d’un appel réseau ou d’une requête SQL lente, le profil CPU sera quasiment vide alors que le problème, lui, est bien là. Dans ce cas il faut regarder wall.
Le mode alloc est précieux pour traquer la pression GC. Il montre où la heap est allouée, et pointe donc directement vers les boucles qui fabriquent trop d’objets temporaires.
Avoir des stacks justes : DebugNonSafepoints
Pour que les frames Java soient attribuées au bon endroit, et pas recalées sur le safepoint le plus proche, lancez la JVM avec :
-XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints
Sans ça, le code inliné par le JIT peut être mal localisé. Ces deux flags n’ont pas de coût mesurable sur les perfs, autant les activer par défaut sur tout environnement que vous comptez profiler.
Permissions et conteneurs
perf_events demande un accès au noyau. En général il faut :
sysctl kernel.perf_event_paranoid=1 # autorise le profiling user-space
sysctl kernel.kptr_restrict=0 # symboles du noyau dans les stacks
Dans un conteneur, ces réglages ne sont pas toujours accessibles et perf peut carrément manquer. async-profiler propose alors un moteur qui ne dépend pas de perf :
asprof -d 30 -e ctimer -f profile.html <pid>
ctimer (ou itimer sur les versions plus anciennes) repose sur un timer POSIX et fonctionne sans capability particulière. On perd les frames du noyau, mais pour profiler du code applicatif c’est largement suffisant.
Profiler dès le démarrage
Pour capturer ce qui se passe au boot, ou pour intégrer le profiling dans un run automatisé, on attache l’agent directement :
java -agentpath:/opt/async-profiler/lib/libasyncProfiler.so=start,event=cpu,file=profile.jfr \
-jar app.jar
La sortie au format jfr (JDK Flight Recorder) s’ouvre dans JDK Mission Control et permet de croiser le profil avec les autres événements de la JVM.
Et après ?
Vous avez un profile.html sous les yeux. Un flamegraph se lit vite une fois qu’on connaît les règles du jeu, et c’est justement le sujet de l’article suivant : Comment lire un flamegraph.