qpid-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Pavel Moravec (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (QPID-5117) Java client deadlocks if connection is closed while onMessage() is creating a session
Date Thu, 05 Sep 2013 16:36:52 GMT

     [ https://issues.apache.org/jira/browse/QPID-5117?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Pavel Moravec updated QPID-5117:
--------------------------------

    Attachment: test_QPID5117.java

.. and I have (nondeterministic) reproducer.

java test_QPID5117 50

sometimes hungs in the deadlock (not printing out "Finishing.") with jstack:

2013-09-05 16:33:11
Full thread dump OpenJDK 64-Bit Server VM (20.0-b12 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007f3ca8001000 nid=0x799f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Dispatcher-0-Conn-1" prio=10 tid=0x00007f3cd030d000 nid=0x798f waiting for monitor entry
[0x00007f3cca6e4000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:666)
	- waiting to lock <0x00000000f2a90d30> (a java.lang.Object)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:658)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:652)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:84)
	at test_QPID5117$1.onMessage(test_QPID5117.java:45)
	at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:744)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:141)
	at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:718)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:187)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:53)
	at org.apache.qpid.client.AMQSession$Dispatcher.notifyConsumer(AMQSession.java:3362)
	at org.apache.qpid.client.AMQSession$Dispatcher.dispatchMessage(AMQSession.java:3301)
	- locked <0x00000000f23c0580> (a java.lang.Object)
	- locked <0x00000000f25147f8> (a java.lang.Object)
	at org.apache.qpid.client.AMQSession$Dispatcher.access$900(AMQSession.java:3088)
	at org.apache.qpid.client.AMQSession.dispatch(AMQSession.java:3081)
	at org.apache.qpid.client.message.UnprocessedMessage.dispatch(UnprocessedMessage.java:54)
	at org.apache.qpid.client.AMQSession$Dispatcher.run(AMQSession.java:3224)
	at java.lang.Thread.run(Thread.java:679)

"ack-flusher" daemon prio=10 tid=0x00007f3cd022e000 nid=0x798e in Object.wait() [0x00007f3cca7e5000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f23514b0> (a java.util.TaskQueue)
	at java.util.TimerThread.mainLoop(Timer.java:531)
	- locked <0x00000000f23514b0> (a java.util.TaskQueue)
	at java.util.TimerThread.run(Timer.java:484)

"IoReceiver - localhost/127.0.0.1:5672" daemon prio=10 tid=0x00007f3cd01f9000 nid=0x798d runnable
[0x00007f3ccaaed000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:146)
	at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:156)
	at java.lang.Thread.run(Thread.java:679)

"IoSender - localhost/127.0.0.1:5672" daemon prio=10 tid=0x00007f3cd017c800 nid=0x798c in
Object.wait() [0x00007f3ccabee000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f2a90120> (a java.lang.Object)
	at java.lang.Object.wait(Object.java:502)
	at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:284)
	- locked <0x00000000f2a90120> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:679)

"Low Memory Detector" daemon prio=10 tid=0x00007f3cd00a0000 nid=0x7988 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007f3cd009e000 nid=0x7987 waiting on condition
[0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007f3cd0098800 nid=0x7986 waiting on condition
[0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007f3cd008a800 nid=0x7985 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007f3cd0078000 nid=0x7984 in Object.wait() [0x00007f3ccb5d7000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f2a903b0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133)
	- locked <0x00000000f2a903b0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

"Reference Handler" daemon prio=10 tid=0x00007f3cd0076000 nid=0x7983 in Object.wait() [0x00007f3ccb6d8000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f2aa0290> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
	- locked <0x00000000f2aa0290> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x00007f3cd0008000 nid=0x797d waiting for monitor entry [0x00007f3cd4dd9000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:879)
	- waiting to lock <0x00000000f23c0580> (a java.lang.Object)
	- locked <0x00000000f2a90d30> (a java.lang.Object)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:863)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:854)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:849)
	at test_QPID5117.<init>(test_QPID5117.java:78)
	at test_QPID5117.main(test_QPID5117.java:26)

"VM Thread" prio=10 tid=0x00007f3cd0071800 nid=0x7982 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f3cd0012800 nid=0x797e runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f3cd0014800 nid=0x797f runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f3cd0016800 nid=0x7980 runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f3cd0018000 nid=0x7981 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007f3cd00a2800 nid=0x7989 waiting on condition 

JNI global references: 1618


Found one Java-level deadlock:
=============================
"Dispatcher-0-Conn-1":
  waiting to lock monitor 0x00007f3c800047a8 (object 0x00000000f2a90d30, a java.lang.Object),
  which is held by "main"
"main":
  waiting to lock monitor 0x00007f3c80006338 (object 0x00000000f23c0580, a java.lang.Object),
  which is held by "Dispatcher-0-Conn-1"

Java stack information for the threads listed above:
===================================================
"Dispatcher-0-Conn-1":
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:666)
	- waiting to lock <0x00000000f2a90d30> (a java.lang.Object)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:658)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:652)
	at org.apache.qpid.client.AMQConnection.createSession(AMQConnection.java:84)
	at test_QPID5117$1.onMessage(test_QPID5117.java:45)
	at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:744)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:141)
	at org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:718)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:187)
	at org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:53)
	at org.apache.qpid.client.AMQSession$Dispatcher.notifyConsumer(AMQSession.java:3362)
	at org.apache.qpid.client.AMQSession$Dispatcher.dispatchMessage(AMQSession.java:3301)
	- locked <0x00000000f23c0580> (a java.lang.Object)
	- locked <0x00000000f25147f8> (a java.lang.Object)
	at org.apache.qpid.client.AMQSession$Dispatcher.access$900(AMQSession.java:3088)
	at org.apache.qpid.client.AMQSession.dispatch(AMQSession.java:3081)
	at org.apache.qpid.client.message.UnprocessedMessage.dispatch(UnprocessedMessage.java:54)
	at org.apache.qpid.client.AMQSession$Dispatcher.run(AMQSession.java:3224)
	at java.lang.Thread.run(Thread.java:679)
"main":
	at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:879)
	- waiting to lock <0x00000000f23c0580> (a java.lang.Object)
	- locked <0x00000000f2a90d30> (a java.lang.Object)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:863)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:854)
	at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:849)
	at test_QPID5117.<init>(test_QPID5117.java:78)
	at test_QPID5117.main(test_QPID5117.java:26)

Found 1 deadlock.

                
> Java client deadlocks if connection is closed while onMessage() is creating a session
> -------------------------------------------------------------------------------------
>
>                 Key: QPID-5117
>                 URL: https://issues.apache.org/jira/browse/QPID-5117
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Client
>    Affects Versions: 0.22
>            Reporter: Philip Harvey
>         Attachments: jcarder_result_2.dot, test_QPID5117.java
>
>
> I have run the java systests with the [JCarder|http://jcarder.org/] agent attached. JCarder
detected a potential deadlock when the following are done concurrently:
> * Application thread closes a connection
> * A MessageListener creates a new session on that connection inside onMessage().
> Here is a sketch of the wrongly-ordered locking:
> {noformat}
> Thread "main"
> 	AMQConnection.close()
> 		AMQConnection.doClose()
> 			lock AMQConnection._sessionCreationLock
> 			lock AMQSession.getMessageDeliveryLock()
> Thread "Dispatcher-1-Conn-780"
> 	AMQSession$Dispatcher.dispatchMessage()
> 		lock AMQSession.this._messageDeliveryLock
> 		myMessageListener.onMessage()
> 			AMQConnection.createSession()
> 				lock AMQConnection._sessionCreationLock
> {noformat}
> I've attached JCarder's GraphViz-format .dot file which represents this slightly more
comprehensively.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

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


Mime
View raw message