2015-05-22 13 views
10

In Java 8 Update 45, l'aggiunta di queste opzioni alla chiamata java:Che cosa causa lunghi tempi di rotazione e sincronizzazione in Java?

-XX:+PrintGCApplicationStoppedTime 
-XX:+PrintSafepointStatistics 
-XX:PrintSafepointStatisticsCount=1 

mi mostra le statistiche come questi:

vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count 
3679.229: no vm operation [ 72 1 2 ] [ 6016 0 6016 0 0 ] 1 
2015-05-22T11:25:27.519+0200: Total time for which application threads were stopped: 6.0168551 seconds, Stopping threads took: 6.0164099 seconds 

Il problema qui è il tempo lungo per Stopping threads. In questo esempio, è 6 secondi che è già un problema per la nostra applicazione, ma ho visto anche tempi più grandi, in un'istanza (senza registrazione completa, però) pari a quasi un minuto.

L'operazione di VM (qui: no vm operation) è variabile. Ho anche visto, ad es. RevokeBias, G1IncCollectionPause o GCG_Operation. Inoltre, lo page_trap_count sembra irrilevante. Ho visto esempi in cui era 0, e altri in cui era 2. Coerente, tuttavia, è che l'ora si riflette sempre nei valori di spin e sync.

Sto cercando una spiegazione approfondita di quei valori di temporizzazione spin e sync, ma soprattutto sono interessato al motivo per cui ciò sta accadendo e cosa posso fare contro di esso. Non sono a conoscenza di nulla di "cattivo" nella nostra configurazione. Ci sono un sacco di core annoiati e memoria inutilizzata sulla macchina, stiamo eseguendo Java puro (senza JNI), e non siamo a conoscenza di alcuna eccessiva sincronizzazione nel nostro codice.

+0

Puoi fornire maggiori dettagli del tuo caso d'uso specifico, in modo che le persone possano sapere come aiutarti. –

+0

In realtà, vedo questo non solo con una delle nostre applicazioni, ma la vedo su tutta la linea. Quindi non c'è davvero un caso d'uso specifico. Se sapessi cosa cercare, potrei andare a caccia di somiglianze. Ho il sospetto, tuttavia, che molte persone abbiano lo stesso problema ma non l'abbiano ancora notato. La registrazione 'Stopping thread took:' che mi ha indicato è piuttosto nuova. – malamut

risposta

2

Il problema qui è che la tua applicazione impiega molto tempo per raggiungere un safepoint. L'uscita Stopping threads denota il tempo che intercorre tra la JVM emette una richiesta safepoint fino a quando tutti i thread hanno raggiunto un safepoint.

Il valore sync mostra la stessa cosa: è il tempo necessario affinché tutti i thread raggiungano il safeponit.

I spin e block valori indicano i tempi impiegato blocked e spinning fili (codice di esecuzione) per raggiungere il safepoint.

Sapendo questo possiamo concludere che il problema per te è che un thread è occupato a girare e non è in grado di raggiungere il suo safepoint in diversi secondi.

Esattamente perché questo si verifica è difficile da dire. Un esempio, come illustrato nella domanda this e la sua risposta è che il compilatore JIT può compilare cicli pesanti senza controlli safepoint.

Si potrebbe provare a eseguire la JVM con le opzioni -XX:+SafepointTimeout -XX:SafepointTimeoutDelay=500. Ciò interromperà il timeout delle sincronizzazioni safepoint dopo 500 ms e stamperà le informazioni sui thread che non sono riusciti a raggiungere il safepoint.

+0

Grazie! Proverò questo e riferirò. – malamut

+0

Le opzioni aggiuntive mi daranno effettivamente il nome del thread (senza stack, ma sembra che al momento non ci sia modo di ottenerlo). Guardando una delle applicazioni che presentano il problema, il thread è lo stesso il più delle volte. Sembra un duro lavoro per trovare il vero problema, ma ora so da dove cominciare e alla domanda viene data sicuramente una risposta! – malamut

+0

@malamut Ora che conosci il thread, possono essere utili i dump regolari dei thread ('jstack '). Aspettano anche un safepoint, quindi potrebbe essere difficile dire il problema anche con questo aiuto. Mi piacerebbe sapere qual è il problema una volta che l'hai identificato. È una domanda interessante. –