RFR: 8076161: LogEvents filter is now applied earlier to avoid unnecessary string construction.
Max Ockner
max.ockner at oracle.com
Mon Jun 8 22:13:31 UTC 2015
Hello,
Please review this fix.
Bug: https://bugs.openjdk.java.net/browse/JDK-8076161
Webrev: http://cr.openjdk.java.net/~mockner/8076161/
Summary: The body of Events::log_exception() is filtered by the
LogEvents flag. This is supposed to prevent the function from wasting
time when LogEvents is turned off. Before this fix, a possibly large
format string was passed into the function and is constructed before the
LogEvents filter is applied. Since the entire body of
Events::log_exception is conditioned on LogEvents, there is another
LogEvents filter around Events::log_exception(). The only call to
log_exceptions that this change applies to is the one in
Exceptions::_throw because most of the calls come from there, and I do
not want to suggest that this is the best permanent fix. However, I do
believe this is the best fix that doesn't change or add a lot of code,
and I have shown that it does improve performance. Below are some
benchmark results (the benchmark is the same one that appeared in the
comments on the bug page).
Benchmarks:
1) Clean repo with LogEvents OFF
Baseline-off (bias) (count) Mode Cnt Score
Error Units
ImplicitNullChecks.testExplicit 0.0 1000 avgt 50 3.161 ±
0.006 us/op
ImplicitNullChecks.testExplicit 0.5 1000 avgt 50 5991.922 ±
83.419 us/op
ImplicitNullChecks.testExplicit 1.0 1000 avgt 50 12047.777 ±
78.517 us/op
ImplicitNullChecks.testImplicit 0.0 1000 avgt 50 3.168 ±
0.007 us/op
ImplicitNullChecks.testImplicit 0.5 1000 avgt 50 20751.388 ±
325.065 us/op
ImplicitNullChecks.testImplicit 1.0 1000 avgt 50 41402.197 ±
407.636 us/op
2) Fixed repo with LogEvents OFF
Modified-off (bias) (count) Mode Cnt Score
Error Units
ImplicitNullChecks.testExplicit 0.0 1000 avgt 50 3.163 ±
0.007 us/op
ImplicitNullChecks.testExplicit 0.5 1000 avgt 50 5733.610 ±
86.945 us/op
ImplicitNullChecks.testExplicit 1.0 1000 avgt 50 11362.151 ±
71.750 us/op
ImplicitNullChecks.testImplicit 0.0 1000 avgt 50 3.163 ±
0.007 us/op
ImplicitNullChecks.testImplicit 0.5 1000 avgt 50 17721.661 ±
362.937 us/op
ImplicitNullChecks.testImplicit 1.0 1000 avgt 50 35007.120 ±
309.886 us/op
3) Clean repo with LogEvents ON
Baseline-on (bias) (count) Mode Cnt Score
Error Units
ImplicitNullChecks.testExplicit 0.0 1000 avgt 50 3.161 ±
0.007 us/op
ImplicitNullChecks.testExplicit 0.5 1000 avgt 50 6086.867 ±
100.584 us/op
ImplicitNullChecks.testExplicit 1.0 1000 avgt 50 12130.285 ±
87.830 us/op
ImplicitNullChecks.testImplicit 0.0 1000 avgt 50 3.159 ±
0.007 us/op
ImplicitNullChecks.testImplicit 0.5 1000 avgt 50 25559.707 ±
324.303 us/op
ImplicitNullChecks.testImplicit 1.0 1000 avgt 50 50383.913 ±
377.618 us/op
4) Fixed repo with LogEvents ON
Modified-on (bias) (count) Mode Cnt Score
Error Units
ImplicitNullChecks.testExplicit 0.0 1000 avgt 50 3.163 ±
0.007 us/op
ImplicitNullChecks.testExplicit 0.5 1000 avgt 50 5690.737 ±
97.704 us/op
ImplicitNullChecks.testExplicit 1.0 1000 avgt 50 11376.765 ±
67.243 us/op
ImplicitNullChecks.testImplicit 0.0 1000 avgt 50 3.161 ±
0.009 us/op
ImplicitNullChecks.testImplicit 0.5 1000 avgt 50 24464.360 ±
393.227 us/op
ImplicitNullChecks.testImplicit 1.0 1000 avgt 50 48913.627 ±
449.750 us/op
Looks like up to 10-15% speedup on this particular benchmark for runs
with -XX:-LogEvents.
Tested with jtreg runtime tests.
Thanks,
Max
More information about the hotspot-runtime-dev
mailing list