Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
Bug 484048 - qpidd+store flush() failed: jexception 0x0106 slock::slo ck() threw JERR__PTHREAD: pthread failure. (pthread_mutex_lock failed: errno=22 (Invalid argument)) (MessageStoreImpl.cpp:1331)
qpidd+store flush() failed: jexception 0x0106 slock::slo ck() threw JERR__PTH...
Status: CLOSED ERRATA
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: qpid-cpp (Show other bugs)
1.1
All Linux
high Severity high
: 1.3
: ---
Assigned To: Kim van der Riet
Frantisek Reznicek
:
Depends On: 587505
Blocks:
  Show dependency treegraph
 
Reported: 2009-02-04 09:33 EST by Frantisek Reznicek
Modified: 2015-11-15 19:06 EST (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Previously, a race condition may have occurred, allowing one thread to delete a message queue while another one was flushing it. When this happened, the following error message was logged: JERR__PTHREAD: pthread failure. With this update, this error has been fixed, and the race condition no longer occurs.
Story Points: ---
Clone Of:
Environment:
Last Closed: 2010-10-14 12:08:03 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
qpid_test_qpidd-perftest_performance test failed on RHEL 5.2 x86_64 incl. journal (18.86 KB, application/x-bzip2)
2009-02-04 09:33 EST, Frantisek Reznicek
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2010:0773 normal SHIPPED_LIVE Moderate: Red Hat Enterprise MRG Messaging and Grid Version 1.3 2010-10-14 11:56:44 EDT

  None (edit)
Description Frantisek Reznicek 2009-02-04 09:33:03 EST
Created attachment 330866 [details]
qpid_test_qpidd-perftest_performance test failed on RHEL 5.2 x86_64 incl. journal

Description of problem:
The RHTS perftest perfornamce test (qpid_test_qpidd-perftest_performance) triggered JERR__PTHREAD.
Test runs single qpidd vs. single perftest and sweep tha parameters
This occurence seen on RHEL 5.2 x86_64.

Version-Release number of selected component (if applicable):
[root@dhcp-lab-200 MRG_Messaging]# rpm -qa | grep qpid
qpidc-perftest-0.4.738274-1.el5
qpidc-0.4.738274-1.el5
qpidd-ssl-0.4.738274-1.el5
qpidc-rdma-0.4.738274-1.el5
qpid-java-common-0.4.738568-1.el5
qpidd-acl-0.4.738274-1.el5
qpidd-0.4.738274-1.el5
python-qpid-0.4.738182-1.el5
qpidd-rdma-0.4.738274-1.el5
qpidc-ssl-0.4.738274-1.el5
qpid-java-client-0.4.738568-1.el5
qpidd-cluster-0.4.738274-1.el5
qpidc-devel-0.4.738274-1.el5
qpidd-xml-0.4.738274-1.el5
qpidd-devel-0.4.738274-1.el5


How reproducible:
rarely

Steps to Reproduce:
1. qpidd --auth no --num-jfiles 32 --jfile-size-pgs 64 --wcache-page-size 64 --tpl-num-jfiles 32 --tpl-jfile-size-pgs 64 --tpl-wcache-page-size 64 --log-enable info+ --mgmt-enable 0 -p 43426 --data-dir X >qpidd.transcript.log
2. perftest --iterations 1 --summary --unique-data yes --log-enable info+ -p 43426 --mode fanout --qt 1 --durable yes --npubs 2 --nsubs 2 --count 200000 --size 128 --tx 0 --async-commit no
3. check $? and qpidd.transcript.log
  
Actual results:
rarely observed JERR__PTHREAD

Expected results:
no issue expected

Additional info: (transcript)

[15:18:32] qpidd_start: qpidd launched normal bg way (port:43426, log:qpidd.transcript.log, params: --auth no --num-jfiles 32 --jfile-size-pgs 64 --wcache-page-size 64 --tpl-num-jfiles 32 --tpl-jfile-size-pgs 64 --tpl-wcache-page-size 64 --log-enable info+ --mgmt-enable 0)
[15:18:33] qpidd_wait_on_settle: qpidd started-up (dur:0sec)
[15:18:33] .qpidd settled
[15:18:33] launching perftest --iterations 1 --summary --unique-data yes --log-enable info+ -p 43426 --mode fanout --qt 1 --durable yes --npubs 2 --nsubs 2 --count 200000 --size 128 --tx 0 --async-commit no


An attachement contains the test + journal + log files
qpid_test_qpidd-perftest_performance/qpidd.transcript.log is qpidd log file
qpid_test_qpidd-perftest_performance/perftest.transcript.log is perftest log
qpid_test_qpidd-perftest_performance/qpid_test_qpidd-perftest_performance.log
  is rough test log file
Comment 1 Frantisek Reznicek 2009-02-04 09:49:32 EST
Here are packages I used for testing: (rhm version omitted above)
[root@dhcp-lab-200 MRG_Messaging]# rpm -qa qpidc qpidd rhm
qpidc-0.4.738274-1.el5
qpidd-0.4.738274-1.el5
rhm-0.4.3075-3.el5
Comment 2 Kim van der Riet 2009-02-04 14:25:51 EST
Checked in a change to the check for the pthread error. It now aborts instead of throwing an exception. This should allow a stack trace to be obtained provided a 
core dump can be captured.

I will take a closer look at this, but a fist analysis suggests that MessageStoreImpl::flush() might be called after the Queue to which it is attached has been deleted, and consequently the MessageStoreImpl instance is also deleted. Error 22 (EINVAL) is thrown by posix_mutex_lock() if the mutex being used in a lock has already been destroyed - this is done in the MessageStoreImpl destructor.

This does not look like a regression. Setting target milestone to 1.1.2, but if additional data which reveals the source of the problem is uncovered in time, this could be pushed into 1.1.1.

r.3106

QA: Setting NEEDINFO: Rerun the test with ulimit -c unlimited. This will allow a stack trace to be recovered if this error should it reoccur. An error message will print to std::err before the abort.
Comment 4 Frantisek Reznicek 2009-12-15 11:06:30 EST
The issue has not been seen for months. Retesting on latest packages. Feedback soon...
Comment 5 Frantisek Reznicek 2010-01-07 01:40:47 EST
Retested (long term run) on RHEL 4.8 / 5.4 i386 / x86_64 on packages without seeing any occurrence of this issue.

[root@mrg-qe-02 qpid_test_qpidd-perftest_performance]# rpm -qa | grep -E '(openais|qpid)' | sort | uniq
openais-0.80.6-8.el5_4.1
openais-debuginfo-0.80.6-8.el5_4.1
openais-devel-0.80.6-8.el5_4.1
python-qpid-0.5.758389-2.el5
qpid*-0.5.752581-34.el5
Comment 6 Frantisek Reznicek 2010-01-07 07:54:57 EST
Candidate for CLOSED/WORKSFORME... update in ETA 1 month if not triggered...
Comment 7 Frantisek Reznicek 2010-01-13 04:28:53 EST
I believe I might found the occurrence of this during long extreme stress test with perftest and sweeping parameters on an RHEL 4.8 i386.

No such message seen, but this is explaines by Kim's comment 2. I got qpidd crash where ome thread is exactly in MessageStoreImpl::flush() see below thread nr. 9...

Could you possibly check whether this threaded backtrace is relevant to this BZ, please? (putting NEEDINFO)

[root@mrg-qe-07 qpid_test_qpidd-perftest_performance]# ll /root/MRG/Messaging/qpid_test_qpidd-perftest_performance/core.23088
-rw-------  1 root root 124706816 Jan 11 04:10 /root/MRG/Messaging/qpid_test_qpidd-perftest_performance/core.23088
[root@mrg-qe-07 qpid_test_qpidd-perftest_performance]# gdb `which qpidd` /root/MRG/Messaging/qpid_test_qpidd-perftest_performance/core.23088
GNU gdb Red Hat Linux (6.3.0.0-1.162.el4rh)
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu"...Using host libthread_db library "/lib/tls/libthread_db.so.1".

Core was generated by `/usr/sbin/qpidd --data-dir /root/MRG/Messaging/qpid_test_qpidd-perftest_perform'.
Program terminated with signal 6, Aborted.
Reading symbols from /usr/lib/libqpidbroker.so.0...Reading symbols from /usr/lib/debug/usr/lib/libqpidbroker.so.0.1.0.debug...done.
done.
Loaded symbols for /usr/lib/libqpidbroker.so.0
Reading symbols from /usr/lib/libqpidcommon.so.0...Reading symbols from /usr/lib/debug/usr/lib/libqpidcommon.so.0.1.0.debug...done.
done.
Loaded symbols for /usr/lib/libqpidcommon.so.0
Reading symbols from /usr/lib/libboost_program_options.so.1...done.
...
Loaded symbols for /usr/lib/libplds4.so
Reading symbols from /usr/lib/qpid/daemon/acl.so...Reading symbols from /usr/lib/debug/usr/lib/qpid/daemon/acl.so.debug...done.
done.
Loaded symbols for /usr/lib/qpid/daemon/acl.so
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
(gdb) info threads
  12 process 23088  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  11 process 23093  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  10 process 23094  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  9 process 23095  0x004db56e in io_submit () from /usr/lib/libaio.so.1
  8 process 23096  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  7 process 23097  0x001915ab in __i686.get_pc_thunk.bx () from /usr/lib/libqpidbroker.so.0
  6 process 23098  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  5 process 23099  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  4 process 23100  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  3 process 23101  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
  2 process 23102  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
* 1 process 23103  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
(gdb) thread apply all bt

Thread 12 (process 23088):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0076058e in epoll_wait () from /lib/tls/libc.so.6
#2  0x00ce687d in qpid::sys::Poller::wait (this=0x824a9d8, timeout={nanosecs = 9223372036854775807}) at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00ce8384 in qpid::sys::Poller::run (this=0x824a9d8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#5  0x001f49b4 in qpid::broker::Broker::run (this=0x8257e08) at qpid/broker/Broker.cpp:324
#6  0x08053d77 in QpiddBroker::execute (this=0xbfe98e87, options=0x8248140) at /usr/include/boost/intrusive_ptr.hpp:119
#7  0x0804fdd0 in main (argc=23, argv=0xbfe990e4) at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:301
#8  0x006a8df3 in __libc_start_main () from /lib/tls/libc.so.6
#9  0x0804c531 in _start ()

Thread 11 (process 23093):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0084cf7c in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libpthread.so.0
#2  0x0076ca7e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libc.so.6
#3  0x00317d69 in qpid::broker::Timer::run (this=0x825802c) at ./qpid/sys/posix/Condition.h:69
#4  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#5  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#6  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 10 (process 23094):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0084cf7c in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libpthread.so.0
#2  0x0076ca7e in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/tls/libc.so.6
#3  0x00317d69 in qpid::broker::Timer::run (this=0x82580ac) at ./qpid/sys/posix/Condition.h:69
#4  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#5  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#6  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 9 (process 23095):
#0  0x004db56e in io_submit () from /usr/lib/libaio.so.1
#1  0x00498975 in mrg::journal::wmgr::write_flush () from /usr/lib/qpid/daemon/msgstore.so
---Type <return> to continue, or q <return> to quit---
#2  0x00498cf2 in mrg::journal::wmgr::flush () from /usr/lib/qpid/daemon/msgstore.so
#3  0x0046d36f in mrg::journal::jcntl::flush () from /usr/lib/qpid/daemon/msgstore.so
#4  0x00401f82 in mrg::msgstore::JournalImpl::flush () from /usr/lib/qpid/daemon/msgstore.so
#5  0x00402108 in mrg::msgstore::JournalImpl::flushFire () from /usr/lib/qpid/daemon/msgstore.so
#6  0x00402d40 in mrg::msgstore::InactivityFireEvent::fire () from /usr/lib/qpid/daemon/msgstore.so
#7  0x00318040 in qpid::broker::Timer::run (this=0x825dee0) at /usr/include/boost/intrusive_ptr.hpp:119
#8  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0x1) at qpid/sys/posix/Thread.cpp:35
#9  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#10 0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 8 (process 23096):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0076058e in epoll_wait () from /lib/tls/libc.so.6
#2  0x00ce687d in qpid::sys::Poller::wait (this=0x824a9d8, timeout={nanosecs = 9223372036854775807}) at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00ce8384 in qpid::sys::Poller::run (this=0x824a9d8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#5  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#6  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#7  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 7 (process 23097):
#0  0x001915ab in __i686.get_pc_thunk.bx () from /usr/lib/libqpidbroker.so.0
#1  0x002a9c03 in qpid::broker::TransferAdapter::requiresAccept (this=0x395964, f=@0xb0900d38) at qpid/broker/MessageAdapter.cpp:65
#2  0x002a752f in qpid::broker::Message::requiresAccept (this=0xb0900d38) at qpid/broker/Message.cpp:109
#3  0x00300a2c in qpid::broker::SessionState::enqueued (this=0x82fba38, msg={p_ = 0xb0900cb8}) at /usr/include/boost/intrusive_ptr.hpp:119
#4  0x0030b78b in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::broker::SessionState, boost::intrusive_ptr<qpid::broker::Message> >, boost::_bi::list2<boost::_bi::value<qpid::broker::SessionState*>, boost::arg<1> > >, void, boost::intrusive_ptr<qpid::broker::Message> const&>::invoke (function_obj_ptr=
      {obj_ptr = 0x82bae18, const_obj_ptr = 0x82bae18, func_ptr = 0x82bae18, data = "\030"}, a0=@0xb0c06a10)
    at ./boost/detail/atomic_count_gcc.hpp:47
#5  0x0028341c in boost::function1<void, boost::intrusive_ptr<qpid::broker::Message> const&, std::allocator<void> >::operator() (this=0x391f48,
    a0=@0x395964) at /usr/include/boost/function/function_template.hpp:581
#6  0x0028284c in qpid::broker::IncompleteMessageList::process (this=0x82fbcec, listen=@0x82fbd48, sync=false)
    at qpid/broker/IncompleteMessageList.cpp:67
---Type <return> to continue, or q <return> to quit---
#7  0x00309769 in qpid::broker::SessionState::handleContent (this=0x82fba38, frame=@0xb5687880, id=@0x395964)
    at qpid/broker/SessionState.cpp:262
#8  0x0030a909 in qpid::broker::SessionState::handleIn (this=0x82fba38, frame=@0xb5687880) at qpid/broker/SessionState.cpp:326
#9  0x0030b93b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x395964,
    t=@0x395964) at ./qpid/framing/Handler.h:67
#10 0x00d0edb8 in qpid::amqp_0_10::SessionHandler::handleIn (this=0x82bacb8, f=@0xb5687880) at qpid/amqp_0_10/SessionHandler.cpp:93
#11 0x0030b93b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x395964,
    t=@0x395964) at ./qpid/framing/Handler.h:67
#12 0x00242db5 in qpid::broker::Connection::received (this=0x82ba638, frame=@0xb5687880) at ./qpid/framing/Handler.h:42
#13 0x001ea7f4 in qpid::amqp_0_10::Connection::decode (this=0x8260040, buffer=0x82eae60 "\a\003", size=65536)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#14 0x002d19f4 in qpid::broker::SecureConnection::decode (this=0x82601a8, buffer=0x82eae60 "\a\003", size=137345760)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#15 0x00d42d3f in qpid::sys::AsynchIOHandler::readbuff (this=0x825fb80, buff=0x8260168) at qpid/sys/AsynchIOHandler.cpp:113
#16 0x00340f2c in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=
      {obj_ptr = 0x825fd88, const_obj_ptr = 0x825fd88, func_ptr = 0x825fd88, data = "\210"}, a0=@0x825fc68, a1=0x8260168)
    at /usr/include/boost/bind/mem_fn_template.hpp:251
#17 0x00cd4a76 in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=0x391f48, a0=@0x395964, a1=0x395964) at /usr/include/boost/function/function_template.hpp:581
#18 0x00cd3860 in qpid::sys::posix::AsynchIO::readable (this=0x825fc68, h=@0x825fc6c) at qpid/sys/posix/AsynchIO.cpp:448
#19 0x00cd788a in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (function_obj_ptr={obj_ptr = 0x825fe00, const_obj_ptr = 0x825fe00, func_ptr = 0x825fe00, data = ""}, a0=@0x395964)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#20 0x00d4b722 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (this=0x391f48,
    a0=@0x395964) at /usr/include/boost/function/function_template.hpp:581
#21 0x00d49c6f in qpid::sys::DispatchHandle::processEvent (this=0x825fc6c, type=qpid::sys::Poller::READABLE) at qpid/sys/DispatchHandle.cpp:447
#22 0x00ce83ad in qpid::sys::Poller::run (this=0x824a9d8) at ./qpid/sys/Poller.h:122
#23 0x00d44742 in qpid::sys::Dispatcher::run (this=0x395964) at /usr/include/boost/shared_ptr.hpp:252
#24 0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0x395964) at qpid/sys/posix/Thread.cpp:35
---Type <return> to continue, or q <return> to quit---
#25 0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#26 0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 6 (process 23098):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0076058e in epoll_wait () from /lib/tls/libc.so.6
#2  0x00ce687d in qpid::sys::Poller::wait (this=0x824a9d8, timeout={nanosecs = 9223372036854775807}) at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00ce8384 in qpid::sys::Poller::run (this=0x824a9d8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#5  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#6  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#7  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 5 (process 23099):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0084f3de in __lll_mutex_lock_wait () from /lib/tls/libpthread.so.0
#2  0x0084c00b in _L_mutex_lock_35 () from /lib/tls/libpthread.so.0
#3  0x082a44e4 in ?? ()
#4  0x007beff4 in ?? () from /lib/tls/libc.so.6
#5  0x082a4084 in ?? ()
#6  0xb0b19820 in ?? ()
#7  0xb4284c88 in ?? ()
#8  0x0076cc5e in pthread_mutex_lock () from /lib/tls/libc.so.6
#9  0x0076cc5e in pthread_mutex_lock () from /lib/tls/libc.so.6
#10 0x00469073 in mrg::journal::jcntl::dequeue_data_record () from /usr/lib/qpid/daemon/msgstore.so
#11 0x00409d30 in mrg::msgstore::JournalImpl::dequeue_data_record () from /usr/lib/qpid/daemon/msgstore.so
#12 0x00423119 in mrg::msgstore::MessageStoreImpl::async_dequeue () from /usr/lib/qpid/daemon/msgstore.so
#13 0x0042d746 in mrg::msgstore::MessageStoreImpl::dequeue () from /usr/lib/qpid/daemon/msgstore.so
#14 0x002ac728 in qpid::broker::MessageStoreModule::dequeue (this=0x825d3d0, ctxt=0x0, msg=@0xb42852b0, queue=@0x82a37f0)
    at qpid/broker/MessageStoreModule.cpp:131
#15 0x0022073c in qpid::broker::Queue::dequeue (this=0x82a37f0, ctxt=0x0, msg=@0xb42853d0) at qpid/broker/Queue.cpp:748
#16 0x002e0364 in qpid::broker::SemanticState::ConsumerImpl::deliver (this=0xb0b00470, msg=@0xb42853d0) at /usr/include/boost/shared_ptr.hpp:252
#17 0x00228182 in qpid::broker::Queue::dispatch (this=0x82a37f0, c={px = 0xb0b00470, pn = {pi_ = 0xb0b00538}})
    at /usr/include/boost/shared_ptr.hpp:252
---Type <return> to continue, or q <return> to quit---
#18 0x002d6558 in qpid::broker::SemanticState::ConsumerImpl::doOutput (this=0xb0b00470) at /usr/include/boost/shared_ptr.hpp:252
#19 0x00d407d7 in qpid::sys::AggregateOutput::doOutput (this=0xb0d02300)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/bits/stl_vector.h:462
#20 0x002e059a in qpid::broker::SemanticState::doOutput (this=0xb0d02250) at qpid/broker/SemanticState.h:213
#21 0x00d407d7 in qpid::sys::AggregateOutput::doOutput (this=0x837e850)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/bits/stl_vector.h:462
#22 0x00241d0e in qpid::broker::Connection::doOutput (this=0x837e818) at qpid/broker/Connection.cpp:284
#23 0x001ec64d in qpid::amqp_0_10::Connection::encode (this=0x837eb80, buffer=0x83af258 "\v\001", size=65536)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#24 0x002d1a42 in qpid::broker::SecureConnection::encode (this=0x833dbf8, buffer=0x83af258 "\v\001", size=0)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#25 0x00d429b8 in qpid::sys::AsynchIOHandler::idle (this=0x833db28) at qpid/sys/AsynchIOHandler.cpp:206
#26 0x00340fb6 in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&>, boost::_bi::list2<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1> > >, void, qpid::sys::AsynchIO&>::invoke
    (function_obj_ptr={obj_ptr = 0x837ea48, const_obj_ptr = 0x837ea48, func_ptr = 0x837ea48, data = "H"}, a0=@0xfffffffc)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#27 0x00cd48e2 in boost::function1<void, qpid::sys::AsynchIO&, std::allocator<boost::function_base> >::operator() (this=0x853ff4,
    a0=@0xfffffffc) at /usr/include/boost/function/function_template.hpp:581
#28 0x00cd2fa4 in qpid::sys::posix::AsynchIO::writeable (this=0x837e2d8, h=@0x837e2dc) at qpid/sys/posix/AsynchIO.cpp:562
#29 0x00cd788a in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (function_obj_ptr={obj_ptr = 0x837e488, const_obj_ptr = 0x837e488, func_ptr = 0x837e488, data = "\210"}, a0=@0xfffffffc)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#30 0x00d4b722 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (this=0x853ff4,
    a0=@0xfffffffc) at /usr/include/boost/function/function_template.hpp:581
#31 0x00d49c6f in qpid::sys::DispatchHandle::processEvent (this=0x837e2dc, type=qpid::sys::Poller::WRITABLE) at qpid/sys/DispatchHandle.cpp:447
#32 0x00ce83ad in qpid::sys::Poller::run (this=0x824a9d8) at ./qpid/sys/Poller.h:122
#33 0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#34 0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#35 0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#36 0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 4 (process 23100):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
---Type <return> to continue, or q <return> to quit---
#1  0x0076058e in epoll_wait () from /lib/tls/libc.so.6
#2  0x00ce687d in qpid::sys::Poller::wait (this=0x824a9d8, timeout={nanosecs = 9223372036854775807}) at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00ce8384 in qpid::sys::Poller::run (this=0x824a9d8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#5  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#6  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#7  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 3 (process 23101):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0076058e in epoll_wait () from /lib/tls/libc.so.6
#2  0x00ce687d in qpid::sys::Poller::wait (this=0x824a9d8, timeout={nanosecs = 9223372036854775807}) at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00ce8384 in qpid::sys::Poller::run (this=0x824a9d8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#5  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#6  0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#7  0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 2 (process 23102):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x0084f3de in __lll_mutex_lock_wait () from /lib/tls/libpthread.so.0
#2  0x0084c00b in _L_mutex_lock_35 () from /lib/tls/libpthread.so.0
#3  0xb2481248 in ?? ()
#4  0x007beff4 in ?? () from /lib/tls/libc.so.6
#5  0x082a4084 in ?? ()
#6  0x000000c9 in ?? ()
#7  0xb24810d8 in ?? ()
#8  0x0076cc5e in pthread_mutex_lock () from /lib/tls/libc.so.6
#9  0x0076cc5e in pthread_mutex_lock () from /lib/tls/libc.so.6
#10 0x0046ba01 in mrg::journal::jcntl::enqueue_data_record () from /usr/lib/qpid/daemon/msgstore.so
#11 0x0040a866 in mrg::msgstore::JournalImpl::enqueue_data_record () from /usr/lib/qpid/daemon/msgstore.so
#12 0x0042402e in mrg::msgstore::MessageStoreImpl::store () from /usr/lib/qpid/daemon/msgstore.so
#13 0x0042e3c9 in mrg::msgstore::MessageStoreImpl::enqueue () from /usr/lib/qpid/daemon/msgstore.so
#14 0x002ac820 in qpid::broker::MessageStoreModule::enqueue (this=0x825d3d0, ctxt=0x0, msg=@0xb2481770, queue=@0x82a37f0)
---Type <return> to continue, or q <return> to quit---
    at qpid/broker/MessageStoreModule.cpp:124
#15 0x00221137 in qpid::broker::Queue::enqueue (this=0x82a37f0, ctxt=0x0, msg={p_ = 0x83c2620}, suppressPolicyCheck=false)
    at qpid/broker/Queue.cpp:717
#16 0x0022c92b in qpid::broker::Queue::deliver (this=0x82a37f0, msg=@0xb2482098) at ./boost/detail/atomic_count_gcc.hpp:47
#17 0x0025451e in qpid::broker::DeliverableMessage::deliverTo (this=0xb2482090, queue=@0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#18 0x00214a7e in qpid::broker::Exchange::doRoute (this=0x825e064, msg=@0xb2482090, b={px = 0x82a69b0, pn = {pi_ = 0x82a93c0}})
    at /usr/include/boost/shared_ptr.hpp:614
#19 0x00259cae in qpid::broker::DirectExchange::route (this=0x825e030, msg=@0xb2482090, routingKey=@0xb2481f40)
    at ./boost/detail/sp_counted_base_gcc_x86.hpp:66
#20 0x002d7f04 in qpid::broker::SemanticState::route (this=0x82ba3f0, msg={p_ = 0x83c2620}, strategy=@0xb2482090)
    at /usr/include/boost/shared_ptr.hpp:252
#21 0x002d88aa in qpid::broker::SemanticState::handle (this=0x82ba3f0, msg={p_ = 0x83c2620}) at ./boost/detail/atomic_count_gcc.hpp:47
#22 0x003089b0 in qpid::broker::SessionState::handleContent (this=0x82ba2c8, frame=@0xb2482880, id=@0xfffffffc)
    at ./boost/detail/atomic_count_gcc.hpp:47
#23 0x0030a909 in qpid::broker::SessionState::handleIn (this=0x82ba2c8, frame=@0xb2482880) at qpid/broker/SessionState.cpp:326
#24 0x0030b93b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0xfffffffc,
    t=@0xfffffffc) at ./qpid/framing/Handler.h:67
#25 0x00d0edb8 in qpid::amqp_0_10::SessionHandler::handleIn (this=0x82a1a18, f=@0xb2482880) at qpid/amqp_0_10/SessionHandler.cpp:93
#26 0x0030b93b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0xfffffffc,
    t=@0xfffffffc) at ./qpid/framing/Handler.h:67
#27 0x00242db5 in qpid::broker::Connection::received (this=0x82a1470, frame=@0xb2482880) at ./qpid/framing/Handler.h:42
#28 0x001ea7f4 in qpid::amqp_0_10::Connection::decode (this=0x82a0ca0, buffer=0x8270278 "\a\003", size=65536)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#29 0x002d19f4 in qpid::broker::SecureConnection::decode (this=0x825f9a0, buffer=0x8270278 "\a\003", size=0)
    at /usr/lib/gcc/i386-redhat-linux/3.4.6/../../../../include/c++/3.4.6/memory:285
#30 0x00d42d3f in qpid::sys::AsynchIOHandler::readbuff (this=0x82a0ff8, buff=0x82a2ec0) at qpid/sys/AsynchIOHandler.cpp:113
#31 0x00340f2c in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=
      {obj_ptr = 0x82a0e90, const_obj_ptr = 0x82a0e90, func_ptr = 0x82a0e90, data = "\220"}, a0=@0x825fed8, a1=0x82a2ec0)
    at /usr/include/boost/bind/mem_fn_template.hpp:251
#32 0x00cd4a76 in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator()---Type <return> to continue, or q <return> to quit---
 (this=0x853ff4, a0=@0xfffffffc, a1=0xfffffffc) at /usr/include/boost/function/function_template.hpp:581
#33 0x00cd3860 in qpid::sys::posix::AsynchIO::readable (this=0x825fed8, h=@0x825fedc) at qpid/sys/posix/AsynchIO.cpp:448
#34 0x00cd788a in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (function_obj_ptr={obj_ptr = 0x82a47a8, const_obj_ptr = 0x82a47a8, func_ptr = 0x82a47a8, data = "�"}, a0=@0xfffffffc)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#35 0x00d4b722 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (this=0x853ff4,
    a0=@0xfffffffc) at /usr/include/boost/function/function_template.hpp:581
#36 0x00d49c6f in qpid::sys::DispatchHandle::processEvent (this=0x825fedc, type=qpid::sys::Poller::READABLE) at qpid/sys/DispatchHandle.cpp:447
#37 0x00ce83ad in qpid::sys::Poller::run (this=0x824a9d8) at ./qpid/sys/Poller.h:122
#38 0x00d44742 in qpid::sys::Dispatcher::run (this=0xfffffffc) at /usr/include/boost/shared_ptr.hpp:252
#39 0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0xfffffffc) at qpid/sys/posix/Thread.cpp:35
#40 0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#41 0x0075ff0e in clone () from /lib/tls/libc.so.6

Thread 1 (process 23103):
#0  0x0067a7a2 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0x006bb825 in raise () from /lib/tls/libc.so.6
#2  0x006bd289 in abort () from /lib/tls/libc.so.6
#3  0x0021a66d in ~Mutex (this=0x833d358) at ./qpid/sys/posix/Mutex.h:112
#4  0x00d44daf in qpid::sys::DispatchHandle::~DispatchHandle$base () from /usr/lib/libqpidcommon.so.0
#5  0x00ccc652 in ~AsynchIO (this=0x833d2f8) at /usr/include/boost/function/function_template.hpp:396
#6  0x00d49c23 in qpid::sys::DispatchHandle::processEvent (this=0x833d2fc, type=qpid::sys::Poller::READ_WRITABLE)
    at qpid/sys/DispatchHandle.cpp:506
#7  0x00ce83ad in qpid::sys::Poller::run (this=0x824a9d8) at ./qpid/sys/Poller.h:122
#8  0x00d44742 in qpid::sys::Dispatcher::run (this=0x0) at /usr/include/boost/shared_ptr.hpp:252
#9  0x00cda5f1 in qpid::sys::(anonymous namespace)::runRunnable (p=0x0) at qpid/sys/posix/Thread.cpp:35
#10 0x0084a3cc in start_thread () from /lib/tls/libpthread.so.0
#11 0x0075ff0e in clone () from /lib/tls/libc.so.6
(gdb) [root@mrg-qe-07 qpid_test_qpidd-perftest_performance]#
[root@mrg-qe-07 qpid_test_qpidd-perftest_performance]# rpm -qa | grep -E '(qpid|openais)'
qpid-java-client-0.5.751061-9.el4
qpidc-devel-0.5.752581-34.el4
qpidc-0.5.752581-34.el4
qpidc-ssl-0.5.752581-34.el4
python-qpid-0.5.760500-6.el4
qpid-dotnet-0.4.738274-2.el4
qpid-java-common-0.5.751061-9.el4
qpidd-acl-0.5.752581-34.el4
qpidd-xml-0.5.752581-34.el4
qpidc-perftest-0.5.752581-34.el4
qpidd-0.5.752581-34.el4
qpidc-debuginfo-0.5.752581-34.el4
qpidd-ssl-0.5.752581-34.el4
qpidd-devel-0.5.752581-34.el4
Comment 8 Frantisek Reznicek 2010-01-13 04:39:54 EST
I recently found a bit different case (rhel5.4 x86_64), could you possibly review and suggest if relevant to this bz, please? (one thread also in flush())...

[root@mrg-qe-02 qpid_test_qpidd-perftest_performance]# gdb `which qpidd` /root/MRG/Messaging/qpid_test_qpidd-perftest_performance/core.5198
GNU gdb Fedora (6.8-37.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu"...
Reading symbols from /usr/lib64/libqpidbroker.so.0...Reading symbols from /usr/lib/debug/usr/lib64/libqpidbroker.so.0.1.0.debug...done.
done.
...
Loaded symbols for /usr/lib64/qpid/daemon/replicating_listener.so
Core was generated by `/usr/sbin/qpidd --data-dir /root/MRG/Messaging/qpid_test_qpidd-perftest_perform'.
Program terminated with signal 6, Aborted.
[New process 5213]
[New process 5212]
[New process 5211]
[New process 5210]
[New process 5209]
[New process 5208]
[New process 5207]
[New process 5206]
[New process 5205]
[New process 5204]
[New process 5203]
[New process 5198]
#0  0x0000003840230265 in raise () from /lib64/libc.so.6
(gdb) info threads
  12 process 5198  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
  11 process 5203  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  10 process 5204  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  9 process 5205  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  8 process 5206  0x00000038402dfa1f in __lll_unlock_wake_private () from /lib64/libc.so.6
  7 process 5207  0x0000003840e0ba25 in pthread_sigmask () from /lib64/libpthread.so.0
  6 process 5208  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
  5 process 5209  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
  4 process 5210  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
  3 process 5211  0x00000038402dfa1f in __lll_unlock_wake_private () from /lib64/libc.so.6
  2 process 5212  0x0000003840e0ba25 in pthread_sigmask () from /lib64/libpthread.so.0
* 1 process 5213  0x0000003840230265 in raise () from /lib64/libc.so.6
(gdb) thread apply all bt

Thread 12 (process 5198):
#0  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
#1  0x0000003841b7ffbd in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:439
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x00000038424cb75e in qpid::broker::Broker::run (this=<value optimized out>) at qpid/broker/Broker.cpp:324
#4  0x00000000004069b8 in QpiddBroker::execute (this=<value optimized out>, options=0x1ea11d20) at posix/QpiddBroker.cpp:166
#5  0x00000000004054a8 in main (argc=23, argv=0x7fffb2390b88) at qpidd.cpp:77

Thread 11 (process 5203):
#0  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000003842596ef9 in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:69
#2  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#3  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#4  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 10 (process 5204):
#0  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000003842596ef9 in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:69
#2  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#3  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#4  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 9 (process 5205):
#0  0x0000003840e0af70 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000003842596ef9 in qpid::broker::Timer::run (this=<value optimized out>) at qpid/sys/posix/Condition.h:69
#2  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#3  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#4  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 8 (process 5206):
#0  0x00000038402dfa1f in __lll_unlock_wake_private () from /lib64/libc.so.6
#1  0x0000003840276d4c in _L_unlock_6230 () from /lib64/libc.so.6
---Type <return> to continue, or q <return> to quit---
#2  0x00000038402720ac in _int_free () from /lib64/libc.so.6
#3  0x000000384027273b in free () from /lib64/libc.so.6
#4  0x00002b9bf33d8b10 in mrg::msgstore::JournalImpl::wr_aio_cb () from /usr/lib64/qpid/daemon/msgstore.so
#5  0x00002b9bf3452d3c in mrg::journal::wmgr::get_events () from /usr/lib64/qpid/daemon/msgstore.so
#6  0x00002b9bf34557b3 in mrg::journal::wmgr::write_flush () from /usr/lib64/qpid/daemon/msgstore.so
#7  0x00002b9bf3455a76 in mrg::journal::wmgr::flush () from /usr/lib64/qpid/daemon/msgstore.so
#8  0x00002b9bf342fba1 in mrg::journal::jcntl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#9  0x00002b9bf33dbb66 in mrg::msgstore::JournalImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#10 0x00002b9bf34072e7 in mrg::msgstore::MessageStoreImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#11 0x000000384254aeab in qpid::broker::MessageStoreModule::flush (this=<value optimized out>, queue=<value optimized out>)
    at qpid/broker/MessageStoreModule.cpp:136
#12 0x00000038424eeb90 in qpid::broker::Queue::destroy (this=<value optimized out>) at qpid/broker/Queue.cpp:864
#13 0x00000038424eee01 in qpid::broker::Queue::tryAutoDelete (broker=<value optimized out>, queue=<value optimized out>)
    at qpid/broker/Queue.cpp:957
#14 0x0000003842570e90 in qpid::broker::SemanticState::cancel (this=<value optimized out>, c=<value optimized out>)
    at qpid/broker/SemanticState.cpp:336
#15 0x0000003842571a48 in ~SemanticState (this=<value optimized out>) at qpid/broker/SemanticState.cpp:74
#16 0x000000384258bed5 in ~SessionState (this=<value optimized out>) at qpid/broker/SessionState.cpp:97
#17 0x00000038425936b1 in qpid::broker::SessionHandler::handleDetach (this=<value optimized out>) at /usr/include/c++/4.1.2/memory:259
#18 0x0000003841b9d928 in qpid::amqp_0_10::SessionHandler::detach (this=<value optimized out>, name=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:178
#19 0x0000003841b55bf2 in qpid::framing::AMQP_AllOperations::SessionHandler::Invoker::visit (this=<value optimized out>,
    body=<value optimized out>) at gen/qpid/framing/SessionDetachBody.h:62
#20 0x0000003841b9fade in qpid::framing::invoke<qpid::amqp_0_10::SessionHandler> (target=<value optimized out>, body=<value optimized out>)
    at qpid/framing/Invoker.h:67
#21 0x0000003841b9b053 in qpid::amqp_0_10::SessionHandler::invoke (this=<value optimized out>, m=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:67
#22 0x0000003841b9eab4 in qpid::amqp_0_10::SessionHandler::handleIn (this=<value optimized out>, f=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:82
#23 0x00000038424fea59 in qpid::broker::Connection::received (this=<value optimized out>, frame=<value optimized out>)
    at qpid/framing/Handler.h:42
#24 0x00000038424c63a2 in qpid::amqp_0_10::Connection::decode (this=<value optimized out>, buffer=<value optimized out>,
    size=<value optimized out>) at qpid/amqp_0_10/Connection.cpp:55
#25 0x0000003841bc6f87 in qpid::sys::AsynchIOHandler::readbuff (this=<value optimized out>, buff=<value optimized out>)
---Type <return> to continue, or q <return> to quit---
    at qpid/sys/AsynchIOHandler.cpp:113
#26 0x00000038425ba618 in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=<value optimized out>,
    a0=<value optimized out>, a1=<value optimized out>) at /usr/include/boost/bind/mem_fn_template.hpp:252
#27 0x0000003841b730da in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=<value optimized out>, a0=<value optimized out>, a1=<value optimized out>)
    at /usr/include/boost/function/function_template.hpp:576
#28 0x0000003841b70d43 in qpid::sys::posix::AsynchIO::readable (this=<value optimized out>, h=<value optimized out>)
    at qpid/sys/posix/AsynchIO.cpp:448
#29 0x0000003841bcc8c7 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (
    this=<value optimized out>, a0=<value optimized out>) at /usr/include/boost/function/function_template.hpp:576
#30 0x0000003841bca5cb in qpid::sys::DispatchHandle::processEvent (this=<value optimized out>, type=<value optimized out>)
    at qpid/sys/DispatchHandle.cpp:432
#31 0x0000003841b80b93 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/Poller.h:122
#32 0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#33 0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#34 0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 7 (process 5207):
#0  0x0000003840e0ba25 in pthread_sigmask () from /lib64/libpthread.so.0
#1  0x0000003841b7ff9c in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:438
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#4  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#5  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 6 (process 5208):
#0  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
#1  0x0000003841b7ffbd in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:439
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
---Type <return> to continue, or q <return> to quit---
#4  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#5  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 5 (process 5209):
#0  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
#1  0x0000003841b7ffbd in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:439
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#4  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#5  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 4 (process 5210):
#0  0x00000038402d4018 in epoll_wait () from /lib64/libc.so.6
#1  0x0000003841b7ffbd in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:439
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#4  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#5  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 3 (process 5211):
#0  0x00000038402dfa1f in __lll_unlock_wake_private () from /lib64/libc.so.6
#1  0x0000003840276d4c in _L_unlock_6230 () from /lib64/libc.so.6
#2  0x00000038402720ac in _int_free () from /lib64/libc.so.6
#3  0x000000384027273b in free () from /lib64/libc.so.6
#4  0x00002b9bf33d8b10 in mrg::msgstore::JournalImpl::wr_aio_cb () from /usr/lib64/qpid/daemon/msgstore.so
#5  0x00002b9bf3452d3c in mrg::journal::wmgr::get_events () from /usr/lib64/qpid/daemon/msgstore.so
#6  0x00002b9bf34557b3 in mrg::journal::wmgr::write_flush () from /usr/lib64/qpid/daemon/msgstore.so
#7  0x00002b9bf3455a76 in mrg::journal::wmgr::flush () from /usr/lib64/qpid/daemon/msgstore.so
#8  0x00002b9bf342fba1 in mrg::journal::jcntl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#9  0x00002b9bf33dbb66 in mrg::msgstore::JournalImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#10 0x00002b9bf34072e7 in mrg::msgstore::MessageStoreImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#11 0x000000384254aeab in qpid::broker::MessageStoreModule::flush (this=<value optimized out>, queue=<value optimized out>)
---Type <return> to continue, or q <return> to quit---
    at qpid/broker/MessageStoreModule.cpp:136
#12 0x00000038424eeb90 in qpid::broker::Queue::destroy (this=<value optimized out>) at qpid/broker/Queue.cpp:864
#13 0x00000038424eee01 in qpid::broker::Queue::tryAutoDelete (broker=<value optimized out>, queue=<value optimized out>)
    at qpid/broker/Queue.cpp:957
#14 0x0000003842570e90 in qpid::broker::SemanticState::cancel (this=<value optimized out>, c=<value optimized out>)
    at qpid/broker/SemanticState.cpp:336
#15 0x0000003842571a48 in ~SemanticState (this=<value optimized out>) at qpid/broker/SemanticState.cpp:74
#16 0x000000384258bed5 in ~SessionState (this=<value optimized out>) at qpid/broker/SessionState.cpp:97
#17 0x00000038425936b1 in qpid::broker::SessionHandler::handleDetach (this=<value optimized out>) at /usr/include/c++/4.1.2/memory:259
#18 0x0000003841b9d928 in qpid::amqp_0_10::SessionHandler::detach (this=<value optimized out>, name=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:178
#19 0x0000003841b55bf2 in qpid::framing::AMQP_AllOperations::SessionHandler::Invoker::visit (this=<value optimized out>,
    body=<value optimized out>) at gen/qpid/framing/SessionDetachBody.h:62
#20 0x0000003841b9fade in qpid::framing::invoke<qpid::amqp_0_10::SessionHandler> (target=<value optimized out>, body=<value optimized out>)
    at qpid/framing/Invoker.h:67
#21 0x0000003841b9b053 in qpid::amqp_0_10::SessionHandler::invoke (this=<value optimized out>, m=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:67
#22 0x0000003841b9eab4 in qpid::amqp_0_10::SessionHandler::handleIn (this=<value optimized out>, f=<value optimized out>)
    at qpid/amqp_0_10/SessionHandler.cpp:82
#23 0x00000038424fea59 in qpid::broker::Connection::received (this=<value optimized out>, frame=<value optimized out>)
    at qpid/framing/Handler.h:42
#24 0x00000038424c63a2 in qpid::amqp_0_10::Connection::decode (this=<value optimized out>, buffer=<value optimized out>,
    size=<value optimized out>) at qpid/amqp_0_10/Connection.cpp:55
#25 0x0000003841bc6f87 in qpid::sys::AsynchIOHandler::readbuff (this=<value optimized out>, buff=<value optimized out>)
    at qpid/sys/AsynchIOHandler.cpp:113
#26 0x00000038425ba618 in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=<value optimized out>,
    a0=<value optimized out>, a1=<value optimized out>) at /usr/include/boost/bind/mem_fn_template.hpp:252
#27 0x0000003841b730da in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=<value optimized out>, a0=<value optimized out>, a1=<value optimized out>)
    at /usr/include/boost/function/function_template.hpp:576
#28 0x0000003841b70d43 in qpid::sys::posix::AsynchIO::readable (this=<value optimized out>, h=<value optimized out>)
    at qpid/sys/posix/AsynchIO.cpp:448
---Type <return> to continue, or q <return> to quit---
#29 0x0000003841bcc8c7 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (
    this=<value optimized out>, a0=<value optimized out>) at /usr/include/boost/function/function_template.hpp:576
#30 0x0000003841bca5cb in qpid::sys::DispatchHandle::processEvent (this=<value optimized out>, type=<value optimized out>)
    at qpid/sys/DispatchHandle.cpp:432
#31 0x0000003841b80b93 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/Poller.h:122
#32 0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#33 0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#34 0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 2 (process 5212):
#0  0x0000003840e0ba25 in pthread_sigmask () from /lib64/libpthread.so.0
#1  0x0000003841b7ffcf in qpid::sys::Poller::wait (this=<value optimized out>, timeout=<value optimized out>)
    at qpid/sys/epoll/EpollPoller.cpp:440
#2  0x0000003841b80b67 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/epoll/EpollPoller.cpp:405
#3  0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#4  0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#5  0x00000038402d3c2d in clone () from /lib64/libc.so.6

Thread 1 (process 5213):
#0  0x0000003840230265 in raise () from /lib64/libc.so.6
#1  0x0000003840231d10 in abort () from /lib64/libc.so.6
#2  0x00002b9bf342fb95 in mrg::journal::jcntl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#3  0x00002b9bf33dbb66 in mrg::msgstore::JournalImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#4  0x00002b9bf34072e7 in mrg::msgstore::MessageStoreImpl::flush () from /usr/lib64/qpid/daemon/msgstore.so
#5  0x000000384254aeab in qpid::broker::MessageStoreModule::flush (this=<value optimized out>, queue=<value optimized out>)
    at qpid/broker/MessageStoreModule.cpp:136
#6  0x00000038424f82c1 in qpid::broker::PersistableMessage::flush (this=<value optimized out>) at qpid/broker/PersistableMessage.cpp:56
#7  0x000000384252d8c1 in qpid::broker::IncompleteMessageList::process (this=<value optimized out>, listen=<value optimized out>,
    sync=<value optimized out>) at qpid/broker/IncompleteMessageList.cpp:58
#8  0x000000384258e6b0 in qpid::broker::SessionState::handleCommand (this=<value optimized out>, method=<value optimized out>,
    id=<value optimized out>) at qpid/broker/SessionState.cpp:202
#9  0x000000384258fd27 in qpid::broker::SessionState::handleIn (this=<value optimized out>, frame=<value optimized out>)
    at qpid/broker/SessionState.cpp:328
#10 0x0000003841b9ea57 in qpid::amqp_0_10::SessionHandler::handleIn (this=<value optimized out>, f=<value optimized out>)
---Type <return> to continue, or q <return> to quit---
    at qpid/amqp_0_10/SessionHandler.cpp:93
#11 0x00000038424fea59 in qpid::broker::Connection::received (this=<value optimized out>, frame=<value optimized out>)
    at qpid/framing/Handler.h:42
#12 0x00000038424c63a2 in qpid::amqp_0_10::Connection::decode (this=<value optimized out>, buffer=<value optimized out>,
    size=<value optimized out>) at qpid/amqp_0_10/Connection.cpp:55
#13 0x0000003841bc6f87 in qpid::sys::AsynchIOHandler::readbuff (this=<value optimized out>, buff=<value optimized out>)
    at qpid/sys/AsynchIOHandler.cpp:113
#14 0x00000038425ba618 in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=<value optimized out>,
    a0=<value optimized out>, a1=<value optimized out>) at /usr/include/boost/bind/mem_fn_template.hpp:252
#15 0x0000003841b730da in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=<value optimized out>, a0=<value optimized out>, a1=<value optimized out>)
    at /usr/include/boost/function/function_template.hpp:576
#16 0x0000003841b70d43 in qpid::sys::posix::AsynchIO::readable (this=<value optimized out>, h=<value optimized out>)
    at qpid/sys/posix/AsynchIO.cpp:448
#17 0x0000003841bcc8c7 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (
    this=<value optimized out>, a0=<value optimized out>) at /usr/include/boost/function/function_template.hpp:576
#18 0x0000003841bca5cb in qpid::sys::DispatchHandle::processEvent (this=<value optimized out>, type=<value optimized out>)
    at qpid/sys/DispatchHandle.cpp:432
#19 0x0000003841b80b93 in qpid::sys::Poller::run (this=<value optimized out>) at qpid/sys/Poller.h:122
#20 0x0000003841b76bca in runRunnable (p=<value optimized out>) at qpid/sys/posix/Thread.cpp:35
#21 0x0000003840e06617 in start_thread () from /lib64/libpthread.so.0
#22 0x00000038402d3c2d in clone () from /lib64/libc.so.6
(gdb) quit
[root@mrg-qe-02 qpid_test_qpidd-perftest_performance]# rpm -qa | grep -E '(qpid|openais)' | sort
openais-0.80.6-8.el5_4.1
openais-0.80.6-8.el5_4.1
openais-debuginfo-0.80.6-8.el5_4.1
openais-debuginfo-0.80.6-8.el5_4.1
openais-devel-0.80.6-8.el5_4.1
openais-devel-0.80.6-8.el5_4.1
python-qpid-0.5.758389-2.el5
qpidc-0.5.752581-34.el5
qpidc-debuginfo-0.5.752581-34.el5
qpidc-devel-0.5.752581-34.el5
qpidc-perftest-0.5.752581-34.el5
qpidc-rdma-0.5.752581-34.el5
qpidc-ssl-0.5.752581-34.el5
qpidd-0.5.752581-34.el5
qpidd-acl-0.5.752581-34.el5
qpidd-cluster-0.5.752581-34.el5
qpidd-devel-0.5.752581-34.el5
qpid-dotnet-0.4.738274-2.el5
qpidd-rdma-0.5.752581-34.el5
qpidd-ssl-0.5.752581-34.el5
qpidd-xml-0.5.752581-34.el5
qpid-java-client-0.5.751061-9.el5
qpid-java-common-0.5.751061-9.el5
rh-qpid-tests-0.5.752581-34.el5
Comment 9 Frantisek Reznicek 2010-01-13 04:57:45 EST
And finally one more from RHEL 5.4 i386 may I ask you for check whether it is related, please? (mrg::journal::jcntl::flush() in thread 1)

root@mrg-qe-12:~/MRG/Messaging/qpid_test_qpidd-perftest_performance# gdb `which qpidd` /root/MRG/Messaging/qpid_test_qpidd-perftest_performance/core.11479
GNU gdb Fedora (6.8-37.el5)
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu"...

warning: Can't read pathname for load map: Input/output error.

warning: .dynamic section for "/usr/lib/libnss3.so" is not at the expected address

warning: difference appears to be caused by prelink, adjusting expectations

warning: .dynamic section for "/usr/lib/libssl3.so" is not at the expected address

warning: difference appears to be caused by prelink, adjusting expectations

warning: .dynamic section for "/usr/lib/libnssutil3.so" is not at the expected address

warning: difference appears to be caused by prelink, adjusting expectations
Reading symbols from /usr/lib/libqpidbroker.so.0...Reading symbols from /usr/lib/debug/usr/lib/libqpidbroker.so.0.1.0.debug...done.
done.
Loaded symbols for /usr/lib/libqpidbroker.so.0
...
Reading symbols from /usr/lib/qpid/daemon/ssl.so...Reading symbols from /usr/lib/debug/usr/lib/qpid/daemon/ssl.so.debug...done.
done.
Loaded symbols for /usr/lib/qpid/daemon/ssl.so
Core was generated by `/usr/sbin/qpidd --data-dir /root/MRG/Messaging/qpid_test_qpidd-perftest_perform'.
Program terminated with signal 6, Aborted.
[New process 11487]
[New process 11494]
[New process 11493]
[New process 11492]
[New process 11491]
[New process 11490]
[New process 11489]
[New process 11488]
[New process 11486]
[New process 11485]
[New process 11484]
[New process 11479]
#0  0x00a13410 in __kernel_vsyscall ()
(gdb) info threads
  12 process 11479  0x00a13410 in __kernel_vsyscall ()
  11 process 11484  0x00a13410 in __kernel_vsyscall ()
  10 process 11485  0x00a13410 in __kernel_vsyscall ()
  9 process 11486  0x00a13410 in __kernel_vsyscall ()
  8 process 11488  0x00a13410 in __kernel_vsyscall ()
  7 process 11489  0x00a13410 in __kernel_vsyscall ()
  6 process 11490  0x00a13410 in __kernel_vsyscall ()
  5 process 11491  0x00374ae5 in pthread_mutex_lock () from /lib/libpthread.so.0
  4 process 11492  0x00a13410 in __kernel_vsyscall ()
  3 process 11493  0x00a13410 in __kernel_vsyscall ()
  2 process 11494  0x00a13410 in __kernel_vsyscall ()
* 1 process 11487  0x00a13410 in __kernel_vsyscall ()
(gdb) thread apply all bt

Thread 12 (process 11479):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b6b322 in unlink () from /lib/libc.so.6
#2  0x03ff4986 in mrg::journal::jdir::delete_dir () from /usr/lib/qpid/daemon/msgstore.so
#3  0x03ff60f8 in mrg::journal::jdir::delete_dir () from /usr/lib/qpid/daemon/msgstore.so
#4  0x03ff0a0d in mrg::journal::jcntl::delete_jrnl_files () from /usr/lib/qpid/daemon/msgstore.so
#5  0x03fba1de in mrg::msgstore::MessageStoreImpl::destroy () from /usr/lib/qpid/daemon/msgstore.so
#6  0x00de374f in qpid::broker::MessageStoreModule::destroy (this=0x88e7980, queue=@0xb0f014d0)
    at qpid/broker/MessageStoreModule.cpp:56
#7  0x00d7b54c in qpid::broker::Queue::destroy (this=0xb0f014d0) at qpid/broker/Queue.cpp:865
#8  0x00d7b774 in qpid::broker::Queue::tryAutoDelete (broker=@0x88f5a30, queue={px = 0xbfddfd94, pn = {pi_ = 0xbfddfd88}})
    at qpid/broker/Queue.cpp:957
#9  0x00e0ba20 in qpid::broker::SemanticState::cancel (this=0xb0f017f8, c={px = 0xbfddfe04, pn = {pi_ = 0xe19b8b}})
    at qpid/broker/SemanticState.cpp:336
#10 0x00e0c6a1 in ~SemanticState (this=0xb0f017f8) at qpid/broker/SemanticState.cpp:74
#11 0x00e2b1d9 in ~SessionState (this=0xb0f016d0) at qpid/broker/SessionState.cpp:97
#12 0x00e32cae in qpid::broker::SessionHandler::handleDetach (this=0xb0f00ec8) at /usr/include/c++/4.1.2/memory:259
#13 0x002b4943 in qpid::amqp_0_10::SessionHandler::detach (this=0xb0f00ec8, name=@0xb0377e40)
    at qpid/amqp_0_10/SessionHandler.cpp:178
#14 0x002299c9 in qpid::framing::AMQP_AllOperations::SessionHandler::Invoker::visit (this=0xbfde002c, body=@0xb0377e38)
    at gen/qpid/framing/SessionDetachBody.h:62
#15 0x00243268 in qpid::framing::SessionDetachBody::accept (this=0xb0377e38, v=@0xbfde002c)
    at gen/qpid/framing/SessionDetachBody.h:66
#16 0x002b68a7 in qpid::framing::invoke<qpid::amqp_0_10::SessionHandler> (target=@0xb0f00ec8, body=@0xb0377e38)
    at qpid/framing/Invoker.h:67
#17 0x002b13c0 in qpid::amqp_0_10::SessionHandler::invoke (this=0xb0f00ec8, m=@0xb0377e38)
    at qpid/amqp_0_10/SessionHandler.cpp:67
#18 0x002b52c7 in qpid::amqp_0_10::SessionHandler::handleIn (this=0xb0f00ec8, f=@0xbfde06e8)
    at qpid/amqp_0_10/SessionHandler.cpp:82
#19 0x00e2fb0b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0xb0f00ed0, t=@0xbfde06e8) at qpid/framing/Handler.h:67
#20 0x00d8f610 in qpid::broker::Connection::received (this=0xb0f00750, frame=@0xbfde06e8) at qpid/framing/Handler.h:42
#21 0x00d51d0f in qpid::amqp_0_10::Connection::decode (this=0xb0f006b8, buffer=0x89c0ba0 "\v\001", size=149)
---Type <return> to continue, or q <return> to quit---
    at qpid/amqp_0_10/Connection.cpp:55
#22 0x00e03d94 in qpid::broker::SecureConnection::decode (this=0xb0f00640, buffer=0x89c0ba0 "\v\001", size=0)
    at qpid/broker/SecureConnection.cpp:42
#23 0x002e3be6 in qpid::sys::AsynchIOHandler::readbuff (this=0x89bf1a0, buff=0x89bf148)
    at qpid/sys/AsynchIOHandler.cpp:113
#24 0x00e5d6f4 in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (
    function_obj_ptr={obj_ptr = 0x89bf860, const_obj_ptr = 0x89bf860, func_ptr = 0x89bf860, data = "`"}, a0=@0x89bf740,
    a1=0x89bf148) at /usr/include/boost/bind/mem_fn_template.hpp:252
#25 0x0028582e in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=0x89bf7bc, a0=@0x89bf740, a1=0x89bf148)
    at /usr/include/boost/function/function_template.hpp:576
#26 0x0028371e in qpid::sys::posix::AsynchIO::readable (this=0x89bf740, h=@0x89bf744) at qpid/sys/posix/AsynchIO.cpp:448
#27 0x0028429d in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (function_obj_ptr=
      {obj_ptr = 0x89bf8d8, const_obj_ptr = 0x89bf8d8, func_ptr = 0x89bf8d8, data = "�"}, a0=@0x89bf744)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#28 0x002e7f14 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (
    this=0x89bf74c, a0=@0x89bf744) at /usr/include/boost/function/function_template.hpp:576
#29 0x002e75f9 in qpid::sys::DispatchHandle::processEvent (this=0x89bf744, type=qpid::sys::Poller::READABLE)
    at qpid/sys/DispatchHandle.cpp:432
#30 0x00294934 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/Poller.h:122
#31 0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#32 0x00d60f61 in qpid::broker::Broker::run (this=0x88f5a30) at qpid/broker/Broker.cpp:324
#33 0x0804dd44 in QpiddBroker::execute (this=0xbfde13b5, options=0x88f2d88) at posix/QpiddBroker.cpp:166
#34 0x0804c6c7 in main (argc=23, argv=0xbfde1464) at qpidd.cpp:77

Thread 11 (process 11484):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00376d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x00b85414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00e36c5e in qpid::broker::Timer::run (this=0x88f5c38) at qpid/sys/posix/Condition.h:69
#4  0x00289871 in runRunnable (p=0x88f5c38) at qpid/sys/posix/Thread.cpp:35
---Type <return> to continue, or q <return> to quit---
#5  0x0037273b in start_thread () from /lib/libpthread.so.0
#6  0x00b78cfe in clone () from /lib/libc.so.6

Thread 10 (process 11485):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00376d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x00b85414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00e36c5e in qpid::broker::Timer::run (this=0x88f5cb8) at qpid/sys/posix/Condition.h:69
#4  0x00289871 in runRunnable (p=0x88f5cb8) at qpid/sys/posix/Thread.cpp:35
#5  0x0037273b in start_thread () from /lib/libpthread.so.0
#6  0x00b78cfe in clone () from /lib/libc.so.6

Thread 9 (process 11486):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00376d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2  0x00b85414 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libc.so.6
#3  0x00e36c5e in qpid::broker::Timer::run (this=0x88e8000) at qpid/sys/posix/Condition.h:69
#4  0x00289871 in runRunnable (p=0x88e8000) at qpid/sys/posix/Thread.cpp:35
#5  0x0037273b in start_thread () from /lib/libpthread.so.0
#6  0x00b78cfe in clone () from /lib/libc.so.6

Thread 8 (process 11488):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 7 (process 11489):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
---Type <return> to continue, or q <return> to quit---
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 6 (process 11490):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 5 (process 11491):
#0  0x00374ae5 in pthread_mutex_lock () from /lib/libpthread.so.0
#1  0x00b85536 in pthread_mutex_lock () from /lib/libc.so.6
#2  0x00d53228 in qpid::sys::Mutex::lock (this=0x88e9b18) at qpid/sys/posix/Mutex.h:116
#3  0x00293803 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/Mutex.h:33
#4  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#5  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#6  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#7  0x0037273b in start_thread () from /lib/libpthread.so.0
#8  0x00b78cfe in clone () from /lib/libc.so.6

Thread 4 (process 11492):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
---Type <return> to continue, or q <return> to quit---
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 3 (process 11493):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 2 (process 11494):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00b79376 in epoll_wait () from /lib/libc.so.6
#2  0x002938e9 in qpid::sys::Poller::wait (this=0x88f4dd8, timeout={nanosecs = 9223372036854775807})
    at qpid/sys/epoll/EpollPoller.cpp:439
#3  0x00294916 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/epoll/EpollPoller.cpp:405
#4  0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#5  0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#6  0x0037273b in start_thread () from /lib/libpthread.so.0
#7  0x00b78cfe in clone () from /lib/libc.so.6

Thread 1 (process 11487):
#0  0x00a13410 in __kernel_vsyscall ()
#1  0x00acfdf0 in raise () from /lib/libc.so.6
#2  0x00ad1701 in abort () from /lib/libc.so.6
#3  0x03ff07ea in mrg::journal::jcntl::flush () from /usr/lib/qpid/daemon/msgstore.so
#4  0x03f922f3 in mrg::msgstore::JournalImpl::flush () from /usr/lib/qpid/daemon/msgstore.so
---Type <return> to continue, or q <return> to quit---
#5  0x03fc2671 in mrg::msgstore::MessageStoreImpl::flush () from /usr/lib/qpid/daemon/msgstore.so
#6  0x00de3d6f in qpid::broker::MessageStoreModule::flush (this=0x88e7980, queue=@0xb0f03cf8)
    at qpid/broker/MessageStoreModule.cpp:136
#7  0x00d88981 in qpid::broker::PersistableMessage::flush (this=0xb0374600) at qpid/broker/PersistableMessage.cpp:56
#8  0x00dc355f in qpid::broker::IncompleteMessageList::process (this=0x897e4cc, listen=@0x897e528, sync=true)
    at qpid/broker/IncompleteMessageList.cpp:58
#9  0x00e2f30a in qpid::broker::SessionState::handleCommand (this=0x897e218, method=0xb04221d8, id=@0xb60ef40c)
    at qpid/broker/SessionState.cpp:202
#10 0x00e2fa2e in qpid::broker::SessionState::handleIn (this=0x897e218, frame=@0xb60efaa8)
    at qpid/broker/SessionState.cpp:328
#11 0x00e2fb0b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x897e318, t=@0xb60efaa8) at qpid/framing/Handler.h:67
#12 0x002b5266 in qpid::amqp_0_10::SessionHandler::handleIn (this=0x897d598, f=@0xb60efaa8)
    at qpid/amqp_0_10/SessionHandler.cpp:93
#13 0x00e2fb0b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x897d5a0, t=@0xb60efaa8) at qpid/framing/Handler.h:67
#14 0x00d8f610 in qpid::broker::Connection::received (this=0x893cd18, frame=@0xb60efaa8) at qpid/framing/Handler.h:42
#15 0x00d51d0f in qpid::amqp_0_10::Connection::decode (this=0x893cc80, buffer=0x896d4f8 "\a\003", size=670)
    at qpid/amqp_0_10/Connection.cpp:55
#16 0x00e03d94 in qpid::broker::SecureConnection::decode (this=0x893cc68, buffer=0x896d4f8 "\a\003", size=11487)
    at qpid/broker/SecureConnection.cpp:42
#17 0x002e3be6 in qpid::sys::AsynchIOHandler::readbuff (this=0x88ea860, buff=0x893a7f8)
    at qpid/sys/AsynchIOHandler.cpp:113
#18 0x00e5d6f4 in boost::detail::function::function_obj_invoker2<boost::_bi::bind_t<bool, boost::_mfi::mf2<bool, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (
    function_obj_ptr={obj_ptr = 0x893a6b8, const_obj_ptr = 0x893a6b8, func_ptr = 0x893a6b8, data = "�"}, a0=@0x893a598,
    a1=0x893a7f8) at /usr/include/boost/bind/mem_fn_template.hpp:252
#19 0x0028582e in boost::function2<bool, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*, std::allocator<boost::function_base> >::operator() (this=0x893a614, a0=@0x893a598, a1=0x893a7f8)
    at /usr/include/boost/function/function_template.hpp:576
#20 0x0028371e in qpid::sys::posix::AsynchIO::readable (this=0x893a598, h=@0x893a59c) at qpid/sys/posix/AsynchIO.cpp:448
#21 0x0028429d in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid:---Type <return> to continue, or q <return> to quit---
:sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (function_obj_ptr=
      {obj_ptr = 0x893a730, const_obj_ptr = 0x893a730, func_ptr = 0x893a730, data = "0"}, a0=@0x893a59c)
    at /usr/include/boost/bind/mem_fn_template.hpp:149
#22 0x002e7f14 in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (
    this=0x893a5a4, a0=@0x893a59c) at /usr/include/boost/function/function_template.hpp:576
#23 0x002e75f9 in qpid::sys::DispatchHandle::processEvent (this=0x893a59c, type=qpid::sys::Poller::READABLE)
    at qpid/sys/DispatchHandle.cpp:432
#24 0x00294934 in qpid::sys::Poller::run (this=0x88f4dd8) at qpid/sys/Poller.h:122
#25 0x002e48d4 in qpid::sys::Dispatcher::run (this=0xbfde10c8) at qpid/sys/Dispatcher.cpp:37
#26 0x00289871 in runRunnable (p=0xbfde10c8) at qpid/sys/posix/Thread.cpp:35
#27 0x0037273b in start_thread () from /lib/libpthread.so.0
#28 0x00b78cfe in clone () from /lib/libc.so.6
(gdb) quit
root@mrg-qe-12:~/MRG/Messaging/qpid_test_qpidd-perftest_performance# rpm -qa | grep -E '(qpidd|opena)'
openais-debuginfo-0.80.6-8.el5_4.1
qpidd-ssl-0.5.752581-34.el5
openais-0.80.6-8.el5_4.1
qpidd-acl-0.5.752581-34.el5
qpidd-cluster-0.5.752581-34.el5
qpidd-xml-0.5.752581-34.el5
qpidd-0.5.752581-34.el5
qpidd-devel-0.5.752581-34.el5
qpidd-rdma-0.5.752581-34.el5
Comment 10 Kim van der Riet 2010-03-04 16:11:53 EST
Looking at these traces, it seems that comment #7 above is unrelated. Although there is a flush in progress in one of the threads, the abort is happening elsewhere in the broker.

However, comment #8 and  comment #9 are in fact the cases I am looking for. There should have been an error message printed to stderr - is there any record of it? This will indicate the error code from the lock operation that is failing.

What is clear from these traces is that the error occurs in the following context:

qpid::broker::SessionState::handleIn()
qpid::broker::SessionState::handleCommand()
qpid::broker::IncompleteMessageList::process()
qpid::broker::PersistableMessage::flush()
qpid::broker::MessageStoreModule::flush()
mrg::msgstore::MessageStoreImpl::flush()
mrg::msgstore::JournalImpl::flush()
mrg::journal::jcntl::flush()

Most likely causes are that a thread flushing the store before the mutex is initialized or after it has been destroyed. Seeing where in the sequence of the test this error occurs would be helpful (ie was the broker in recovery, steady state operation, or being killed?).
Comment 11 Frantisek Reznicek 2010-04-30 06:29:38 EDT
The test kills the broker after set of tests (runs of perftest) or after each perftest run.

There is long timeout for perftest to finish operation.
Currently I can see that there are many triggers of queue policy size or journal capacity.
In that particular case perftest is killed and broker is then killed as well with delay of around 10 seconds.


My tests at following packages:
[root@mrg-qe-02 qpid_test_qpidd-perftest_performance]# rpm -qa | grep qpid | sort
python-qpid-0.7.934605-1.el4|5
qpid-cpp-*-0.7.935473-1.el4|5
do not trigger the issue so far (4 machines in parallel, around 20 hours of operation).
Comment 12 Frantisek Reznicek 2010-05-10 08:30:28 EDT
The long term stress tests showed bug dependency on bug 587505 which might currently block bug 484048 trigger.

So far no JERR__PTHREAD and abort in the msgstore's flush() was observed on current candidate set: qpid-cpp-*0.7.935473
Comment 13 Kim van der Riet 2010-05-13 15:41:36 EDT
The error message (according to gsim) is:

slock::slock(): ::pthread_mutex_lock: Invalid argument

Invalid argument is errno 22 (EINVAL), which suggests that the mutex has either not been initialized or has been destroyed. The latter is more likely, meaning that a queue has been deleted prior to the flush call.
Comment 14 Gordon Sim 2010-05-13 15:44:01 EDT
I can reproduce it with:

while ~/qpid/cpp/build/src/tests/perftest --mode topic --npubs 2 --nsubs 4 --summary --durable true --sub-ack 0 --count 100000 --size 8; do true; done

but I have to fix bug 587505 by reverting r736810 first or I hit that issue far more quickly. WIth that fix in I can run for many iterations before hitting this issue.
Comment 15 Kim van der Riet 2010-05-14 15:34:53 EDT
This error occurs because the queue is being flushed on one thread after being deleted on another. Checking the stacktrace from a recent occurrence on RHEL 5.5 (x86_64):

(part of stack)
Thread 3:
#12 0x00002ac9b2fad384 in mrg::journal::jcntl::~jcntl (this=0x2aaab8019ab8, __in_chrg=<value optimized out>) at jrnl/jcntl.cpp:84
#13 0x00002ac9b2f52ee9 in mrg::msgstore::JournalImpl::~JournalImpl (this=0x2aaab8019ab0, __in_chrg=<value optimized out>) at JournalImpl.cpp:128
#14 0x00002ac9b1f16a49 in qpid::broker::Queue::setExternalQueueStore (this=0x2aaab8016320, inst=0x0) at qpid/broker/Queue.cpp:1053
#15 0x00002ac9b2f787d6 in mrg::msgstore::MessageStoreImpl::destroy (this=0x1a078810, queue=...) at MessageStoreImpl.cpp:519
#16 0x00002ac9b1f113e5 in qpid::broker::MessageStoreModule::destroy (this=0x1a07d820, queue=...) at qpid/broker/MessageStoreModule.cpp:56
#17 0x00002ac9b1f1b190 in qpid::broker::Queue::destroy (this=0x2aaab8016320) at qpid/broker/Queue.cpp:901
#18 0x00002ac9b1f1b305 in qpid::broker::Queue::tryAutoDelete (broker=..., queue=...) at qpid/broker/Queue.cpp:1013
#19 0x00002ac9b1f48cc4 in qpid::broker::SemanticState::cancel (this=0x2aaab801cf08, c=...) at qpid/broker/SemanticState.cpp:402
#20 0x00002ac9b1f4be08 in qpid::broker::SemanticState::~SemanticState (this=0x2aaab801cf08, __in_chrg=<value optimized out>) at qpid/broker/SemanticState.cpp:84
#21 0x00002ac9b1f70c6a in qpid::broker::SessionState::~SessionState (this=0x2aaab801cd30, __in_chrg=<value optimized out>) at qpid/broker/SessionState.cpp:96
#22 0x00002ac9b1f69640 in std::auto_ptr<qpid::broker::SessionState>::~auto_ptr (this=0x4774b070, __in_chrg=<value optimized out>)
    at /usr/lib/gcc/x86_64-redhat-linux/4.1.2/../../../../include/c++/4.1.2/memory:259
#23 0x00002ac9b1f68e08 in qpid::broker::SessionHandler::handleDetach (this=0x2aaab822bc60) at qpid/broker/SessionHandler.cpp:70
#24 0x00002ac9b251f499 in qpid::amqp_0_10::SessionHandler::detach (this=0x2aaab822bc60, name=...) at qpid/amqp_0_10/SessionHandler.cpp:188

Thread 1:
#1  0x0000003d3c431d10 in abort () from /lib64/libc.so.6
#2  0x00002ac9b2f61e21 in mrg::journal::slock::slock (this=0x46348d30, sm=...) at jrnl/slock.hpp:53
#3  0x00002ac9b2faba26 in mrg::journal::jcntl::flush (this=0x2aaab8019ab8, block_till_aio_cmpl=false) at jrnl/jcntl.cpp:402
#4  0x00002ac9b2f508ee in mrg::msgstore::JournalImpl::flush (this=0x2aaab8019ab0, block_till_aio_cmpl=false) at JournalImpl.cpp:504
#5  0x00002ac9b2f74dd8 in mrg::msgstore::MessageStoreImpl::flush (this=0x1a078810, queue=...) at MessageStoreImpl.cpp:1236
#6  0x00002ac9b1f1039f in qpid::broker::MessageStoreModule::flush (this=0x1a07d820, queue=...) at qpid/broker/MessageStoreModule.cpp:136
#7  0x00002ac9b1f1407c in qpid::broker::PersistableMessage::flush (this=0x2aaab40180f0) at qpid/broker/PersistableMessage.cpp:56
#8  0x00002ac9b1ef6434 in qpid::broker::IncompleteMessageList::process(const boost::function<void ()(const boost::intrusive_ptr<qpid::broker::Message>&),std::allocator<void> > &, b

Thus thread 3 has deleted the queue because of a session detach while thread 1 is still busy with processing the IncompleteMessageList on that queue.

Comment #9 above follows a similar pattern: Thread 1 is busy with the IncompleteMessageList while thread 12 has deleted the queue.

Comment #8 above is partly similar: Thread 1 is busy with the IncompleteMessageList, but I cannot see the thread that deleted the queue. The other threads are clearly busy with a shutdown, but are still flushing their respective queues. Perhaps the deleting thread has already returned to idle state.
Comment 16 Gordon Sim 2010-05-16 05:37:05 EDT
Fixed in r944683.
Comment 17 Frantisek Reznicek 2010-06-14 04:32:33 EDT
The issue has been fixed (no aborts / crashes detected), tested in four extended week runs on RHEL 4.8 / 5.5 i386 / x86_64 on packages:
python-qpid-0.7.946106-1.el5
python-saslwrapper-0.1.934605-2.el5
qpid-cpp-client-0.7.946106-2.el5
qpid-cpp-client-devel-0.7.946106-2.el5
qpid-cpp-client-devel-docs-0.7.946106-2.el5
qpid-cpp-client-ssl-0.7.946106-2.el5
qpid-cpp-mrg-debuginfo-0.7.946106-2.el5
qpid-cpp-server-0.7.946106-2.el5
qpid-cpp-server-cluster-0.7.946106-2.el5
qpid-cpp-server-devel-0.7.946106-2.el5
qpid-cpp-server-ssl-0.7.946106-2.el5
qpid-cpp-server-store-0.7.946106-2.el5
qpid-cpp-server-xml-0.7.946106-2.el5
qpid-java-client-0.7.946106-3.el5
qpid-java-common-0.7.946106-3.el5
qpid-tests-0.7.946106-1.el5
qpid-tools-0.7.946106-4.el5
ruby-qpid-0.7.946106-2.el5
ruby-saslwrapper-0.1.934605-2.el5
saslwrapper-0.1.934605-2.el5
saslwrapper-devel-0.1.934605-2.el5

-> VERIFIED
Comment 18 Kim van der Riet 2010-10-05 11:04:05 EDT
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
Cause: A race condition in the broker allows one thread to delete a queue while another is flushing it. This results in the "JERR__PTHREAD: pthread failure" message. The race condition is somewhat difficult to reproduce.
Consequence: The broker closes the connection of the affected client.
Fix: The race condition was identified and fixed.
Result: The race condition no longer occurs.
Comment 19 Jaromir Hradilek 2010-10-06 09:56:19 EDT
    Technical note updated. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    Diffed Contents:
@@ -1,4 +1,5 @@
-Cause: A race condition in the broker allows one thread to delete a queue while another is flushing it. This results in the "JERR__PTHREAD: pthread failure" message. The race condition is somewhat difficult to reproduce.
+Previously, a race condition may have occurred, allowing one thread to delete a message queue while another one was flushing it. When this happened, the following error message was logged:
-Consequence: The broker closes the connection of the affected client.
+
-Fix: The race condition was identified and fixed.
+  JERR__PTHREAD: pthread failure.
-Result: The race condition no longer occurs.+
+With this update, this error has been fixed, and the race condition no longer occurs.
Comment 21 errata-xmlrpc 2010-10-14 12:08:03 EDT
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2010-0773.html

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