harmony-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Geir Magnusson Jr." <g...@pobox.com>
Subject Re: [drlvm] things feel slow...
Date Sat, 09 Dec 2006 22:56:53 GMT
This is great stuff, but I meant "relative to a week or so ago".  IOW, 
it feels like we slowed down recently.

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 
site?  I'm going to make a little JVMTI "how to" and that's a cute bit 
of code to use as an example.


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