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