Il fatto che ciò che vedi sia il risultato di qualche ottimizzazione JIT dovrebbe essere chiaro guardando tutti i commenti che hai ricevuto. Ma cosa sta realmente succedendo e perché quel codice è ottimizzato quasi sempre dopo la stessa quantità di iterazioni del for
esterno?
Proverò a rispondere a entrambe le domande, ma ricorda che tutto ciò che viene spiegato qui è relativo solo all'Hotspot VM di Oracle. Non esiste una specifica Java che definisca il comportamento di JIT JVM.
Prima di tutto, vediamo cosa sta facendo il JIT eseguendo quel programma di test con qualche flag aggiuntivo (la semplice JVM è sufficiente per eseguirlo, non c'è bisogno di caricare la libreria condivisa di debug, richiesta per alcune delle opzioni UnlockDiagnosticVMOptions
) :
java -XX:+PrintCompilation Test
l'esecuzione viene completata con questa uscita (rimuovendo poche righe all'inizio che mostrano che altri metodi sono stati compilati):
[...]
195017
184573
184342
184262
183491
189494
131 51% 3 Test::getTimes @ 2 (22 bytes)
245167
132 52 3 Test::getTimes (22 bytes)
165144
65090
132 53 1 java.nio.Buffer::limit (5 bytes)
59427
132 54% 4 Test::getTimes @ 2 (22 bytes)
75137
48110
135 51% 3 Test::getTimes @ -2 (22 bytes) made not entrant
142 55 4 Test::getTimes (22 bytes)
150820
86951
90012
91421
il printlns
dal codice sono intercalati diagnost informazioni relative alla compilation che la JIT sta eseguendo. Guardando una sola riga:
131 51% 3 Test::getTimes @ 2 (22 bytes)
Ogni colonna ha il seguente significato:
- timestamp
- Compilation Id (con attributi aggiuntivi se necessario)
- Tiered livello compilazione
- Method nome breve (con @
osr_bci
se disponibile)
- Compilato m dimensioni etodo
mantenendo solo le linee relative alla getTimes
:
131 51% 3 Test::getTimes @ 2 (22 bytes)
132 52 3 Test::getTimes (22 bytes)
132 54% 4 Test::getTimes @ 2 (22 bytes)
135 51% 3 Test::getTimes @ -2 (22 bytes) made not entrant
142 55 4 Test::getTimes (22 bytes)
E 'chiaro che getTimes
viene compilato più di una volta, ma ogni volta è compilato in un modo diverso.
Tale %
simbolo indica che sostituzione in pila (OSR) è stata eseguita, il che significa che il ciclo 10k contenuta in getTimes
essere compilato isolata dal resto del metodo e che la JVM sostituito quella sezione di il codice del metodo con la versione compilata. Lo osr_bci
è un indice che punta a questo nuovo blocco di codice compilato.
La compilation successiva è una classica compilation JIT che compila tutto il metodo getTimes
(la dimensione è sempre la stessa perché non c'è nient'altro in quel metodo oltre al loop).
La terza volta viene eseguito un altro OSR ma a un livello diverso. compilazione Tiered sono stati aggiunti in Java7 e fondamentalmente permette la JVM di scegliere il cliente o server di modalità JIT in fase di esecuzione, passando liberamente tra i due quando necessario. La modalità Client esegue un insieme più semplice di strategie di ottimizzazione, mentre la modalità server è in grado di applicare ottimizzazioni più sofisticate che d'altra parte hanno un costo maggiore in termini di tempo impiegato per la compilazione.
Non voglio entrare nei dettagli circa le diverse modalità di compilazione o su più livelli, se avete bisogno di ulteriori informazioni vi consiglio Java Performance: The Definitive Guide da Scott Oaks e controllare anche this question che spiegano cosa cambia tra i livelli.
Torna all'output di PrintCompilation, l'essenza qui è che da un certo punto nel tempo, viene eseguita una sequenza di compilazioni con complessità crescente fino a quando il metodo diventa apparentemente stabile (cioè il JIT non lo ricompone di nuovo).
Quindi, perché tutto questo inizia in quel determinato momento, dopo 5-10 iterazioni del ciclo principale?
Perché il ciclo interno getTimes
è diventato "caldo".
L'Hotspot VM, di solito definisce "caldo" quei metodi che sono stati invocati almeno 10k volte (che è la soglia predefinita storica, può essere modificata utilizzando -XX:CompileThreshold=<num>
, con la compilazione a più livelli ci sono ora diverse soglie), ma nel caso di OSR sto supponendo che venga eseguito quando un blocco di codice è ritenuto abbastanza "caldo", in termini di tempo di esecuzione assoluto o relativo, all'interno del metodo che lo contiene.
Ulteriori riferimenti
PrintCompilation Guide di Krystal Mok
Java Performance: The Definitive Guide
È possibile riprodurre in modo coerente questo comportamento? – CodeNewbie
L'ho fatto molto spesso, c'è sempre un punto in cui il tempo diventa molto più piccolo. – MarkusK96
Sembra il JIT per me. Una dimostrazione molto significativa del perché non dovresti mai eseguire da solo benchmark su Java, ma utilizzare strumenti di microbenching appropriati come [jmh] (http://openjdk.java.net/projects/code-tools/jmh/). –