You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cocoon.apache.org by Berin Loritsch <bl...@apache.org> on 2002/02/20 19:48:31 UTC

[HEADS UP] Don't use -Xincgc with JDK 1.4

There was a tip running around late last year that if you ran the JVM 
with the -Xincgc that the system would perform better.  With my current
testing using JDK 1.4 (final release), I found that enabling that option
lengthens the time of the ECM/ContainerManager test by a factor of 2. 
In both cases, the overall time is lengthened.  For the 
ContainerManager, it is only 1.5 times as long; but for the ECM it is 
twice as long.

While incremental garbage collection is supposed to make you spend less
time in the garbage collector, it is called more often.  The net result
is that you spend more time in the garbage collector.

Incremental GC cycles are only about 10 ms in length, while the small
GC cycles are roughly .1-6ms.  A full GC takes anywhere between 100 to
1500 ms to complete.  Full GCs are few and far between in a well tuned
system, while regular GC cycles occur every second or so.  The problem
with incremental garbage collection is it is called every 4 seconds or
so.

I look forward to the day where the JVM GC cycles are completely 
asynchronous (I think this is slated for JDK 1.5).  Currently all 
threads are stopped while garbage collection occurs.

Regarding other options I tried:

-Xnoclassgc
      Not alot of change.  Class GC doesn't happen often as most Avalon
      systems keep using the set of classes it has.  When run with
      -verbosegc, I only detected one instance of Class GC--and that
      was related to a JUnit class only used during startup....

-Xrs
      The test is flawed in that there is not alot of JVM/OS signalling
      to begin with.  It *may* help a Servlet environment, and it *may*
      hurt.  My test is all JVM bound, and the filesystem is only
      accessed at set up.

-Xms/-Xmx
      Presizing the JVM memmory usage had little affect on the test.
      Just make sure your -Xmx is set high enough....

-Xfuture
      This is a strictness checking parameter.  It provides stricter
      rules checking on the bytecode.  Don't worry--we pass.

-Xprofile
      Provides a very useful human readable dump of JVM activity.  Hats
      off to the JDK 1.4 crew!

-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org


Re: [HEADS UP] Don't use -Xincgc with JDK 1.4

Posted by Berin Loritsch <bl...@apache.org>.
Berin Loritsch wrote:

> -Xprofile
>      Provides a very useful human readable dump of JVM activity.  Hats
>      off to the JDK 1.4 crew!


Here is the typical execution thread for ContainerManager code:

Flat profile of 27.64 secs (1402 total ticks): Latched_Thread_68

   Interpreted + native   Method
  78.7%     0  +   767    java.lang.Thread.yield
   0.4%     0  +     4    java.io.WinNTFileSystem.canonicalize
   0.1%     0  +     1    java.io.BufferedReader.<init>
  79.3%     0  +   772    Total interpreted

      Compiled + native   Method
   0.2%     2  +     0 
org.apache.avalon.excalibur.collections.BucketMap.getHash
   0.1%     1  +     0    java.net.URLStreamHandler.getHostAddress
   0.1%     1  +     0    java.lang.StringBuffer.expandCapacity
   0.1%     1  +     0    sun.nio.cs.UTF_8$Decoder.decodeArrayLoop
   0.5%     5  +     0    Total compiled

          Stub + native   Method
  19.1%     0  +   186    java.lang.Thread.yield
   0.4%     0  +     4    java.io.WinNTFileSystem.getBooleanAttributes
   0.2%     0  +     2    java.util.zip.ZipFile.getEntry
   0.2%     0  +     2    java.io.WinNTFileSystem.canonicalize
   0.1%     1  +     0    java.lang.ClassLoader.findLoadedClass
  20.0%     1  +   194    Total stub

   Thread-local ticks:
  30.5%   428             Blocked (of total)
   0.2%     2             Unknown: thread_state



Here is the typical execution thread for ECM code:

Flat profile of 194.59 secs (5729 total ticks): Latched_Thread_94

   Interpreted + native   Method
   0.1%     1  +     3 
org.apache.avalon.excalibur.pool.ResourceLimitingPool.get
   0.0%     1  +     0 
org.apache.avalon.excalibur.component.DefaultComponentFactory.decommission
   0.0%     1  +     0 
org.apache.avalon.excalibur.collections.BucketMap.put
   0.2%     3  +     3    Total interpreted

      Compiled + native   Method
   0.2%     6  +     0    java.lang.StringBuffer.expandCapacity
   0.1%     5  +     0    java.lang.StringBuffer.append
   0.1%     5  +     0    sun.nio.cs.StreamDecoder$CharsetSD.<init>
   0.1%     3  +     0    java.lang.StringBuffer.append
   0.1%     3  +     0    java.io.Win32FileSystem.normalize
   0.1%     3  +     0    java.io.BufferedReader.<init>
   0.1%     2  +     0    javax.xml.parsers.FactoryFinder.find
   0.1%     2  +     0    vtable chunks
   0.1%     2  +     0    java.lang.String.startsWith
   0.1%     2  +     0    sun.net.www.ParseUtil.canonizeString
   0.0%     0  +     1 
org.apache.avalon.framework.parameters.Parameters.getParameter
   0.0%     1  +     0    java.lang.StringBuffer.length
   0.0%     1  +     0    java.net.URL.hashCode
   0.0%     1  +     0    sun.misc.URLClassPath$4.getURL
   0.0%     1  +     0    sun.nio.cs.UTF_8.newDecoder
   0.0%     1  +     0    sun.net.www.protocol.file.FileURLConnection.<init>
   0.0%     1  +     0    sun.misc.Launcher$AppClassLoader.loadClass
   0.0%     1  +     0    javax.xml.parsers.SAXParserFactory.newInstance
   0.0%     1  +     0    java.util.HashMap.<init>
   0.0%     1  +     0    sun.net.www.protocol.jar.URLJarFile.getEntry
   0.0%     1  +     0    java.lang.String.getChars
   0.0%     1  +     0    java.lang.reflect.Constructor.newInstance
   0.0%     1  +     0    java.lang.String.equals
   0.0%     1  +     0    java.io.Win32FileSystem.prefixLength
   0.0%     1  +     0    java.util.zip.ZipFile.getEntry
   1.7%    60  +     1    Total compiled (including elided)

          Stub + native   Method
  91.1%     0  +  3264    java.lang.Thread.yield
   2.1%     0  +    75    java.io.WinNTFileSystem.canonicalize
   1.2%     0  +    42    java.io.WinNTFileSystem.getBooleanAttributes
   0.9%     0  +    31    java.util.zip.ZipFile.getEntry
   0.3%     0  +     9    java.lang.Throwable.fillInStackTrace
   0.1%     0  +     3    java.lang.Class.forName0
   0.1%     0  +     2    java.security.AccessController.doPrivileged
   0.1%     0  +     2    java.security.AccessController.doPrivileged
   0.1%     0  +     2    java.lang.ClassLoader.findLoadedClass
   0.0%     0  +     1    java.util.zip.ZipFile.read
   0.0%     1  +     0    java.util.zip.ZipFile.getSize
   0.0%     0  +     1    sun.reflect.Reflection.getClassAccessFlags
   0.0%     0  +     1    java.lang.Class.getComponentType
   0.0%     0  +     1    java.lang.reflect.Array.newArray
   0.0%     0  +     1    java.util.zip.ZipEntry.initFields
   0.0%     1  +     0    java.lang.Thread.currentThread
   0.0%     0  +     1    sun.reflect.Reflection.getCallerClass
  95.9%     2  +  3436    Total stub

   Runtime stub + native  Method
   0.0%     1  +     0    checkcast
   0.0%     1  +     0    Total runtime stubs

   Thread-local ticks:
  37.4%  2145             Blocked (of total)
   0.1%     3             Compilation
   0.2%     8             Unknown: running frame
   1.9%    67             Unknown: thread_state



As you can see, most of the time is spent in yield(), which is
OK.  We want a typical situation where multiple threads are 
interactively vying for the component instances.  There is *alot* less 
activity in ContainerManager than in ECM.  It would be interesting
to see how the execution plays out linearly.....



-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


--
To unsubscribe, e-mail:   <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>


Re: [HEADS UP] Don't use -Xincgc with JDK 1.4

Posted by Berin Loritsch <bl...@apache.org>.
Berin Loritsch wrote:

> -Xprofile
>      Provides a very useful human readable dump of JVM activity.  Hats
>      off to the JDK 1.4 crew!


Here is the typical execution thread for ContainerManager code:

Flat profile of 27.64 secs (1402 total ticks): Latched_Thread_68

   Interpreted + native   Method
  78.7%     0  +   767    java.lang.Thread.yield
   0.4%     0  +     4    java.io.WinNTFileSystem.canonicalize
   0.1%     0  +     1    java.io.BufferedReader.<init>
  79.3%     0  +   772    Total interpreted

      Compiled + native   Method
   0.2%     2  +     0 
org.apache.avalon.excalibur.collections.BucketMap.getHash
   0.1%     1  +     0    java.net.URLStreamHandler.getHostAddress
   0.1%     1  +     0    java.lang.StringBuffer.expandCapacity
   0.1%     1  +     0    sun.nio.cs.UTF_8$Decoder.decodeArrayLoop
   0.5%     5  +     0    Total compiled

          Stub + native   Method
  19.1%     0  +   186    java.lang.Thread.yield
   0.4%     0  +     4    java.io.WinNTFileSystem.getBooleanAttributes
   0.2%     0  +     2    java.util.zip.ZipFile.getEntry
   0.2%     0  +     2    java.io.WinNTFileSystem.canonicalize
   0.1%     1  +     0    java.lang.ClassLoader.findLoadedClass
  20.0%     1  +   194    Total stub

   Thread-local ticks:
  30.5%   428             Blocked (of total)
   0.2%     2             Unknown: thread_state



Here is the typical execution thread for ECM code:

Flat profile of 194.59 secs (5729 total ticks): Latched_Thread_94

   Interpreted + native   Method
   0.1%     1  +     3 
org.apache.avalon.excalibur.pool.ResourceLimitingPool.get
   0.0%     1  +     0 
org.apache.avalon.excalibur.component.DefaultComponentFactory.decommission
   0.0%     1  +     0 
org.apache.avalon.excalibur.collections.BucketMap.put
   0.2%     3  +     3    Total interpreted

      Compiled + native   Method
   0.2%     6  +     0    java.lang.StringBuffer.expandCapacity
   0.1%     5  +     0    java.lang.StringBuffer.append
   0.1%     5  +     0    sun.nio.cs.StreamDecoder$CharsetSD.<init>
   0.1%     3  +     0    java.lang.StringBuffer.append
   0.1%     3  +     0    java.io.Win32FileSystem.normalize
   0.1%     3  +     0    java.io.BufferedReader.<init>
   0.1%     2  +     0    javax.xml.parsers.FactoryFinder.find
   0.1%     2  +     0    vtable chunks
   0.1%     2  +     0    java.lang.String.startsWith
   0.1%     2  +     0    sun.net.www.ParseUtil.canonizeString
   0.0%     0  +     1 
org.apache.avalon.framework.parameters.Parameters.getParameter
   0.0%     1  +     0    java.lang.StringBuffer.length
   0.0%     1  +     0    java.net.URL.hashCode
   0.0%     1  +     0    sun.misc.URLClassPath$4.getURL
   0.0%     1  +     0    sun.nio.cs.UTF_8.newDecoder
   0.0%     1  +     0    sun.net.www.protocol.file.FileURLConnection.<init>
   0.0%     1  +     0    sun.misc.Launcher$AppClassLoader.loadClass
   0.0%     1  +     0    javax.xml.parsers.SAXParserFactory.newInstance
   0.0%     1  +     0    java.util.HashMap.<init>
   0.0%     1  +     0    sun.net.www.protocol.jar.URLJarFile.getEntry
   0.0%     1  +     0    java.lang.String.getChars
   0.0%     1  +     0    java.lang.reflect.Constructor.newInstance
   0.0%     1  +     0    java.lang.String.equals
   0.0%     1  +     0    java.io.Win32FileSystem.prefixLength
   0.0%     1  +     0    java.util.zip.ZipFile.getEntry
   1.7%    60  +     1    Total compiled (including elided)

          Stub + native   Method
  91.1%     0  +  3264    java.lang.Thread.yield
   2.1%     0  +    75    java.io.WinNTFileSystem.canonicalize
   1.2%     0  +    42    java.io.WinNTFileSystem.getBooleanAttributes
   0.9%     0  +    31    java.util.zip.ZipFile.getEntry
   0.3%     0  +     9    java.lang.Throwable.fillInStackTrace
   0.1%     0  +     3    java.lang.Class.forName0
   0.1%     0  +     2    java.security.AccessController.doPrivileged
   0.1%     0  +     2    java.security.AccessController.doPrivileged
   0.1%     0  +     2    java.lang.ClassLoader.findLoadedClass
   0.0%     0  +     1    java.util.zip.ZipFile.read
   0.0%     1  +     0    java.util.zip.ZipFile.getSize
   0.0%     0  +     1    sun.reflect.Reflection.getClassAccessFlags
   0.0%     0  +     1    java.lang.Class.getComponentType
   0.0%     0  +     1    java.lang.reflect.Array.newArray
   0.0%     0  +     1    java.util.zip.ZipEntry.initFields
   0.0%     1  +     0    java.lang.Thread.currentThread
   0.0%     0  +     1    sun.reflect.Reflection.getCallerClass
  95.9%     2  +  3436    Total stub

   Runtime stub + native  Method
   0.0%     1  +     0    checkcast
   0.0%     1  +     0    Total runtime stubs

   Thread-local ticks:
  37.4%  2145             Blocked (of total)
   0.1%     3             Compilation
   0.2%     8             Unknown: running frame
   1.9%    67             Unknown: thread_state



As you can see, most of the time is spent in yield(), which is
OK.  We want a typical situation where multiple threads are 
interactively vying for the component instances.  There is *alot* less 
activity in ContainerManager than in ECM.  It would be interesting
to see how the execution plays out linearly.....



-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org


Re: [HEADS UP] Don't use -Xincgc with JDK 1.4

Posted by Berin Loritsch <bl...@apache.org>.
Berin Loritsch wrote:
> There was a tip running around late last year that if you ran the JVM 
> with the -Xincgc that the system would perform better.  With my current
> testing using JDK 1.4 (final release), I found that enabling that option
> lengthens the time of the ECM/ContainerManager test by a factor of 2. In 
> both cases, the overall time is lengthened.  For the ContainerManager, 
> it is only 1.5 times as long; but for the ECM it is twice as long.
> 


BTW, my tests were running the CLient VM.  When I switched to the server 
VM, the ExcaliburComponentManager ran in less than half the time.

If you are running JDK 1.4, I highly recommend enabling the "-server"
option on the java command.  Esp. for Cocoon.

Average time went from 210 seconds for ECM to use 100 threads to request
3 components 50,000 times to only 97 seconds.  Alot of the savings has 
to do with the reduced garbage collection cycles in Server hotspot, and 
the native compilation that happens in the background.

The ContainerManager also had improvements, but not nearly as remarkable
as that.


-- 

"They that give up essential liberty to obtain a little temporary safety
  deserve neither liberty nor safety."
                 - Benjamin Franklin


---------------------------------------------------------------------
To unsubscribe, e-mail: cocoon-dev-unsubscribe@xml.apache.org
For additional commands, email: cocoon-dev-help@xml.apache.org