Wie sieht Thread-Dump aus, wenn JVM Zeit in GC verbracht hat?

Question

Bei der Profilerstellung von Java-Anwendungen stelle ich interessante Fakten fest.Wenn sich JVM in der GC-Spirale des Todes befindet, sieht der Thread-Dump folgendermaßen aus:

"1304802943@qtp-393978767-9985" prio=10 tid=0x00007f3ed02dd000 nid=0x74e7 in Object.wait() [0x000000004febb000]
 java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed40048> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

"26774405@qtp-393978767-9984" prio=10 tid=0x00007f3ee4b37000 nid=0x74e6 in Object.wait() [0x0000000045d1a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed83aa0> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

"764808089@qtp-393978767-9983" prio=10 tid=0x00007f3ee4c50000 nid=0x74e5 in Object.wait() [0x000000004ad6a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed5c448> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

Es gibt also viele Threads im TIMED_WAITING-Status.Theoretisch könnte diese Situation in einer normal funktionierenden Anwendung leicht gefunden werden (die Anwendung hat im Moment einfach keine eingehenden Anfragen), aber ich kann nicht einmal einen einzelnen Anfrage-Dispatching-Thread finden, der etwas Nützliches tut (die nominale Trefferquote beträgt etwa 100 PS).

Hat dieses Verhalten etwas mit GC zu tun oder ist es nur Zufall?

Answer 1

Beantworten Sie nur den Titel der Frage:

Wie sieht ein Thread-Dump aus, wenn JVM Zeit in GC verbracht hat?

Die Antwort lautet: Sie haben keine Möglichkeit, einen solchen Speicherauszug (auf übliche Weise) zu erhalten.

JVM verarbeitet die Anforderung für den Thread-Dump erst, nachdem safepoint was im GC einfach nicht passieren kann.

Es gibt jedoch eine betrügerische Möglichkeit, den Thread-Dump des aktiven GC mithilfe der undokumentierten JVMTI-Funktion AsyncGetCallTrace abzurufen, die in diesem Beitrag erwähnt wird:

http://jeremymanson.blogspot.com/ 2010/07 / warum-viele-Profiler-haben-ernst.html

Es wird auch darauf hingewiesen, dass Oracle Solaris Studio wird verwendet , um solche gemischten nativen / Java-Thread-Dumps zu erstellen.

Answer 2

Versuchen Sie es mit einer jmap -histo: Wenn Sie im Laufe der Zeit leben, können Sie die Ausgabe vergleichen und sehen, welche Objekttypen wachsen.

Sie müssen das JDK für jmap installiert haben. http://docs.oracle.com/javase/6/docs/technotes/tools/share/jmap.html

Eine Warnung, jmap ist intensiv, es werden alle Threads angehalten, während es ausgeführt wird. Dies sollte nur einige Sekunden dauern.Prozesse können Core Dump sein, weil es intensiv ist, im Allgemeinen schnell und sicher, aber ich habe gesehen, dass es große Anwendungen, Multi-Gig-Heaps, blockiert oder beendet.

Answer 3

Ich vermute, Sie haben einen Thread-Pool, der darauf wartet, dass etwas getan wird.Wenn Ihr Prozess effizient ist und Sie sogar 100 Anfragen pro Sekunde haben, haben Sie möglicherweise Probleme, auch nur einen Thread zu fangen, der etwas tut.Ich schlage vor, Sie sehen sich die CPU-Auslastung Ihres Prozesses an.Wenn es 50% sind, haben Sie eine 50% ige Chance, einen Thread (möglicherweise keinen Anfragethread) zu finden, der etwas tut.

Wenn Sie sehen möchten, was Ihr Server seine Zeit verbringt, würde ich einen Profiler wie VisualVM oder einen kommerziellen Profiler wie YourKit ausprobieren.

Bei einer Google-Suche nach Ihrem Code habe ich eine andere Version gefunden. http://grepcode.com/file/repo1.maven.org/maven2/org.mortbay.jetty/jetty-util/7.0.0.pre5 / org / mortbay / thread / QueuedThreadPool.java Ich vermute jedoch, dass Ihre Threads in diesem Block TIMED_WAIT sind, wenn er die Methode run () ausführt

                // We are idle
                // wait for a dispatched job
                synchronized (this)
                {
                    if (_job==null)
                        this.wait(getMaxIdleTimeMs());
                    job=_job;
                    _job=null;
                }