Mardi dans l’après-midi j’ai assisté à une présentation de 30 minutes sur Java-Monitor par Kees jan Koster. Java-Monitor est un outil gratuit open-source qui permet de monitorer votre JVM. La particuliarité de Java-Monitor, c’est que cette surveillance s’effectue directement sur le serveur de Java-Monitor. Une sonde est installée sous la forme d’un agent dans votre JVM et elle se connecte ensuite vers le serveur de Java-Monitor. Les résultats sont donc hébergés sur le site de Java-Monitor. Le tout est gratuit, et fonctionne avec aussi Amazon EC2.
Le fait de surveiller votre JVM avec ce service permet de partager avec une communauté vos soucis. Kees nous a présenté des cas typiques rencontrés sur des applications en production. Sa présentation très vivante nous a appris quelques informations intéressantes sur la JVM.
Kees commence par nous montre un graphique classique de l’occupation mémoire d’une application. Visiblement celle-ci souffre d’une fuite mémoire. Si vous n’avez jamais eu de fuite (et je vous le souhaite, vous êtes jeune) voici à quoi cela ressemble:
Les 2 Garbages Collectors de la JVM s’activent régulièrement comme le montre cette courbe:
La solution est de trouver la fuite mémoire avec un outil comme JProfiler
Kees nous a ensuite montré un graphe qui montre que le système souffre d’un souci difficile à pointer au premier regard. Cette courbe montre l’activité du Garbage Collector. Comme vous pouvez le constater, celui-ci tourne en permanence, alors que la mémoire n’est pas remplie. Bizarre non ?
La raison de cette suractivité est un System.gc() placé par le développeur dans le code. Or comme il l’explique, c’est une très mauvaise idée. System.gc() risque de mettre en marche le Scavenge Collection Garbage Collector. Celui-ci met en pause les Threads le temps d’effectuer la collecte et de ranger les différents espaces mémoires. Il cite l’exemple d’un développeur qui avait ajouté System.gc() dans la méthode destroy() de sa Servlet, afin de libérer les ressources. Mauvaise idée, regardez l’implication pour les autres sessions dans le conteneur Web:
Si vous souhaitez en savoir plus, lisez les articles sur son site à cette adresse.
Pour trouver ces bouts de code, il conseille l’utilisation de FindBugs. Il est aussi possible de désactiver les appels System.gc() en spécifiant cette option pour la JVM de Sun :
-XX:-DisableExplicitGC
FindBugs signale les bugs en analysant le bytecode des JARs. Quelques tests sur le driver JDBC de MySQL 5.1.5 montre qu’il y a ainsi 154 warnings, dont des soucis de NullPointer, et des vulnérabilités à l’injection SQL. Le driver d’Oracle ojdbc6.jar de son côté souffre de presque 1028 warnings, avec par exemple des System.exit() dans le code du driver, ou des boucles infinies… Super non ?
Il montre ensuite un problème des systèmes 32-bits:
java.lang.OutOfMemoryError: unable to create new native thread at java.lang.Thread.start0(Native Method) at java.lang.Thread.start(Thread.java:597) at org.apache.tomcat.util.net.JIoEndpoint$Worker.start(JIoEndpoint.java:478) at org.apache.tomcat.util.net.JIoEndpoint.newWorkerThread(JIoEndpoint.java:697) at org.apache.tomcat.util.net.JIoEndpoint.createWorkerThread(JIoEndpoint.java:676) at org.apache.tomcat.util.net.JIoEndpoint.getWorkerThread(JIoEndpoint.java:708) at org.apache.tomcat.util.net.JIoEndpoint.processSocket(JIoEndpoint.java:743) at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:320) at java.lang.Thread.run(Thread.java:619)
Cette erreur est levée lorsque le système ne peut plus allouer de mémoire. Rappelons que l’espace addressable sur les systèmes 32-bits n’est que de 4Gb. En effet il n’y a que 2^32 adresses, ce qui correspond à presque 4Gb. Sachant que le système lui-même et les autres processus ont besoin de mémoire, il y a donc une limite rapidement atteinte sur les systèmes 32-bits. Il existe beaucoup d’articles sur ce sujet, je vous recommande de lire « Tuning Garbage Collection with the JVM 5.0« . La solution lorsque votre application nécessite réellement autant de mémoire, c’est de passer sur un système 64-bits.
Il explique ensuite un concept dont je n’avais jamais entendu parler : l’échec de promotion d’un objet de la Young Generation vers le Survivor Spaces. Il faut vraiment lire ce whitepaper pour comprendre, c’est un truc compliqué que je vais tenter de vous expliquer en quelques lignes. Certaines options du GC font que l’espace mémoire se fragmente comme votre disque dur. C’est le cas lorsque vous utilisez le Concurrent Mark-Sweep GC. Imaginez que les promotions des objets de la Young-Generation vers la Old-Generation soit comparable à la recopie d’un disque A vers un disque B. Le CMSweep ne compacte pas le disque B lorsqu’il détruit des objets qui ne sont plus adressables. Le problème est lors de la recopie : Java n’arrive pas à déplacer des objets pour les stocker dans la Old Generation. Cela n’est pas très grave : votre application va exploser avec un OutOfMemory quand bien même il reste de la mémoire… Mais celle-ci est fragmentée. Pour voir ce problème il faut activer certaines options de la JVM:
-Xloggc:/var/log/gc.log -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
Il faut ensuite regarder les logs du serveur, vous verrez que des messages « promotion failed » apparaissent alors
42536.572: [GC 42536.572: [ParNew: 353920K->2080K(353920K), 0.1246980 secs] 1450967K- >1137843K(2520704K), 0.1249020 secs] 42546.733: [GC 42546.733: [ParNew: 316704K->3604K(353920K), 0.0599980 secs] 1452467K- >1139368K(2520704K), 0.0602080 secs] 42555.527: [GC 42555.527: [ParNew: 318228K->5034K(353920K), 0.0609210 secs] 1453992K- >1140797K(2520704K), 0.0611270 secs] 42564.154: [GC 42564.154: [ParNew: 319658K->5214K(353920K), 0.0780650 secs] 1455421K- >1142411K(2520704K), 0.0782850 secs] 42571.444: [GC 42571.444: [ParNew: 319838K->5514K(353920K), 0.0649090 secs] 1457035K- >1144161K(2520704K), 0.0651220 secs] 42576.714: [GC 42576.714: [ParNew (promotion failed): 320138K->320138K (353920K), 0.2365970 secs]42576.951: [CMS: 1139969K->1120688K( 2166784K), 9.2214860 secs] 1458785K->1120688K(2520704K), 9.4584090 secs] 42587.017: [GC 42587.017: [ParNew: 314624K->34454K(353920K), 0.1340880 secs] 1435312K- >1205264K(2520704K), 0.1344800 secs] 42588.700: [GC 42588.701: [ParNew: 349078K->23091K(353920K),
La solution est de régler la taille des différents espaces de la JVM (voir ce document).
Il continue sa présentation en nous parlant des problèmes de File Descriptor sous Unix (Too Many Files open). Il suffit de changer la limite du nombre des fichiers pour l’utilisateur qui exécute votre serveur. A noter que les sockets sont comptés comme des fichiers sous Unix (je sais que ce que je dis n’est pas tout à fait exact, je fais court…) ce qui concerne donc les connexions vers la base, ou la partie web de votre serveur.
ll rappelle aussi la grosse différence entre le mode serveur (-server) ou client pour la JVM de Sun avec quelques courbes.
En conclusion, une petite présentation plutôt sympa de 30 minutes, qui me fait dire que si vous êtes en galère avec la JVM, il serait bon de passer un peu de temps sur les forums de Java-Monitor.
Références
Les slides de la présentation
Java-Monitor.com
FindBugs, excellent outil pour analyser son bytecode.
Hello Nicolas,
Pour info, j’ai découvert visualVM (open source java.net, intégré au jdk 6, ou à installer séparément), il n’a pas besoin pas d’agent spécifique… et possède déjà pas mal de plugin ! hot spot, suivi cpu, thread, vm, gc, jmx… Il remplace pas encore tout à fait jconsole et jprofiler mais très prometteur à mon avis et 100% standard hotspot (à partir des jre 5 ou 6 par contre)
sur la vm hotspot à monitorer, les simples var d’env java suffisent (accès distant ou non)
-Dcom.sun.management.jmxremote.port=1234
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false
@+, Jérôme
@Jérôme: merci pour ces infos. Il faudrait que j’écrive un article sur JProfiler, visualVM et les différents outils qui sont dans notre boite. Si vous avez des produits open-sources ou commerciaux à me suggérer, n’hésitez pas à envoyer un email