You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Martin Ritchie (JIRA)" <qp...@incubator.apache.org> on 2008/07/16 13:37:31 UTC

[jira] Created: (QPID-1180) QueueBrowser receive timeout needs to be configurable.

QueueBrowser receive timeout needs to be configurable.
------------------------------------------------------

                 Key: QPID-1180
                 URL: https://issues.apache.org/jira/browse/QPID-1180
             Project: Qpid
          Issue Type: Bug
          Components: Java Client
            Reporter: Martin Ritchie


As highlighted in QPID-1179 the QueueBrowser test on a slow machine can cause the fixed timeout in receive of 1000 to be reached while there are actually messages being delivered.

The value in this receive should be configurable to prevent such failures on hardware that is known to be slow.

Logging highlighting the failure is attached in a comment:


-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (QPID-1180) QueueBrowser receive timeout needs to be configurable.

Posted by "Martin Ritchie (JIRA)" <qp...@incubator.apache.org>.
     [ https://issues.apache.org/jira/browse/QPID-1180?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Martin Ritchie updated QPID-1180:
---------------------------------

    Attachment: TEST-org.apache.qpid.test.client.QueueBrowserTransactedTest.txt

Extracted summary of the test run

> QueueBrowser receive timeout needs to be configurable.
> ------------------------------------------------------
>
>                 Key: QPID-1180
>                 URL: https://issues.apache.org/jira/browse/QPID-1180
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Client
>            Reporter: Martin Ritchie
>         Attachments: TEST-org.apache.qpid.test.client.QueueBrowserTransactedTest.txt
>
>
> As highlighted in QPID-1179 the QueueBrowser test on a slow machine can cause the fixed timeout in receive of 1000 to be reached while there are actually messages being delivered.
> The value in this receive should be configurable to prevent such failures on hardware that is known to be slow.
> Logging highlighting the failure is attached in a comment:

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (QPID-1180) QueueBrowser receive timeout needs to be configurable.

Posted by "Aidan Skinner (JIRA)" <qp...@incubator.apache.org>.
     [ https://issues.apache.org/jira/browse/QPID-1180?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Aidan Skinner updated QPID-1180:
--------------------------------

    Fix Version/s: M3

> QueueBrowser receive timeout needs to be configurable.
> ------------------------------------------------------
>
>                 Key: QPID-1180
>                 URL: https://issues.apache.org/jira/browse/QPID-1180
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Client
>            Reporter: Martin Ritchie
>             Fix For: M3
>
>         Attachments: TEST-org.apache.qpid.test.client.QueueBrowserTransactedTest.txt
>
>
> As highlighted in QPID-1179 the QueueBrowser test on a slow machine can cause the fixed timeout in receive of 1000 to be reached while there are actually messages being delivered.
> The value in this receive should be configurable to prevent such failures on hardware that is known to be slow.
> Logging highlighting the failure is attached in a comment:

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (QPID-1180) QueueBrowser receive timeout needs to be configurable.

Posted by "Martin Ritchie (JIRA)" <qp...@incubator.apache.org>.
    [ https://issues.apache.org/jira/browse/QPID-1180?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12613921#action_12613921 ] 

Martin Ritchie commented on QPID-1180:
--------------------------------------

There are 100 messages on the queue and everything is going fine up to this point:

...
main 2008-07-15 22:52:35,197 INFO [apache.qpid.client.AMQQueueBrowser] QB:nextElement received:Body:
Message 41
JMS Correlation ID: null
JMS timestamp: 1216158752929
JMS expiration: 0
JMS priority: 0
JMS delivery mode: 2
JMS Redelivered: false
JMS Destination: direct://amq.direct//example.queue?routingkey='example.queue'&durable='true'
JMS Type: null
JMS MessageID: ID:92ddf169-c7b5-46d4-9813-dd4f08e8b4a1
AMQ message number: 582
Properties:
{MessageIDProperty=[INT: 41]}
main 2008-07-15 22:52:35,197 INFO [apache.qpid.client.AMQQueueBrowser] QB:hasMoreElements:true
main 2008-07-15 22:52:35,197 INFO [apache.qpid.client.AMQQueueBrowser] QB:nextElement about to receive
...
<Next Logging is by broker processing messages on the queue, checking the filters for message delivery and sending them out>
pool-6-thread-3 2008-07-15 22:52:35,198 DEBUG [qpid.server.subscription.SubscriptionImpl] (5486927) checking filters for message ((HC:10813582 ID:61 Ref:1)
pool-6-thread-3 2008-07-15 22:52:35,198 DEBUG [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is '<snip>'
pool-6-thread-3 2008-07-15 22:52:35,198 DEBUG [qpid.server.protocol.AMQPFastProtocolHandler] Message sent: org.apache.qpid.server.output.amqp0_9.ProtocolOutputConverterImpl$CompositeAMQBodyBlock@1f15f1a
...
<The client then gets these msgs>
pool-6-thread-4 2008-07-15 22:52:39,865 DEBUG [qpid.client.protocol.AMQProtocolHandler] (32978439)Method frame received: [BasicDeliverBodyImpl: consumerTag=10, deliveryTag=583, redelivered=false, exchange=amq.direct, routingKey=example.queue]
pool-6-thread-4 2008-07-15 22:52:39,865 DEBUG [qpid.client.handler.BasicDeliverMethodHandler] New JmsDeliver method received:org.apache.qpid.client.protocol.AMQProtocolSession@164c243
pool-6-thread-4 2008-07-15 22:52:39,865 DEBUG [apache.qpid.client.AMQSession] Message[Channel Id : 1ContentHeader org.apache.qpid.framing.ContentHeaderBody@c2a5a5] received in session
pool-6-thread-4 2008-07-15 22:52:39,865 DEBUG [apache.qpid.framing.BasicContentHeaderProperties] Property flags: 63936
...
<But the client has waited to long>
main 2008-07-15 22:52:39,870 INFO [apache.qpid.client.AMQQueueBrowser] QB:nextElement received:null
main 2008-07-15 22:52:39,870 INFO [apache.qpid.client.AMQQueueBrowser] QB:hasMoreElements:false
Dispatcher-Channel-1 2008-07-15 22:52:39,870 DEBUG [apache.qpid.client.BasicMessageConsumer] notifyMessage called with message number 583
Dispatcher-Channel-1 2008-07-15 22:52:39,871 DEBUG [qpid.client.message.AbstractJMSMessageFactory] Non-fragmented message body (bodySize=10)
Dispatcher-Channel-1 2008-07-15 22:52:39,871 DEBUG [qpid.client.message.AbstractJMSMessageFactory] Creating message from buffer with position=0 and remaining=10
Dispatcher-Channel-1 2008-07-15 22:52:39,871 DEBUG [apache.qpid.framing.FieldTable] FieldTable::PropFieldTable(buffer,23): Read type 'INT', key 'MessageIDProperty', value '42'
...
<The broker and dispatcher then fight for CPU to send out and deliver the remainder of the queue>
...
<But the client has timed out the receive and failed the test>
main 2008-07-15 22:52:39,885 INFO [apache.qpid.client.AMQSession] Closing session: org.apache.qpid.client.AMQSession_0_8@157c7e6
main 2008-07-15 22:52:39,885 INFO [apache.qpid.client.BasicMessageConsumer] Closing consumer:10[16830647]
main 2008-07-15 22:52:39,886 DEBUG [qpid.client.protocol.AMQProtocolSession] closeSession called on protocol session for session 1
main 2008-07-15 22:52:39,886 DEBUG [apache.qpid.framing.AMQDataBlockEncoder] Encoded frame byte-buffer is '0x010001000000250014002800c81a4a4d5320636c69656e7420636c6f73696e67206368616e6e656c00000000ce'
main 2008-07-15 22:52:39,886 DEBUG [qpid.client.protocol.AMQProtocolHandler] Sent frame Frame channelId: 1, bodyFrame: [ChannelCloseBodyImpl: replyCode=200, replyText=JMS client closing channel, classId=0, methodId=0]
pool-6-thread-3 2008-07-15 22:52:39,886 DEBUG [qpid.server.protocol.AMQProtocolSession] Frame Received: Frame channelId: 1, bodyFrame: [ChannelCloseBodyImpl: replyCode=200, replyText=JMS client closing channel, classId=0, methodId=0]



> QueueBrowser receive timeout needs to be configurable.
> ------------------------------------------------------
>
>                 Key: QPID-1180
>                 URL: https://issues.apache.org/jira/browse/QPID-1180
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Client
>            Reporter: Martin Ritchie
>
> As highlighted in QPID-1179 the QueueBrowser test on a slow machine can cause the fixed timeout in receive of 1000 to be reached while there are actually messages being delivered.
> The value in this receive should be configurable to prevent such failures on hardware that is known to be slow.
> Logging highlighting the failure is attached in a comment:

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (QPID-1180) QueueBrowser receive timeout needs to be configurable.

Posted by "Marnie McCormack (JIRA)" <qp...@incubator.apache.org>.
     [ https://issues.apache.org/jira/browse/QPID-1180?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Marnie McCormack updated QPID-1180:
-----------------------------------

    Fix Version/s:     (was: M4)

Descoping items not being worked on for M4 into Unknown Fix Version for now

> QueueBrowser receive timeout needs to be configurable.
> ------------------------------------------------------
>
>                 Key: QPID-1180
>                 URL: https://issues.apache.org/jira/browse/QPID-1180
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Client
>            Reporter: Martin Ritchie
>            Assignee: Martin Ritchie
>         Attachments: TEST-org.apache.qpid.test.client.QueueBrowserTransactedTest.txt
>
>
> As highlighted in QPID-1179 the QueueBrowser test on a slow machine can cause the fixed timeout in receive of 1000 to be reached while there are actually messages being delivered.
> The value in this receive should be configurable to prevent such failures on hardware that is known to be slow.
> Logging highlighting the failure is attached in a comment:

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.