GC uscita chiarimento

Question

Sono in esecuzione un'applicazione Java con le seguenti impostazioni:
-XX: + CMSParallelRemarkEnabled
-XX: + UseConcMarkSweepGC
-XX: + UseParNewGC
-XX: + PrintGCApplicationStoppedTime
-XX : + PrintGCApplicationConcurrentTime
-XX: + PrintGCDetails
-XX: + PrintGCTimeStamps
-XX: + PrintGCDateStamps
-XX: + PrintHeapAtGC
-XX: + PrintTenuringDistribution

Non so come interpretare i relativi log gc (sotto). In particolare:

• Heap dopo invocazioni GC = 31 (full 3): significa c'erano 31 minori GC e GC 3 pieno?

• Che cosa fa scattare le diverse linee consecutive di Tempo totale per il quale i thread delle applicazioni sono stati fermati eApplication tempo? È possibile ottenere i timestamp associati a ciascuna di queste righe?

tronchi GC:

 
Total time for which application threads were stopped: 0.0046910 seconds 
Application time: 0.7946670 seconds 
Total time for which application threads were stopped: 0.0002900 seconds 
Application time: 1.0153640 seconds 
Total time for which application threads were stopped: 0.0002780 seconds 
Application time: 1.0161890 seconds 
Total time for which application threads were stopped: 0.0002760 seconds 
Application time: 1.0145990 seconds 
Total time for which application threads were stopped: 0.0002950 seconds 
Application time: 0.9999800 seconds 
Total time for which application threads were stopped: 0.0002770 seconds 
Application time: 1.0151640 seconds 
Total time for which application threads were stopped: 0.0002730 seconds 
Application time: 0.9996590 seconds 
Total time for which application threads were stopped: 0.0002880 seconds 
Application time: 0.9624290 seconds 

{Heap before GC invocations=30 (full 3): 
par new generation total 131008K, used 130944K [0x00000000eac00000, 0x00000000f2c00000, 0x00000000f2c00000) 
    eden space 130944K, 100% used [0x00000000eac00000, 0x00000000f2be0000, 0x00000000f2be0000) 
    from space 64K, 0% used [0x00000000f2bf0000, 0x00000000f2bf0000, 0x00000000f2c00000) 
    to space 64K, 0% used [0x00000000f2be0000, 0x00000000f2be0000, 0x00000000f2bf0000) 
concurrent mark-sweep generation total 131072K, used 48348K [0x00000000f2c00000, 0x00000000fac00000, 0x00000000fac00000) 
concurrent-mark-sweep perm gen total 30000K, used 19518K [0x00000000fac00000, 0x00000000fc94c000, 0x0000000100000000) 

2010-05-11T09:30:13.888+0100: 384.955: [GC 384.955: [ParNew 
Desired survivor size 32768 bytes, new threshold 0 (max 0) 
: 130944K->0K(131008K), 0.0052470 secs] 179292K->48549K(262080K), 0.0053030 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 

Heap after GC invocations=31 (full 3): 
par new generation total 131008K, used 0K [0x00000000eac00000, 0x00000000f2c00000, 0x00000000f2c00000) 
    eden space 130944K, 0% used [0x00000000eac00000, 0x00000000eac00000, 0x00000000f2be0000) 
    from space 64K, 0% used [0x00000000f2be0000, 0x00000000f2be0000, 0x00000000f2bf0000) 
    to space 64K, 0% used [0x00000000f2bf0000, 0x00000000f2bf0000, 0x00000000f2c00000) 
concurrent mark-sweep generation total 131072K, used 48549K [0x00000000f2c00000, 0x00000000fac00000, 0x00000000fac00000) 
concurrent-mark-sweep perm gen total 30000K, used 19518K [0x00000000fac00000, 0x00000000fc94c000, 0x0000000100000000) 
} 

Total time for which application threads were stopped: 0.0056410 seconds 
Application time: 0.0475220 seconds 
Total time for which application threads were stopped: 0.0001800 seconds 
Application time: 1.0174830 seconds 
Total time for which application threads were stopped: 0.0003820 seconds 
Application time: 1.0126350 seconds 
Total time for which application threads were stopped: 0.0002750 seconds 
Application time: 1.0155910 seconds 
Total time for which application threads were stopped: 0.0002680 seconds 
Application time: 1.0155580 seconds 
Total time for which application threads were stopped: 0.0002880 seconds 
Application time: 1.0155480 seconds 
Total time for which application threads were stopped: 0.0002970 seconds 
Application time: 0.9896810 seconds 

Answer 1

quelle righe senza data e ora non sono eventi gc, registrano quando si verificano i punti di sicurezza e per quanto tempo sono durati. Pre 6u21 sono in qualche modo inaffidabili.

Answer 2

Sì, questo è il numero di collezioni minori e maggiori insieme. C'erano 28 GC minori e 3 GC principali.

Le raccolte secondarie attivano quelle linee che citi. Se non ci sono timestamp, non penso che si possa forzarli a non modificare la JVM. Tuttavia, è a mia conoscenza che "Tempo di applicazione" è l'ora in cui l'app è stata eseguita dall'ultima raccolta secondaria (pausa), in modo che potesse darti quello che vuoi. È, credo, almeno un delta temporale dall'ultima uscita.

Answer 3

I timestamp corrispondono a ciascuna voce.

Un campione dal mio registro del server mostra

124951.831: [GC 1915727K->1295438K(1994752K), 0.1964641 secs] 
Total time for which application threads were stopped: 0.1983187 seconds 
125015.262: [GC 1909838K->1302111K(1994752K), 0.2037094 secs] 
Total time for which application threads were stopped: 0.2055489 seconds 

Il 124.951,831 e 125.015,262 in questo caso è ha iniziato il numero di secondi trascorsi dal JVM.

124951.831 corrisponde a 34 ore, 42 minuti, 31 secondi di tempo di attività JVM.

125015.262 corrisponde a 34 ore, 43 minuti, 35 secondi di tempo di attività JVM.

È necessario correlare questo all'indietro all'orario di inizio del server, e quindi è possibile ottenere i timestamp.

La differenza è importante (125015 - 124951) indica che il GC Minore è stato avviato dopo 64 secondi (nel mio caso).

Queste righe di data e ora mancano nel registro?