2015-11-19 14 views
9

Dopo aver eseguito diverse ore, il mio server http inizia frequentemente con maggiore gc, ma nessun heap è stato liberato.frequente maggiore gc ma non heap libero?

più volte maggiore gc dopo, promotion failed e concurrent mode failure, quindi l'heap è stato liberato. Il mio registro gc è qui sotto:

{Heap before GC invocations=7172 (full 720): 
par new generation total 737280K, used 667492K [0x000000076b800000, 0x000000079d800000, 0x000000079d800000) 
    eden space 655360K, 100% used [0x000000076b800000, 0x0000000793800000, 0x0000000793800000) 
    from space 81920K, 14% used [0x0000000793800000, 0x00000007943d91d0, 0x0000000798800000) 
    to space 81920K, 0% used [0x0000000798800000, 0x0000000798800000, 0x000000079d800000) 
concurrent mark-sweep generation total 1482752K, used 1479471K [0x000000079d800000, 0x00000007f8000000, 0x00000007f8000000) 
concurrent-mark-sweep perm gen total 131072K, used 58091K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 
2015-11-19T21:50:02.692+0800: 113963.532: [GC2015-11-19T21:50:02.692+0800: 113963.532: [ParNew (promotion failed) 
Desired survivor size 41943040 bytes, new threshold 15 (max 15) 
- age 1: 3826144 bytes, 3826144 total 
- age 2:  305696 bytes, 4131840 total 
- age 3:  181416 bytes, 4313256 total 
- age 4:  940632 bytes, 5253888 total 
- age 5:  88368 bytes, 5342256 total 
- age 6:  159840 bytes, 5502096 total 
- age 7:  733856 bytes, 6235952 total 
- age 8:  64712 bytes, 6300664 total 
- age 9:  314304 bytes, 6614968 total 
- age 10:  587160 bytes, 7202128 total 
- age 11:  38728 bytes, 7240856 total 
- age 12:  221160 bytes, 7462016 total 
- age 13:  648376 bytes, 8110392 total 
- age 14:  33296 bytes, 8143688 total 
- age 15:  380768 bytes, 8524456 total 
: 667492K->665908K(737280K), 0.7665810 secs]2015-11-19T21:50:03.459+0800: 113964.299: [CMS2015-11-19T21:50:05.161+0800: 113966.001: [CMS-concurrent-mark: 3.579/4.747 secs] [Times: user=13.41 sys=0.35, rea 
l=4.75 secs] 
(concurrent mode failure): 1479910K->44010K(1482752K), 4.7267420 secs] 2146964K->44010K(2220032K), [CMS Perm : 58091K->57795K(131072K)], 5.4939440 secs] [Times: user=9.07 sys=0.13, real=5.49 secs] 
Heap after GC invocations=7173 (full 721): 
par new generation total 737280K, used 0K [0x000000076b800000, 0x000000079d800000, 0x000000079d800000) 
    eden space 655360K, 0% used [0x000000076b800000, 0x000000076b800000, 0x0000000793800000) 
    from space 81920K, 0% used [0x0000000798800000, 0x0000000798800000, 0x000000079d800000) 
    to space 81920K, 0% used [0x0000000793800000, 0x0000000793800000, 0x0000000798800000) 
concurrent mark-sweep generation total 1482752K, used 44010K [0x000000079d800000, 0x00000007f8000000, 0x00000007f8000000) 
concurrent-mark-sweep perm gen total 131072K, used 57795K [0x00000007f8000000, 0x0000000800000000, 0x0000000800000000) 
} 

Sembra che il CMS GC non ha alcun senso. Potresti spiegarmi per favore?

Questo è il mio config gc:

/usr/local/jdk1.7.0_79/bin/java 
-server 
-Xms2248m 
-Xmx2248m 
-Xmn800m 
-XX:PermSize=128m 
-XX:MaxPermSize=128m 
-XX:MaxTenuringThreshold=15 
-XX:+UseCMSCompactAtFullCollection 
-XX:CMSFullGCsBeforeCompaction=0 
-XX:+UseConcMarkSweepGC 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDateStamps 
-Xloggc:gc.log 
-XX:+PrintHeapAtGC 
-XX:+PrintTenuringDistribution 
-XX:+UseFastAccessorMethods 

UPDATE

C'è un task periodico dall'inizio del server. Il suo compito è caricare i dati da mysql e conservare in jvm heap. Quando arriva la richiesta del client, il server dovrebbe calcolare con i dati. Il codice di compito in questo modo:

private volatile List<ActivityInfo> activityInfos; 

public void run() { 
    activityInfos = db.loadActivity(); 
} 

public ActivityInfo getActivityByClient() { 
    // 
    List<ActivityInfo> local = activityInfos; 
    // biz code 
    ActivityInfo response = // biz code 
    return response; 
} 

// executor 
executor.scheduleWithFixedDelay(task, 0, 1, TimeUnit.MINUTES); 

Quello che mi ha confuso di più è il motivo per cui cumulo è stato liberato dopo la piena gc, non dopo importanti gc?

UPDATE

full gc log is here

risposta

4

che possa indicare che si sta eseguendo molto vicino al vostro dimensione heap massima, quindi non ci sono frequenti GC ma molto poco essere stato liberato. Prova ad aumentarlo in modo significativo, diciamo per 1.5x o 2x.

+0

Ho confuso il motivo per cui l'heap è stato liberato dopo il pieno gc, non dopo il maggiore gc? – znlyj

+0

Err, perché il GC completo ha liberato qualcosa che il GC principale non ha raggiunto? – EJP

+0

L'utilizzo dell'heap dopo una raccolta principale è di soli 44 MB, quindi l'heap è già di dimensioni generose e l'aumento non sarà di aiuto. –

3

tuo mucchio vivaio è impostato su 800 MB con -Xmn800m ma l'utilizzo di heap scuola materna dopo la raccolta è solo 8MB

- age 15: 380768 bytes, 8524456 total

Quindi l'applicazione può funzionare a lungo solo spazzatura raccolta mucchio vivaio. Tuttavia, ad un certo punto, l'heap di riserva si riempirà. Dalla collezione 7172 rimangono solo circa 3 MB - la differenza tra il totale e il valore dell'heap usato.

concurrent mark-sweep generation total 1482752K, used 1479471K

il garbage collector ha notato che il cumulo di ruolo è vicino a capacità e un marchio concorrente sarà stato attivato prima dell'inizio dell'attività di log pubblicato. Durante la fase di mark simultaneo, gli oggetti continuano ad essere allocati e l'heap della nursery si riempie attivando una collezione di vivai.

Quando il vivaio viene raccolto, non vi è più spazio sufficiente nell'archivio tenuto per contenere gli oggetti da promuovere nell'heap protetto. Il risultato è promotion failed e il garbage collector è costretto a elaborare l'intero heap, non solo il vivaio. Poiché ciò si verifica prima che sia completata la fase di marchio simultaneo, viene registrato anche uno concurrent mode failure. Dopo la raccolta completa ci sono 1,4 GB nell'archivio tenuto.

concurrent mark-sweep generation total 1482752K, used 44010K

questo è il modo che le cose sono destinate ad accadere. Le raccolte di articoli per la scuola materna sono economiche se la maggior parte degli oggetti nuovi escono rapidamente dal campo di applicazione e la JVM raccoglierà felicemente il vivaio solo il più a lungo possibile. Alla fine, però, l'heap di riserva si riempie e viene richiesto il GC completo più costoso.

Che cosa accadrebbe se riducessi la stanza dei bambini, ad esempio la metà delle sue dimensioni? Supponendo che l'applicazione stia creando oggetti a un ritmo costante, l'asilo nido si riempirebbe in circa la metà del tempo. Poiché la quantità di dati utilizzati dall'applicazione è indipendente da GC, lo stesso numero di oggetti verrà mantenuto e promosso come nel vivaio più grande. Quindi la raccolta di ruolo si riempirebbe più velocemente pure.

Con le stesse dimensioni di heap totali. l'area di possesso è più grande di prima, quindi ci vorranno più raccolte di asili nido per riempire l'area di possesso, quindi ci sono trade off. Una buona regola è quella di dimensionare la scuola materna a un quarto delle dimensioni dell'area occupata.

UPDATE

Il gc.log completo è da una diversa corsa GC ma credo che il comportamento dell'applicazione è simile. In esso vedo molti messaggi CMS: abort preclean due to time. Questi sono descritti in Jon Masamitsu's Weblog. Per ragioni di efficienza, il raccoglitore CMS fa affidamento su una raccolta di articoli per l'infanzia prima di interrompere tutti i thread eseguibili. Se tale raccolta non avviene entro un certo periodo di tempo, la raccolta CMS viene interrotta.

Quando il carico dell'applicazione è basso, ma l'utilizzo dell'archivio di tenure è elevato, il raccoglitore CMS inizierà a funzionare e passerà alla fase di mark iniziale. Quando una raccolta di articoli per l'infanzia non riesce a funzionare, la raccolta CMS viene interrotta. Questo può accadere più volte. Quindi si verifica un ammasso di vivaio e il ciclo si ripete. Ciò continuerà fino a quando una raccolta CMS e un vivaio non coincideranno o l'ammontare dei depositi si riempirà completamente.

Poiché gli oggetti vengono promossi lentamente all'heap protetto solo lentamente, questo comportamento può persistere per qualche tempo. Qui dura dal 2015-11-24T00: 28: 23.921 al 2015-11-24T01: 55: 52.461 - un'ora e mezza. Durante questo periodo, il tempo viene perso eseguendo un segno iniziale solo per interrompere l'operazione.

Esistono numerose possibilità per risolvere questo problema.

  • Ridurre le dimensioni della stanza dei bambini. Ciò aumenterà il tasso di raccolte di asili nido e quindi coinciderà più spesso con le raccolte CMS. Tuttavia, il vivaio di grandi dimensioni sembra funzionare bene e la sua riduzione causerà più raccolte CMS con prestazioni peggiori sotto carico pesante.
  • Aumentare CMSMaxAbortablePrecleanTime. Ciò significa che CMS aspetterà più a lungo prima di interrompere la raccolta. Tuttavia, più lunga è l'attesa, più costosa sarà la collezione CMS
  • Attivare CMSScavengeBeforeRemark. Questa è la mia raccomandazione Ciò costringerà una collezione di vivai al momento giusto e la collezione CMS non verrà mai interrotta. Il tempo di pausa per la fase di osservazione sarà più lungo in quanto avverrà anche una raccolta di asili nido, ma poiché il tempo extra è piccolo e le raccolte complete sono così rare, è improbabile che ciò rappresenti un problema.

Si noti che il cumulo dei vivai è talvolta chiamato la giovane generazione e il mucchio di vecchiaia. Per maggiori informazioni date un'occhiata al Understanding Garbage Collection o Garbage Collection Basics

+0

Forse dovrei impostare '-Xmn' più piccolo? Ciò che mi ha confuso è il motivo per cui l'heap è stato liberato dopo il pieno gc, non dopo il maggiore gc? – znlyj

+0

Ho risposto alla prima domanda con un aggiornamento alla mia risposta. Per quanto riguarda il secondo, non sono a conoscenza di alcuna differenza tra "full" e "major". Che cosa ti dice che si sono verificati i maggiori punteggi? –

+0

Posso dire che gc maggiore si è verificato da gc log. – znlyj

4

Per risolverlo, è possibile utilizzare Eclipse Memory Analyzer. Ti mostrerà tutti questi problemi relativi alla memoria e ai thread in dettaglio. Puoi anche acquistare jConsole.

+0

Memory Analyzer è un ottimo strumento per indagare il contenuto del tuo heap, ma l'ultima volta che ho guardato non c'è alcuna possibilità di esaminare i log gc o le prestazioni degli algoritmi GC. –

Problemi correlati