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

["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.