The mystery boils down to:
"*The exact same block of code becomes slower after a busy spin pause.*"
I posted a short source code that *unequivocally* proves and demonstrates
the problem:
http://stackoverflow.com/questions/43696948/why-does-the-jvm-show-more-latency-for-the-same-block-of-code-after-a-busy-spin
Note that I'm not using Thread.sleep. Also note that there are no
conditionals leading to a HotSpot/JIT de-optimization as I'm changing the
pause using a math operation instead of an IF.
The story told by the short source code is:
- There is a block of math operations that I want to time.
- First I time the block pausing 1 nanosecond before I start my
measurement. I do that 20,000 times.
- Then I change the pause from 1 nanosecond to 5 seconds and proceed to
measure the latency as usual. I do that 15 times.
- Then I print the last 30 measurements, so you can see 15 measurements
with the pause of 1 nanosecond and 15 measurements with the pause of 5
seconds.
As you can see below, *the discrepancy is big, *especially in the very
first measurement after the pause change. *Why is that!?*
$ java -server -cp . JvmPauseLatency
Sat Apr 29 10:34:28 EDT 2017 => Please wait 75 seconds for the results...
Sat Apr 29 10:35:43 EDT 2017 => Calculation: 4.0042328611017236E11
Results:
215
214
215
214
215
214
217
215
216
214
216
213
215
214
215
*2343* <----- FIRST MEASUREMENT AFTER PAUSE CHANGE
795
727
942
778
765
856
762
801
708
692
765
776
780
754
Thanks!
-JC
--
You received this message because you are subscribed to the Google Groups
"mechanical-sympathy" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/d/optout.
