Debugger une image native GraalVM avec GDB
Dans un précédent article, j’avais évoqué comment profiler une image native GraalVM avec perf. Si vous ne connaissez pas l’outil GraalVM et les limitations qu’il apporte, je vous conseille de relire mon article, ou tout du moins son début.
Comme vu dans mon article précédent, une image native va contenir une JVM minimaliste, appelée SubstrateVM, qui ne supporte pas JVM-TI, et ne permet donc pas l’utilisation de debugger Java. Pour débugger une image native, il faut donc un debugger système (OS-level), je vous propose ici d’utiliser GDB – The GNU Project Debugger qui fonctionne sur la plupart des distributions Linux ainsi que MacOS.
Tout d’abord, nous allons créer un projet Hello World Quarkus avec la commande Maven suivante :
mvn io.quarkus:quarkus-maven-plugin:1.13.4.Final:create \ -DprojectGroupId=fr.loicmathieu.quarkus.debug \ -DprojectArtifactId=helloworld-debug \ -DclassName="fr.loicmathieu.quarkus.debug.GreetingResource" \ -Dpath="/hello"
Puis, nous allons modifier la classe GreetingResource
pour qu’elle prenne en paramètre le nom de la personne à qui dire Hello :
@Path("/hello") public class GreetingResource { @GET @Produces(MediaType.TEXT_PLAIN) public String hello(@QueryParam("name") String name) { return "Hello " + (name == null ? "World" : name); } }
Vous pouvez alors lancer l’application via mvn quarkus:dev
, et la tester via curl localhost:8080/hello/myself
.
Nous allons maintenant packager l’application en une image native, en incluant les symboles de debug pour que notre debugger puisse les trouver. Pour cela il faut utiliser la commande suivant : mvn package -Pnative -Dquarkus.native.debug.enabled=true -DskipTests
.
-Pnative
: indique à Maven d’utiliser le profilnative
qui indique au plugin Maven Quarkus de générer une image native de votre application. Le plugin Quarkus s’occupera de tout pour vous (et entre autre de générer la très longue ligne de commande de l’outil native-image).quarkus.native.debug.enabled=true
: option de configuration qui active les fonctionnalités de debug des applications natives. Permet d’inclure les symboles de debug dans l’image native. Pour plus d’informations sur les symboles de debug avec l’outils native image : DebugInfo-DskipTests
: on ne lance pas les tests car comme on a modifié le code de la ressource mais pas les tests, ils ne marcheront pas
Si tout se passe bien, au bout d’une minute et quelques, vous aurez votre image native dans le répertoire target
. Mais avant de le lancer en mode debug, il nous faut copier les sources de nos librairies pour que GDB puisse y accéder (les sources de votre code sont déjà disponibles pour GDB).
Pour cela on peut utiliser la commande Maven suivante : mvn dependency:sources
.
Si tout s’est bien passé, vous aurez dans le répertoire target
les répertoires et fichiers suivants :
helloworld-debug-1.0.0-SNAPSHOT-runner
: l’image native de votre applicationhelloworld-debug-1.0.0-SNAPSHOT-runner.debug
: les symboles de debugsources
: le répertoire de source de l’application et des librairies tierces
Sur Linux ou MacOS, si vous n’avez pas le fichier helloworld-debug-1.0.0-SNAPSHOT-runner.debug
, c’est parce qu’il vous manque le package binutils. Les symboles de debug seront alors intégrés à l’image native.
Sur les distributions classiques Linux, vous pouvez facilement installer GDB depuis les repos de votre distribution. Sous Ubuntu, c’est aussi simple qu’un sudo apt-get install gdb
.
Pour lancer votre application en mode debug, positionnez-vous dans le répertoire target
puis exécutez gdb helloworld-debug-1.0.0-SNAPSHOT-runner
. GDB va automatiquement détecter les symboles de votre application ainsi que les sources, car nous utilisons les fichiers et répertoires par défaut.
A ce stade, votre application n’est pas encore lancée. Avant de la lancer, nous allons mettre un point d’arrêt (breakpoint) en entrée de la méthode de notre ressource, pour pouvoir la debugger via break GreetingResource.java:1
. Cela va mettre un breakpoint à la première ligne d’instruction de votre classe.
Puis nous pouvons lancer l’application via run&
, le &
permet de rendre la main au shell de GDB (tapez sur entrée si vous ne voyez pas l’invite du shell de GDB).
A ce stade, l’application est lancée, nous pouvons l’utiliser. Vous pouvez appeler votre endpoint via votre navigateur, ou un curl dans un shell externe. GDB permet même d’appeler une commande shell directement depuis son propre shell via shell curl localhost:8080/hello?name=me &
.
Vous devez normalement avoir dans le shell de GDB un message comme quoi le point d’arrêt a été atteint :
Thread 31 "ecutor-thread-2" hit Breakpoint 1, fr.loicmathieu.quarkus.debug.GreetingResource.hello(java.lang.String)(void) () at fr/loicmathieu/quarkus/debug/GreetingResource.java:15 15 return "Hello " + (name == null ? "World" : name);
Maintenant, on va lancer quelques commandes pour debugger notre application.
Pour voir la valeur d’une variable on va utiliser print
.
(gdb) print name $6 = '\000'
Hélas, les chaînes de caractères sont vues comme des tableaux de char, et GDB nous en affiche le premier élément. Ce n’est pas très utile ici.
Pour voir ce que sont en train de faire les threads de l’application, tapez info threads
. Vous aurez alors une sortie comme suit.
Id Target Id Frame 1 Thread 0x7ffff7d6f2c0 (LWP 154724) "helloworld-debu" futex_wait_cancelable (private=, expected=0, futex_word=0x2223dfc) at ../sysdeps/nptl/futex-internal.h:183 2 Thread 0x7ffff6bff640 (LWP 154729) "gnal Dispatcher" futex_abstimed_wait_cancelable (private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x221c060 ) at ../sysdeps/nptl/futex-internal.h:320 4 Thread 0x7ffff55ff640 (LWP 154731) "ecutor-thread-1" futex_abstimed_wait_cancelable (private=, abstime=0x7ffff55fec78, clockid=-178263168, expected=0, futex_word=0x7fffe8000dac) at ../sysdeps/nptl/futex-internal.h:320 5 Thread 0x7ffff4bff640 (LWP 154732) "-thread-checker" futex_abstimed_wait_cancelable (private=, abstime=0x7ffff4bfebe8, clockid=-188749072, expected=0, futex_word=0x7fffec000da8) at ../sysdeps/nptl/futex-internal.h:320 6 Thread 0x7fffe7fff640 (LWP 154733) "ntloop-thread-0" 0x00007ffff7e8956e in epoll_wait (epfd=9, events=0x2227f90, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 7 Thread 0x7fffe75ff640 (LWP 154734) "ntloop-thread-1" 0x00007ffff7e8956e in epoll_wait (epfd=12, events=0x222afa0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 8 Thread 0x7fffe6dfe640 (LWP 154735) "ntloop-thread-2" 0x00007ffff7e8956e in epoll_wait (epfd=15, events=0x222dfb0, maxevents=1024, timeout=1800000) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 9 Thread 0x7fffe61ff640 (LWP 154736) "ntloop-thread-3" 0x00007ffff7e8956e in epoll_wait (epfd=18, events=0x2230fc0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 10 Thread 0x7fffe57ff640 (LWP 154737) "ntloop-thread-4" 0x00007ffff7e8956e in epoll_wait (epfd=21, events=0x2233fd0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30 [...]
La commande backtrace
vous permet de récupérer la stack d’appel du point d’arrêt :
#0 fr.loicmathieu.quarkus.debug.GreetingResource.hello(java.lang.String)(void) () at fr/loicmathieu/quarkus/debug/GreetingResource.java:15 #1 0x00000000004e1300 in com.oracle.svm.reflect.GreetingResource_hello_ff2c07ee54b83f7b7e9993013704c94177591f6c_119.invoke(java.lang.Object, java.lang.Object[])(void) () at com/oracle/svm/core/graal/snippets/TypeSnippets.java:75 #2 0x0000000000f04dd7 in org.jboss.resteasy.core.MethodInjectorImpl.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object, java.lang.Object[])(void) () at java/lang/reflect/Method.java:566 #3 0x0000000000f048fa in org.jboss.resteasy.core.MethodInjectorImpl.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/MethodInjectorImpl.java:130 #4 0x0000000000f11cdd in org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:660 #5 0x0000000000f129e3 in org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:524 #6 0x0000000000f103b8 in org.jboss.resteasy.core.ResourceMethodInvoker..Lambda.1337/1751592192.get(void) () #7 0x0000000000f2c557 in org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(void) () at org/jboss/resteasy/core/interception/jaxrs/PreMatchContainerRequestContext.java:364 #8 0x0000000000f126d0 in org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:476 #9 0x0000000000f123a9 in org.jboss.resteasy.core.ResourceMethodInvoker.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:433 #10 0x0000000000f121a5 in org.jboss.resteasy.core.ResourceMethodInvoker.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:402 #11 0x0000000000f2381c in org.jboss.resteasy.core.SynchronousDispatcher.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, org.jboss.resteasy.spi.ResourceInvoker)(void) () at org/jboss/resteasy/core/ResourceMethodInvoker.java:69 #12 0x0000000000f23d90 in org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse)(void) () at org/jboss/resteasy/core/SynchronousDispatcher.java:261 [...]
Vous pouvez ensuite utiliser la commande step
pour aller à l’instruction suivante, et continue&
pour aller au point d’arrêt suivant.
Quand votre session de debug est finie, vous pouvez quitter GDB avec quit
.
Si on reprend l’intégralité des commandes lancée, ça donne ça :
(gdb) break GreetingResource.java:1 Breakpoint 1 at 0x5158d0: file fr/loicmathieu/quarkus/debug/GreetingResource.java, line 15. (gdb) run& Starting program: /data/dev/helloworld-debug/target/helloworld-debug-1.0.0-SNAPSHOT-runner (gdb) [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". [New Thread 0x7ffff6bff640 (LWP 154729)] [New Thread 0x7ffff61ff640 (LWP 154730)] [Thread 0x7ffff61ff640 (LWP 154730) exited] [...] __ ____ __ _____ ___ __ ____ ______ --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \ --\___\_\____/_/ |_/_/|_/_/|_|\____/___/ 2021-05-27 12:45:05,992 INFO [io.quarkus] (main) helloworld-debug 1.0.0-SNAPSHOT native (powered by Quarkus 1.13.4.Final) started in 0.064s. Listening on: http://0.0.0.0:8080 2021-05-27 12:45:05,999 INFO [io.quarkus] (main) Profile prod activated. 2021-05-27 12:45:05,999 INFO [io.quarkus] (main) Installed features: [cdi, resteasy] (gdb) shell curl localhost:8080/hello?name=me & (gdb) Thread 31 "ecutor-thread-2" hit Breakpoint 1, fr.loicmathieu.quarkus.debug.GreetingResource.hello(java.lang.String)(void) () at fr/loicmathieu/quarkus/debug/GreetingResource.java:15 15 return "Hello " + (name == null ? "World" : name); (gdb) print name $6 = '\000' (gdb) info threads Id Target Id Frame 1 Thread 0x7ffff7d6f2c0 (LWP 154724) "helloworld-debu" futex_wait_cancelable (private=, expected=0, futex_word=0x2223dfc) at ../sysdeps/nptl/futex-internal.h:183 2 Thread 0x7ffff6bff640 (LWP 154729) "gnal Dispatcher" futex_abstimed_wait_cancelable (private=0, abstime=0x0, clockid=0, expected=0, futex_word=0x221c060 ) at ../sysdeps/nptl/futex-internal.h:320 4 Thread 0x7ffff55ff640 (LWP 154731) "ecutor-thread-1" futex_abstimed_wait_cancelable (private=, abstime=0x7ffff55fec78, clockid=-178263168, expected=0, futex_word=0x7fffe8000dac) at ../sysdeps/nptl/futex-internal.h:320 [...] (gdb) backtrace #0 fr.loicmathieu.quarkus.debug.GreetingResource.hello(java.lang.String)(void) () at fr/loicmathieu/quarkus/debug/GreetingResource.java:15 #1 0x00000000004e1300 in com.oracle.svm.reflect.GreetingResource_hello_ff2c07ee54b83f7b7e9993013704c94177591f6c_119.invoke(java.lang.Object, java.lang.Object[])(void) () at com/oracle/svm/core/graal/snippets/TypeSnippets.java:75 #2 0x0000000000f04dd7 in org.jboss.resteasy.core.MethodInjectorImpl.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object, java.lang.Object[])(void) () at java/lang/reflect/Method.java:566 #3 0x0000000000f048fa in org.jboss.resteasy.core.MethodInjectorImpl.invoke(org.jboss.resteasy.spi.HttpRequest, org.jboss.resteasy.spi.HttpResponse, java.lang.Object)(void) () at org/jboss/resteasy/core/MethodInjectorImpl.java:130 [...] (gdb) step [Thread 0x7ffff55ff640 (LWP 154731) exited] [New Thread 0x7ffff61ff640 (LWP 154825)] [Switching to Thread 0x7ffff61ff640 (LWP 154825)] Thread 32 "ecutor-thread-3" hit Breakpoint 1, fr.loicmathieu.quarkus.debug.GreetingResource.hello(java.lang.String)(void) () at fr/loicmathieu/quarkus/debug/GreetingResource.java:15 15 return "Hello " + (name == null ? "World" : name); (gdb) step Hello mejava.lang.String.valueOf(java.lang.Object)(void) () at java/lang/String.java:2951 2951 return (obj == null) ? "null" : obj.toString(); (gdb) continue& Continuing. (gdb) Hello me (gdb) quit
Pour conclure, même si debugger en ligne de commande n’est pas forcément très pratique, GDB nous permet d’avoir une vue sur l’exécution interne de notre application quand elle est packagée comme une image native relativement facilement. C’est un outil intéressant à avoir dans sa boîte à outils.