You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@commons.apache.org by Rick Moynihan <ri...@calicojack.co.uk> on 2006/07/13 15:01:06 UTC

Re: [Launcher] Eating my cpu

I have recently been diagnosing a performance issue with a network
service we are starting via commons launcher.

The problem is that the service starts excessively consuming CPU cycles
to the point at having near 100% utilisation (as shown by top).

At first I thought it was in some of our code, but after running hprof I
 managed to trace the problem into Commons Launcher.  After searching
the commons mail archives I uncovered this post concerning what looks to
be precisely the issue I have diagnosed.  My hprof results are almost
identical.

I am running this on Linux with Java 1.5.0-b64, though I have
experienced what appears to be the same problem under 1.4 vm's and also
on Solaris 9.  To my knowledge Windows does not suffer from this.

It appears to me that this issue seems to have been unresolved, is this
true?  Commons Launcher also seems to be suffering from a lack of usage
and community, has it been abandoned??  Is it still being used by the
Tomcat community?  If so have they resolved this issue or not?

I have done some digging in the commons launcher source code and have
found that the ParentListener class seems to be the root of the problem.
  The javadoc class description describes ParentListener as  "A class
for detecting if the parent JVM that launched this process  terminated."

On Unix/Linux the problem appears to be the following code:

// Cache System.in in case the application redirects
InputStream is = System.in;
int bytesAvailable = 0;
int bytesRead = 0;
byte[] buf = new byte[1024];
try {
    while (true) {
        synchronized (is) {
            // Mark the stream position so that other threads can
            // reread the strea
            is.mark(buf.length);
            // Read one more byte than has already been read to
            // force the stream to wait for input
            bytesAvailable = is.available();
            if (bytesAvailable < buf.length) {
                bytesRead = is.read(buf, 0, bytesAvailable + 1);
                // Reset so that we "unread" the bytes that we read
                is.reset();
                if (bytesRead == -1)
                    break;
            } else {
                // Make the buffer larger
                if (buf.length < Integer.MAX_VALUE / 2)
                    buf = new byte[buf.length * 2];
            }
        }
        yield();
    }
} catch (IOException ioe) {}


Note that this loops forever until the input stream returns -1
(presumably on it's closing).  Despite the call to yield() I fear that
the problem is that this loop is incredibly tight and is what is causing
the CPU drain.  Is there anyway that this can be efficiently alleviated?
  Perhaps rather than using the classical java.io it could be moved to
use java.nio?  Would this not remove the requirement to fire off a
separate thread?  I believe that Java NIO was introduced in Java 1.4.2,
does launcher need to support versions prior to this?

Any thoughts on the best way to resolve this issue would be highly
appreciated.

R.

on 10/10/05 21:06 Warren Crossing said the following:
> Sorry I include Thread 0 here
> 
> "Thread-0" daemon prio=1 tid=0x081dd158 nid=0x70be runnable
> [bdbff000..bdbff8cc]
>         at java.io.FileInputStream.available(Native Method)
>         at
> java.io.BufferedInputStream.available(BufferedInputStream.java:337)
>         - locked <0x469a6288> (a java.io.BufferedInputStream)
>         at
> org.apache.commons.launcher.ParentListener.run(ParentListener.java:113)
>         - locked <0x469a6288> (a java.io.BufferedInputStream)
> 
> 
> Warren Crossing wrote:
>> My Cpu level suddenly shot up to 99% "wow that's a lot of work for a
>> AMD Athlon(tm) 64 Processor 3500+ (actually a 2.2Ghz).
>>
>> Then I checked top like this
>>
>> top
>>
>> PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>> 28862 warren    25   0  431m 218m  48m R 81.4 21.6  34:22.14
>> /opt/j2sdk1.4.2_08/jre/bin/java -Xdebug -
>>
>> Then using Nicks outstanding knowledge of python
>> python
>>
>>  >>> "%x" % 28862
>> '70be'
>>
>>
>> Then I hit CTRL-\ for SIG QUIT  and get this...
>>
>> Thread 0 is eating all the CPU, but why? If know one knows I will
>> check the code site?
>>
>> Full thread dump Java HotSpot(TM) Client VM (1.4.2_08-b03 mixed mode):
>>
>> "Thread-6" prio=1 tid=0x082592d0 nid=0x70b1 runnable [be1ff000..be1ff8cc]
>>         at java.io.FileInputStream.readBytes(Native Method)
>>         at java.io.FileInputStream.read(FileInputStream.java:194)
>>         at
>> java.io.BufferedInputStream.read1(BufferedInputStream.java:220)
>>         at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
>>         - locked <0x44c93d10> (a java.io.BufferedInputStream)
>>         at java.io.FilterInputStream.read(FilterInputStream.java:90)
>>         at
>> org.apache.commons.launcher.StreamConnector.run(StreamConnector.java:74)
>>
>> "Thread-5" prio=1 tid=0x08259080 nid=0x70af runnable [be5ff000..be5ff8cc]
>>         at java.io.FileInputStream.readBytes(Native Method)
>>         at java.io.FileInputStream.read(FileInputStream.java:177)
>>         at
>> org.apache.commons.launcher.StreamConnector.run(StreamConnector.java:74)
>>
>> "Thread-4" prio=1 tid=0x08258e90 nid=0x70ae runnable [be7ff000..be7ff8cc]
>>         at java.io.FileInputStream.readBytes(Native Method)
>>         at java.io.FileInputStream.read(FileInputStream.java:194)
>>         at
>> java.io.BufferedInputStream.read1(BufferedInputStream.java:220)
>>         at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
>>         - locked <0x447c1dd0> (a java.io.BufferedInputStream)
>>         at java.io.FilterInputStream.read(FilterInputStream.java:90)
>>         at
>> org.apache.commons.launcher.StreamConnector.run(StreamConnector.java:74)
>>
>> "process reaper" daemon prio=1 tid=0x082583b8 nid=0x70aa runnable
>> [be9ff000..be9ff8cc]
>>         at java.lang.UNIXProcess.waitForProcessExit(Native Method)
>>         at java.lang.UNIXProcess.access$1500(UNIXProcess.java:20)
>>         at java.lang.UNIXProcess$2.run(UNIXProcess.java:127)
>>
>> "Signal Dispatcher" daemon prio=1 tid=0x080a83e0 nid=0x7098 waiting on
>> condition [0..0]
>>
>> "Finalizer" daemon prio=1 tid=0x080932f0 nid=0x7096 in Object.wait()
>> [bf3ff000..bf3ff8cc]
>>         at java.lang.Object.wait(Native Method)
>>         - waiting on <0x44c921c8> (a java.lang.ref.ReferenceQueue$Lock)
>>         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
>>         - locked <0x44c921c8> (a java.lang.ref.ReferenceQueue$Lock)
>>         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
>>         at
>> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>>
>> "Reference Handler" daemon prio=1 tid=0x08092778 nid=0x7095 in
>> Object.wait() [bf5ff000..bf5ff8cc]
>>         at java.lang.Object.wait(Native Method)
>>         - waiting on <0x44c92230> (a java.lang.ref.Reference$Lock)
>>         at java.lang.Object.wait(Object.java:429)
>>         at
>> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
>>         - locked <0x44c92230> (a java.lang.ref.Reference$Lock)
>>
>> "main" prio=1 tid=0x0805b9a0 nid=0x7092 in Object.wait()
>> [bfffb000..bfffc718]
>>         at java.lang.Object.wait(Native Method)
>>         - waiting on <0x447bb8c8> (a java.lang.UNIXProcess)
>>         at java.lang.Object.wait(Object.java:429)
>>         at java.lang.UNIXProcess.waitFor(UNIXProcess.java:160)
>>         - locked <0x447bb8c8> (a java.lang.UNIXProcess)
>>         at
>> org.apache.commons.launcher.LaunchTask.execute(LaunchTask.java:664)
>>         at
>> org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:275)
>>         at org.apache.tools.ant.Task.perform(Task.java:364)
>>         at org.apache.tools.ant.Target.execute(Target.java:341)
>>         at org.apache.tools.ant.Target.performTasks(Target.java:369)
>>         at org.apache.tools.ant.Project.executeTarget(Project.java:1214)
>>         at org.apache.commons.launcher.Launcher.start(Launcher.java:370)
>>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>         at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>
>>         at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>
>>         at java.lang.reflect.Method.invoke(Method.java:324)
>>         at LauncherBootstrap.main(LauncherBootstrap.java:142)
>>
>> "VM Thread" prio=1 tid=0x0808f5f0 nid=0x7094 runnable
>>
>> "VM Periodic Task Thread" prio=1 tid=0x080aab20 nid=0x709a waiting on
>> condition
>> "Suspend Checker Thread" prio=1 tid=0x080a7a40 nid=0x7097 runnable
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: commons-user-unsubscribe@jakarta.apache.org
>> For additional commands, e-mail: commons-user-help@jakarta.apache.org
>>
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: commons-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: commons-user-help@jakarta.apache.org
> 

---------------------------------------------------------------------
To unsubscribe, e-mail: commons-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: commons-user-help@jakarta.apache.org