Bug 1061633

Description of problem:
If transaction commit raises a journal error (for possible scenario, see bz1060202), the journal leaves some (dequque only?) records locked. Once the cause of journal error is cleared and new transactions can be committed properly, they fail due to the locked records.


Version-Release number of selected component (if applicable):
any (MRG 2.3, 3.0)


How reproducible:
100%


Steps to Reproduce:
(use attached patched qpid-txtest.cpp for reproducer)

service qpidd stop; rm -rf /var/lib/qpidd/* ; service qpidd start
date; /data_xfs/qpid/cpp/BLD/src/tests/qpid-txtest --queues=1 --total-messages=1 --dtx=1 --dtx-commit=no --dtx-timeout=60
src/tests/qpid-send -a "testQueue; {create:always, node:{durable:true}}" -m 4000 --durable=yes --tx=1
src/tests/qpid-receive -a "testQueue; {create:always, node:{durable:true}}" -m 4000 --tx=1 --print-content=no
date
# ensure by "date" commands the latest 3 steps were executed within minute, such that Tpl has one orphaned record and reports "Enqueue capacity threshold"
sleep 60     # or whatever time remains to let dtx timeout elapse
/usr/libexec/qpid/store_chk /var/lib/qpidd/rhm/tpl -b tpl    # just to check Tpl journal is empty, see bz1060114 what you can get until fixed
src/tests/qpid-receive -a "testQueue; {create:always, node:{durable:true}}" -m 4000 --tx=1 --print-content=no


Actual results:
First qpid-receive fails with:

2014-02-05 09:14:13 [Client] warning Exception received from broker: internal-error: internal-error: Commit failed (qpid/broker/SemanticState.cpp:177) [caused by 5123 \x05:\x02]
qpid-receive: internal-error: internal-error: Commit failed (qpid/broker/SemanticState.cpp:177)
2014-02-05 09:14:13 [Client] warning Ignoring frame while closing connection: Frame[BEbe; channel=1; {SessionDetachBody: name=ee82d5ff-fd85-49cb-944f-c8f627c22629; }]

Second qpid-receive fails with almost the same (just "caused by 11" instead of "caused by 5123")


Expected results:
First qpid-receive to fail as now.

Second qpid-receive should drain messages without an error.


Additional info:

Broker logs for 2nd qpid-rceive failure:

2014-02-05 09:26:41 [Broker] trace anonymous.01192ee5-58f3-44f2-b8a6-1ff9fc69295f: recv cmd 15: {TxCommitBody: }
2014-02-05 09:26:41 [System] debug Exception constructed: Queue testQueue: async_dequeue() failed: jexception 0x0b02 wmgr::dequeue_check() threw JERR_MAP_LOCKED: Record ID locked by a pending transaction. (drid=0x31e7) (MessageStoreImpl.cpp:1420)
2014-02-05 09:26:41 [Broker] error Failed to prepare: Queue testQueue: async_dequeue() failed: jexception 0x0b02 wmgr::dequeue_check() threw JERR_MAP_LOCKED: Record ID locked by a pending transaction. (drid=0x31e7) (MessageStoreImpl.cpp:1420)
2014-02-05 09:26:41 [System] debug Exception constructed: Commit failed (qpid/broker/SemanticState.cpp:177)
2014-02-05 09:26:41 [Protocol] error Execution exception: internal-error: Commit failed (qpid/broker/SemanticState.cpp:177)
2014-02-05 09:26:41 [Protocol] trace SENT [127.0.0.1:5672-127.0.0.1:36184]: Frame[BEbe; channel=1; {ExecutionExceptionBody: error-code=541; command-id=15; class-code=5; command-code=2; field-index=0; description=internal-error: Commit failed (qpid/broker/SemanticState.cpp:177); error-info={}; }]

The "pending transaction" is obviously the one that failed in commit.