Geir Magnusson Jr. wrote:
This is great stuff, but I meant "relative to a week or so ago". IOW,
it feels like we slowed down recently.
Well, actually the analysis that I've done is not very fresh. This code
I've written in the end of September but didn't make a comparison with
Sun. Back then the numbers were smaller, it used to be "just" ~195k
method calls in LIVE phase, and java/io/ByteArrayOutputStream;.write(I)V
method was called "only" 93k times.
The number of Java methods which are executed just for system class
loader to find a user class grew since that time in 1.5 times. Maybe it
happened in the last 2 weeks.
That said, what you have below is great, and certainly will be good
fodder for someone to look into. We should capture it as a ToDo.
Could you please put an Apache license on the top of the code on your
Done.
site? I'm going to make a little JVMTI "how to" and that's a cute bit
of code to use as an example.
If you have any questions, I'd really like to help with this.
Gregory Shimansky wrote:
Geir Magnusson Jr. wrote:
The DRLVM suite...
So the question is... was 20-25 min the time you expected?
Mikhail Loenko wrote:
which tests did you run?
I ran Classlib tests on DRLVM in "once" fork mode. it took about
20-25 minutes
on each x86 and x86_64 on Linux
2006/12/9, Geir Magnusson Jr. <[EMAIL PROTECTED]>:
I've been running tests on x86 and x86_64 linux, and things "feel"
slow.
Problem is I don't have any times to compare to - can we add that to
the data recorded in harmonytest?
Does anyone else feel that things are slow?
I think the worst place in executing tests in "once" mode is
initialization stage of VM + classlib. I've written a simple JVMTI
agent which uses JVMTI MethodEntry event [1] just to count called
classlib methods to execute a Hello world program. The program itself
is very small, so almost all of the called methods are classlib
initialization. Also keep in mind that MethodEntry event is sent only
in LIVE [2] JVMTI phase, this means that classlib bootstrap, and
classlib shutdown are not included.
After agent is executed, it creates a log of called methods. The
number of methods which I get is 345718. This is very very many.
Comparing with Sun JRE, the number of methods they use is 9482. True
that when drlvm runs in JVMTI mode, it uses only Jitrino.JET, which
doesn't inline any methods, but on the other hand Sun when running in
JVMTI mode should report every called method as well. So the
difference with Sun is 36 times. Agent code is in [3]. On windows
compile like this:
cl
-Ic:/work/harmony/enhanced/trunk/working_vm/build/win_ia32_msvc_debug/deploy/jre/include
-Femethodee.dll -LD methodee.cpp
execute like this:
java -agentpath:methodee.dll Hello
To count methods which agent doesn't see in classlib bootstrap and
shutdown phases I've created a small patch which adds tracing to drlvm
to jvmti_method_enter_callback. This function is always called when
JVMTI registers can_generate_method_entry_events capability. The calls
to agent are filtered out when phase is not LIVE. Using this patch I
get all of the methods which are executed. The number in this case is
356826. So this gives only 11108 calls in bootstrap and shutdown. The
number is not very big compared to what is executed in LIVE phase.
Patch code is in [4]. Add
-Xtrace:jvmti.event.method.entry:log.txt
to the above command line to log tracing to file when running drlvm).
It seems like 99% of all LIVE phase calls are user class loader
execution. All of those 345k calls are what it takes for Java class
loader to find Hello world class. Analyzing the log with this script
cat method_entry.log | sort | uniq -c | sort -nr
I've found the top 10 methods which are executed most of the times:
156382 Ljava/io/ByteArrayOutputStream;.write(I)V
19985 Ljava/lang/Object;.<init>()V
13927 Ljava/lang/String;.hashCode()I
9259 Ljava/lang/Character;.toLowerCase(C)C
7807 Ljava/io/ByteArrayOutputStream;.size()I
7648 Ljava/lang/String;.<init>(II[C)V
6299
Ljava/lang/System;.arraycopy(Ljava/lang/Object;ILjava/lang/Object;II)V
6219 Ljava/lang/String;.length()I
6101 Ljava/lang/String;.substring(II)Ljava/lang/String;
6089 Ljava/util/ArrayList;.size()I
the first one is absolute champion. I wonder why it is used to many
times. It looks like some parts of classlib copy memory byte by byte
extensively using ByteArrayOutputStream. It is probably a good
starting place for performance improvement.
[1]
http://java.sun.com/j2se/1.5.0/docs/guide/jvmti/jvmti.html#MethodEntry
[2] http://java.sun.com/j2se/1.5.0/docs/guide/jvmti/jvmti.html#GetPhase
[3] http://people.apache.org/~gshimansky/methodee.cpp
[4] http://people.apache.org/~gshimansky/jvmti.patch
--
Gregory
