Analyse mémoire d’une JVM

Mardi, 10 heures
– La production « Allo, le projet, depuis 10 minutes on voit passer des messages ‘OutOfMemoryError’. Que fait-on ? « 
– Le projet « Augmentez la mémoire de la JVM, doublez-la valeur de l’option -Xmx « 

Mardi, 13 heures
– La production « Allo, le projet, depuis 5 minutes on voit encore passer des messages ‘OutOfMemoryError’. Que fait-on ? « 
– Le projet « Augmentez la mémoire de la JVM, doublez encore la valeur de l’option -Xmx « 

Mardi 18 heures
– La production « Allo, le projet, depuis 2 minutes on voit passer encore des messages ‘OutOfMemoryError’. Que fait-on ? « 
– Le projet « Tut, tut, tut,….. »
– La production « Plus d’équipe projet, la nuit va être longue… »

Cette petite scène est un classique, un air de déjà-vu mais que faire ? Si votre application a déjà subi une batterie de tests techniques, augmenter la mémoire est rarement la bonne solution. La scène décrite ci-dessus laisse penser à ce que l’on appelle classiquement une Fuite Mémoire (Memory Leak). En réalité, avec les JVM récentes, la fuite mémoire n’existe pas, je préfère parler d’accumulation d’objets non désirés. Cet article va vous montrer comment débusquer cette accumulation avec les outils jmap, jhat et Eclipse Memory Analyser

jmap

jmap est l’outil qui permet d’effectuer des photographies de la mémoire d’une JVM. Deux options sont particulièrement intéressantes : l’histogramme et le dump.

L’histogramme

L’option -histo permet d’obtenir un histogramme de la mémoire de la JVM. Les informations suivantes sont affichées pour chacune des classes Java :

• son nom complet
• le nombre d’objets et
• la taille de la mémoire occupée en octets

L’ensemble est trié par taille mémoire décroissante. Attention, la demande d’un histogramme implique automatiquement un Full GC de la mémoire de la JVM.

Exemple :

jmap -histo 

 num     #instances         #bytes  class name
----------------------------------------------
   1:         41202       27502288  [C
   2:          2304        1332520  [I
   3:         37934         910416  java.lang.String
   4:          5130         503632  
   5:          5130         412968  
   6:         12348         395136  fr.xebia.memory.bean.Person
   7:         12846         308304  java.util.concurrent.ConcurrentHashMap$HashEntry
   8:          7650         285656  
   9:         12518         200288  java.lang.Long
  10:           349         189184  
  11:           349         138704  
  12:           327         132144  
  13:            38         115456  [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
  14:           414          76392  [B
  15:           422          40512  java.lang.Class
  16:           556          32656  [[I
  17:           518          32056  [S
  18:            44          14080  
  19:           315          13480  [Ljava.lang.Object;
  20:           576           9216  java.lang.StringBuffer
.....
 184:             1              8  java.lang.System$2
 185:             1              8  java.io.File$1
 186:             1              8  java.lang.Terminator$1
Total        142211       32693376

Que peut-on en déduire ?

• Les premières places sont souvent trustées par les objets de base ( java.lang.String, java.lang.Object, java.lang.class) et leur déclinaison en collections (java.util.* et les tableaux, symbolisé par des ‘[‘). Si vous retrouvez des classes de votre application dans le top 20, elles deviennent suspectes. Dans notre exemple, l’histogramme montre que la classe ‘fr.xebia.memory.bean.Person’ est instanciée 12348 fois pour une occupation mémoire de 308304 octets. Elle est suivie de près par des entrées d’une ConcurrentHashMap (java.util.concurrent.ConcurrentHashMap$HashEntry)
• L’obtention de cet histogramme est extrêmement rapide et perturbe peu la JVM (au Full GC près ;) ). Il est donc possible d’en faire régulièrement (exemple toutes les ‘n’ secondes) et d’en déduire ainsi des tendances : nombre d’instances d’une classe qui augmente, taille des instances d’une classe qui diminue, …

Note : avec les JVM en version 1.4.2, il est possible d’obtenir également un histogramme à chaque thread dump en ajoutant l’option -XX:+PrintClassHistogram au démarrage de la JVM. Comme pour jstat -histo, cette option implique automatiquement un Full GC de la mémoire de la JVM.

L’histogramme permet de connaître les classes qui occupent le plus de mémoire, il n’indique pas qui les a allouées.

Le dump

L’histogramme c’est bien, mais ce n’est pas suffisant : il est parfois nécessaire d’obtenir un dump complet de la mémoire afin de déterminer précisément la chaîne de référencement.

L’outil jmap permet également d’effectuer un dump complet et binaire de la mémoire d’une JVM. Deux remarques importantes :

• pendant la durée du dump, plus rien ne s’exécute dans la JVM, tous les threads sont stoppés, qu’ils soient applicatifs ou systèmes.
• la durée du dump est proportionnelle à la taille de la mémoire occupée et fonction de la taille de la mémoire restante (il faut un peu de mémoire libre pour exécuter le traitement du dump !). Exemple: la durée d’un dump d’une JVM avec un heap de 1 Go à la limite de la saturation mémoire se compte en minute !

Exemple : création d’un dump

jmap -dump:format=b,file=c:tempheap.bin 
Dumping heap to c:tempheap.bin ...
Heap dump file created

Note : L’option -XX:+HeapDumpOnOutOfMemoryError indique à la JVM d’effectuer un heap dump en cas d’OutOfMemoryError. Le fichier est généré dans le répertoire de lancement de la JVM.

Vous voilà l’heureux propriétaire d’un fichier binaire de plusieurs centaines de méga-octets. Comment en extraire des informations ? C’est là que le compagnon de jmap rentre en jeu : jhat.

jhat

jhat est un analyseur de dump mémoire. C’est en réalité un serveur web, comme le montre l’exemple ci-dessous.

D:ProjetsMesProjetsMemoryLeakjmap5968>jhat heap5968.bin
Reading from heap5968.bin...
Dump file created Mon Nov 24 13:03:54 CET 2008
Snapshot read, resolving...
Resolving 118955 objects...
Chasing references, expect 23 dots.......................
Eliminating duplicate references.......................
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

L’application jhat lancée, il suffit de lancer un navigateur web pour commencer l’exploration du dump.

Grâce à jhat, on a pu voir que les instances de type fr.xebia.memory.bean.Person étaient majoritairement référencées par un champ statique de type fr.xebia.memory.dao.MySuperSmartCache qui fait office de cache. Sans rentrer dans le code, on peut commencer à avoir des doutes sur l’efficacité de ce cache !

jhat a l’avantage d’être disponible dans tous les JDK récents. Cependant, l’interface proposée permet certes de naviguer facilement de classe en classe, d’instance en instance, mais il manque de fonctions d’analyse. Un outil est venu combler ce manque…

Eclipse Memory Analyzer

Eclipse Memory Analyzer (MAT) est un sous projet de la fondation Eclipse, initié par la société SAP. Son but est non seulement d’offrir une interface graphique permettant de naviguer dans un dump mémoire, mais également de proposer des rapports d’analyses précablés (Leak Suspects, Heap Dump Overview, Top Consumers,…).

Ouvrons le dump avec MAT. Après analyse, MAT ouvre une fenêtre avec une vue d’ensemble de la mémoire. Il est clair que l’ensemble de la mémoire est retenu par une seule instance de type fr.xebia.memory.dao.Loader.

La vue histogramme ressemble à celle fournie par jmap ou jhat mais avec des libellés un peu plus clairs.

Une fonction très intéressante, le ‘Dominator Tree’ donne la liste des plus gros objets, consolidée avec l’ensemble de leurs références.

Pour terminer, jetons un coup d’œil sur le rapport ‘Leak Suspect’, et là il n’y a plus de doute, nous avons trouvé le coupable.

Conclusion

Avec ces outils de capture et d’analyse de la mémoire, il est maintenant facile de débusquer les consommations mémoires excessives, même dans un environnement de production. N’hésitez pas à user et à abuser de ces outils afin de déterminer au plus tôt les tailles des JVM et les éventuelles accumulations d’objets non désirés !