Loading classes with many methods is very expensive
Peter Levart
peter.levart at gmail.com
Wed Oct 29 17:16:02 UTC 2014
On 10/29/2014 02:08 PM, Joel Borggrén-Franck wrote:
> Hi Peter,
>
> I’m not entirely convinced this is a bug.
>
> The lookup order for getMethod has for a long time been walk up superclasses and return what you find there first without even looking at interfaces. It might be desirable to change that but I’m not sure.
Hi Joel,
It has been for a long time like that as you say, but for a long time
Java did not have default methods. It's unexpected for getMethod() to
return a method that is not contained in getMethods() result.
Anyway, I have created a bug to track this:
https://bugs.openjdk.java.net/browse/JDK-8062389
For next iteration of the getMethods() O(n^2) fix, I used a slightly
different approach, which you might like more or not. Instead of using
linked-lists of Method objects as values of a LinkedHashMap I created a
special Key object, holding a reference to Method object and an
additional 'seq' int field, which discriminates among methods with same
signature. Values of LinkedHashMap are Method objects themselves:
http://cr.openjdk.java.net/~plevart/jdk9-dev/Class.getMethods/webrev.03/
I have encapsulated this functionality into a package-private
java.lang.MethodTable. The implementation of this API can be easily
changed to using linked-lists as values of LinkedHashMap if desired. The
performance characteristics are similar, with hardly measurable
advantage of this latest approach as can be seen from
http://cr.openjdk.java.net/~plevart/jdk9-dev/Class.getMethods/GetAllRtMethods.java
benchmark:
Original code:
19658 classes loaded in 2.071013902 seconds.
494392 methods obtained in 1.089983418 seconds.
494392 methods obtained in 0.952488497 seconds.
494392 methods obtained in 0.912878317 seconds.
494392 methods obtained in 0.940293784 seconds.
494392 methods obtained in 0.987640733 seconds.
494392 methods obtained in 0.925393355 seconds.
494392 methods obtained in 0.89397002 seconds.
494392 methods obtained in 0.915042463 seconds.
494392 methods obtained in 0.897669082 seconds.
494392 methods obtained in 0.878140502 seconds.
Patched code:
19658 classes loaded in 2.153024197 seconds.
494392 methods obtained in 0.875651469 seconds.
494392 methods obtained in 0.791937742 seconds.
494392 methods obtained in 0.780995693 seconds.
494392 methods obtained in 0.759593461 seconds.
494392 methods obtained in 0.766528355 seconds.
494392 methods obtained in 0.756567663 seconds.
494392 methods obtained in 0.739177848 seconds.
494392 methods obtained in 0.729245613 seconds.
494392 methods obtained in 0.74081083 seconds.
494392 methods obtained in 0.731749505 seconds.
Martin's ManyMethodsBenchmark shows this algorithm has O(n) time
complexity too:
Original:
Base class load time: 131.95 ms
getDeclaredMethods: 65521 methods, 32.00 ms total time, 0.0005 ms per method
getMethods : 65530 methods, 44.24 ms total time, 0.0007 ms per method
Derived class load time: 32525.23 ms
getDeclaredMethods: 65521 methods, 30.37 ms total time, 0.0005 ms per method
getMethods : 65530 methods, 7897.03 ms total time, 0.1205 ms per
method
Patched:
Base class load time: 129.72 ms
getDeclaredMethods: 65521 methods, 32.76 ms total time, 0.0005 ms per method
getMethods : 65530 methods, 42.68 ms total time, 0.0007 ms per method
Derived class load time: 31620.47 ms
getDeclaredMethods: 65521 methods, 30.49 ms total time, 0.0005 ms per method
getMethods : 65530 methods, 88.23 ms total time, 0.0013 ms per method
I have also run Martin's LoadAllClassesAndMethods test (Thanks Martin, I
changed it slightly so that exceptions are collected and reported at the
end instead of bailing-out on first exception).
Original LoadAllClassesAndMethods write classlist.txt:
class load: 23052 classes, 1563.75 ms total time, 0.0678 ms per class
4 exceptions encountered:
java.lang.IncompatibleClassChangeError:
jdk.nashorn.internal.codegen.CompilationPhase$10 and
jdk.nashorn.internal.codegen.CompilationPhase$10$1 disagree on
InnerClasses attribute
java.lang.IncompatibleClassChangeError:
jdk.nashorn.internal.codegen.CompilationPhase$5 and
jdk.nashorn.internal.codegen.CompilationPhase$5$1 disagree on
InnerClasses attribute
java.lang.IncompatibleClassChangeError:
java.security.ProtectionDomain$3 and java.security.ProtectionDomain$3$1
disagree on InnerClasses attribute
java.lang.IncompatibleClassChangeError: java.lang.Compiler and
java.lang.Compiler$1 disagree on InnerClasses attribute
getMethods: 23052 classes, 831.87 ms total time, 0.0361 ms per class
Patched LoadAllClassesAndMethods diff classlist.txt:
class load: 23051 classes, 1596.58 ms total time, 0.0693 ms per class
5 exceptions encountered:
java.lang.IncompatibleClassChangeError:
jdk.nashorn.internal.codegen.CompilationPhase$10 and
jdk.nashorn.internal.codegen.CompilationPhase$10$1 disagree on
InnerClasses attribute
java.lang.IncompatibleClassChangeError:
jdk.nashorn.internal.codegen.CompilationPhase$5 and
jdk.nashorn.internal.codegen.CompilationPhase$5$1 disagree on
InnerClasses attribute
java.lang.IncompatibleClassChangeError: java.lang.Class and
java.lang.Class$MethodArray disagree on InnerClasses attribute
java.lang.IncompatibleClassChangeError:
java.security.ProtectionDomain$3 and java.security.ProtectionDomain$3$1
disagree on InnerClasses attribute
java.lang.IncompatibleClassChangeError: java.lang.Compiler and
java.lang.Compiler$1 disagree on InnerClasses attribute
getMethods: 23051 classes, 799.99 ms total time, 0.0347 ms per class
The following classes were expected, but not found:
[java.lang.Class$MethodArray]
The reason for Class$MethodArray to not be loaded by patched code is the
way I tested patched j.l.Class. I prepended the boot classpath with a
directory holding patched Class/MethodTable. Martin's
LoadAllClassesAndMethods tries to load Class$MethodArray anyway, since
it's in rt.jar, but this class is gone in patched j.l.Class, so
"IncompatibleClassChangeError: java.lang.Class and
java.lang.Class$MethodArray disagree on InnerClasses attribute" is
expected in this case. Otherwise this test shows that original and
patched code agree on results returned from getMethods() for all system
and extension JDK classes.
All 86 jtreg tests in java/lang/Class/ and java/lang/reflect/ pass.
I still have to create a test case for inconsistency I discovered in
previous iteration.
Regards, Peter
>
> cheers
> /Joel
>
> On 29 okt 2014, at 12:26, Peter Levart <peter.levart at gmail.com> wrote:
>
>> Hi Joel,
>>
>> I found an inconsistency between getMethod() and getMethods() results that is present in current JDK8/9 code and in my latest webrev.02. The following program:
>>
>> import java.util.stream.Collectors;
>> import java.util.stream.Stream;
>>
>> public class GetMethodTest {
>>
>> static void test(Class<?> clazz) throws Exception {
>>
>> System.out.println(clazz.getName() + ".class.getMethods(): " +
>> Stream
>> .of(clazz.getMethods())
>> .filter(m -> m.getDeclaringClass() != Object.class)
>> .collect(Collectors.toList()));
>>
>> System.out.println(clazz.getName() + ".class.getMethod(\"m\"): " +
>> clazz.getMethod("m"));
>>
>> System.out.println();
>> }
>>
>> public static void main(String[] args) throws Exception {
>> test(I.class);
>> test(J.class);
>> test(A.class);
>> test(B.class);
>> }
>> }
>>
>> interface I {
>> void m();
>> }
>>
>> interface J extends I {
>> default void m() {}
>> }
>>
>> abstract class A implements I {}
>>
>> abstract class B extends A implements J {}
>>
>>
>> prints:
>>
>> I.class.getMethods(): [public abstract void I.m()]
>> I.class.getMethod("m"): public abstract void I.m()
>>
>> J.class.getMethods(): [public default void J.m()]
>> J.class.getMethod("m"): public default void J.m()
>>
>> A.class.getMethods(): [public abstract void I.m()]
>> A.class.getMethod("m"): public abstract void I.m()
>>
>> B.class.getMethods(): [public default void J.m()]
>> B.class.getMethod("m"): public abstract void I.m()
>>
>> B.class.getMethods() reports default method J.m() (which I think is correct), but B.class.getMethod("m") reports the abstract I.m() inherited from A, because here the getMethod0() algorithm stops searching for and consolidating any methods in (super)interfaces. Do you agree that this is a bug?
>>
>>
>> Regards, Peter
>>
>> On 10/27/2014 02:45 PM, Joel Borggrén-Franck wrote:
>>> Hi Peter,
>>>
>>> As always, thanks for doing this! It has been on my todolist for a while but never quite bubbling up to the top.
>>>
>>> I don’t have time to look att his right now, but I expect to have some free time next week, but i have two short comments
>>>
>>> First, I have been thinking about moving MethodArray to its’s own top-level class, isn’t it about time?
>>>
>>> Second I would expect testing for the missing cases you uncovered (good catch!).
>>>
>>> I’ll try to get back to you asap.
>>>
>>> cheers
>>> /Joel
>>>
>>>
>>> On 26 okt 2014, at 23:53, Peter Levart <peter.levart at gmail.com> wrote:
>>>
>>>> On 10/26/2014 09:25 PM, Peter Levart wrote:
>>>>> 19657 classes loaded in 1.987373401 seconds.
>>>>> 494141 methods obtained in 1.02493941 seconds.
>>>>>
>>>>> vs.
>>>>>
>>>>> 19657 classes loaded in 2.084409717 seconds.
>>>>> 494124 methods obtained in 0.915928578 seconds.
>>>> Hi,
>>>>
>>>> As you might have noticed, the number of methods obtained from patched code differed from original code. I have investigated this and found that original code treats abstract class methods the same as abstract interface methods as far as multiple inheritance is concerned (it keeps them together in the returned array). So I fixed this and here's new webrev which behaves the same as original code:
>>>>
>>>> http://cr.openjdk.java.net/~plevart/jdk9-dev/Class.getMethods/webrev.02/
>>>>
>>>> Comparing original vs. patched code still shows speed-up:
>>>>
>>>> Original:
>>>>
>>>> 19657 classes loaded in 1.980493029 seconds.
>>>> 494141 methods obtained in 0.976318927 seconds.
>>>> 494141 methods obtained in 0.886504437 seconds.
>>>> 494141 methods obtained in 0.911153722 seconds.
>>>> 494141 methods obtained in 0.880550509 seconds.
>>>> 494141 methods obtained in 0.875526704 seconds.
>>>> 494141 methods obtained in 0.877258894 seconds.
>>>> 494141 methods obtained in 0.871794344 seconds.
>>>> 494141 methods obtained in 0.884159644 seconds.
>>>> 494141 methods obtained in 0.892648522 seconds.
>>>> 494141 methods obtained in 0.884581841 seconds.
>>>>
>>>> Patched:
>>>>
>>>> 19657 classes loaded in 2.055697675 seconds.
>>>> 494141 methods obtained in 0.853922188 seconds.
>>>> 494141 methods obtained in 0.776203794 seconds.
>>>> 494141 methods obtained in 0.858774803 seconds.
>>>> 494141 methods obtained in 0.778178867 seconds.
>>>> 494141 methods obtained in 0.760043997 seconds.
>>>> 494141 methods obtained in 0.756352444 seconds.
>>>> 494141 methods obtained in 0.740826372 seconds.
>>>> 494141 methods obtained in 0.744264782 seconds.
>>>> 494141 methods obtained in 0.73805894 seconds.
>>>> 494141 methods obtained in 0.746852752 seconds.
>>>>
>>>>
>>>> 55 java/lang/reflect jtreg tests still pass. As they did before, which means that we don't have a coverage for such cases. I'll see where I can add such a case (EnumSet for example, which inherits from Set interface and AbstractColection class via two different paths, so Set.size()/iterator() and AbstractCollection.size()/iterator() are both returned from getMethods())...
>>>>
>>>>
>>>> Regards, Peter
>>>>
More information about the hotspot-runtime-dev
mailing list