harmony-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stefano Mazzocchi <stef...@apache.org>
Subject Re: [drlvm] things feel slow...
Date Mon, 11 Dec 2006 15:13:19 GMT
Tim Ellison wrote:
> Good work Gregory -- we may need to use some Java performance tools to
> figure out where these are being called and look for the right fixes.
> Anyone like to recommend their favourite tools?

Of all the java profilers I used, IBM's alphaworks jinsight[1] was
always close to my heart (some of the best visualization and UI ideas).
Since it fell off the alphaworks wagon, I have been missing it.

Lately, I've used YourKit[2] and liked it very very much. It's not as
good as JInsight in terms of UI and result understanding, but it's way
better at runtime tracing and super-low-intrusion profiling.

I think the ASF has a licence for its use... if not, the Harmony PMC
could ask for one, they are very helpful to open source projects and
just require credits somewhere in the web site as a payback.

[1] http://www.alphaworks.ibm.com/formula/jinsight
[2] http://www.yourkit.com/

> Regards,
> Tim
> 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. <geir@pobox.com>:
>>>>> 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


View raw message