You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Robbie Gemmell (JIRA)" <ji...@apache.org> on 2015/12/18 16:37:47 UTC

[jira] [Commented] (QPID-6863) AMQP 1.0 message flow to consumers stops

    [ https://issues.apache.org/jira/browse/QPID-6863?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15064101#comment-15064101 ] 

Robbie Gemmell commented on QPID-6863:
--------------------------------------

Adding links to the causes, QPID-6947 and then PROTON-1077.

> 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