harmony-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gregory Shimansky <gshiman...@gmail.com>
Subject Re: [drlvm] things feel slow...
Date Sun, 24 Dec 2006 20:01:27 GMT
On Saturday 23 December 2006 20:48 Mikhail Loenko wrote:
> Can you publish most common stacks for the
> "157114 Ljava/io/ByteArrayOutputStream;.write(I)V"

Yes I've been going to do this for some time already and now that you've 
asked, I have finally written a modified agent version which can monitor a 
method which is specified on the command line. The agent code is available at 
[1] (run like 
this: -agentlib:methodee-stack='Ljava/io/ByteArrayOutputStream;.write(I)V').

After the log is generated it can be parsed with the following script

cat method_stack.log | sort | uniq -c | sort -nr | sed -e 's/ /\n/g'

I've found that Ljava/io/ByteArrayOutputStream;.write(I)V is used only in 9 
different stacks when running hello world. The most popular stack trace which 
is used 147319 times looks like this:

Ljava/io/ByteArrayOutputStream;.write(I)V:0
Ljava/util/jar/InitManifest;.nextChunk(Ljava/io/InputStream;Ljava/util/List;)
[B:310
Ljava/util/jar/InitManifest;.<init>(Ljava/io/InputStream;Ljava/util/jar/Attributes;Ljava/util/Map;Ljava/util/Map;Ljava/lang/String;)V:373
Ljava/util/jar/Manifest;.read(Ljava/io/InputStream;)V:20
Ljava/util/jar/Manifest;.<init>(Ljava/io/InputStream;Z)V:45
Ljava/util/jar/JarFile;.getManifest()Ljava/util/jar/Manifest;:92
Ljava/net/URLClassLoader;.explore(Ljava/net/URL;I)[Ljava/net/URL;:475
Ljava/net/URLClassLoader;.findClassImpl([Ljava/net/URL;Ljava/lang/String;)Ljava/lang/Class;:897
Ljava/net/URLClassLoader$4;.run()Ljava/lang/Class;:14
Ljava/net/URLClassLoader$4;.run()Ljava/lang/Object;:0
Ljava/security/AccessController;.doPrivilegedImpl(Ljava/security/PrivilegedAction;Ljava/security/AccessControlContext;)Ljava/lang/Object;:82
Ljava/security/AccessController;.doPrivileged(Ljava/security/PrivilegedAction;Ljava/security/AccessControlContext;)Ljava/lang/Object;:15
Ljava/net/URLClassLoader;.findClass(Ljava/lang/String;)Ljava/lang/Class;:12
Ljava/lang/ClassLoader;.loadClass(Ljava/lang/String;Z)Ljava/lang/Class;:49
Ljava/lang/ClassLoader$SystemClassLoader;.loadClass(Ljava/lang/String;Z)Ljava/lang/Class;:64
Ljava/lang/ClassLoader;.loadClass(Ljava/lang/String;)Ljava/lang/Class;:2

The rest 8 different stack traces differ only after 
Ljava/util/jar/Manifest;.read(Ljava/io/InputStream;)V:20 line. The top 2 
methods are called from different locations of 
Ljava/util/jar/InitManifest;.<init>(Ljava/io/InputStream;Ljava/util/jar/Attributes;Ljava/util/Map;Ljava/util/Map;Ljava/lang/String;)V

and 
Ljava/util/jar/InitManifest;.nextChunk(Ljava/io/InputStream;Ljava/util/List;)
[B. I am afraid the manifest parsing code has to be changed to improve its 
performance.

[1] http://people.apache.org/~gshimansky/methodee-stack.cpp

> 2006/12/23, Gregory Shimansky <gshimansky@gmail.com>:
> > On Saturday 23 December 2006 04:09 Stefano Mazzocchi wrote:
> > > Gregory Shimansky wrote:
> > > > I was not aware that drlvm didn't generate MethodEnter/Exit events
> > > > for native methods when I wrote this email. Now after applying
> > > > HARMONY-2828 which fills this gap I've rerun my test agent and the
> > > > top10 for most called methods to run hello world application has
> > > > changed. The new top10 list looks like this:
> > > >
> > > >  157114 Ljava/io/ByteArrayOutputStream;.write(I)V
> > > >   20093 Ljava/lang/Object;.<init>()V
> > > >   13975 Ljava/lang/String;.hashCode()I
> > > >    9301 Ljava/lang/Character;.toLowerCase(C)C
> > > >    7842 Ljava/io/ByteArrayOutputStream;.size()I
> > > >    7692 Ljava/lang/String;.<init>(II[C)V
> > > >    6300
> > > > Ljava/lang/VMMemoryManager;.arrayCopy(Ljava/lang/Object;ILjava/lang/O
> > > >bjec t;II)V 6300
> > > > Ljava/lang/System;.arraycopy(Ljava/lang/Object;ILjava/lang/Object;II)
> > > >V 6248 Ljava/lang/String;.length()I
> > > >    6130 Ljava/lang/String;.substring(II)Ljava/lang/String;
> > > >
> > > > We seem to copy memory really too much...
> > >
> > > Not sure I get these results: assuming a "hello world" application
> > > reads only, why is 80% of the time spent writing?
> >
> > Most of the executed code in the table is what it takes for the system
> > java class loader to find and load hello world application class. I think
> > many of those java.io.ByteArrayOutputStream.write calls are used in JAR
> > files manifest parser which writes to memory byte by byte. Maybe there
> > are other places too.
> >
> > --
> > Gregory

-- 
Gregory

Mime
View raw message