Utilizzo delle informazioni verbose: gc (solo perAIX, Linux )

È possibile utilizzare l'opzione -verbose:gc con l'opzione -Xgc:verboseGCCycleTime=N per scrivere informazioni sulla console relative all'attività del programma di raccolta dati inutilizzati Metronome. Non tutte le proprietà XML nell'output -verbose:gc dalla JVM standard vengono create o applicate all'output del programma di raccolta dati inutilizzati Metronome.

Utilizzare l'opzione -verbose:gc per visualizzare lo spazio libero minimo, massimo e medio nell'heap. In questo modo, è possibile controllare il livello di attività e l'utilizzo dell'heap, quindi regolare i valori, se necessario. L'opzione -verbose:gc scrive le statistiche Metronome nella console.

L'opzione -Xgc:verboseGCCycleTime=N controlla la frequenza di richiamo delle informazioni. Determina il tempo in millisecondi in cui viene eseguito il dump dei riepiloghi. Il valore predefinito per N è 1000 millisecondi. Il tempo di ciclo non significa che il riepilogo viene scaricato esattamente in quel momento, ma quando l'ultimo evento di raccolta dati inutilizzati che soddisfa questo criterio di tempo viene superato. La raccolta e la visualizzazione di queste statistiche possono aumentare i tempi di pausa di Metronome Garbage Collector e, man mano che N diminuisce, i tempi di pausa possono diventare grandi.

Un quantum è un singolo periodo di attività del Garbage Collector di Metronome, che causa un'interruzione o un tempo di pausa per un'applicazione.

Esempio di output verbose: gc

Immettere:

java -Xgcpolicy:metronome -verbose:gc -Xgc:verboseGCCycleTime=N myApplication
Quando viene attivata la raccolta dati inutilizzati, si verifica un evento avvio trigger , seguito da qualsiasi numero di eventi heartbeat , quindi un evento fine trigger quando il trigger viene soddisfatto. Questo esempio mostra un ciclo di raccolta dati inutilizzati attivato come output verbose:gc :
<trigger-start id="25" timestamp="2011-07-12T09:32:04.503" /> 

<cycle-start id="26" type="global" contextid="26" timestamp="2011-07-12T09:32:04.503" intervalms="984.285" /> 

<gc-op id="27" type="heartbeat" contextid="26" timestamp="2011-07-12T09:32:05.209">   
  <quanta quantumCount="321" quantumType="mark" minTimeMs="0.367" meanTimeMs="0.524" maxTimeMs="1.878" 
    maxTimestampMs="598704.070" />   
  <exclusiveaccess-info minTimeMs="0.006" meanTimeMs="0.062" maxTimeMs="0.147" />   
  <free-mem type="heap" minBytes="99143592" meanBytes="114374153" maxBytes="134182032" />   
  <thread-priority maxPriority="11" minPriority="11" />
</gc-op> 

<gc-op id="28" type="heartbeat" contextid="26" timestamp="2011-07-12T09:32:05.458">   
  <quanta quantumCount="115" quantumType="sweep" minTimeMs="0.430" meanTimeMs="0.471" maxTimeMs="0.511" 
    maxTimestampMs="599475.654" />   
  <exclusiveaccess-info minTimeMs="0.007" meanTimeMs="0.067" maxTimeMs="0.173" />   
  <classunload-info classloadersunloaded=9 classesunloaded=156  />     
  <references type="weak" cleared="660" />   
  <free-mem type="heap" minBytes="24281568" meanBytes="55456028" maxBytes="87231320" />   
  <thread-priority maxPriority="11" minPriority="11" />
</gc-op> 

<gc-op id="29" type="syncgc" timems="136.945" contextid="26" timestamp="2011-07-12T09:32:06.046">   
  <syncgc-info reason="out of memory" exclusiveaccessTimeMs="0.006" threadPriority="11" />   
  <free-mem-delta type="heap" bytesBefore="21290752" bytesAfter="171963656" />
</gc-op> 

<cycle-end id="30" type="global" contextid="26" timestamp="2011-07-12T09:32:06.046" /> 

<trigger-end id="31" timestamp="2011-07-12T09:32:06.046" />

Possono verificarsi i seguenti tipi di evento:

< avvio trigger ...>
L'inizio di un ciclo di raccolta dati inutilizzati, quando la quantità di memoria utilizzata è diventata superiore alla soglia di trigger. La soglia predefinita è 50% dell'heap. L'attributo intervalms è l'intervallo tra l'evento trigger end precedente (con id-1) e questo evento trigger start .
< fine - trigger ...>
Un ciclo di raccolta dati inutilizzati ha ridotto correttamente la quantità di memoria utilizzata al di sotto della soglia di trigger. Se un ciclo di raccolta dati inutilizzati è terminato, ma la memoria utilizzata non è stata inferiore alla soglia del trigger, viene avviato un nuovo ciclo di raccolta dati inutilizzati con lo stesso ID contesto. Per ogni evento trigger start , esiste un evento trigger end corrispondente con lo stesso ID contesto. L'attributo intervalms è l'intervallo tra l'evento trigger start precedente e quello trigger end corrente. Durante questo periodo, uno o più cicli di raccolta dati inutilizzati verranno completati fino a quando la memoria utilizzata non scenderà al di sotto della soglia di trigger.
< gc-op id="28 "type="heartbeat" ...>
Un evento periodico che raccoglie informazioni (sulla memoria e sull'ora) su tutti i quantum di raccolta dati inutilizzati per il tempo coperto. Un evento heartbeat può verificarsi solo tra una coppia corrispondente di eventi trigger start e trigger end , ossia mentre è in corso un ciclo di raccolta dati inutilizzati attivo. L'attributo " intervalms " è l'intervallo tra l'evento heartbeat precedente (con " id " -1) e questo evento heartbeat.
< gc-op id="29 "type="syncgc" ...>
Un evento di raccolta dati inutilizzati sincrono (non deterministico). Vedere Raccolte dati inutilizzati sincrone
Le tag XML in questo esempio hanno i seguenti significati:
< quantum ...>
Un riepilogo dei tempi di pausa quantistici durante l'intervallo heartbeat, inclusa la lunghezza delle pause in millisecondi.
< tipo di memoria libera = "heap " ...>
Un riepilogo della quantità di spazio heap libero durante l'intervallo di heartbeat, campionato alla fine di ogni quantum della raccolta dati inutilizzati.
< classunload - info classloadersunloaded=9 classesunloaded=156 />
Il numero di programmi di caricamento classi e di classi scaricati durante l'intervallo heartbeat.
< references type="weak " cleared="660 />
Il numero e il tipo di oggetti di riferimento Java™ eliminati durante l'intervallo di heartbeat.
Nota:
  • Se solo un quantum di raccolta dati inutilizzati si è verificato nell'intervallo tra due heartbeat, la memoria libera viene campionata solo alla fine di questo quantum. Pertanto, le quantità minima, massima e media fornite nel riepilogo heartbeat sono tutte uguali.
  • L'intervallo tra due eventi heartbeat potrebbe essere significativamente maggiore del tempo di ciclo specificato se l'heap non è abbastanza pieno per richiedere l'attività di raccolta dati inutilizzati. Ad esempio, se il programma richiede l'attività di raccolta dati inutilizzati solo una volta ogni pochi secondi, è probabile che venga visualizzato un heartbeat solo una volta ogni pochi secondi.
  • È possibile che l'intervallo sia significativamente maggiore del tempo di ciclo specificato poiché la raccolta dati inutilizzati non ha alcun lavoro su un heap che non è abbastanza pieno da garantire l'attività di raccolta dati inutilizzati. Ad esempio, se il programma richiede l'attività di raccolta dati inutilizzati solo una volta ogni pochi secondi, è probabile che venga visualizzato un heartbeat solo una volta ogni pochi secondi.

    Se si verifica un evento come una raccolta dati inutilizzati sincrona o una modifica della priorità, i dettagli dell'evento e tutti gli eventi in sospeso, come gli heartbeat, vengono immediatamente prodotti come output.

  • Se il quantum massimo della raccolta dati inutilizzati per un determinato periodo è troppo grande, è possibile ridurre l'utilizzo di destinazione utilizzando l'opzione -Xgc:targetUtilization . Questa azione fornisce al programma di raccolta dati inutilizzati più tempo per lavorare. In alternativa, è possibile aumentare la dimensione heap con l'opzione -Xmx . Allo stesso modo, se l'applicazione può tollerare ritardi più lunghi di quelli attualmente riportati, è possibile aumentare l'utilizzo di destinazione o diminuire la dimensione heap.
  • L'output può essere reindirizzato a un file log invece che alla console con l'opzione -Xverbosegclog:<file> ; ad esempio, -Xverbosegclog:out scrive l'output -verbose:gc nel file out.
  • La priorità elencata in thread-priority è la priorità del thread del sistema operativo sottostante, non una priorità del thread Java.

Raccolte dati inutilizzati sincrone

Una voce viene scritta anche nel log -verbose:gc quando si verifica una raccolta dati inutilizzati sincrona (non deterministica). Questo evento ha tre possibili cause:
  • Una chiamata System.gc() esplicita nel codice.
  • La JVM esaurisce la memoria, quindi esegue una raccolta dati inutilizzati sincrona per evitare una condizione OutOfMemoryError .
  • La JVM viene chiusa durante una raccolta dati inutilizzati continua. La JVM non può annullare la raccolta, quindi completa la raccolta in modo sincrono e quindi esce.
Un esempio di una voce System.gc() è:
<gc-op id="9" type="syncgc" timems="12.92" contextid="8" timestamp=
"2011-07-12T09:41:40.808">
  <syncgc-info reason="system GC" totalBytesRequested="260" exclusiveaccessTimeMs="0.009" 
  threadPriority="11" />
  <free-mem-delta type="heap" bytesBefore="22085440" bytesAfter="136023450" />
  <classunload-info classloadersunloaded="54" classesunloaded="234" />
  <references type="soft" cleared="21" dynamicThreshold="29" maxThreshold="32" />
  <references type="weak" cleared="523" />
  <finalization enqueued="124" />
</gc-op> 
Un esempio di una voce di raccolta dati inutilizzati sincrona come risultato dell'arresto di JVM è:
<gc-op id="24" type="syncgc" timems="6.439" contextid="19" timestamp="2011-07-12T09:43:14.524">   
  <syncgc-info reason="VM shut down" exclusiveaccessTimeMs="0.009" threadPriority="11" />   
  <free-mem-delta type="heap" bytesBefore="56182430" bytesAfter="151356238" />   
  <classunload-info classloadersunloaded="14" classesunloaded="276" />   
  <references type="soft" cleared="154" dynamicThreshold="29" maxThreshold="32" /> 
  <references type="weak" cleared="53" />   
  <finalization enqueued="34" />
</gc-op>
Le tag XML e gli attributi in questo esempio hanno i seguenti significati:
< gc-op id="9 "type="syncgc" timems= "6.439" ...
Questa riga indica che il tipo di evento è una raccolta dati inutilizzati sincrona. L'attributo timems è la durata della raccolta dati inutilizzati sincrona in millisecondi.
< syncgc - info motivo=" ... " />
La causa della raccolta dati inutilizzati sincrona.
< delta - mem - libero .../>
La memoria heap Java disponibile prima e dopo la raccolta dati inutilizzati sincrona in byte.
< finalizzazione .../>
Il numero di oggetti in attesa di completamento.
< info - classunload .../>
Il numero di programmi di caricamento classi e di classi scaricati durante l'intervallo heartbeat.
< references type="weak " cleared="53" .../>
Il numero e il tipo di oggetti di riferimento Java eliminati durante l'intervallo di heartbeat.

La raccolta dati inutilizzati sincrona a causa di condizioni di memoria esaurita o l'arresto della VM può verificarsi solo quando il programma di raccolta dati inutilizzati è attivo. Deve essere preceduto da un evento avvio trigger , anche se non necessariamente immediatamente. Alcuni eventi heartbeat si verificano probabilmente tra un evento trigger start e l'evento synchgc . La raccolta dati inutilizzati sincrona causata da System.gc() può verificarsi in qualsiasi momento.

Traccia di tutti i quantum GC

I singoli quantum GC possono essere tracciati abilitando i punti di traccia GlobalGCStart e GlobalGCEnd . Questi punti di analisi vengono prodotti all'inizio e alla fine di tutte le attività del programma di raccolta dati inutilizzati Metronome, incluse le raccolte dati inutilizzati sincrone. L'output per questi punti di analisi è simile a:
03:44:35.281 0x833cd00 j9mm.52 - GlobalGC start: globalcount=3

03:44:35.284 0x833cd00 j9mm.91 - GlobalGC end: workstackoverflow=0 overflowcount=0 

Voci di memoria esaurita

Quando l'heap esaurisce lo spazio libero, viene scritta una voce nel log -verbose:gc prima che venga generata l'eccezione OutOfMemoryError . Un esempio di questo output è:
<out-of-memory id="71" timestamp="2011-07-12T10:21:50.135" memorySpaceName="Metronome" 
  memorySpaceAddress="0806DFDC"/>

Per default, un Javadump viene prodotto come risultato di una eccezione OutOfMemoryError . Questo dump contiene informazioni sulla memoria utilizzata dal programma.

NULL
1STSEGTOTAL    Total memory:           4066080 (0x003E0B20)
1STSEGINUSE    Total memory in use:    3919440 (0x003BCE50)
1STSEGFREE     Total memory free:       146640 (0x00023CD0)