Description of problem: See attached program that: - creates a queue (via QMF) and fetches QMF response in a response queue (response got very fast) - runs a new thread that subscribes to a queue and fetches messages in loop - deletes the queue (not-used at all) via QMF and fetches response in a response queue - joins the child thread The latest fetch takes as much time as timeout is set on it. Despite the response gets quite fast (similarly as fast the QMF response to create request). Version-Release number of selected component (if applicable): qpid-cpp-client-0.18-14 How reproducible: 100% Steps to Reproduce: 1. See attached test_qmf_DeleteOnly.cpp 2. g++ test_qmf_DeleteOnly.cpp -o test_qmf_DeleteOnly.cpp -lpthread -lqpidmessaging -lqpidclient -lqpidcommon -lqpidtypes -lboost_date_time -lboost_thread-mt 3. ./test_qmf_CreateDeleteOnly 3000 (the parameter specifies fetch timeout in ms) Actual results: 2013-Apr-23 09:20:32.299674] Fetch timeout to be set to 3000ms. 2013-Apr-23 09:20:32.299860] Connecting to amqp:127.0.0.1:5672... 2013-Apr-23 09:20:32.313633] Creating session... 2013-Apr-23 09:20:32.315619] Creating sender... 2013-Apr-23 09:20:32.316667] Declaring queue... 2013-Apr-23 09:20:32.318789] just before QMF fetch response on queue 1reply-queue; {create:always, node:{x-declare:{auto-delete:true}}} 2013-Apr-23 09:20:32.359730] just after QMF fetch response: _method_response 2013-Apr-23 09:20:32.360898] Creating receiver... 2013-Apr-23 09:20:32.401596] Starting thread... 2013-Apr-23 09:20:32.402169] Deleting queue... 2013-Apr-23 09:20:32.443053] just before QMF fetch response on queue 2reply-queue; {create:always, node:{x-declare:{auto-delete:true}}} 2013-Apr-23 09:20:35.456709] just after QMF fetch response: _method_response 2013-Apr-23 09:20:35.457935] Finalizing thread... 2013-Apr-23 09:20:35.618518] Done, press Ctrl+C to exit - see the 3 seconds delay after "just before QMF fetch response on queue 2reply-queue". - increasing the program parameter (fetch timeout) directly impacts the delay Expected results: No such delay. Additional info: tcpdump showed that the client gets the message quite early but it re-issue credit to the broker in order to attempt to fetch new messages. traces of qpid client library showed second (child) thread running fetch in loop in fact gets the message, but enqueues it to internal buffer - see qpid/client/amqp0_10/IncomingMessages.cpp, method IncomingMessages::process and log: QPID_LOG(debug, "Pushed " << *content->getMethod() << " to received queue"); The child thread did the enqueue properly, as it fetches for messages of different destination; the problem is that the parent thread fetching QMF response does not check the received queue before querying broker. The concurrent fetching in two threads is essential for the reproducer. Moving "should_end.unlock(); thread.join();" before deleting the queue _prevents_ the delay at all.
Created attachment 738931 [details] Reproducer
A jira that mentions fetch delays: https://issues.apache.org/jira/browse/QPID-4664
Proposed fix available for review: https://reviews.apache.org/r/10839/.
Fix committed upstream as http://svn.apache.org/viewvc?view=revision&revision=1477975
Created attachment 750469 [details] reproducer for rhel5 (boost 1.33.1)
An testing update: qpid-cpp-client-0.22-2.el6 comes with fix, but qpid-cpp-client-0.22-2.el5 does not. Waiting for el5 packages with applied fix.
The issue has been fully fixed (long term test), tested on RHEL 5.9 / 6.4 i[36]86 / x86_64 on packages: python-qpid-0.22-2.el5 python-qpid-proton-0.4-2.2.el5 python-qpid-proton-doc-0.4-2.2.el5 python-qpid-qmf-0.22-2.el5 qpid-cpp-client-0.22-4.el5 qpid-cpp-client-devel-0.22-4.el5 qpid-cpp-client-devel-docs-0.22-4.el5 qpid-cpp-client-rdma-0.22-4.el5 qpid-cpp-client-ssl-0.22-4.el5 qpid-cpp-mrg-debuginfo-0.22-4.el5 qpid-cpp-server-0.22-4.el5 qpid-cpp-server-devel-0.22-4.el5 qpid-cpp-server-ha-0.22-4.el5 qpid-cpp-server-rdma-0.22-4.el5 qpid-cpp-server-ssl-0.22-4.el5 qpid-cpp-server-store-0.22-4.el5 qpid-cpp-server-xml-0.22-4.el5 qpid-java-client-0.22-2.el5 qpid-java-common-0.22-2.el5 qpid-java-example-0.22-2.el5 qpid-jca-0.18-8.el5 qpid-jca-xarecovery-0.18-8.el5 qpid-jca-zip-0.18-8.el5 qpid-proton-c-0.4-2.2.el5 qpid-proton-c-devel-0.4-2.2.el5 qpid-proton-debuginfo-0.4-2.2.el5 qpid-qmf-0.22-2.el5 qpid-qmf-debuginfo-0.22-2.el5 qpid-qmf-devel-0.22-2.el5 qpid-tests-0.22-2.el5 qpid-tools-0.22-2.el5 rh-qpid-cpp-tests-0.22-4.el5 ruby-qpid-qmf-0.22-2.el5 -> VERIFIED
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