You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2015/11/17 08:39:11 UTC
[jira] [Created] (QPID-6863) AMQP 1.0 message flow to consumers
stops
Keith Wall created QPID-6863:
--------------------------------
Summary: AMQP 1.0 message flow to consumers stops
Key: QPID-6863
URL: https://issues.apache.org/jira/browse/QPID-6863
Project: Qpid
Issue Type: Bug
Components: Java Broker
Affects Versions: qpid-java-6.0
Reporter: Keith Wall
I am seeing an issue whilst running the Java perf tests (transient/autoack plain) where the flow of messages to the participant consumers is seen to stop. The problem manifests for me for at around the 32768 flow rate..
The Broker seems to indicate that flow to all queues is suspended (indicated by a succession of SUB-1003 messages with times steadily increasing). The participant producers continue to fill the Broker, which eventually runs out of direct memory.
To reproduce I am running with QPID-6852 applied and a local change to perftests/etc/testdefs/defaultTests.js to run only the second test. Test fails after about 1 min.
{code}
mvn -f perftests/pom.xml -Dclient=qpid-jms-client exec:java -Dqpid.disttest.hillclimb=true -Dqpid.disttest.duration=20000 -Dqpid.disttest.hillclimb.start_target_rate=16384 -Dqpid.disttest.loglevel=debug
{code}
{noformat}
2015-11-17 07:32:00,881 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 10,059 ms
2015-11-17 07:32:04,071 INFO [IO-/127.0.0.1:57542] (q.m.s.state) - [IO Pool] [sub:109(vh(/default)/qu(testQueue_8)] SUB-1003 : Suspended for 10,000 ms
2015-11-17 07:32:04,604 INFO [IO-/127.0.0.1:57539] (q.m.q.flow_to_disk_active) - [con:75(guest@/127.0.0.1:57539/default)/ch:1] [vh(/default)/qu(testQueue_7)] QUE-1014 : Message flow to disk active : Message memory use 46277632 kB exceeds threshold 46277154 kB
2015-11-17 07:32:07,704 INFO [IO-/127.0.0.1:57541] (q.m.q.flow_to_disk_active) - [con:77(guest@/127.0.0.1:57541/default)/ch:1] [vh(/default)/qu(testQueue_8)] QUE-1014 : Message flow to disk active : Message memory use 46277632 kB exceeds threshold 46277154 kB
2015-11-17 07:32:09,001 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:66(guest@/127.0.0.1:57530/default)/ch:1] [sub:103(vh(/default)/qu(testQueue_2)] SUB-1002 : Close
2015-11-17 07:32:09,112 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:80(guest@/127.0.0.1:57544/default)/ch:1] [sub:110(vh(/default)/qu(testQueue_9)] SUB-1002 : Close
2015-11-17 07:32:09,140 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:64(guest@/127.0.0.1:57528/default)/ch:1] [sub:102(vh(/default)/qu(testQueue_1)] SUB-1002 : Close
2015-11-17 07:32:09,205 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:72(guest@/127.0.0.1:57536/default)/ch:1] [sub:106(vh(/default)/qu(testQueue_5)] SUB-1002 : Close
2015-11-17 07:32:09,314 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:70(guest@/127.0.0.1:57534/default)/ch:1] [sub:105(vh(/default)/qu(testQueue_4)] SUB-1002 : Close
2015-11-17 07:32:09,316 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:68(guest@/127.0.0.1:57532/default)/ch:1] [sub:104(vh(/default)/qu(testQueue_3)] SUB-1002 : Close
2015-11-17 07:32:09,353 INFO [VirtualHostNode-default-Config] (q.m.s.close) - [con:62(guest@/127.0.0.1:57526/default)/ch:1] [sub:101(vh(/default)/qu(testQueue_0)] SUB-1002 : Close
2015-11-17 07:32:10,581 INFO [IO-/127.0.0.1:57541] (q.m.q.flow_to_disk_inactive) - [con:77(guest@/127.0.0.1:57541/default)/ch:1] [vh(/default)/qu(testQueue_8)] QUE-1015 : Message flow to disk inactive : Message memory use 50240512 kB within threshold 456207857 kB
2015-11-17 07:32:10,581 INFO [IO-/127.0.0.1:57539] (q.m.q.flow_to_disk_inactive) - [con:75(guest@/127.0.0.1:57539/default)/ch:1] [vh(/default)/qu(testQueue_7)] QUE-1015 : Message flow to disk inactive : Message memory use 50536448 kB within threshold 458895152 kB
2015-11-17 07:32:10,813 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 20,000 ms
2015-11-17 07:32:14,353 INFO [IO-/127.0.0.1:57542] (q.m.s.state) - [IO Pool] [sub:109(vh(/default)/qu(testQueue_8)] SUB-1003 : Suspended for 20,282 ms
2015-11-17 07:32:15,206 INFO [IO-/127.0.0.1:57538] (q.m.s.state) - [IO Pool] [sub:107(vh(/default)/qu(testQueue_6)] SUB-1003 : Suspended for 10,000 ms
2015-11-17 07:32:20,813 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 30,000 ms
2015-11-17 07:32:24,071 INFO [IO-/127.0.0.1:57542] (q.m.s.state) - [IO Pool] [sub:109(vh(/default)/qu(testQueue_8)] SUB-1003 : Suspended for 30,000 ms
2015-11-17 07:32:24,561 INFO [IO-/127.0.0.1:57525] (q.m.q.flow_to_disk_active) - [con:61(guest@/127.0.0.1:57525/default)/ch:1] [vh(/default)/qu(testQueue_0)] QUE-1014 : Message flow to disk active : Message memory use 50650112 kB exceeds threshold 50649468 kB
2015-11-17 07:32:25,209 INFO [IO-/127.0.0.1:57538] (q.m.s.state) - [IO Pool] [sub:107(vh(/default)/qu(testQueue_6)] SUB-1003 : Suspended for 20,004 ms
2015-11-17 07:32:27,973 INFO [IO-/127.0.0.1:57527] (q.m.q.flow_to_disk_active) - [con:63(guest@/127.0.0.1:57527/default)/ch:1] [vh(/default)/qu(testQueue_1)] QUE-1014 : Message flow to disk active : Message memory use 55094272 kB exceeds threshold 55094198 kB
2015-11-17 07:32:28,589 INFO [IO-/127.0.0.1:57543] (q.m.q.flow_to_disk_active) - [con:79(guest@/127.0.0.1:57543/default)/ch:1] [vh(/default)/qu(testQueue_9)] QUE-1014 : Message flow to disk active : Message memory use 58702848 kB exceeds threshold 58702054 kB
2015-11-17 07:32:28,680 INFO [IO-/127.0.0.1:57529] (q.m.q.flow_to_disk_active) - [con:65(guest@/127.0.0.1:57529/default)/ch:1] [vh(/default)/qu(testQueue_2)] QUE-1014 : Message flow to disk active : Message memory use 58404864 kB exceeds threshold 58404499 kB
2015-11-17 07:32:29,293 INFO [IO-/127.0.0.1:57531] (q.m.q.flow_to_disk_active) - [con:67(guest@/127.0.0.1:57531/default)/ch:1] [vh(/default)/qu(testQueue_3)] QUE-1014 : Message flow to disk active : Message memory use 60897280 kB exceeds threshold 60896523 kB
2015-11-17 07:32:29,519 INFO [IO-/127.0.0.1:57533] (q.m.q.flow_to_disk_active) - [con:69(guest@/127.0.0.1:57533/default)/ch:1] [vh(/default)/qu(testQueue_4)] QUE-1014 : Message flow to disk active : Message memory use 61827072 kB exceeds threshold 61826383 kB
2015-11-17 07:32:30,440 INFO [IO-/127.0.0.1:57535] (q.m.q.flow_to_disk_active) - [con:71(guest@/127.0.0.1:57535/default)/ch:1] [vh(/default)/qu(testQueue_5)] QUE-1014 : Message flow to disk active : Message memory use 67294208 kB exceeds threshold 67293959 kB
2015-11-17 07:32:30,817 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 40,004 ms
2015-11-17 07:32:34,072 INFO [IO-/127.0.0.1:57542] (q.m.s.state) - [IO Pool] [sub:109(vh(/default)/qu(testQueue_8)] SUB-1003 : Suspended for 40,000 ms
2015-11-17 07:32:35,268 INFO [IO-/127.0.0.1:57538] (q.m.s.state) - [IO Pool] [sub:107(vh(/default)/qu(testQueue_6)] SUB-1003 : Suspended for 30,062 ms
2015-11-17 07:32:40,955 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 50,142 ms
2015-11-17 07:32:40,965 INFO [IO-/127.0.0.1:57529] (q.m.q.flow_to_disk_inactive) - [con:65(guest@/127.0.0.1:57529/default)/ch:1] [vh(/default)/qu(testQueue_2)] QUE-1015 : Message flow to disk inactive : Message memory use 91884544 kB within threshold 136494259 kB
2015-11-17 07:32:40,965 INFO [IO-/127.0.0.1:57533] (q.m.q.flow_to_disk_inactive) - [con:69(guest@/127.0.0.1:57533/default)/ch:1] [vh(/default)/qu(testQueue_4)] QUE-1015 : Message flow to disk inactive : Message memory use 92329984 kB within threshold 137155966 kB
2015-11-17 07:32:40,965 INFO [IO-/127.0.0.1:57527] (q.m.q.flow_to_disk_inactive) - [con:63(guest@/127.0.0.1:57527/default)/ch:1] [vh(/default)/qu(testQueue_1)] QUE-1015 : Message flow to disk inactive : Message memory use 90429440 kB within threshold 134332681 kB
2015-11-17 07:32:40,965 INFO [IO-/127.0.0.1:57543] (q.m.q.flow_to_disk_inactive) - [con:79(guest@/127.0.0.1:57543/default)/ch:1] [vh(/default)/qu(testQueue_9)] QUE-1015 : Message flow to disk inactive : Message memory use 91532288 kB within threshold 135970978 kB
2015-11-17 07:32:40,966 INFO [IO-/127.0.0.1:57531] (q.m.q.flow_to_disk_inactive) - [con:67(guest@/127.0.0.1:57531/default)/ch:1] [vh(/default)/qu(testQueue_3)] QUE-1015 : Message flow to disk inactive : Message memory use 92062720 kB within threshold 136758942 kB
2015-11-17 07:32:40,968 INFO [IO-/127.0.0.1:57535] (q.m.q.flow_to_disk_inactive) - [con:71(guest@/127.0.0.1:57535/default)/ch:1] [vh(/default)/qu(testQueue_5)] QUE-1015 : Message flow to disk inactive : Message memory use 93029376 kB within threshold 138194923 kB
2015-11-17 07:32:40,969 INFO [IO-/127.0.0.1:57525] (q.m.q.flow_to_disk_inactive) - [con:61(guest@/127.0.0.1:57525/default)/ch:1] [vh(/default)/qu(testQueue_0)] QUE-1015 : Message flow to disk inactive : Message memory use 89222144 kB within threshold 132539226 kB
2015-11-17 07:32:44,071 INFO [IO-/127.0.0.1:57542] (q.m.s.state) - [IO Pool] [sub:109(vh(/default)/qu(testQueue_8)] SUB-1003 : Suspended for 50,000 ms
2015-11-17 07:32:45,210 INFO [IO-/127.0.0.1:57538] (q.m.s.state) - [IO Pool] [sub:107(vh(/default)/qu(testQueue_6)] SUB-1003 : Suspended for 40,004 ms
2015-11-17 07:32:50,897 INFO [IO-/127.0.0.1:57540] (q.m.s.state) - [IO Pool] [sub:108(vh(/default)/qu(testQueue_7)] SUB-1003 : Suspended for 60,084 ms
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org