← Articles · Mémoire et garbage collector · Ghassane LATFI · 23 juillet 2026

Lire les logs GC sans outil externe

Quand le GC pose problème, le réflexe est d’envoyer le gc.log à GCeasy ou de l’ouvrir dans JDK Mission Control. C’est très bien, ces outils sortent des graphes propres en quelques secondes.

Mais le log lui-même se lit. Ce n’est pas du binaire, ce sont des lignes de texte, et chacune raconte ce qui s’est passé pendant une collecte. Une fois qu’on sait les décoder, on comprend le rythme du GC, on repère une fuite ou un Full GC de trop, et on sait dire si le problème vient vraiment du GC ou d’ailleurs. Tout ça sans rien installer, souvent avant même d’ouvrir un profiler.

On va lire une sortie G1 sur JDK 25, ligne par ligne. G1 est le collecteur par défaut, donc c’est ce que vous avez le plus de chances de croiser. Si vous ne savez pas encore quel collecteur choisir ni comment dimensionner la heap, commencez par Régler le GC de la JVM.

Activer les logs

Le logging GC passe par le logging unifié de la JVM. La forme utile :

-Xlog:gc:file=gc.log:time,uptime,level,tags

Une nuance qui change tout : le tag gc seul donne une ligne résumé par collecte, ce qui suffit dans la plupart des cas. Le tag gc* (avec l’étoile) active en plus tous les sous-tags, et sort le détail région par région, les phases internes et le temps CPU. C’est verbeux, mais c’est là qu’on va chercher quand la ligne résumé ne suffit plus :

-Xlog:gc*:file=gc.log:time,uptime,level,tags

Les décorateurs à la fin (time,uptime,level,tags) préfixent chaque ligne : l’horodatage, le nombre de secondes depuis le démarrage de la JVM, le niveau et les tags. L’uptime est précieux, c’est lui qui sert à mesurer les intervalles entre collectes.

La ligne qui résume tout

Voici la ligne produite par le tag gc, une par collecte. C’est le point de départ de toute lecture :

[2026-07-20T10:15:32.412+0200][634.129s][info][gc] GC(148) Pause Young (Normal) (G1 Evacuation Pause) 1804M->216M(4096M) 8.735ms

On la lit de gauche à droite :

• GC(148) : le numéro de la collecte. Il s’incrémente à chaque fois, ce qui permet de recoller les lignes entre elles quand on est en mode gc*.
• Pause Young (Normal) : le type de collecte.
• (G1 Evacuation Pause) : la cause qui l’a déclenchée.
• 1804M->216M(4096M) : la heap utilisée avant la collecte, puis après, et entre parenthèses la taille totale de la heap. Ici on est passé de 1804 Mo à 216 Mo sur une heap de 4 Go.
• 8.735ms : la durée de la pause.

Deux chiffres se lisent tout de suite. D’abord ce qui a été libéré : 1804 vers 216, presque 1,6 Go récupéré. Une collecte qui vide bien, c’est le signe d’objets temporaires en majorité, donc du sain. Ensuite la durée de la pause, à comparer à votre budget de latence. 8 ms sur un service web, personne ne le sent. 8 ms sur du trading, c’est une éternité. Tout dépend du contexte.

Les types de pause G1

Le champ après GC(n) dit quel genre de collecte vient d’avoir lieu. Sur G1, les principaux :

• Pause Young (Normal) : une collecte de la jeune génération. La plus fréquente et la plus courte. G1 ramasse l’eden et les survivors, rien d’autre.
• Pause Young (Concurrent Start) : une collecte jeune qui, en plus, lance un cycle de marquage concurrent en arrière-plan. Elle apparaît quand l’occupation de la vieille génération dépasse un seuil (l’IHOP, autour de 45 %, ajusté dynamiquement par défaut). C’est G1 qui commence à regarder l’old pour préparer son nettoyage.
• Pause Young (Prepare Mixed) puis une série de Pause Young (Mixed) : des collectes qui ramassent la jeune génération et une partie des régions old repérées par le marquage. C’est comme ça que G1 nettoie la vieille génération, petit à petit, sans jamais tout arrêter.
• Pause Remark et Pause Cleanup : deux courtes pauses qui font partie du cycle de marquage concurrent.
• Pause Full (G1 Compaction Pause) : le Full GC. Il arrête toute l’application et balaie toute la heap d’un coup. C’est l’événement à éviter.

Le rythme sain ressemble à ça : beaucoup de Pause Young (Normal), de temps en temps un Concurrent Start suivi de quelques Mixed, et aucun Full GC. Si un Pause Full apparaît en fonctionnement normal, c’est déjà un signal.

Le détail région par région

Quand la ligne résumé ne suffit pas, on passe en gc* et on regarde le découpage. G1 ne gère pas la heap en deux gros blocs, mais en régions de taille fixe. Voici ce qu’il imprime pour la collecte du dessus :

[634.129s][info][gc,heap] GC(148) Eden regions: 800->0(800)
[634.129s][info][gc,heap] GC(148) Survivor regions: 20->24(114)
[634.129s][info][gc,heap] GC(148) Old regions: 80->82
[634.129s][info][gc,heap] GC(148) Humongous regions: 2->2

Ligne par ligne :

• Eden 800->0(800) : 800 régions d’eden étaient pleines, elles sont vidées à 0, et la cible pour le prochain tour est 800. Après une collecte jeune, l’eden retombe toujours à zéro.
• Survivor 20->24(114) : les objets qui ont survécu à cette collecte ont été recopiés dans 24 régions de survivor.
• Old 80->82 : deux régions de plus en old. Ces deux régions sont des objets promus, assez vieux pour quitter la jeune génération. Une promotion qui grimpe lentement, c’est normal. Une promotion qui explose d’une collecte à l’autre, c’est le signe d’objets qui survivent trop, et ça finit par nourrir la vieille génération plus vite que G1 ne la nettoie.
• Humongous 2->2 : les objets énormes. Dans G1, tout objet qui dépasse la moitié d’une région est stocké à part, dans des régions dédiées. Ici deux d’entre eux n’ont pas été collectés.

Un mot sur la taille des régions. G1 la calcule au démarrage à partir de la taille de la heap, entre 1 et 32 Mo, en visant environ 2048 régions. Sur une heap de 4 Go, ça fait des régions de 2 Mo. D’où le calcul : 800 régions d’eden × 2 Mo = 1600 Mo, ce qui colle avec le 1,6 Go libéré qu’on lisait sur la ligne résumé. Tout est cohérent, et c’est ce qui permet de vérifier une intuition avec une simple multiplication.

Calculer le taux d’allocation à la main

C’est le chiffre le plus utile, et un outil comme GCeasy le calcule pour vous. Mais c’est juste deux soustractions.

Entre deux collectes jeunes, l’eden se remplit entièrement. Il suffit donc de prendre la taille d’eden ramassée et le temps écoulé entre les deux collectes. Reprenons GC(148) à 634.129s, avec ses 1,6 Go d’eden. Disons que la collecte suivante, GC(149), arrive à 635.512s :

Eden collecté : 1600 Mo
Intervalle    : 635.512 - 634.129 = 1.383 s
Taux          : 1600 / 1.383 ≈ 1157 Mo/s, soit ~1,1 Go/s

Voilà votre taux d’allocation. C’est la vitesse à laquelle le code fabrique des objets. Un taux élevé et constant veut dire beaucoup d’objets temporaires créés, donc beaucoup de collectes jeunes, donc du temps grignoté par le GC. Et là, aucun flag ne vous sauvera : le vrai levier est dans le code. Pour voir d’où viennent les allocations, le mode alloc d’async-profiler pointe directement les chemins responsables, c’est le sujet de Profiler la JVM avec async-profiler.

Repérer un problème sans profiler

Voici ce qu’on cherche en parcourant un gc.log, du plus grave au plus discret.

Un Full GC apparaît. La ligne Pause Full (G1 Compaction Pause) ne devrait pas exister en fonctionnement sain :

[812.400s][info][gc] GC(201) Pause Full (G1 Compaction Pause) 3980M->3120M(4096M) 412.006ms

412 ms de pause, et surtout la heap qui reste à 3120 Mo sur 4096 après coup. G1 n’a pas réussi à suivre avec ses collectes Mixed, souvent parce que l’allocation va plus vite que le marquage concurrent, ou parce que la heap est trop petite.

La heap reste pleine après la collecte. Quand le « après » est presque égal au « avant » sur la ligne résumé, par exemple 3900M->3850M(4096M), la collecte n’a quasiment rien libéré. Répété sur plusieurs collectes, c’est soit une heap sous-dimensionnée, soit une fuite mémoire. La suite logique est un OutOfMemoryError, et là il faut passer au heap dump : Diagnostiquer une fuite mémoire avec un heap dump.

Une Evacuation Failure. Elle s’ajoute à la fin de la cause de la collecte, entre parenthèses :

[788.220s][info][gc] GC(178) Pause Young (Normal) (G1 Evacuation Pause) (Evacuation Failure: Allocation) 3900M->3600M(4096M) 95.204ms

G1 a manqué de régions libres pour recopier les survivants pendant la pause. C’est lent et coûteux, souvent le dernier avertissement avant un Full GC. Ça veut dire que la heap est trop pleine ou que la promotion s’emballe.

Les régions humongous grimpent. Beaucoup de régions humongous trahissent de gros tableaux ou de gros buffers. Ils fragmentent la heap et peuvent déclencher des cycles à eux seuls. Souvent, mieux vaut revoir le code qui les alloue que la taille des régions.

Les pauses s’allongent. La durée en fin de ligne résumé qui dépasse votre budget de latence, de façon répétée et pas juste sur un pic isolé.

La pause n’est pas que du GC

Un piège pour finir. La durée affichée sur la ligne gc, c’est le travail du GC. Mais l’application est arrêtée dès l’instant où tous les threads ont atteint un point d’arrêt sûr, le safepoint. Et atteindre ce safepoint prend du temps lui aussi.

Si un thread est coincé dans une longue boucle sans point de sondage, il fait attendre tous les autres. Le GC affiche 8 ms, mais l’application a peut-être été gelée bien plus longtemps. Pour voir ce temps caché :

-Xlog:safepoint:file=safepoint.log:time,uptime

La sortie donne une ligne par safepoint, avec les durées en nanosecondes :

[635.512s] Safepoint "G1CollectForAllocation", Time since last: 219964917 ns, Reaching safepoint: 2208 ns, At safepoint: 8735000 ns, Leaving safepoint: 1625 ns, Total: 8738833 ns, Threads: 0 runnable, 10 total

At safepoint correspond au travail du GC, ici les 8,7 ms qu’on retrouve sur la ligne gc. Reaching safepoint est le temps qu’il a fallu pour arrêter tous les threads avant de commencer. Quand ce dernier gonfle alors que le GC reste court, le problème n’est pas le GC : c’est un thread lent à s’arrêter. On ne le voit jamais si on ne regarde que la ligne gc.

En résumé

Activez les logs avec -Xlog:gc pour l’essentiel, -Xlog:gc* pour le détail. Lisez d’abord la ligne résumé : combien la collecte a libéré, et combien de temps elle a duré. Servez-vous du type de pause pour suivre le rythme, et méfiez-vous du premier Full GC. Descendez dans le détail région par région pour surveiller la promotion et les humongous. Calculez le taux d’allocation à la main, c’est deux soustractions. Et n’oubliez pas que la vraie pause inclut le temps d’atteindre le safepoint. Un gc.log bien lu vous dit où est le problème avant que vous n’ayez ouvert le moindre outil.