Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1090368 - [Selectors] does not recognize redelivered message with amqp.redelivered
Summary: [Selectors] does not recognize redelivered message with amqp.redelivered
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: qpid-cpp
Version: 3.0
Hardware: Unspecified
OS: Unspecified
medium
high
Target Milestone: 3.0
: ---
Assignee: Andrew Stitcher
QA Contact: Zdenek Kraus
URL:
Whiteboard:
Depends On:
Blocks: 453539
TreeView+ depends on / blocked
 
Reported: 2014-04-23 07:52 UTC by Zdenek Kraus
Modified: 2014-09-24 15:11 UTC (History)
5 users (show)

Fixed In Version: qpid-cpp-0.22-40
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-09-24 15:11:14 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Apache JIRA QPID-5735 None None None Never
Red Hat Product Errata RHEA-2014:1296 normal SHIPPED_LIVE Red Hat Enterprise MRG Messaging 3.0 Release 2014-09-24 19:00:06 UTC

Description Zdenek Kraus 2014-04-23 07:52:53 UTC
[Selectors] does not recognize redelivered message with amqp.redelivered

Description of problem:
selector amqp.redelivered treating all messages as not redelivered.

Version-Release number of selected component (if applicable):
qpid-cpp-server-0.22-37

How reproducible:
100%

Steps to Reproduce:
# create redelivered message
1. ./qc2_spout --log-msgs dict "q;{create:always}"
2. ./qc2_drain -a noack "q"

# create not redelivered message
3. ./qc2_spout --log-msgs dict "q;{create:always}"

# read redelivered messages
4. ./qc2_drain --log-msgs dict "q;{link:{selector:\"amqp.redelivered = TRUE\"}}"

# read not redelivered messages
5. ./qc2_drain --log-msgs dict "q;{link:{selector:\"amqp.redelivered = FALSE\"}}"

Actual results:
[4]

[5]
{'redelivered': True, 'reply_to': None, 'subject': None, 'content_type': None, 'id': None, 'user_id': None, 'correlation_id': None, 'priority': 0, 'durable': False, 'ttl': 0.000000e+00, 'size': None, 'properties': {'spout-id': '8db488f5-1b91-43f6-a5f8-5c6ae994d072:0', 'x-amqp-0-10.routing-key': 'q'}, 'content': None}
{'redelivered': False, 'reply_to': None, 'subject': None, 'content_type': None, 'id': None, 'user_id': None, 'correlation_id': None, 'priority': 0, 'durable': False, 'ttl': 0.000000e+00, 'size': None, 'properties': {'spout-id': '479cb9c7-2e9b-45ad-a122-78409c9b236d:0', 'x-amqp-0-10.routing-key': 'q'}, 'content': None}

Expected results:
[4]
{'redelivered': True, 'reply_to': None, 'subject': None, 'content_type': None, 'id': None, 'user_id': None, 'correlation_id': None, 'priority': 0, 'durable': False, 'ttl': 0.000000e+00, 'size': None, 'properties': {'spout-id': '8db488f5-1b91-43f6-a5f8-5c6ae994d072:0', 'x-amqp-0-10.routing-key': 'q'}, 'content': None}

[5]
{'redelivered': False, 'reply_to': None, 'subject': None, 'content_type': None, 'id': None, 'user_id': None, 'correlation_id': None, 'priority': 0, 'durable': False, 'ttl': 0.000000e+00, 'size': None, 'properties': {'spout-id': '479cb9c7-2e9b-45ad-a122-78409c9b236d:0', 'x-amqp-0-10.routing-key': 'q'}, 'content': None}

Additional info:

# qpid log
2014-04-23 09:47:02 [Model] debug Create connection. user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47217
2014-04-23 09:47:02 [Broker] debug anonymous.2ca67218-6613-426f-bbb1-d7b75b005f7d: attached on broker.
2014-04-23 09:47:02 [Broker] debug anonymous.2ca67218-6613-426f-bbb1-d7b75b005f7d: ready to send, activating output.
2014-04-23 09:47:02 [Broker] debug Selector parsed[amqp.redelivered = TRUE] into: (I:amqp.redelivered=BOOL:true)
2014-04-23 09:47:02 [Model] debug Create subscription. queue:q destination:q user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47217 exclusive:F
2014-04-23 09:47:02 [Broker] debug next() called for invalid cursor, index started at 0 (of 2)
2014-04-23 09:47:02 [Broker] debug in next(), cursor set to 1
2014-04-23 09:47:02 [Broker] debug in next(), returning message at 1
2014-04-23 09:47:02 [Broker] debug Selector identifier: amqp.redelivered->BOOL:false
2014-04-23 09:47:02 [Broker] debug Consumer doesn't want message from 'q'
2014-04-23 09:47:02 [Broker] debug next() called for cursor at 1, index set to 1 (of 2)
2014-04-23 09:47:02 [Broker] debug in next(), cursor set to 2
2014-04-23 09:47:02 [Broker] debug in next(), returning message at 2
2014-04-23 09:47:02 [Broker] debug Selector identifier: amqp.redelivered->BOOL:false
2014-04-23 09:47:02 [Broker] debug Consumer doesn't want message from 'q'
2014-04-23 09:47:02 [Broker] debug next() called for cursor at 2, index set to 2 (of 2)
2014-04-23 09:47:02 [Broker] debug no message to return from next
2014-04-23 09:47:02 [Broker] debug No messages to dispatch on queue 'q'
2014-04-23 09:47:02 [Model] debug Delete subscription. destination:q user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47217
2014-04-23 09:47:02 [Broker] debug anonymous.2ca67218-6613-426f-bbb1-d7b75b005f7d: detached on broker.
2014-04-23 09:47:02 [Model] debug Delete connection. user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47217
2014-04-23 09:47:06 [Security] debug SASL: No Authentication Performed
2014-04-23 09:47:06 [Broker] debug LinkRegistry::notifyConnection(); key=qpid.127.0.0.1:5672-127.0.0.1:47218
2014-04-23 09:47:06 [Model] debug Create connection. user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47218
2014-04-23 09:47:06 [Broker] debug anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c: attached on broker.
2014-04-23 09:47:06 [Broker] debug anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c: ready to send, activating output.
2014-04-23 09:47:06 [Broker] debug Selector parsed[amqp.redelivered = FALSE] into: (I:amqp.redelivered=BOOL:false)
2014-04-23 09:47:06 [Model] debug Create subscription. queue:q destination:q user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47218 exclusive:F
2014-04-23 09:47:06 [Broker] debug next() called for invalid cursor, index started at 0 (of 2)
2014-04-23 09:47:06 [Broker] debug in next(), cursor set to 1
2014-04-23 09:47:06 [Broker] debug in next(), returning message at 1
2014-04-23 09:47:06 [Broker] debug Selector identifier: amqp.redelivered->BOOL:false
2014-04-23 09:47:06 [Broker] debug Subscription q on anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c has sufficient  credit for message of 90 bytes: messages: 1 bytes: unlimited
2014-04-23 09:47:06 [Broker] debug Attempting to acquire message 1 from 'q' with state 1
2014-04-23 09:47:06 [Broker] debug Message 1 retrieved from 'q'
2014-04-23 09:47:06 [Broker] debug Credit allocated for q on anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c, was messages: 1 bytes: unlimited now messages: 0 bytes: unlimited
2014-04-23 09:47:06 [Broker] debug clean(): 1 messages remain; head is now 0
2014-04-23 09:47:06 [Broker] debug DeliveryRecord::setEnded() id=1
2014-04-23 09:47:06 [Broker] debug Accepted 1
2014-04-23 09:47:06 [Broker] debug next() called for cursor at 1, index set to 0 (of 1)
2014-04-23 09:47:06 [Broker] debug in next(), cursor set to 2
2014-04-23 09:47:06 [Broker] debug in next(), returning message at 2
2014-04-23 09:47:06 [Broker] debug Selector identifier: amqp.redelivered->BOOL:false
2014-04-23 09:47:06 [Broker] debug Subscription q on anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c has sufficient  credit for message of 90 bytes: messages: 1 bytes: unlimited
2014-04-23 09:47:06 [Broker] debug Attempting to acquire message 2 from 'q' with state 1
2014-04-23 09:47:06 [Broker] debug Message 2 retrieved from 'q'
2014-04-23 09:47:06 [Broker] debug Credit allocated for q on anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c, was messages: 1 bytes: unlimited now messages: 0 bytes: unlimited
2014-04-23 09:47:06 [Broker] debug clean(): 0 messages remain; head is now 0
2014-04-23 09:47:06 [Broker] debug DeliveryRecord::setEnded() id=2
2014-04-23 09:47:06 [Broker] debug Accepted 2
2014-04-23 09:47:06 [Broker] debug next() called for cursor at 2, index set to 0 (of 0)
2014-04-23 09:47:06 [Broker] debug no message to return from next
2014-04-23 09:47:06 [Broker] debug No messages to dispatch on queue 'q'
2014-04-23 09:47:06 [Model] debug Delete subscription. destination:q user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47218
2014-04-23 09:47:06 [Broker] debug anonymous.c68b8752-224b-4d7a-b6d2-45646cc12e5c: detached on broker.
2014-04-23 09:47:06 [Model] debug Delete connection. user:anonymous rhost:qpid.127.0.0.1:5672-127.0.0.1:47218

Comment 2 Andrew Stitcher 2014-04-29 19:35:32 UTC
The 3.0 selector functionality should include the redelivered flag

In my quick tests I am seeing a strange behaviour:

The first time the message is redelivered it still matches the selector "amqp.redelivered=false" (although it has the Redelivered header) but subsequently it matches "amqp.redelivered=true"

It may be that the header is set *after* the selector is run so that the selector test happens before the msg field is updated to take account of the redelivery.

Comment 3 Andrew Stitcher 2014-04-30 03:50:10 UTC
This is now fixed on the trunk branch of qpid in r1591183
[ https://svn.apache.org/r1591183 ]

Comment 6 Irina Boverman 2014-05-14 20:28:33 UTC
Merging 0.22-mrg-astitcher-bz1090368 branch.

Comment 8 Zdenek Kraus 2014-05-21 10:42:55 UTC
tested on RHEL 6.5 i686 && x86_64 with following packages:

python-qpid-0.22-14.el6
qpid-proton-c-0.7-1.el6
qpid-cpp-server-devel-0.22-40.el6
qpid-cpp-server-ha-0.22-40.el6
qpid-jca-0.22-2.el6
qpid-cpp-server-0.22-40.el6
qpid-tools-0.22-12.el6
qpid-java-client-0.22-6.el6
qpid-qmf-debuginfo-0.22-31.el6
qpid-snmpd-debuginfo-1.0.0-16.el6
qpid-cpp-client-devel-docs-0.22-40.el6
qpid-cpp-client-0.22-40.el6
qpid-cpp-client-devel-0.22-40.el6
qpid-tests-0.22-15.el6
qpid-snmpd-1.0.0-16.el6
qpid-cpp-server-linearstore-0.22-40.el6
qpid-java-common-0.22-6.el6
qpid-java-example-0.22-6.el6
qpid-proton-debuginfo-0.7-1.el6
qpid-proton-c-devel-0.7-1.el6
python-qpid-qmf-0.22-31.el6
qpid-qmf-devel-0.22-31.el6
qpid-cpp-server-rdma-0.22-40.el6
qpid-cpp-server-xml-0.22-40.el6
qpid-jca-xarecovery-0.22-2.el6
perl-qpid-debuginfo-0.22-12.el6
qpid-qmf-0.22-31.el6
perl-qpid-0.22-12.el6
qpid-cpp-debuginfo-0.22-40.el6
qpid-cpp-client-rdma-0.22-40.el6
ruby-qpid-qmf-0.22-31.el6


works as expected.

Comment 9 errata-xmlrpc 2014-09-24 15:11:14 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHEA-2014-1296.html


Note You need to log in before you can comment on or make changes to this bug.