Java 6 JVM Hang

Question

Apologies for the long post, but I wonder if I could get some more eyeballs on this before I submit a bug report to Sun.

JVM: 6u11
O/S: Windows XP SP3
Hardware: AMD Athlon 64 X2 4600+ @ 2.41GHz, with 3.25 GB RAM.

I believe I have encountered a fault in the JVM where no thread is given a monitor. In the following thread traces, the monitor <0x12a8f9f8> was acquired by RelayedMessages-0000000001, which ended up waiting on it; that thread was subsequently notified. However, even though all of the threads listed are contending for the monitor, none are getting it.

I promise the thread dump is complete for every thread which refers to monitor <0x12a8f9f8>. The dump was obtained using Java VisualVM, three times over a period of 16 hours, and shown to be consistent each time (these threads were unchanged).

Does anyone disagree with my assessment that the JVM is failing to deliver the monitor to any of the eligible threads, when it should deliver it to one of them?

"RelayedMessages-0000000001" daemon prio=6 tid=0x03694400 nid=0x1750 waiting for monitor entry [0x05e1f000..0x05e1fc94]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at java.lang.Object.wait(Native Method)
    at com.companyremoved.thd.EzWaiter.ezWait(EzWaiter.java:249)
    - locked <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.waitWithinMessage(IsolatedObject.java:352)
    - locked <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.system.coms.ComsSender.waitForAvailablePipe(ComsSender.java:219)
    at com.companyremoved.system.coms.ComsSender.sendObject(ComsSender.java:185)
    at com.companyremoved.system.coms.ComsSender.processIocMessage(ComsSender.java:98)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:311)
    - locked <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.iocMessage(IsolatedObject.java:265)
    at com.companyremoved.ioc.IocTarget.iocMessage(IocTarget.java:138)
    at com.companyremoved.ioc.IocBinding.iocMessage(IocBinding.java:105)
    at com.companyremoved.system.coms.ComsSender$Messages.sendObject(ComsSender.java:333)
    at com.companyremoved.system.coms.ComsSender$Messages.sendObject(ComsSender.java:316)
    at com.companyremoved.system.coms.RelayedMessage.run(RelayedMessage.java:104)
    - locked <0x130fe8e0> (a com.companyremoved.system.coms.RelayedMessage)
    at com.companyremoved.thd.RunQueue.runEntry(RunQueue.java:293)
    at com.companyremoved.thd.RunQueue.run(RunQueue.java:273)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - None

"ScbPipe Writer" daemon prio=6 tid=0x4fff0c00 nid=0xf14 waiting for monitor entry [0x0594f000..0x0594fc14]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:293)
    - waiting to lock <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.iocMessage(IsolatedObject.java:265)
    at com.companyremoved.ioc.IocTarget.iocMessage(IocTarget.java:138)
    at com.companyremoved.coms.stm.ioc.ComsPipe$Receiver.scbPipeDefaultProcessor(ComsPipe.java:403)
    at com.companyremoved.scb.ScbPipe.processObject(ScbPipe.java:915)
    - locked <0x131a4ea0> (a java.lang.Object)
    at com.companyremoved.scb.ScbPipe.writerRun(ScbPipe.java:817)
    at com.companyremoved.scb.ScbPipe.run(ScbPipe.java:728)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - None

"ScbPipe Writer" daemon prio=6 tid=0x4c647400 nid=0xe00 waiting for monitor entry [0x059ef000..0x059efb94]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:293)
    - waiting to lock <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.iocMessage(IsolatedObject.java:265)
    at com.companyremoved.ioc.IocTarget.iocMessage(IocTarget.java:138)
    at com.companyremoved.coms.stm.ioc.ComsPipe$Receiver.scbPipeDefaultProcessor(ComsPipe.java:403)
    at com.companyremoved.scb.ScbPipe.processObject(ScbPipe.java:915)
    - locked <0x13188bb8> (a java.lang.Object)
    at com.companyremoved.scb.ScbPipe.writerRun(ScbPipe.java:817)
    at com.companyremoved.scb.ScbPipe.run(ScbPipe.java:728)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - None

"ScbPipe Writer" daemon prio=6 tid=0x035f7800 nid=0x1130 waiting for monitor entry [0x0726f000..0x0726fc94]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:293)
    - waiting to lock <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.iocMessage(IsolatedObject.java:265)
    at com.companyremoved.ioc.IocTarget.iocMessage(IocTarget.java:138)
    at com.companyremoved.coms.stm.ioc.ComsPipe$Receiver.scbPipeDefaultProcessor(ComsPipe.java:403)
    at com.companyremoved.scb.ScbPipe.processObject(ScbPipe.java:915)
    - locked <0x12a8a478> (a java.lang.Object)
    at com.companyremoved.scb.ScbPipe.writerRun(ScbPipe.java:817)
    at com.companyremoved.scb.ScbPipe.run(ScbPipe.java:728)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - None

"IOC Signals-0000000001" daemon prio=6 tid=0x03673000 nid=0x1434 waiting for monitor entry [0x0415f000..0x0415fd94]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:293)
    - waiting to lock <0x12a8f9f8> (a com.companyremoved.system.coms.ComsSender)
    at com.companyremoved.ioc.IsolatedObject.iocMessage(IsolatedObject.java:265)
    at com.companyremoved.ioc.IocTarget.iocMessage(IocTarget.java:138)
    at com.companyremoved.ioc.IocBinding.iocMessage(IocBinding.java:105)
    at com.companyremoved.system.coms.ComsSender$Messages.removePipe(ComsSender.java:302)
    at com.companyremoved.system.coms.ConnectionController.disconnect(ConnectionController.java:712)
    at com.companyremoved.system.coms.ConnectionController.shutdown(ConnectionController.java:224)
    at com.companyremoved.system.coms.ConnectionController.processIocMessage(ConnectionController.java:168)
    at com.companyremoved.ioc.IsolatedObject.deliver(IsolatedObject.java:311)
    - locked <0x12a8b798> (a com.companyremoved.system.coms.ConnectionController)
    at com.companyremoved.ioc.IsolatedObject.access$100(IsolatedObject.java:36)
    at com.companyremoved.ioc.IsolatedObject$SignalProxy.run(IsolatedObject.java:526)
    at com.companyremoved.thd.RunQueue.runEntry(RunQueue.java:293)
    at com.companyremoved.thd.RunQueue.run(RunQueue.java:273)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - None

Answer 1

Are you sure thread RelayedMessages-0000000001 gets notified? It is normal for the other threads to be blocked as the first thread still obtains the lock for <0x12a8f9f8>. In order to other threads can obtain the lock, first thread should be removed from wait list and scheduled to run again and afterwards release the lock that it obtained.

May be there are other threads waiting the same object that the first thread waits for and when you say notify those threads are chosen to wake up. If it is possible make sure to use notifyAll().

Also may be you can release the lock before putting the thread in wait list or call wait by giving a timeout value. it doesn't make sense that the thread is in wait list for 16 hours. If you can also post the other threads that would be also helpful.

Update:

You're right, I should've taken into consideration the Thread.State. As you commented, it is not in wait state since it has been notified. Being in wait list is not the reason of not releasing the lock <0x12a8f9f8>, then. However, it is in Blocked state. That means, it's trying to obtain the lock it had acquired prior to object.wait, but it cannot. So, it seems there is another thread (not in the list that you've provided) blocking it.

I think, you're thinking object.wait should have released the the lock <0x12a8f9f8>. But object.wait only release the lock on that object monitor and keeps the other locks. And I think, lock <0x12a8f9f8> is not the lock for the monitor of the object (for which wait is called)

This might not also be the case of course, and there can be a really bug. I am just trying to come up with possible reasons.

Answer 2

The provided thread trace is complete with respect to the lock in question. Two other people I work with agree that a JVM fault is clearly indicated, as do the programmers at jProfiler (ej-technologies).

Answer 3

it seems that there is a bug on JVM. becauase wait should release the lock. but it doesnt relase the lock. have u reported this bug to SUN?