[rabbitmq-discuss] Java client Channel.Close blocking indefinitely

Iain Hull iain.hull at workday.com
Wed Aug 31 15:38:26 BST 2011 

Hi,

I have been going through the Java Client code to see if I could spot
any problems.  I noticed that the ChannelN.close() it calls
BlockingRpcContinuation.getReply with a -1, which causes it to block
until the server sends a response to the channel.  This suggests that
the close response either got lost or was routed to the wrong channel.  

Do you have any suggestions how I can test either of these cases out?
Enable extra logging etc.
Is there any reason that this call blocks indefinitely? Could it use a
timeout make this code more robust?

In the mean time I am going to try my test with the just released 2.6.0

Regards,
Iain.

-----Original Message-----
From: rabbitmq-discuss-bounces at lists.rabbitmq.com
[mailto:rabbitmq-discuss-bounces at lists.rabbitmq.com] On Behalf Of Iain
Hull
Sent: 31 August 2011 11:06
To: rabbitmq-discuss at lists.rabbitmq.com
Subject: Re: [rabbitmq-discuss] Java client Channel.Close
blockingindefinitely

Sorry I forgot to mention that I am using rabbitmq-client-2.5.1.jar and
rabbitmq_server-2.5.1.

Iain.

-----Original Message-----
From: rabbitmq-discuss-bounces at lists.rabbitmq.com
[mailto:rabbitmq-discuss-bounces at lists.rabbitmq.com] On Behalf Of Iain
Hull
Sent: 31 August 2011 10:46
To: rabbitmq-discuss at lists.rabbitmq.com
Subject: [rabbitmq-discuss] Java client Channel.Close blocking
indefinitely

Hi,

I hope you can help.  I am investigating the feasibility of deploying
RabbitMQ in our application.  Our chosen RabbitMQ deployment requires
lots of queues.  To maintain fairness across our application every
tenant requires their own set of queues, this is to ensure that one busy
tenant does not starve the others.  As a result am trying to find the
maximum number of queues RabbitMQ can support to ensure that we can
scale the number of tenants and logical queues.

During one of my tests a call to Channel.Close blocked and never
returned.  I have included the stack trace below.  Each iteration of my
test creates three tasks per queue which send 100 messages, send and
receive 100 messages and just receive 100 messages.  It was one of these
tasks that blocked up.  The code for my test is on
http://pastebin.com/LZTcpnzd.  (CountingCompletionService is a simple
decorator on a CompletionService, but the extra code is not currently
used).

Basically I would like to know am I doing anything wrong in my test, or
is this a bug in the client?  For example is it safe to call
Channel.close in a finally block after an exception was thrown?

I am not sure if this is relevant but I noticed some information in the
logs indicating that the memory high_watermark was hit around the time
the test stopped.

Regards,
Iain.




2011-08-31 08:38:20
Full thread dump Java HotSpot(TM) 64-Bit Server VM (19.1-b02 mixed
mode):

"pool-1-thread-1" prio=6 tid=0x0000000008304000 nid=0x15d4 in
Object.wait() [0x000000000925f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:485)
	at com.rabbitmq.utility.BlockingCell.get(BlockingCell.java:50)
	- locked <0x00000007d5d09968> (a
com.rabbitmq.utility.BlockingValueOrException)
	at com.rabbitmq.utility.BlockingCell.get(BlockingCell.java:65)
	- locked <0x00000007d5d09968> (a
com.rabbitmq.utility.BlockingValueOrException)
	at
com.rabbitmq.utility.BlockingCell.uninterruptibleGet(BlockingCell.java:1
11)
	- locked <0x00000007d5d09968> (a
com.rabbitmq.utility.BlockingValueOrException)
	at
com.rabbitmq.utility.BlockingValueOrException.uninterruptibleGetValue(Bl
ockingValueOrException.java:37)
	at
com.rabbitmq.client.impl.AMQChannel$BlockingRpcContinuation.getReply(AMQ
Channel.java:334)
	at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:466)
	at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:410)
	at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:403)
	at
com.workday.messaging.test.BreakRabbitBreakTest$AbstractMessageRunner.ca
ll(BreakRabbitBreakTest.java:141)
	at
com.workday.messaging.test.BreakRabbitBreakTest$AbstractMessageRunner.ca
ll(BreakRabbitBreakTest.java:1)
	at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
r.java:886)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
va:908)
	at java.lang.Thread.run(Thread.java:662)

   Locked ownable synchronizers:
	- <0x0000000781004160> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)

"AMQP Connection 127.0.0.1:5672" prio=6 tid=0x0000000008223800
nid=0x11d4 runnable [0x000000000906f000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at
java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at
java.io.BufferedInputStream.read(BufferedInputStream.java:237)
	- locked <0x0000000781004ad8> (a java.io.BufferedInputStream)
	at
java.io.DataInputStream.readUnsignedByte(DataInputStream.java:271)
	at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:104)
	at
com.rabbitmq.client.impl.SocketFrameHandler.readFrame(SocketFrameHandler
.java:140)
	- locked <0x0000000781004ab8> (a java.io.DataInputStream)
	at
com.rabbitmq.client.impl.AMQConnection.readFrame(AMQConnection.java:397)
	at
com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:4
25)

   Locked ownable synchronizers:
	- None

"ReaderThread" prio=6 tid=0x0000000008164000 nid=0x39c runnable
[0x000000000876f000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
	at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
	at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
	- locked <0x0000000781008130> (a java.io.InputStreamReader)
	at java.io.InputStreamReader.read(InputStreamReader.java:167)
	at java.io.BufferedReader.fill(BufferedReader.java:136)
	at java.io.BufferedReader.readLine(BufferedReader.java:299)
	- locked <0x0000000781008130> (a java.io.InputStreamReader)
	at java.io.BufferedReader.readLine(BufferedReader.java:362)
	at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner$ReaderThread.run(
RemoteTestRunner.java:140)

   Locked ownable synchronizers:
	- None

"Low Memory Detector" daemon prio=6 tid=0x0000000006d76000 nid=0x1a64
runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

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

   Locked ownable synchronizers:
	- None

"Finalizer" daemon prio=8 tid=0x0000000006cfe000 nid=0x1d5c in
Object.wait() [0x0000000007a3f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
	- locked <0x0000000781014090> (a
java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
	at
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

   Locked ownable synchronizers:
	- None

"Reference Handler" daemon prio=10 tid=0x0000000006cf8000 nid=0x13d8 in
Object.wait() [0x000000000793f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:485)
	at
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
	- locked <0x0000000781002108> (a java.lang.ref.Reference$Lock)

   Locked ownable synchronizers:
	- None

"main" prio=6 tid=0x0000000000b0d000 nid=0x1f74 waiting on condition
[0x0000000002b8e000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000078100c350> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at
java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
	at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.aw
ait(AbstractQueuedSynchronizer.java:1987)
	at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:3
99)
	at
java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionSe
rvice.java:164)
	at
com.workday.messaging.test.CountingCompletionService.take(CountingComple
tionService.java:34)
	at
com.workday.messaging.test.BreakRabbitBreakTest.performTestMaxQueues(Bre
akRabbitBreakTest.java:88)
	at
com.workday.messaging.test.BreakRabbitBreakTest.testMaxQueues(BreakRabbi
tBreakTest.java:63)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.jav
a:39)
	at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessor
Impl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMet
hod.java:44)
	at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallab
le.java:15)
	at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMetho
d.java:41)
	at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod
.java:20)
	at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.jav
a:28)
	at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner
.java:76)
	at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner
.java:50)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
	at
org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
	at
org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
	at
org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
	at
org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
	at
org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4Tes
tReference.java:49)
	at
org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.ja
va:38)
	at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTe
stRunner.java:467)
	at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTe
stRunner.java:683)
	at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRun
ner.java:390)
	at
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRu
nner.java:197)

   Locked ownable synchronizers:
	- None

"VM Thread" prio=10 tid=0x0000000006cee800 nid=0xa50 runnable 

"GC task thread#0 (ParallelGC)" prio=6 tid=0x00000000001c7800 nid=0x1840
runnable 

"GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000001ca800 nid=0x17e0
runnable 

"GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000001cc000 nid=0x1a68
runnable 

"GC task thread#3 (ParallelGC)" prio=6 tid=0x00000000001ce000 nid=0x1b7c
runnable 

"GC task thread#4 (ParallelGC)" prio=6 tid=0x00000000001d1800 nid=0x1e0c
runnable 

"GC task thread#5 (ParallelGC)" prio=6 tid=0x00000000001d3000 nid=0x14c4
runnable 

"GC task thread#6 (ParallelGC)" prio=6 tid=0x00000000001d4000 nid=0xa28
runnable 

"GC task thread#7 (ParallelGC)" prio=6 tid=0x00000000001d5800 nid=0x1838
runnable 

"VM Periodic Task Thread" prio=10 tid=0x0000000006d80000 nid=0x1ae4
waiting on condition 

JNI global references: 951

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss at lists.rabbitmq.com
https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss at lists.rabbitmq.com
https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss

More information about the rabbitmq-discuss mailing list