Stack trace provided. Help needed in debugging

Thread view:

rajatag - 19 Feb 2007 13:28 GMT

Hello,

Please see information below.

Thanks!

===============

BASIC INFO:

Given below is the stack trace of our application that connects to a
server. This application creates multiple threads. Each thread
connects separately with the server. Each thread also has a timer that
sends out a message to the client every 15 minutes.

For the output / input methods in the client, I am using the code
located at:

http://www.boutell.com/javaclass/talk/Client.java

PROBLEM:

After sometime, the threads start to lockup and no data is sent to the
server. It would be great if anyone can figure out something from the
stack trace below. In the stack trace below, only one out of 19 total
clients was active.

STACK TRACE:

Full thread dump Java HotSpot(TM) Client VM (1.5.0_10-b03 mixed mode,
sharing):

"Timer-1651" prio=1 tid=0x080f2638 nid=0x33e2 in Object.wait()
[0xb02fe000..0xb02fefb0]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x72560068> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Timer-1586" prio=1 tid=0x080b2bc0 nid=0x339e in Object.wait()
[0xb076c000..0xb076d030]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7ddd5960> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Timer-1272" prio=1 tid=0x082d5038 nid=0x323b in Object.wait()
[0xb0b74000..0xb0b75130]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7d3b0e60> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Timer-667" prio=1 tid=0xb0300470 nid=0x2e1c in Object.wait()
[0xb04e7000..0xb04e7fb0]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7c318ca8> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Timer-349" prio=1 tid=0xb0302490 nid=0x2cd7 in Object.wait()
[0xb027d000..0xb027deb0]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7b96eb70> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Timer-60" prio=1 tid=0x080a7c60 nid=0x2bb4 in Object.wait()
[0xb0568000..0xb0568f30]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7af7e188> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"DestroyJavaVM" prio=1 tid=0x0805c818 nid=0x2b44 waiting on condition
[0x00000000..0xbfffd660]

"Thread-74" prio=1 tid=0x080d0cb8 nid=0x2b89 in Object.wait()
[0xb066a000..0xb066b0b0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae94dd0> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae94dd0> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-70" prio=1 tid=0x080f1878 nid=0x2b86 in Object.wait()
[0xb07ed000..0xb07ede30]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae9b0b8> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae9b0b8> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-66" prio=1 tid=0x0829ef48 nid=0x2b83 in Object.wait()
[0xb0970000..0xb0970fb0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aea13a0> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aea13a0> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-62" prio=1 tid=0x080e8f50 nid=0x2b80 in Object.wait()
[0xb0af3000..0xb0af4130]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aea15c8> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aea15c8> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-58" prio=1 tid=0x080e4050 nid=0x2b7d in Object.wait()
[0xb0c76000..0xb0c76eb0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aea78b0> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aea78b0> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-54" prio=1 tid=0x080d4af0 nid=0x2b7a in Object.wait()
[0xb0df9000..0xb0dfa030]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aeadb98> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aeadb98> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-51" prio=1 tid=0x080da8b0 nid=0x2b78 runnable
[0xb0efb000..0xb0efc130]
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(Unknown Source)
    at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(Unknown Source)
    at sun.nio.cs.StreamDecoder$CharsetSD.implRead(Unknown Source)
    at sun.nio.cs.StreamDecoder.read(Unknown Source)
    - locked <0x7aeb3d30> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(Unknown Source)
    at java.io.BufferedReader.fill(Unknown Source)
    at java.io.BufferedReader.readLine(Unknown Source)
    - locked <0x7aeb3d30> (a java.io.InputStreamReader)
    at java.io.BufferedReader.readLine(Unknown Source)
    at ServerThread.readline(ServerThread.java:79)
    at ServerThread.inputRun(ServerThread.java:141)
    at ServerThread.run(ServerThread.java:87)
    at java.lang.Thread.run(Unknown Source)

"Thread-50" prio=1 tid=0x080d9ad8 nid=0x2b77 in Object.wait()
[0xb0f7d000..0xb0f7d1b0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aeb3e80> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aeb3e80> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Timer-12" prio=1 tid=0x080d2910 nid=0x2b76 in Object.wait()
[0xb0ffd000..0xb0ffde30]
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Unknown Source)
    - locked <0x7aeb3f00> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Unknown Source)

"Thread-46" prio=1 tid=0x082cd8a0 nid=0x2b74 in Object.wait()
[0xb10ff000..0xb10fff30]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aeba168> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aeba168> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-42" prio=1 tid=0x0829b890 nid=0x2b71 in Object.wait()
[0xb1282000..0xb12830b0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7aec0450> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7aec0450> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-38" prio=1 tid=0x082d21e8 nid=0x2b6e in Object.wait()
[0xb1405000..0xb1405e30]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae3ed80> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae3ed80> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-34" prio=1 tid=0x082d4260 nid=0x2b6b in Object.wait()
[0xb1588000..0xb1588fb0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae45038> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae45038> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-30" prio=1 tid=0x082cf3c0 nid=0x2b68 in Object.wait()
[0xb170b000..0xb170c130]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae4b320> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae4b320> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-26" prio=1 tid=0x082cad40 nid=0x2b65 in Object.wait()
[0xb188e000..0xb188eeb0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae51608> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae51608> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-22" prio=1 tid=0x082e49d8 nid=0x2b62 in Object.wait()
[0xb1a11000..0xb1a12030]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae578f0> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae578f0> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-18" prio=1 tid=0x08096ec8 nid=0x2b5f in Object.wait()
[0xb1b95000..0xb1b951b0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae5dbd8> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae5dbd8> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-14" prio=1 tid=0x08091fc8 nid=0x2b5c in Object.wait()
[0xb1d17000..0xb1d17f30]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae797f0> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae797f0> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-10" prio=1 tid=0x082ae0a0 nid=0x2b59 in Object.wait()
[0xb1e9a000..0xb1e9b0b0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae640f8> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae640f8> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-6" prio=1 tid=0x080cc638 nid=0x2b56 in Object.wait()
[0xb201d000..0xb201de30]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae64320> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae64320> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Thread-2" prio=1 tid=0x080c3a80 nid=0x2b53 in Object.wait()
[0xb21a1000..0xb21a1fb0]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x7ae6a608> (a java.util.Vector)
    at java.lang.Object.wait(Unknown Source)
    at ServerThread.outputStep(ServerThread.java:115)
    - locked <0x7ae6a608> (a java.util.Vector)
    at ServerThread.outputRun(ServerThread.java:96)
    at ServerThread.run(ServerThread.java:89)
    at java.lang.Thread.run(Unknown Source)

"Low Memory Detector" daemon prio=1 tid=0x080a59e0 nid=0x2b4a runnable
[0x00000000..0x00000000]

"CompilerThread0" daemon prio=1 tid=0x080a4430 nid=0x2b49 waiting on
condition [0x00000000..0xb260db98]

"Signal Dispatcher" daemon prio=1 tid=0x080a3520 nid=0x2b48 runnable
[0x00000000..0x00000000]

"Finalizer" daemon prio=1 tid=0x0809c688 nid=0x2b47 in Object.wait()
[0xb290f000..0xb290feb0]
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(Unknown Source)
    - locked <0x73de5e68> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(Unknown Source)
    at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

"Reference Handler" daemon prio=1 tid=0x0809b980 nid=0x2b46 in
Object.wait() [0xb2990000..0xb2990f30]
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Unknown Source)
    at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)
    - locked <0x73de5ee8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=1 tid=0x08098da0 nid=0x2b45 runnable

"VM Periodic Task Thread" prio=1 tid=0x080a6ed0 nid=0x2b4b waiting on
condition

Reply to this Message

Andrew Thompson - 19 Feb 2007 13:40 GMT

> Given below is the stack trace of our application ..

>..that connects to a
> server. This application creates multiple threads. Each thread
[quoted text clipped - 5 lines]
>
> http://www.boutell.com/javaclass/talk/Client.java

..
public class Client extends Applet implements Runnable

* To be specific, that is not an application,
but an applet. Applets can suffer extra
problems due to the VM's interaction with/
control by the browser.

I suggest you launch the applet using ..
a) web start or
b) another browser
..and see if that sorts the problem.

Andrew T.

Reply to this Message

rajatag - 19 Feb 2007 13:52 GMT

> public class Client extends Applet implements Runnable
>
[quoted text clipped - 9 lines]
>
> Andrew T.

We're running this as a console application, the only code used from
the other side is the transmission of messages for sockets (i.e. the
input / output thread concept).

Thanks!
Rajat

Reply to this Message

Chris Uppal - 19 Feb 2007 16:38 GMT

> After sometime, the threads start to lockup and no data is sent to the
> server. It would be great if anyone can figure out something from the
> stack trace below. In the stack trace below, only one out of 19 total
> clients was active.

The stack trace seems to have come from the server process, and it doesn't
really say a lot without the server code. If the problem is all in the client
then a client stack trace would be more informative.

Anyway, looking at the client code, I have a couple of comments, I don't know
whether they relate to your problem.

In your client code, when you have called flushOutputStrings() and before you
call wait(). you should flush() outputStream or the data probably won't be sent
off to the server. (You may have similar problems in the server too. If so
then that's a great way to make a client/server application deadlock itself --
client and server both think that they've sent data off to the other, so they
both wait for a response, but no data has actually been sent so nothing more
ever happens...) BTW: your code doesn't use buffering around the
SocketStreams -- that will actually reduce the chance of a problem caused by
the lack of flush()es, but will also make your application run slowly and put a
bigger load on the network than it should.

I could be wrong, but there seem to be a few places where you are updating the
GUI from one of your background threads -- you are not supposed to do that:
Swing code (with a very few exceptions) must only run on the EDT.

Your code relies on outputStings being a Vector, and thus having synchronised
methods. I can't see anything that you are doing that is wrong (but I may
easily have missed something), but it does make it harder to see /whether/ the
code is correct if the synchronisation is sometimes explicit, and sometimes
implicit. What makes it even harder to follow is that only /some/ of Vector's
methods are actually safe -- the ones it inherits from AbstractList typically
are not (e.g. addElement(Object) is safe, but add(Object) is not).

It's not usually a good idea to catch and ignore exceptions (even ones that
don't matter or "can't happen"). That's /especially/ true when you are trying
to find out why the program doesn't work !

Lastly: never use Thread.stop() -- it's deprecated for very good reason (see
the JavaDoc).

-- chris

P.S.

inputThread = new Thread(this);
outputThread = new Thread(this);
inputThread.start();
outputThread.start();

Weird !

Reply to this Message

rajatag - 20 Feb 2007 00:48 GMT

On Feb 19, 9:38 pm, "Chris Uppal" <chris.up...@metagnostic.REMOVE-
THIS.org> wrote:

> > After sometime, the threads start to lockup and no data is sent to the
> > server. It would be great if anyone can figure out something from the
[quoted text clipped - 4 lines]
> really say a lot without the server code. If the problem is all in the client
> then a client stack trace would be more informative.

This is the client stack trace. It is a console based client.

> Anyway, looking at the client code, I have a couple of comments, I don't know
> whether they relate to your problem.
[quoted text clipped - 9 lines]
> the lack of flush()es, but will also make your application run slowly and put a
> bigger load on the network than it should.

I have tried flushing but it still gave the same problem.

> I could be wrong, but there seem to be a few places where you are updating the
> GUI from one of your background threads -- you are not supposed to do that:
> Swing code (with a very few exceptions) must only run on the EDT.

GUI code from the original source has been removed.

> Your code relies on outputStings being a Vector, and thus having synchronised
> methods. I can't see anything that you are doing that is wrong (but I may
[quoted text clipped - 3 lines]
> methods are actually safe -- the ones it inherits from AbstractList typically
> are not (e.g. addElement(Object) is safe, but add(Object) is not).

This works fine in another application so we're sure its not the
portion creating a problem.

Basically it seems that it's a timer issue because when there is
continuous activity on the client, it never hangs. But as soon as
there is reduced activity it starts hanging up ... Do you think a
timer can block the socket when we add to outputStrings Vector from
within the timer?

Reply to this Message

Stack trace provided. Help needed in debugging

Free Magazines