Bug 449088 - 'failed to prepare' for large transactions
Summary: 'failed to prepare' for large transactions
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: qpid-cpp
Version: beta
Hardware: All
OS: Linux
urgent
high
Target Milestone: ---
: ---
Assignee: messaging-bugs
QA Contact: Kim van der Riet
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-05-30 11:16 UTC by Gordon Sim
Modified: 2009-05-07 20:09 UTC (History)
0 users

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2008-12-02 16:06:15 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Gordon Sim 2008-05-30 11:16:40 UTC
Reported via IRC by tim fox:

"with rhm c++ trunk, is for small transactions (2 msgs per tx) is ok. but when i
start to concurrently send/consume large transactions (1000 msgs/sec) the broker
eventually fails with 'failed to prepare'"

Comment 1 Gordon Sim 2008-05-30 11:18:15 UTC
correction that should be "(1000 msgs/tx)"

Comment 2 Gordon Sim 2008-05-30 17:00:01 UTC
Though not the same outcome, I hit a few errors when running some tx tests from
c++ client:

2008-may-30 16:17:41 error Journal "tx-test-2": Unexpected I/O response
(RHM_IORES_BUSY) on queue tx-test-2".
Segmentation fault (core dumped)


#0  0xb1a36890 in ?? ()
#1  0x008f70ea in DbTxn::abort () from /usr/lib/libdb_cxx-4.3.so
#2  0x00e1a521 in ~TxnCtxt (this=0xb1f80f30) at TxnCtxt.h:140
#3  0x003765ad in qpid::broker::TxBuffer::commitLocal (this=0x87d9950,
store=0x8180168)
    at /usr/lib/gcc/i386-redhat-linux/4.1.1/../../../../include/c++/4.1.1/memory:259
#4  0x003493cf in qpid::broker::SemanticState::commit (this=0x82af748,
store=0x8180168, completeOnCommit=false)
    at qpid/broker/SemanticState.cpp:128
#5  0x00352ea5 in qpid::broker::SessionAdapter::TxHandlerImpl::commit
(this=0x82af884) at qpid/broker/SessionAdapter.cpp:467

#0  0x46a09eae in clock_gettime () from /lib/librt.so.1
#1  0x0051cff0 in qpid::sys::AbsTime::now () at qpid/sys/posix/Time.cpp:34
#2  0x0036d98e in qpid::broker::Timer::run (this=0x81c6370) at
qpid/broker/Timer.cpp:61
#3  0x0051d0f1 in qpid::sys::Thread::runRunnable (p=0x81c6370) at
qpid/sys/posix/Thread.cpp:27
#4  0x45f0640b in start_thread () from /lib/libpthread.so.0
#5  0x45c71b7e in clone () from /lib/libc.so.6

#0  0x0018b8d1 in _Unwind_Find_FDE () from /lib/libgcc_s.so.1
#1  0x45ca4879 in dl_iterate_phdr () from /lib/libc.so.6
#2  0x0018b45c in _Unwind_Find_FDE () from /lib/libgcc_s.so.1
#3  0x001886f8 in _Unwind_FindEnclosingFunction () from /lib/libgcc_s.so.1
#4  0x00189a77 in _Unwind_RaiseException () from /lib/libgcc_s.so.1
#5  0x006e28fd in __cxa_throw () from /usr/lib/libstdc++.so.6
#6  0x00337813 in qpid::broker::MessageStoreModule::enqueue (this=0x8180168,
ctxt=0x8ccd420, msg=@0xb60d6304,
    queue=@0x81d1798) at qpid/broker/MessageStoreModule.cpp:111
#7  0x002f1660 in qpid::broker::Queue::enqueue (this=0x81d1798, ctxt=0x8ccd420,
msg=@0xb60d6354)
    at qpid/broker/Queue.cpp:485
#8  0x00376ecb in qpid::broker::TxPublish::Prepare::operator() (this=0xb60d639c,
queue=@0x88529f0)
    at qpid/broker/TxPublish.cpp:59
#9  0x0037809f in
std::for_each<std::_List_iterator<boost::shared_ptr<qpid::broker::Queue> >,
qpid::broker::TxPublish::Prepare> (__first={_M_node = 0x88529e8},
__last={_M_node = 0x88526d8}, __f={ctxt = 0x8ccd420, msg = @0x88526d4})
    at
/usr/lib/gcc/i386-redhat-linux/4.1.1/../../../../include/c++/4.1.1/bits/stl_algo.h:159
#10 0x003772e3 in qpid::broker::TxPublish::prepare (this=0x88526c8,
ctxt=0x8ccd420) at qpid/broker/TxPublish.cpp:31
#11 0x0037635c in qpid::broker::TxBuffer::prepare (this=0x86ccb30,
ctxt=0x8ccd420) at qpid/broker/TxBuffer.cpp:30
#12 0x0037653c in qpid::broker::TxBuffer::commitLocal (this=0x86ccb30,
store=0x8180168) at qpid/broker/TxBuffer.cpp:58
#13 0x003493cf in qpid::broker::SemanticState::commit (this=0x826eb40,
store=0x8180168, completeOnCommit=false)
    at qpid/broker/SemanticState.cpp:128
#14 0x00352ea5 in qpid::broker::SessionAdapter::TxHandlerImpl::commit
(this=0x826ec7c) at qpid/broker/SessionAdapter.cpp:467

#0  0x45b8b410 in __kernel_vsyscall ()
#1  0x45c33f16 in __nanosleep_nocancel () from /lib/libc.so.6
#2  0x45c6b653 in usleep () from /lib/libc.so.6
#3  0x00e19565 in rhm::bdbstore::TxnCtxt::sync (this=0x84b4c88) at TxnCtxt.h:111
#4  0x00e199a0 in rhm::bdbstore::TxnCtxt::completeTXN (this=0x84b4c88,
commit=true) at TxnCtxt.h:92
#5  0x00dff113 in rhm::bdbstore::BdbMessageStore::commit (this=0x817d380,
ctxt=@0x84b4c88) at TxnCtxt.h:139
#6  0x00336c4f in qpid::broker::MessageStoreModule::commit (this=0x8180168,
ctxt=@0x84b4c88)
    at qpid/broker/MessageStoreModule.cpp:146
#7  0x00376550 in qpid::broker::TxBuffer::commitLocal (this=0xb2923a78,
store=0x8180168) at qpid/broker/TxBuffer.cpp:59
#8  0x003493cf in qpid::broker::SemanticState::commit (this=0xb29af5f8,
store=0x8180168, completeOnCommit=false)
    at qpid/broker/SemanticState.cpp:128
#9  0x00352ea5 in qpid::broker::SessionAdapter::TxHandlerImpl::commit
(this=0xb29af734)
    at qpid/broker/SessionAdapter.cpp:467

also 

terminate called after throwing an instance of 'rhm::journal::jexception'
what():  jexception 0x0b01 txn_map::set_aio_compl() threw JERR_MAP_NOTFOUND: Key
not found in map. (xid=rhm-tidD rid=0x96bb9b)

These were through running:

 ./src/tests/txtest --size 1024 --queues 5 --messages-per-tx 1000
--total-messages 5000 --tx-count 1000

More testing to follow, just recording this for now.


Comment 3 Gordon Sim 2008-06-03 13:02:56 UTC
The 'failed to prepare' occurring in the JBM example is due to the journal
reaching capacity. This happens because the consumer stops receiving, and that
appears to be due to running out of credit (initial allocation is 1000 messages
and that doesn't seem to get updated within a transaction). With a slightly
lower transaction size the test passes.

I have checked in better error handling for the broker.

Comment 4 Gordon Sim 2008-06-05 10:11:33 UTC
Original reported error has been fixed through changes to JMS client. I was not
able to reproduce above errors with latest store.

Comment 5 Mike Bonnet 2008-06-20 03:52:53 UTC
qpidc-0.2.667603-1.el5, qpidc-perftest-0.2.667603-1.el5, qpidd-0.2.667603-1.el5, and rhm-0.2.2153-1.el5 have been pushed to the staging repo for testing


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