[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [xmlblaster] locking bug
Not yet convinced:
The locking acquire approach is hierarchical, the sequence is always:
-> topicHandler.lock() -> sessionInfo.lock()
The opposite:
-> sessionInfo.lock() -> topicHandler.lock()
does not exist in that stack traces.
So this can't lead to a dead lock.
The locks used are reentrant locks, so the same thread can recursively
enter the same object multiple times.
*********
But, digging in your stack trace send some days ago I have found
following, different from all others, thread:
"XmlBlaster.SessionTimer" daemon prio=10 tid=0x00002aaac4577c00
nid=0x372a in Object.wait() [0x000000004153d000..0x000000004153da20]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at
edu.emory.mathcs.backport.java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:199)
- locked <0x00002aaab42ec888> (a
edu.emory.mathcs.backport.java.util.concurrent.locks.ReentrantLock$NonfairSync)
at
edu.emory.mathcs.backport.java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:481)
at
org.xmlBlaster.engine.TopicAccessor$TopicContainer.lock(TopicAccessor.java:403)
at org.xmlBlaster.engine.TopicAccessor.access(TopicAccessor.java:91)
at
org.xmlBlaster.engine.MsgUnitWrapper.toDestroyed(MsgUnitWrapper.java:595)
at
org.xmlBlaster.engine.MsgUnitWrapper.incrementReferenceCounter(MsgUnitWrapper.java:279)
at
org.xmlBlaster.engine.queuemsg.ReferenceEntry.incrementReferenceCounter(ReferenceEntry.java:191)
at
org.xmlBlaster.engine.queuemsg.ReferenceEntry.removed(ReferenceEntry.java:230)
at
org.xmlBlaster.util.queue.ram.RamQueuePlugin.clear(RamQueuePlugin.java:241)
at
org.xmlBlaster.authentication.Authenticate.resetSessionInfo(Authenticate.java:806)
at
org.xmlBlaster.authentication.Authenticate.disconnect(Authenticate.java:557)
at
org.xmlBlaster.authentication.AuthenticateProtector.disconnect(AuthenticateProtector.java:119)
at
org.xmlBlaster.authentication.SessionInfo.timeout(SessionInfo.java:462)
at org.xmlBlaster.util.Timeout.run(Timeout.java:190)
yes, this is the deadlock you report bewteen sessionInfo and
topicHandler/topicContainer!
RequestBroker.publish does topicHandler.lock() --->
TopicHandler.java does receiverSessionInfo.lock();
versus
SessionInfo.timeout() does sessionInfo.lock() ---> and wants
topicHandler.lock()
I'll look for a solution tomorrow morning,
thanks for your valuable input,
Marcel
Póka Balázs schrieb:
Hi Marcel,
nice approach!
Please report what you find out,
I got the problem! It's a deadlock between two ReentrantLocks. I just
captured the following log messages:
2008-10-28 12:32:27,413 ERROR [XmlBlaster.DispatchWorkerPool.nova-226]
(DebugReentrantLock.java:46) - trylock failed, locked by
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at
EDU.oswego.cs.dl.util.concurrent.ReentrantLock.acquire(ReentrantLock.java:40)
at org.xmlBlaster.util.ReentrantLock.lock(ReentrantLock.java:23)
at
org.xmlBlaster.engine.TopicHandler.forwardToDestinations(TopicHandler.java:844)
at
org.xmlBlaster.engine.TopicHandler.publish(TopicHandler.java:728)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1679)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1405)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1393)
at
org.xmlBlaster.engine.XmlBlasterImpl.publish(XmlBlasterImpl.java:180)
at
org.xmlBlaster.engine.XmlBlasterImpl.publishArr(XmlBlasterImpl.java:219)
at
org.xmlBlaster.engine.XmlBlasterImpl.publishOneway(XmlBlasterImpl.java:233)
at
org.xmlBlaster.util.protocol.RequestReplyExecutor.receiveReply(RequestReplyExecutor.java:441)
at
org.xmlBlaster.protocol.socket.HandleClient.handleMessage(HandleClient.java:194)
at
org.xmlBlaster.protocol.socket.HandleClient$1.run(HandleClient.java:369)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:665)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:690)
at java.lang.Thread.run(Thread.java:619)
2008-10-28 12:32:27,413 ERROR [XmlBlaster.DispatchWorkerPool.nova-226]
(DebugReentrantLock.java:49) - lock() called
at
org.xmlBlaster.debug.DebugReentrantLock.tryLock(DebugReentrantLock.java:40)
at
org.xmlBlaster.engine.TopicAccessor$TopicContainer.lock(TopicAccessor.java:416)
at
org.xmlBlaster.engine.TopicAccessor.findOrCreate(TopicAccessor.java:187)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1677)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1405)
at
org.xmlBlaster.engine.RequestBroker.publish(RequestBroker.java:1393)
at
org.xmlBlaster.engine.XmlBlasterImpl.publish(XmlBlasterImpl.java:180)
at
org.xmlBlaster.engine.XmlBlasterImpl.publishArr(XmlBlasterImpl.java:219)
at
org.xmlBlaster.engine.XmlBlasterImpl.publishOneway(XmlBlasterImpl.java:233)
at
org.xmlBlaster.util.protocol.RequestReplyExecutor.receiveReply(RequestReplyExecutor.java:441)
at
org.xmlBlaster.protocol.socket.HandleClient.handleMessage(HandleClient.java:194)
at
org.xmlBlaster.protocol.socket.HandleClient$1.run(HandleClient.java:369)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:665)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:690)
at java.lang.Thread.run(Thread.java:619)
2008-10-28 12:32:27,414 ERROR [XmlBlaster.DispatchWorkerPool.nova-226]
(DebugReentrantLock.java:51) - failed to lock()
at
org.xmlBlaster.debug.DebugReentrantLock.tryLock(DebugReentrantLock.java:51)
at
org.xmlBlaster.engine.TopicAccessor$TopicContainer.lock(TopicAccessor.java:416)
at
org.xmlBlaster.engine.TopicAccessor.access(TopicAccessor.java:93)
at
org.xmlBlaster.engine.MsgUnitWrapper.toDestroyed(MsgUnitWrapper.java:595)
at
org.xmlBlaster.engine.MsgUnitWrapper.incrementReferenceCounter(MsgUnitWrapper.java:279)
at
org.xmlBlaster.engine.queuemsg.ReferenceEntry.incrementReferenceCounter(ReferenceEntry.java:191)
at
org.xmlBlaster.engine.queuemsg.ReferenceEntry.removed(ReferenceEntry.java:230)
at
org.xmlBlaster.util.queue.ram.RamQueuePlugin.removeRandom(RamQueuePlugin.java:543)
at
org.xmlBlaster.util.dispatch.DispatchManager.removeFromQueue(DispatchManager.java:519)
at
org.xmlBlaster.util.dispatch.DispatchWorker.run(DispatchWorker.java:123)
at
EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:732)
at java.lang.Thread.run(Thread.java:619)
Explanation:
The first stacktrace is the current state of the thread which was the
last to successfully acquire the lock. The second stacktrace is from
the same thread as the first, but it reflects the state when the last
locking was successfully acquired. The third stacktrace is the stack
of the thread which timed out while trying to acquire the lock.
To conclude, the deadlock is between two instances of the following locks:
1) org.xmlBlaster.engine.SessionInfo.lock
2) org.xmlBlaster.authentication.TopicAccessor.TopicContainer.lock
I'm trying to decipher the exact cause and if it can be circumvented,
but I think it's better if you looked into it since this may require
more in-depth knowledge of the inner workings of the server.
Hoping to hear from you soon!
regards,
Balázs Póka
--
Marcel Ruff
http://www.xmlBlaster.org
http://watchee.net
Phone: +49 7551 309371