Quel thread Java monopolise le processeur?

Identifier quel thread Java consomme le plus de CPU dans le serveur de production.

La plupart (sinon tous) des systèmes productifs faisant quelque chose d'important utiliseront plus de 1 thread java. Et quand quelque chose devient fou et que votre utilisation du processeur est à 100%, il est difficile d'identifier quel(s) thread (s) est/est à l'origine de cela. Ou alors j'ai pensé. Jusqu'à ce que quelqu'un de plus intelligent que moi me montre comment cela peut être fait. Et ici je vais vous montrer comment le faire et vous aussi pouvez étonner votre famille et vos amis avec votre geek compétence.

Une application de test

Pour tester cela, nous avons besoin d'une application de test. Je vais donc vous donner un. Il se compose de 3 classes:

• Une classe HeavyThread qui fait quelque chose de CPU intensif (calcul des hachages MD5)
• Une classe LightThread qui fait quelque chose de pas si intensif en cpu (compter et dormir).
• Une classe StartThreads pour démarrer 1 processeur intensif et plusieurs threads légers.

Voici le code pour ces cours:

import java.security.MessageDigest;
import java.security.NoSuchAlgorithmException;
import java.util.UUID;

/**
 * thread that does some heavy lifting
 *
 * @author srasul
 *
 */
public class HeavyThread implements Runnable {

        private long length;

        public HeavyThread(long length) {
                this.length = length;
                new Thread(this).start();
        }

        @Override
        public void run() {
                while (true) {
                        String data = "";

                        // make some stuff up
                        for (int i = 0; i < length; i++) {
                                data += UUID.randomUUID().toString();
                        }

                        MessageDigest digest;
                        try {
                                digest = MessageDigest.getInstance("MD5");
                        } catch (NoSuchAlgorithmException e) {
                                throw new RuntimeException(e);
                        }

                        // hash the data
                        digest.update(data.getBytes());
                }
        }
}


import java.util.Random;

/**
 * thread that does little work. just count & sleep
 *
 * @author srasul
 *
 */
public class LightThread implements Runnable {

        public LightThread() {
                new Thread(this).start();
        }

        @Override
        public void run() {
                Long l = 0l;
                while(true) {
                        l++;
                        try {
                                Thread.sleep(new Random().nextInt(10));
                        } catch (InterruptedException e) {
                                e.printStackTrace();
                        }
                        if(l == Long.MAX_VALUE) {
                                l = 0l;
                        }
                }
        }
}


/**
 * start it all
 *
 * @author srasul
 *
 */
public class StartThreads {

        public static void main(String[] args) {
                // lets start 1 heavy ...
                new HeavyThread(1000);

                // ... and 3 light threads
                new LightThread();
                new LightThread();
                new LightThread();
        }
}

En supposant que vous n'avez jamais vu ce code, et tout ce que vous avez un PID d'un processus Java en cours d'exécution qui exécute ces classes et consomme 100% CPU.

Commençons d'abord la classe StartThreads.

$ ls
HeavyThread.java  LightThread.java  StartThreads.java
$ javac *
$ java StartThreads &

A ce stade, un processus Java en cours d'exécution devrait prendre 100 cpu. Dans mon haut je vois:

En haut, appuyez sur Shift-H qui active les Threads. La page de manuel pour top dit:

   -H : Threads toggle
        Starts top with the last remembered 'H' state reversed.  When
        this  toggle is On, all individual threads will be displayed.
        Otherwise, top displays a  summation  of  all  threads  in  a
        process.

Et maintenant dans mon haut avec l'affichage des fils allumé je voir:

Et j'ai un processus java avec PID 28294. Permet d'obtenir le vidage de pile de ce processus en utilisant jstack:

$ jstack 28924
2010-11-18 13:05:41
Full thread dump Java HotSpot(TM) 64-Bit Server VM (17.0-b16 mixed mode):

"Attach Listener" daemon prio=10 tid=0x0000000040ecb000 nid=0x7150 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" prio=10 tid=0x00007f9a98027800 nid=0x70fd waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Thread-3" prio=10 tid=0x00007f9a98025800 nid=0x710d waiting on condition [0x00007f9a9d543000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at LightThread.run(LightThread.java:21)
    at java.lang.Thread.run(Thread.java:619)

"Thread-2" prio=10 tid=0x00007f9a98023800 nid=0x710c waiting on condition [0x00007f9a9d644000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at LightThread.run(LightThread.java:21)
    at java.lang.Thread.run(Thread.java:619)

"Thread-1" prio=10 tid=0x00007f9a98021800 nid=0x710b waiting on condition [0x00007f9a9d745000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at LightThread.run(LightThread.java:21)
    at java.lang.Thread.run(Thread.java:619)

"Thread-0" prio=10 tid=0x00007f9a98020000 nid=0x710a runnable [0x00007f9a9d846000]
   java.lang.Thread.State: RUNNABLE
    at sun.security.provider.DigestBase.engineReset(DigestBase.java:139)
    at sun.security.provider.DigestBase.engineUpdate(DigestBase.java:104)
    at java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:538)
    at java.security.MessageDigest.update(MessageDigest.java:293)
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:197)
    - locked <0x00007f9aa457e400> (a sun.security.provider.SecureRandom)
    at sun.security.provider.NativePRNG$RandomIO.implNextBytes(NativePRNG.java:257)
    - locked <0x00007f9aa457e708> (a java.lang.Object)
    at sun.security.provider.NativePRNG$RandomIO.access$200(NativePRNG.java:108)
    at sun.security.provider.NativePRNG.engineNextBytes(NativePRNG.java:97)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:433)
    - locked <0x00007f9aa4582fc8> (a java.security.SecureRandom)
    at java.util.UUID.randomUUID(UUID.java:162)
    at HeavyThread.run(HeavyThread.java:27)
    at java.lang.Thread.run(Thread.java:619)

"Low Memory Detector" daemon prio=10 tid=0x00007f9a98006800 nid=0x7108 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x00007f9a98004000 nid=0x7107 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x00007f9a98001000 nid=0x7106 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x0000000040de4000 nid=0x7105 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x0000000040dc4800 nid=0x7104 in Object.wait() [0x00007f9a97ffe000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00007f9aa45506b0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
    - locked <0x00007f9aa45506b0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x0000000040dbd000 nid=0x7103 in Object.wait() [0x00007f9a9de92000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00007f9aa4550318> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:485)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
    - locked <0x00007f9aa4550318> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x0000000040db8800 nid=0x7102 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000040d6e800 nid=0x70fe runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000040d70800 nid=0x70ff runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x0000000040d72000 nid=0x7100 runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000040d74000 nid=0x7101 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007f9a98011800 nid=0x7109 waiting on condition 

JNI global references: 910

De mon haut, je vois que le PID du fil supérieur est 28938. Et 28938 dans l'hexagone 0x710A. Notez que dans le vidage de la pile, chaque thread a un nid qui est dispalyed en hexadécimal. Et il se trouve que 0x710A est l'id du thread:

"Thread-0" prio=10 tid=0x00007f9a98020000 nid=0x710a runnable [0x00007f9a9d846000]
   java.lang.Thread.State: RUNNABLE
    at sun.security.provider.DigestBase.engineReset(DigestBase.java:139)
    at sun.security.provider.DigestBase.engineUpdate(DigestBase.java:104)
    at java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:538)
    at java.security.MessageDigest.update(MessageDigest.java:293)
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:197)
    - locked <0x00007f9aa457e400> (a sun.security.provider.SecureRandom)
    at sun.security.provider.NativePRNG$RandomIO.implNextBytes(NativePRNG.java:257)
    - locked <0x00007f9aa457e708> (a java.lang.Object)
    at sun.security.provider.NativePRNG$RandomIO.access$200(NativePRNG.java:108)
    at sun.security.provider.NativePRNG.engineNextBytes(NativePRNG.java:97)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:433)
    - locked <0x00007f9aa4582fc8> (a java.security.SecureRandom)
    at java.util.UUID.randomUUID(UUID.java:162)
    at HeavyThread.run(HeavyThread.java:27)
    at java.lang.Thread.run(Thread.java:619)

Et vous pouvez donc confirmer que le thread qui exécute la classe HeavyThread consomme le plus CPU.

Dans les situations de lecture du monde, ce sera probablement un tas de threads qui consommeront une partie du CPU et ces threads mis ensemble conduiront au processus Java en utilisant 100% CPU.

Résumé

• Exécuter en haut
• Appuyez sur Shift-H pour activer la vue Threads
• Obtenir le PID du thread avec le CPU le plus élevé
• Convertir PID en HEX
• Obtenir un vidage de pile du processus java
• Recherchez le thread avec le PID hexadécimal correspondant.

Jvmtop peut vous montrer les principaux threads consommateurs:

    TID NAME                                 STATE     CPU    TOTALCPU
     25 http-8080-Processor13                RUNNABLE  4.55%     1.60%
 128022 RMI TCP Connection(18)-10.101.       RUNNABLE  1.82%     0.02%
  36578 http-8080-Processor164               RUNNABLE  0.91%     2.35%
 128026 JMX server connection timeout   TIMED_WAITING  0.00%     0.00%

Lancez simplement JVisualVM, connectez-vous à votre application et utilisez la vue thread. Celui qui reste continuellement actif est votre coupable le plus probable.

Jetez un oeil au pluginTop Threads pour JConsole.

Si vous exécutez sous Windows, essayez Process Explorer. Ouvrez la boîte de dialogue Propriétés de votre processus, puis sélectionnez l'onglet Threads.

Prenez un vidage de thread. Attendez 10 secondes. Prenez un autre vidage de thread. Répétez une fois de plus. Inspectez les vidages de threads et voyez quels threads sont bloqués au même endroit ou traitent la même demande. C'est une façon manuelle de le faire, mais souvent utile.

Utilisez-vous Java 6 sur un ordinateur multicœur?

Il y a de fortes chances que vous souffriez d'un problème que je viens de décrire dans un article sur la famine des fils.

Voir Synchronisé vs Verrouillage vs juste de Verrouillage.

Je recommanderais de jeter un oeil à Arthas outil open source par Alibaba.

, Il contient un tas de commandes utiles qui peuvent vous aider à déboguer votre code de production:

• Dashboard : Aperçu de votre processus Java
• SC : Classe de recherche Chargée par votre JVM
• Jad : Décompiler La Classe En Code Source
• Regarder : Afficher l'entrée et les résultats de l'invocation de la méthode
• Trace : Trouvez le goulot d'étranglement de votre Invocation de méthode
• Monitor : Afficher les statistiques d'invocation de méthode
• Stack : Afficher la pile d'appels de la méthode
• Tt : Tunnel temporel des invocations de méthode

Exemple du tableau de bord:

C'est une sorte de manière hacky, mais il semble que vous puissiez lancer l'application dans un débogueur, puis suspendre tous les threads, et parcourir le code et savoir lequel ne bloque pas sur un verrou ou un appel d'E/S dans une sorte de boucle. Ou est-ce comme ce que vous avez déjà essayé?

Une option que vous pourriez envisager est d'interroger vos threads pour la réponse à partir de l'application. Via le ThreadMXBean , vous pouvez interroger l'utilisation du processeur des threads à partir de votre application Java et interroger les traces de la pile des threads incriminés.

L'option ThreadMXBean vous permet de construire ce type de surveillance dans votre application en direct. Il a un impact négligeable et a l'avantage que vous pouvez lui faire faire exactement ce que vous voulez.

Si vous pensez que VisualVM est un bon outil, essayez-le (car il le fait) Découvrez que les threads ne vous aident que dans la direction générale de la raison pour laquelle il consomme autant de CPU.

Cependant, si c'est évident, j'irais directement à l'aide d'un profileur pour savoir pourquoi vous consommez autant de CPU.