Bienvenue sur ce blog où je diffuse mes retours d expérience sur des technologies et des méthodologies que j utilise au quotidien. Vous y trouverez des informations sur des outils Java, des modeleurs UML, du MDA et même du Scrum.
Profiling SQL
C’est une étape souvent négligée par les projets utilisant des librairies de mapping objet. Mais faire de l’Hibernate c’est bien, regarder les requêtes générées sur la base c’est mieux.
J’ai le souvenir d’un vieux projet utilisant des EJB Entity 2 où à un moment on ajoutait un objet dans une liste. En regardant les requêtes on s’est aperçu que le conteneur chargeait toute la liste avant de faire l’insert. C’était complètement inutile.
Donc comment étudier correctement les requêtes ? Déjà si vous utilisez hibernate mettez la property « show_sql » à true de temps en temps. Après pour avoir plus d’informations j’utilise p6spy et IronEye SQL.
p6Spy est une librairie qui remplace votre driver de base de données. C’est en quelque sorte un driver proxy de BDD. IronEye apporte juste une vue graphique des informations récoltées par p6spy. Pour trouver de la doc c’est un peu dur www.p6spy.com ne fonctionne plus mais j’ai trouvé un site expliquant la mise en place de p6spy et de IronSql.
Par contre ce sont deux outils un peu « vieux ». p6spy n’a pas été mis à jour depuis 2003 et pour IronEye SQL la société IronGrid a disparu. Comme il est maintenant impossible de trouver IronEye en téléchargement je vous propose la version 1.2.359 que j’avais heureusement conservée : ironeyesql-installer-1_2_359.jar. (fonctionne que sur Windows chez moi). Le site sourceForge de p6spy est toujours up.
Sans refaire la doc, installer p6spy c’est simple, il faut juste remplacer le nom de votre driver jdbc par com.p6spy.engine.spy.P6SpyDriver et de mettre le nom du vrai driver dans le fichier spy.properties : realdriver = oracle.jdbc.driver.OracleDriver. Pour utiliser IronEye il faut en plus activer un port d’écoute dans le spy.properties : module.monitor=com.irongrid.monitor.server.MonitorFactory
monitorport=2000
Et voilà ! vous pouvez observer toutes les requêtes faites sur votre base. IronSQL va les regrouper, les compter et calculer le temps moyen d’exécution.
Sans être DBA vous allez très vite voir quelles requêtes sont faites souvent et les plus longues à s’exécuter. Très pratique pour voir si un cache L2 fonctionne bien ou si on a oublié un index sur une table.
Un exemple concret que j’ai corrigé hier :
Dans un service REST on passe en paramètre l’id d’un objet. C’est un service de monitoring appelé par du matériel pour lui passer des infos et s’assurer qu’il est encore en vie (du polling à défaut de push en gros)
Truc t = trucDao.getById(tid);
t.setLastAccess(now);
Assez logique en java avec hibernate, mais l’objet t n’est jamais utilisé après. Le problème c’est qu’au niveau SQL on a un SELECT qui récupère toutes les informations de l’objet pour ensuite faire un UPDATE. Si en plus vous avez configuré des associations de votre objet en lazzy, ça peut être vraiment problématique.
J’ai changé ce code par :
trucDao.updateDateById(tid, now);
Maintenant il ne reste que la requête UPDATE. Lorsque l’on sait que nous allons avoir plusieurs milliers de « Truc » et qu’ils font cette requète toutes les 15 secondes. Je vous laisse calculer le gain en perf. Dans la même fonction j’ai aussi trouvé une requête SQL faite uniquement pour un log debug : no comment.
Ca fait longtemps que je n’ai pas fait de petit post technique où je decris la solution d’un problème simple. Et bien justement j’ai eu à en résoudre quelques uns ces derniers temps. Je vais donc les partager.
En ce moment je travaille sur un projet qui charge beaucoup d’objets en mémoire. Il faut donc redéfinir la taille de mémoire max à allouer pour le faire tourner. Une simple option « -Xmx512m » au niveau de la JVM et les tests unitaires fonctionnent sans pb. Mais comment faire lorsqu’on lance les tests avec Maven ?
La première solution est de redéfinir une variable d’environnement : MAVEN_OPTS=-Xmx512m
Mais dans ce cas chaque personne reprenant mon projet va devoir redéfinir cette variable. Pour moi ce n’est pas viable. En cherchant encore j’ai trouvé comment définir cela dans le pom :
Malheureusement j’avais un second problème. Je fais des tests avec des comparaisons de chaînes de caractères qui contiennent des accents. Et là encore sous Eclipse pas de problème mais en ligne de commande ça ne fonctionnait pas. En plus j’avais un Warning : [WARNING] Using platform encoding (MacRoman actually) to copy filtered resources, i.e. build is platform dependent!
Pour corriger le Warning j’ai ajouter dans le pom :
ISO-8859-1
Et pour que mes JUnit fonctionnent j’ai encore ajouté deux paramètres :
En lisant l’excellent blog de xebia, j’ai découvert l’interface JVMTI : une API native de profiling. Elle permet non seulement de profiler des applications Java mais aussi de les manipuler directement au niveau du bytecode pendant leur exécution.
Je travaille justement sur une application sur laquelle j’aimerais bien savoir s’il n’y a pas de goulot d’étranglement à cause d’un bloc synchronized. Donc ni une ni deux, je me lance !
Pourquoi JVMTI ?
Après tout il existe pas mal d’outils de profiling Java, à commencer par TPTP intégré dans Eclipse. Le problème avec ces outils c’est qu’ils fonctionnent tous à peu près bien avec une petite application, mais dès que l’on utilise un serveur d’application ou que l’on a un code un peu volumineux… c’est le drame. Au pire l’application ne démarre pas, au mieux les temps de traitement sont multipliés par 1000 et on ne voit plus grand chose. Vu que JVMTI utilise une interface native, je suis persuadé que ce sera beaucoup moins lourd que les autres outils.
JVMTI remplace depuis la JDK5 les librairies JVMPI (Profiling) et JVMDI (Debug). Celles-ci sont passées deprecated sur la JDK5 et sont disparus en JDK6.
Ecrire une DLL
Une librairie native c’est bien, mais ça a un prix : il faut l’écrire en C.
Et c’est à ce moment que je me suis rendu compte que ça fait un bon moment que je n’ai pas écrit du C. La dernière fois ça doit faire 10 ans pour programmer un 68HC11 à l’IUT. Mais bon, ça doit être comme le vélo, ça ne s’oublie pas. Et bien c’est tout à fait cela, refaire du C c’est comme refaire du vélo après une pose de 10 ans : on va moins vite et ça fait mal
La première étape a été d’exécuter l’exemple de sun sans toucher au code. Premier problème : comment construire une DLL ? Et oui venant du monde Java je n’avais jamais eu besoin de générer une DLL. Je commence donc par télécharger « Microsoft Visual C++ 2008 Express Edition », mais impossible de faire fonctionner le code de SUN. Je n’arrive pas à inclure les .h de JVMTI à mon projet et encore moins à générer une DLL. En cherchant un autre outil je suis tombé sur Dev-C++ et j’ai enfin réussi. Il faut créer un projet DLL en C et modifier deux options du projet. Dans l’onglet Fichiers il faut décocher l’option « Compiler en tant que C++ » sur notre fichier C. Et dans l’onglet Répertoire il faut ajouter les deux répertoires $JDK_HOME/include et $JDK_HOME/include/win32. Après on clique sur compiler et hop ! on a une DLL !
Dev-C++ est un peu triste au niveau IHM mais il a l’avantage d’avoir été très rapidement pris en main.
L’agent
Une fois la barrière de la langue franchie, il faut attaquer le vif du sujet : construire un Agent.
Le point d’entrée c’est la méthode Agent_OnLoad. C’est dans cette méthode qu’il va falloir indiquer quels événements on souhaite écouter. Cela se passe en trois étapes.
1.Capabilities
En fonction des événements que vous souhaitez écouter et des méthodes dont vous avez besoin il faudra activer les bonnes capabilities. Attention, plus vous activerez de Capabilities, plus les performances en seront affectées.
can_get_current_contended_monitor : Pour écouter les entrées/sorties de block synchronized
can_generate_monitor_events : Pour activer la génération d’event sur l’activité du moniteur
can_get_line_numbers : Pour récupérer les numéros de lignes d’une méthode avec GetLineNumberTable().
2.EventCallbacks
Ensuite il faut abonner nos méthodes aux événements monitorés.
Dans mon cas je vais écouter les événements de début et de fin de vie de la JVM ainsi que la mise en attente et la libération d’un Thread sur un block synchronized.
Et voilà ! Maintenant à chaque fois qu’un Thread est mis en attente ma méthode callbackMonitorContendedEnter est appelée et lorsqu’il est libéré c’est callbackMonitorContendedEntered qui est executé.
OMG WTF memory leak !
On peut traduire poliment ce titre par : Mon dieu que c’est dur de perdre son garbage collector !
En effet après avoir mis en place le moniteur, la tache me paraissait simple. Il suffit de stocker dans le contexte du Thread l’heure de mise en attente et au moment où on le libère on peut en déduire le temps d’attente. Mais ça n’a pas été aussi trivial car la gestion de la mémoire m’a posé beaucoup de problèmes.
Dans JVMTI il y a deux types de gestion de la mémoire. Soit c’est la lib qui gère l’allocation de la mémoire, comme pour la méthode GetMethodName, et dans ce cas il ne faut pas oublier de lui demander de libérer cet espace :
Dans un premier temps je n’avais pas vraiment fait attention à la gestion de la mémoire en pensant naïvement qu’une petite fuite sur une petite application qui n’a pas vocation à s’exécuter longtemps, n’avait pas d’importance. Grave erreur ! Même si mon code fonctionnait sur mon petit exemple à 3 Thread, c’est lorsque je l’ai lancé avec Jonas que j’ai rencontré des problèmes. Mais une fois que l’allocation et la libération de la mémoire a été bien faite, je n’ai plus eu de problème.
Conclusion
J’ai fait ma première DLL !! Ca a été un peu laborieux, mais j’ai fini par y arriver. C’est vrai que de devoir programmer en C m’a beaucoup ralenti, mais d’un autre coté si j’étais un développeur C je n’aurais pas besoin de faire du profiling sur une application Java.
Une autre difficulté venait du manque de documentation. Il y a très peu d’exemple d’utilisation de cette librairie sur le net. En français c’est simple : il n’y en a pas. C’est aussi pour cette raison que je publie cette article à fin d’aider les futurs utilisateurs francophones
Je ne suis pas encore totalement satisfait de mon code car pour le moment le timer fonctionne en secondes. Il ne peut donc détecter que les Thread bloqués au minimum une seconde. Ce n’est pas l’idéal mais ça permet déjà de détecter les plus gros blocages.
