Che cosa causa lunghi tempi di rotazione e sincronizzazione in Java?

Question

In Java 8 Update 45, l'aggiunta di queste opzioni alla chiamata 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.

Answer 1

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.