[JAVA] Informations de référence pour rechercher et analyser l'état d'utilisation de la mémoire de Tomcat

Aperçu

Même dans les temps modernes, il existe encore de nombreuses applications Web qui utilisent Tomcat. (Ce n'est pas une critique, il est utilisé dans de nombreux services, la mise à niveau de la version se poursuit, et c'est un produit avec beaucoup d'informations, donc je pense que c'est un excellent serveur d'applications.)

Si la société de développement crée l'environnement, déploie le système construit en Java sur le serveur et l'exploite pendant un certain temps, des problèmes peuvent inévitablement survenir en termes de performances.

Par exemple, il est bon de générer des journaux, mais comme il ne prend pas en compte la rotation et le cycle de destruction des fichiers, cela met la pression sur le stockage et soudainement la pierre et le serveur tombent en panne, et l'état d'utilisation de la mémoire du tas augmente progressivement. Ensuite, Tomcat meurt à cause d'OutOfMemoryError, etc., et même s'il ne meurt pas, la réponse du système se détériore et des problèmes se produisent, et diverses autres choses se produisent.

Si vous constatez que vous réduisez votre espace de stockage, vous supprimerez souvent les fichiers que vous jugerez inutiles et ** provisoirement ** et ** permanents à nouveau **.

Si la réponse du système est mauvaise et qu'il semble que la mémoire en soit la cause après un examen léger, si l'impact métier est important s'il n'est pas résolu immédiatement, redémarrez Tomcat et ** support provisoire ** et ** support permanent. On dit que l'enquête sur la cause de ** est quelque chose comme «Si vous essayez de le reproduire à nouveau dans les mots magiques de la société de développement», je l'étudierai à ce moment-là », et la ** correspondance permanente ** ne viendra pas pour toujours .. (C'est une expérience personnelle et ne s'applique pas à tout le monde.)

J'ai mentionné quelque chose comme un peu de grognement pendant longtemps, mais l'analyse de l'utilisation de la mémoire peut ne pas être connue avant que le problème réel ne se produise, et la situation se situe également dans l'environnement de production et l'environnement de développement de la société de développement. Je comprends que c'est difficile à reproduire car c'est différent. La situation actuelle est que les contrats de maintenance sont réduits à contrecœur par les entreprises utilisatrices, et ce n'est pas une situation où des travaux de recherche fastidieux peuvent être effectués.

Si tel est le cas, les entreprises utilisatrices doivent enquêter par elles-mêmes. Dans cet esprit, je quitte cet article avec l'intention de résumer mes propres méthodes d'enquête et d'analyse.

Comment vérifier l'état de la mémoire utilisée par Tomcat

Comment vérifier le pid de Tomcat

Dans cet article, j'utiliserai diverses commandes et enquêterai, mais j'ai parfois besoin de connaître le pid de Tomcat à l'avance. Il existe plusieurs façons de vérifier le pid, et vous pouvez le vérifier avec la commande suivante.

Si le seul processus qui utilise Java est Tomcat, vous pouvez le vérifier avec la commande pidof.

# pidof java
3344

Si vous n'êtes pas sûr qu'il ne s'agisse que de Tomcat, vous devez utiliser jcmd pour le lister et déterminer le PID Tomcat.

# jcmd -l
3344 org.apache.catalina.startup.Bootstrap start ← C'est le PID de Tomcat
4894 jdk.jcmd/sun.tools.jcmd.JCmd -l

Vérifiez l'utilisation de la mémoire à l'aide de la commande CentOS top

Spécifiez le PID de Tomcat et vérifiez l'état d'utilisation tel que la mémoire avec la commande top.

# top -p 3344
top - 11:22:30 up 23 min,  1 user,  load average: 0.00, 0.00, 0.00
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3939.0 total,   3295.9 free,    273.2 used,    369.9 buff/cache
MiB Swap:   2048.0 total,   2048.0 free,      0.0 used.   3445.0 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                           
 3344 root      20   0 4204172 190864  28536 S   0.0   4.7   0:03.04 java        

• VIRT --Image virtuelle. Toute la mémoire virtuelle réservée. Comprend l'utilisation de la mémoire permutée. (Unité: kb)
• RES
• Taille du résident. La taille de la mémoire physique utilisée, non permutée. (Unité: kb)
• SHR --Taille de mémoire partagée. La taille de la mémoire qui peut être partagée avec d'autres processus. (Unité: kb)

Vérifiez les paramètres de démarrage JVM (facultatif) à l'aide de jcmd

Dans les options de démarrage de Tomcat (options de démarrage de JVM), vous pouvez spécifier -Xms, -Xmx, etc., et définir la taille de mémoire utilisée par Tomcat.

Comme méthode de réglage

--Définissez le ~ / bash_profile de l'utilisateur tomcat pour exporter la variable d'environnement CATALINA_OPTS --Comment spécifier dans le script de démarrage de tomcat.service --Comment spécifier dans {tomcat-root} / bin / setenv.sh

S'il n'y a pas de procédure et de matériaux de construction d'environnement de Tomcat, de scripts construits avec Ansible, etc., Parfois, il est difficile de vérifier ce qui est configuré pour démarrer. (Surtout si vous demandez à la société de développement de créer, développer et publier l'environnement et de prendre soin du serveur en tant que société utilisatrice, cela est particulièrement gênant.)

Dans un tel cas, vous pouvez utiliser jcmd pour vérifier quel type d'option JVM le Tomcat en cours d'exécution est en cours d'exécution pour le moment.

Vous aurez besoin de votre Tomcat PID à l'avance pour vérifier.

# jcmd -l
899 org.apache.catalina.startup.Bootstrap start
4894 jdk.jcmd/sun.tools.jcmd.JCmd -l

# jcmd 899 VM.flags
899:
-XX:CICompilerCount=2 -XX:InitialHeapSize=62914560 -XX:MaxHeapSize=991952896 -XX:MaxNewSize=330301440 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=20971520 -XX:OldSize=41943040 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC

Il est possible de vérifier comment les réglages des paramètres sont tels que décrits ci-dessus, tels que -XX: MaxHeapSize qui correspond à -Xmx.

Obtenez un vidage de tas Tomcat

Un vidage de tas est comme un journal instantané de l'utilisation de la mémoire Java. En effectuant un vidage du tas et en l'analysant, vous pouvez en quelque sorte comprendre comment Java utilise la mémoire. Ici, un vidage de tas est acquis à l'aide de jcmd qui peut être utilisé à partir de Java 7.

# jcmd -l
899 org.apache.catalina.startup.Bootstrap start
4894 jdk.jcmd/sun.tools.jcmd.JCmd -l

# jcmd 899 GC.heap_dump /var/log/heapdump/heapdmp.hprof
899:
Heap dump file created

# ls
heapdmp.hprof

Analysez les vidages de tas avec les outils Java Visual VM

Vérifiez le vidage de tas acquis par jcmd avec un outil appelé Java Visual VM. Pour analyser, cela se fait dans l'environnement PC local (environnement avec interface graphique), mais JRE doit être installé au préalable.

Dans mon environnement, Java 1.8 a été mis en place et le chemin était en place.

$ java -version
java version "1.8.0_241"
Java(TM) SE Runtime Environment (build 1.8.0_241-b07)
Java HotSpot(TM) 64-Bit Server VM (build 25.241-b07, mixed mode)

Dans cet environnement, exécutez la commande suivante pour démarrer l'outil Java Visual VM.

$ jvisualvm

Spécifiez et ouvrez le fichier de vidage de tas obtenu à partir d'Open File.

Il semble que vous puissiez vérifier si des objets supplémentaires sont créés à partir du vidage du tas. Cependant, je m'attendais à ce que ce soit bien de pouvoir voir l'état d'utilisation de la mémoire et comment la mémoire est libérée par GC sur le graphique. Par conséquent, l'état d'utilisation de la mémoire ne peut être saisi que par ce vidage de tas, la cause peut être identifiée et elle peut être utilisée comme déclencheur pour une réponse permanente. J'ai pensé que ce serait difficile.

Analyse à l'aide de Java Monitoring & Management Console

Il semble qu'il soit possible d'analyser graphiquement l'état d'utilisation de la mémoire, etc. en utilisant un outil appelé JConsole. https://docs.oracle.com/javase/jp/8/docs/technotes/guides/management/jconsole.html

Ici, la JVM est surveillée par JConsole via l'agent JMX pour Tomcat construit sur le serveur CentOS à partir du PC local.

Ajout des paramètres liés à JMX aux options de démarrage JVM de Tomcat

Je pense qu'il existe différentes manières de spécifier l'option de démarrage JVM de Tomcat, mais ici, nous ajouterons le paramètre par la méthode spécifiée dans setenv.sh.

{tomcat-root}/bin/setenv.sh

#!/bin/sh

JAVA_OPTS="-server -Xms512M -Xmx2G -Dspring.profiles.active=production　-Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8888 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -Djava.rmi.server.hostname=192.168.33.10"

Dcom.sun.management.jmxremote.port spécifie le port utilisé par l'agent JMX. En supposant que Tomcat utilise le port 8080, j'ai spécifié un port autre que celui.

De plus, le paramètre Djava.rmi.server.hostname est spécifié pour accéder à distance au serveur Tomcat depuis le PC local et effectuer la surveillance JVM. Si vous ne spécifiez pas ce paramètre, lorsque vous essayez de vous connecter à 192.168.33.10: 8888 dans JConsole, vous recevrez un message tel que" La connexion sécurisée a échoué. Voulez-vous réessayer de manière non sécurisée? " J'ai essayé mais je n'ai pas pu me connecter. Soyez donc prudent si vous avez besoin d'un accès à distance.

Après avoir défini les paramètres ci-dessus et redémarré Tomcat, vérifiez que le port spécifié «8888» est correctement écouté.

# systemctl restart tomcat

# ss -antup | grep 8888
tcp   LISTEN  0       50                         *:8888                *:*       users:(("java",pid=4211,fd=17))  

# ps -ef | grep jmx

Démarrez Java Monitoring & Management Console (JConsole) et effectuez une surveillance JVM

Démarrez l'outil jconsole avec la commande suivante et vérifiez l'utilisation de la mémoire. La commande suivante est exécutée à partir du PC local. Veuillez noter que la commande jconsole ne peut être exécutée que si le JRE est pré-installé et que le chemin n'est pas transmis.

jconsole 192.168.33.10:8888

L'onglet Vue d'ensemble fournit une vue graphique de la façon dont la mémoire, les threads, les classes, l'utilisation du processeur, etc. sont utilisés au fil du temps. Il semble que les informations de cet onglet de présentation soient suffisantes pour l'analyse, mais vérifions quel est le contenu des autres onglets.

Analyse à l'aide de GC Viewer

GCViewer https://github.com/chewiebug/GCViewer/wiki/Changelog

L'analyse JConsole pouvait confirmer le nombre de fois où la GC s'est produite, mais ne savait pas quand la GC s'est produite. Alors, obtenez le journal GC et utilisez GCViewer pour vérifier la fréquence d'occurrence du GC et la quantité de mémoire libérée par GC, ainsi que l'état d'utilisation de la mémoire.

Obtenir le journal GC

Pour obtenir le journal GC, définissez les options JVM de Tomcat comme suit:

{tomcat-root}/bin/setenv.sh

JAVA_OPTS="-server -Xms512M -Xmx2G -Dspring.profiles.active=production -verbose:gc -Xlog:gc*=info:file=/var/log/gclog/gc.log:time,uptime,level,tags:filecount=1,filesize=10m"

Après avoir terminé les paramètres ci-dessus, redémarrez le service tomcat et laissez-le pendant un moment. (Faites fonctionner l'application Web sur Tomcat pendant un certain temps.)

Lorsque j'affiche le journal acquis avec gcviewer, il ressemble à ce qui suit.

Description de la légende du graphique GC Viewer

Il est affiché de différentes manières et je ne sais pas quelle couleur joue quel rôle. Vous pouvez afficher / masquer à quoi ressemble chaque couleur à partir de la vue du menu.

Les implications de chacun sont brièvement expliquées ci-dessous.

• Lignes GC complètes: (noir) --Ligne représentant Full GC --Inc GC Lines: (Cyan) --Ligne représentant GC incrémental --GC Times Line: (vert) --Une ligne indiquant le temps pris pour GC
• GC Times Rectangles:
• Le temps pris pour GC est représenté par un rectangle. Affiche la répartition du GC, etc. en fonction de la couleur. --Il semble être utilisé lorsque vous souhaitez vérifier plus en détail la répartition du temps pris pour GC (GC Times Line), mais je ne sais pas comment l'interpréter par l'expression de Rectangles. ..
• Tas total: (rouge) --Affiche la taille totale du tas.
• Si vous voulez vérifier comment la taille du tas change selon les paramètres de -Xms et -Xmx, vous pouvez également afficher et vérifier uniquement ce tas total. --Tenured Generation: (rose)
• La répartition de la zone de tas est Young Generation / Tenured Generation.
• Également exprimé en zone jeune et zone ancienne, il exprime la taille de la mémoire correspondant à la zone ancienne.
• Utilisé lors de l'analyse de l'état de la mémoire à l'aide de Young Generation / Tenured Generation sans utiliser Total Heap. --Ne peut être utilisé que si le paramètre JVM -PrintGCDetails est spécifié, mais dans Java 9 ou version ultérieure, il est nécessaire de spécifier le paramètre -Xlog: gc *.
• Jeune génération: (orange)
• La répartition de la zone de tas est Young Generation / Tenured Generation.
• Également exprimé en zone Young et zone Old, il exprime la taille de la mémoire correspondant à la zone Young.
• Utilisé lors de l'analyse de l'état de la mémoire à l'aide de Young Generation / Tenured Generation sans utiliser Total Heap. --Ne peut être utilisé que si le paramètre JVM -PrintGCDetails est spécifié, mais dans Java 9 ou version ultérieure, il est nécessaire de spécifier le paramètre -Xlog: gc *.
• Tas utilisé: (bleu)
• La ligne bleue représente la taille d'utilisation du tas. --Taille titulaire: (rose foncé)
• Représente la taille utilisée de l'ancienne zone. (C'est vraiment difficile à voir) -Utilisé jeune taille: (gris)
• Représente la taille d'utilisation de la zone Young. (C'est vraiment difficile à voir)
• Initial mark level: --ʻInitial-mark` Indique l'utilisation du tas dans l'événement
• Concurrent collections
  • Cyan vertical line for every begin (concurrent-mark-start) and pink vertical line for every end (CMS-concurrent-reset / G1: concurrent-cleanup-end) of a concurrent collection cycle

Exemple montrant uniquement le tas total et le GC complet

Si vous continuez à atteindre la taille spécifiée de -Xmx, vous pouvez voir que Full GC se produit fréquemment. De plus, à mesure que la taille du tas diminue après Full GC, la fréquence de Full GC semble avoir tendance à diminuer.

Cependant, il fut un temps où la GC complète ne se produisait pas fréquemment et la taille limite supérieure restait même lorsque la taille limite supérieure était bloquée.

Exemple montrant la répartition du tas (zone jeune et zone ancienne) et FullGC

Au lieu de Total Heap, la zone Young (Young Generation: orange) et Old area (Tenured Generation: rose) sont affichées comme ventilation, et l'état d'utilisation de la mémoire est analysé en combinaison avec Full GC.

L'histoire selon laquelle le paramètre JVM pour l'acquisition du journal GC a changé depuis Java 9 et a été perturbé

J'ai cherché Google et vérifié l'option JVM pour obtenir le journal GC, et j'ai trouvé l'option suivante, alors je l'ai essayée.

{tomcat-root}/bin/setenv.sh

JAVA_OPTS="-server -Xms512M -Xmx2G -Dspring.profiles.active=production -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/var/log/gclog/gc.log"

Après avoir terminé les paramètres ci-dessus, lorsque j'ai redémarré le service tomcat, l'application Web créée avec Tomcat a cessé de fonctionner. Lorsque j'enquêtais sur la raison pour laquelle cela avait cessé de fonctionner, j'ai trouvé l'erreur suivante.

{tomcat-root}/logs/catalina.out

Unrecognized VM option 'PrintGCDateStamps'
Error: Could not create the Java Virtual Machine.
Error: A fatal exception has occurred. Program will exit.
NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAM

Apparemment, certains paramètres JVM ne sont plus disponibles dans Java 9 ou version ultérieure (la JVM ne peut pas être démarrée lorsqu'elle est utilisée). Par conséquent, vous devez remplacer le paramètre indisponible par un autre paramètre.

https://docs.oracle.com/javase/9/tools/java.htm#JSWOR624

Des informations sur les paramètres de remplacement pouvant être utilisés comme référence peuvent être trouvées dans la section Convertir les indicateurs de journalisation GC en Xlog de ce site. Cependant, tous les paramètres ne sont pas remplacés sur une base individuelle, ce qui est un peu déroutant.

Exemples d'analyse et de prise en compte spécifiques de la mémoire

L'utilisation de la mémoire de la zone de tas est bloquée au plafond tout le temps

En regardant le graphique ci-dessous, l'utilisation de la mémoire n'a pas baissé à environ 1,4 Go depuis un certain temps.

Si vous regardez l'état des threads vers 20h41 lorsque l'utilisation de la mémoire a soudainement augmenté, vous pouvez voir que le nombre de threads a atteint son maximum à peu près au même moment. Cependant, étant donné que le nombre d'exécutions de threads a atteint la limite inférieure en quelques minutes après cela, on suppose qu'un accès fréquent simultané temporaire peut avoir eu lieu.

Le fait que l'utilisation de la mémoire du tas ne s'est pas améliorée du tout même après que le nombre de threads a diminué signifie qu'il peut y avoir des objets qui ne sont pas détruits même si un GC se produit.

Si vous vérifiez l'état d'utilisation tel que la mémoire du serveur à ce moment avec la commande top, cela ressemble à ce qui suit.

# top -p 923

top - 11:53:47 up  1:01,  1 user,  load average: 0.00, 0.03, 0.05
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
top - 11:54:02 up  1:01,  1 user,  load average: 0.00, 0.03, 0.05
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.0 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.3 hi,  0.3 si,  0.0 st
MiB Mem :   3939.0 total,   1342.6 free,   1657.3 used,    939.1 buff/cache
MiB Swap:   2048.0 total,   2048.0 free,      0.0 used.   2060.3 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                     
  923 root      20   0 4278196   1.5g  31744 S   0.0  39.7   1:09.33 java  

-Image virtuelle VIRT. Toute la mémoire virtuelle réservée. Comprend l'utilisation de la mémoire permutée. (Unité: kb) ―― Puisqu'il s'agit d'environ 4 Go, vous pouvez voir que le traitement qui devait utiliser la mémoire jusqu'à 4 Go, y compris le traitement permuté, s'est produit pour Tomcat qui a été exécuté en spécifiant 2 Go avec -Xmx. --RES La taille de la mémoire physique utilisée, non permutée. --1,5 Go J'ai utilisé la mémoire physique sans réellement permuter.

S'il ne s'agit que d'un focus temporaire, vous n'avez pas besoin de revoir le paramètre -Xmx, mais si cela se produit fréquemment, vous devrez peut-être augmenter le maximum de mémoire.

Voici un graphique montrant que l'état d'utilisation de la mémoire s'est amélioré immédiatement avant 21h00.

Le résultat de la commande top dans cet état

# top -p 923

top - 12:04:03 up  1:11,  1 user,  load average: 0.09, 0.04, 0.01
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3939.0 total,   1340.3 free,   1659.6 used,    939.1 buff/cache
MiB Swap:   2048.0 total,   2048.0 free,      0.0 used.   2058.0 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                     
  923 root      20   0 4278196   1.5g  31744 S   0.3  39.8   1:12.06 java    

En particulier, les valeurs de VIRT, RES, SHR, etc. n'ont pas changé. À partir de là, nous pouvons voir que la commande top ne peut voir que la valeur maximale de la mémoire qui a bondi temporairement comme un instantané.