Cas pratique de tuning JVM d’une application

J’ai récemment dû analyser les performances d’une application d’un de nos clients, et au cours de mes différentes recherches et essais, je me suis dit que je devais vous faire partager cela 🙂

Comme nous pourrons le voir par la suite, cet article ne vient pas en contradiction avec l’article de Christophe sur Java Ergonomics, mais plutôt en complément, pour présenter un cas pratique et proposer une démarche d’analyse.

Le problème initial

L’application d’un de nos clients a des problèmes de performances en production. L’application freeze pendant plusieurs secondes et il faut redémarrer le serveur d’application plusieurs fois par jour. Après analyse, la mémoire augmente constamment et certains garbage collector (GC) prennent jusqu’à 10 secondes, bloquant l’application pendant son exécution.

Nous avons effectué plusieurs améliorations sur l’application (montée de version des applications tierces, du serveur d’application, du serveur physique), puis lors des tests de charge de validation, nous avons regardé le tuning de la JVM.

La méthode

La méthode est assez simple et utilise des outils gratuits :

  • JMeter pour les tests de montée en charge

  • le plugin PerfMon pour monitorer la JVM et les temps de GC dans JMeter

  • HPjmeter pour analyser les logs de GC

  • jstat pour vérifier les tailles des heap et les temps de GC

Une fois votre script JMeter effectué, il faut le passer sur une durée assez longue pour se mettre dans des conditions de production (mêmes données, même charge) et pour chaque modification des paramètres JVM. C’est simple, mais long 🙂

Petits rappels

Dans un JDK 7, il existe plusieurs types de GC :

  • Serial GC

  • Parallel GC (parallèle uniquement sur la partie “Young generation”)

  • Parallel Old GC (Parallel Compacting GC)

  • Concurrent Mark & Sweep GC  (or “CMS”)

  • Garbage First (G1) GC

Nous n’allons nous intéresser qu’aux 3 derniers, beaucoup plus performants sur nos CPU multi-coeurs. Pour convaincre les sceptiques, voici une comparaison rapide des algorithmes serial et parallel :

La partie “Stop the world pause” représente le temps pendant lequel votre application sera bloquée, le temps que le GC fasse son petit ménage.

Les algorithmes Parallel Old GC et CMS GC sont les anciennes versions du GC qui utilisent les Young et Tenured generations (aussi appelées New et Old) :

Les objets sont créés dans la partie “Eden” de la young generation. Lorsque des minor collections du GC passent, elles nettoient la partie Young uniquement, en copiant les objets se trouvant dans la partie “Eden” vers un des 2 “Survivor spaces”, le second étant vidé dans la partie “Tenured”. Cela permet de laisser une chance aux objets de “mourir” avant de passer dans la partie “Tenured”. Ces minor collections sont très rapides, et un objectif du tuning est de les garder sous les 100ms, voire 50ms.

Les major collections (aussi appelées full collections) nettoient la partie “Tenured” et sont beaucoup plus longues. L’objectif du tuning est de les garder sous les 1 seconde.

Un axe potentiel d’amélioration est rapidement trouvé dans notre cas : augmenter la Young generation pour que peu d’objets ne passent dans la Tenured, et que les major collections se déroulent plus vite (moins d’espace Old à nettoyer = plus vite fait). On verra si c’est effectivement le cas.

Le CMS GC est particulier : il utilise le même algorithme que le Parallel GC sur la Young generation, mais il essaie de nettoyer la Tenured generation au fur et à mesure de la vie de l’application. Il va donc effectuer des petits bouts de full GC en background.

La partie “Initial Mark” va déterminer rapidement les objets éligibles au nettoyage.

Pendant la période “Concurrent Mark”, le GC va parcourir les objets éligibles et les marquer. Puisque l’application continuait à vivre, tous ces objets ne sont peut-être plus atteignables (changement de référence, …).

La partie “Remark” va donc revérifier que les objets marqués sont toujours valides, puis le nettoyage va s’effectuer en parallèle de l’application (Concurrent Sweep)

L’algorithme G1GC est le dernier né. Il n’utilise plus les espaces Young et Tenured, mais des grilles. Les objets sont créés dans des grilles. Une fois la grille complétée, les objets sont créés dans une autre grille, et un GC est exécuté.

Le tuning

Une fois notre objectif trouvé (ici réduire les temps de major collection), nous allons pouvoir élaborer une stratégie de tuning en testant certains paramètres.

Premièrement, il faut comparer l’impact des différents algorithmes :

  • -XX:+UseParallelOldGC

  • -XX:+UseConcMarkSweepGC, avec et sans -XX:+CMSIncrementalMode

  • -XX:+UseG1GC

Ensuite, pour chaque algorithme, nous allons tester les Ergonomics de Java 7, puis lui imposer certaines valeurs :

  • -XX:+UseAdaptiveSizePolicy (non compatible avec CMS)

  • -XX:NewRatio=2,3,4 (fixe le ratio entre Young et Tenured : NewRatio=2 signifie qu’il y aura 2 fois plus de Tenured que de Young, donc la Young generation fera ⅓ de la mémoire totale)

  • -XX:NewSize=800m -XX:MaxNewSize=800m (forcer la taille de la Young generation)

  • -XX:MaxGCPauseMillis=800 (force l’optimisation des Ergonomics sur le temps d’exécution du GC)

Pour monitorer et comparer toutes ces variantes, nous allons partir sur une base d’arguments :

  • -Xms1280M -Xmx1280M : force la heap totale à 1,28Go

  • -XX:MaxPermSize=256m : augmente la PermGen (aucun impacte sur les performances, à augmenter que si vous avez des OutOfMemoryError lors de vos montées en charge)

  • -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/logs/gc.log : créér un fichier de log contenant les informations sur les passages du GC, qui pourra être analysé par HPjmeter

Les résultats

Voici les résultats résumés pour un test de 8 heures :

ParallelOldGC

Sans option

UseAdaptiveSizePolicy

NewRatio=2

NewRatio=3

NewRatio=4

NewSize=800m

MaxGCPauseMillis=800

Nb req

971

994

924

923

948

1064

919

Avg minor (s)

0,162

0,148

0,155

0,138

0,122

0,114

0,157

Avg major (s)

1,14

1,066

1,097

1,151

1,117

0,779

1,081

Max major (s)

1,22

1,2

1,28

1,32

1,28

1,00

1,26

Une vue intéressante de HPjmeter est l’onglet “Duration”, qui montre les temps de GC en fonction du type : minor et major.

-XX:+ParallelOldGC -XX:NewSize=800m -XX:MaxNewSize=800m

CMS

Sans option

NewRatio=2

NewRatio=3

NewRatio=4

NewSize=800m

MaxGCPauseMillis=800

Nb req

441

472

326

346

795

439

Avg minor (s)

0,723

0,670

0,775

0,763

0,492

0,717

Avg major (s)

0,287

0,316

0,354

0,343

0,313

0,294

Max major (s)

3

2,65

2,8

2,8

2,3

3,1

La moyenne des temps de GC est bon, mais on a tout de même plusieurs pics à plus d’une seconde :

-XX:+UseConcMarkSweepGC -XX:NewSize=800m -XX:MaxNewSize=800m

CMS avec incremental

Sans options

NewRatio=2

NewRatio=3

NewRatio=4

NewSize=800m

MaxGCPauseMillis=800

Nb req

456

491

460

440  701 479

Avg minor (ms)

0,392

0,371

0,390

 0,380  0,395  0,350

Avg major (ms)

0,299

0,318

0,289

0,267  0,332  0,289

Max major (s)

2,5

2,4

2,73

2,68 2,05  2,70

-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:NewSize=800m -XX:MaxNewSize=800m

G1GC

Sans options

UseAdaptiveSizePolicy

NewRatio=2

NewRatio=3

NewRatio=4

NewSize=800m

MaxGCPauseMillis=800

Nb req

460 345 461 411  342 692  452

G1 (s)

 0,046  0,026  0,015  0,041  0,023  0,353  0,017

Other full GC (s)

 1,483  1,987  1,593  1,843 1,947  1,204  1,624

Conclusions

Pour cette application en particulier (car chaque application sera différente), le meilleur compromis est d’utiliser les arguments suivants :

-XX:+UseParallelOldGC -XX:+UseAdaptiveSizePolicy -XX:NewSize=800m -XX:MaxNewSize=800m -Xms1280M -Xmx1280M -Xss256k -XX:MaxPermSize=256m

On voit aussi que les Ergonomics n’arrivent pas tout seul à optimiser le Garbage Collector de notre application, mais qu’en lui imposant la taille de la Young Generation on arrive à diminuer grandement les temps de GC et à augmenter notre nombre de requêtes.

Ce qui est important lors de vos tunings, c’est de se donner un but à atteindre (CPU, mémoire, temps de GC, …), puis d’analyser quelles possibilités de tuning s’offrent à vous pour atteindre cet objectif. Je vous ai présenté un cas d’optimisation de temps de GC, mais vous pouvez utiliser les mêmes outils pour atteindre d’autres objectifs.

Bonne chance dans votre tuning !

Tweet about this on TwitterShare on FacebookGoogle+Share on LinkedIn

3 réflexions au sujet de « Cas pratique de tuning JVM d’une application »

  1. Est ce qu’on ne peut pas arriver au même résultat en gardant les options par défaut du gc (comme cela semble recommandé d’après certains articles) et en optimisant la qualité du code (création de moins d’objets, …) ? A moins qu’il soit déjà optimisé au maximum je sais pas

    1. Même si la recommandation de laisser les options par défaut reste valable, il y a certaines choses que la JVM ne peut deviner.
      Le plus important dans une application Java étant de déterminer l’objectif à privilégier : la consommation mémoire ou des temps de pause réduits (les deux étant évidement contradictoires).
      Enfin il y a un point pour lequel la JVM ne peut pas grand chose à l’heure actuelle c’est les fuites mémoires et c’est ce qu’il faut résoudre en priorité dans un éventuel refactoring du code.
      Certes, l’optimisation du code permet d’arriver à des résultats très concluants mais avec les inconvénients suivants :
      – C’est très consommateur de temps
      – L’utilisation de certaines techniques comme les “weaks références” sont à manier avec précaution.

      Enfin dans un projet Java le code que l’on maîtrise est finalement faible par rapport au code des librairies utilisées, du serveur d’application, etc.

  2. Je suis un peu étonné que le GC CMS ne permette pas d’obtenir des freeze plus courts que le ParallelOldGC, c’est généralement pour ce cas d’utilisation qu’il est recommandé.

    J’aurais tendance à penser que les quelques pauses longues que tu as eu avec le CMS (particulièrement en mode incrémental) sont dues à des cas où le GC n’a pas pu terminer son ‘ConcurrentSweep’ avant que la ‘young generation’ ne soit pleine, et du coup il n’a plus d’autre solution que de bloquer les autres threads le temps de finir le travail. Dans ce cas, tu dois avoir quelque chose comme ‘concurrent mode failure’ dans les logs du GC. C’était ton cas ?

    Si c’est bien ça, on peut tenter de limiter le phénomène en jouant sur le seuil de déclenchement de la phase de GC en mode concurrent (par exemple -XX:CMSInitiatingOccupancyFraction=50 : déclenche le process quand la ‘Old generation’ est pleine à 50%). Ça risque d’avoir un overhead non négligeable sur le temps CPU total du GC, mais si ce n’est pas la priorité, pourquoi pas…

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *


*