Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 883469

Summary: c++ client crashes calling a pure virtual after being disconnected from broker.
Product: Red Hat Enterprise MRG Reporter: Frantisek Reznicek <freznice>
Component: qpid-cppAssignee: Andrew Stitcher <astitcher>
Status: CLOSED WORKSFORME QA Contact: MRG Quality Engineering <mrgqe-bugs>
Severity: high Docs Contact:
Priority: high    
Version: DevelopmentCC: astitcher, christopher.pitman, esammons, jdillama, jross, lzhaldyb
Target Milestone: 3.0   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-04-29 18:47:39 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 698367, 803771    
Attachments:
Description Flags
Crash dumps none

Description Frantisek Reznicek 2012-12-04 16:48:52 UTC
Description of problem:

multithreaded qpid client (bz804752, bug 804752 QA enhanced reproducer, attachment 657325 [details]) rarely crashes in qpid::client::TCPConnector::connectFailed() -> ... -> malloc_consolidate():

  [root@dhcp-37-127 bz804752]# gdb ./bz804752 core.8218 
  GNU gdb (GDB) Red Hat Enterprise Linux (7.0.1-45.el5)
  ...
  warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7fffe3ffd000
  Core was generated by `./bz804752'.
  Program terminated with signal 11, Segmentation fault.
  #0  0x00000034e626f534 in malloc_consolidate () from /lib64/libc.so.6
  (gdb) info threads
    6 Thread 0x2b465f4e3f10 (LWP 8218)  0x00000034e6a07c65 in pthread_join () from /lib64/libpthread.so.0
    5 Thread 8221  0x00000034e6a0b019 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
    4 Thread 8222  0x00000034e6a0b019 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
    3 Thread 8234  0x00000034e62302c5 in raise () from /lib64/libc.so.6
    2 Thread 8235  0x00000034e62d5001 in clone () from /lib64/libc.so.6
  * 1 Thread 0x2b4660fbf940 (LWP 8220)  0x00000034e626f534 in malloc_consolidate () from /lib64/libc.so.6
  (gdb) t a a bt
  
  Thread 6 (Thread 0x2b465f4e3f10 (LWP 8218)):
  #0  0x00000034e6a07c65 in pthread_join () from /lib64/libpthread.so.0
  #1  0x00002b465e90f3ce in boost::thread::join() () from /usr/lib64/libboost_thread.so.2
  #2  0x0000000000401fa6 in main ()
  
  Thread 5 (Thread 8221):
  #0  0x00000034e6a0b019 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  #1  0x00002b465edcff99 in wait (this=0x2b4664002528, desired=Traceback (most recent call last):
    File "/usr/share/gdb/python/libstdcxx/v6/printers.py", line 322, in to_string
      return '%s with %d elements' % (self.typename,
  OverflowError: __len__() should return 0 <= outcome < 2**31
  Cannot access memory at address 0x1638
  ) at ../include/qpid/sys/posix/Condition.h:63
  #2  wait (this=0x2b4664002528, desired=Traceback (most recent call last):
    File "/usr/share/gdb/python/libstdcxx/v6/printers.py", line 322, in to_string
      return '%s with %d elements' % (self.typename,
  OverflowError: __len__() should return 0 <= outcome < 2**31
  Cannot access memory at address 0x1638
  ) at ../include/qpid/sys/Monitor.h:41
  #3  qpid::client::StateManager::waitFor (this=0x2b4664002528, desired=Traceback (most recent call last):
    File "/usr/share/gdb/python/libstdcxx/v6/printers.py", line 322, in to_string
      return '%s with %d elements' % (self.typename,
  OverflowError: __len__() should return 0 <= outcome < 2**31
  Cannot access memory at address 0x1638
  ) at qpid/client/StateManager.cpp:51
  #4  0x00002b465ed8a4ac in qpid::client::ConnectionHandler::waitForOpen (this=0x2b4664002448) at qpid/client/ConnectionHandler.cpp:150
  #5  0x00002b465ed98c18 in qpid::client::ConnectionImpl::open (this=0x2b4664002360) at qpid/client/ConnectionImpl.cpp:288
  #6  0x00002b465ed881d8 in qpid::client::Connection::open (this=0x15be72c0, settings=...) at qpid/client/Connection.cpp:125
  #7  0x00002b465ed88a18 in qpid::client::Connection::open (this=0x15be72c0, url=..., settings=...) at qpid/client/Connection.cpp:81
  #8  0x00002b465e6c442a in qpid::client::amqp0_10::ConnectionImpl::tryConnect (this=0x15be7200) at qpid/client/amqp0_10/ConnectionImpl.cpp:300
  #9  0x00002b465e6c4f0f in qpid::client::amqp0_10::ConnectionImpl::connect (this=0x15be7200, started=...) at qpid/client/amqp0_10/ConnectionImpl.cpp:267
  #10 0x00002b465e6c58e2 in qpid::client::amqp0_10::ConnectionImpl::open (this=0x15be7200) at qpid/client/amqp0_10/ConnectionImpl.cpp:249
  #11 0x00002b465e6c008c in qpid::client::amqp0_10::ConnectionImpl::reopen (this=0x2b466400255c) at qpid/client/amqp0_10/ConnectionImpl.cpp:260
  #12 0x00002b465e6d3655 in qpid::client::amqp0_10::SessionImpl::execute<qpid::client::amqp0_10::ReceiverImpl::Fetch> (this=0x15beeb50, f=<value optimized out>)
      at qpid/client/amqp0_10/SessionImpl.h:102
  #13 0x00002b465e6d29ac in qpid::client::amqp0_10::ReceiverImpl::fetch (this=0x15bf0b60, message=<value optimized out>, timeout=...) at qpid/client/amqp0_10/ReceiverImpl.cpp:71
  #14 0x00002b465e6a78ad in qpid::messaging::Receiver::fetch (this=<value optimized out>, message=..., timeout=...) at qpid/messaging/Receiver.cpp:38
  #15 0x000000000040213f in thread(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) ()
  #16 0x0000000000402d31 in void boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> >::operator()<void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list0>(boost::_bi::type<void>, void (*&)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list0&, int) ()
  #17 0x0000000000402ddc in boost::_bi::bind_t<void, void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> > >::operator()() ()
  #18 0x0000000000402dfb in boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> > >, void>::invoke(boost::detail::function::any_pointer) ()
  #19 0x00002b465e90fca7 in boost::function0<void, std::allocator<boost::function_base> >::operator()() const () from /usr/lib64/libboost_thread.so.2
  #20 0x00002b465e90f70f in ?? () from /usr/lib64/libboost_thread.so.2
  #21 0x00000034e6a0683d in start_thread () from /lib64/libpthread.so.0
  #22 0x00000034e62d503d in clone () from /lib64/libc.so.6
  
  Thread 4 (Thread 8222):
  #0  0x00000034e6a0b019 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
  #1  0x00002b465e6c577c in acquire (this=0x15be7200) at ../include/qpid/sys/posix/Condition.h:63
  #2  lock (this=0x15be7200) at qpid/sys/Semaphore.h:32
  #3  ScopedLock (this=0x15be7200) at ../include/qpid/sys/Mutex.h:33
  #4  qpid::client::amqp0_10::ConnectionImpl::open (this=0x15be7200) at qpid/client/amqp0_10/ConnectionImpl.cpp:247
  #5  0x00002b465e6c008c in qpid::client::amqp0_10::ConnectionImpl::reopen (this=0x15be725c) at qpid/client/amqp0_10/ConnectionImpl.cpp:260
  #6  0x00002b465e6d3655 in qpid::client::amqp0_10::SessionImpl::execute<qpid::client::amqp0_10::ReceiverImpl::Fetch> (this=0x15befe20, f=<value optimized out>)
      at qpid/client/amqp0_10/SessionImpl.h:102
  #7  0x00002b465e6d29ac in qpid::client::amqp0_10::ReceiverImpl::fetch (this=0x15bf1110, message=<value optimized out>, timeout=...) at qpid/client/amqp0_10/ReceiverImpl.cpp:71
  #8  0x00002b465e6a78ad in qpid::messaging::Receiver::fetch (this=<value optimized out>, message=..., timeout=...) at qpid/messaging/Receiver.cpp:38
  #9  0x000000000040213f in thread(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) ()
  #10 0x0000000000402d31 in void boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> >::operator()<void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list0>(boost::_bi::type<void>, void (*&)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list0&, int) ()
  #11 0x0000000000402ddc in boost::_bi::bind_t<void, void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> > >::operator()() ()
  #12 0x0000000000402dfb in boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, void (*)(qpid::messaging::Connection, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&), boost::_bi::list2<boost::_bi::value<qpid::messaging::Connection>, boost::_bi::value<char const*> > >, void>::invoke(boost::detail::function::any_pointer) ()
  #13 0x00002b465e90fca7 in boost::function0<void, std::allocator<boost::function_base> >::operator()() const () from /usr/lib64/libboost_thread.so.2
  #14 0x00002b465e90f70f in ?? () from /usr/lib64/libboost_thread.so.2
  #15 0x00000034e6a0683d in start_thread () from /lib64/libpthread.so.0
  #16 0x00000034e62d503d in clone () from /lib64/libc.so.6
  
  Thread 3 (Thread 8234):
  #0  0x00000034e62302c5 in raise () from /lib64/libc.so.6
  #1  0x00000034e6231d70 in abort () from /lib64/libc.so.6
  #2  0x00000034eaebed94 in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib64/libstdc++.so.6
  #3  0x00000034eaebce46 in ?? () from /usr/lib64/libstdc++.so.6
  #4  0x00000034eaebce73 in std::terminate() () from /usr/lib64/libstdc++.so.6
  #5  0x00000034eaebd3cf in __cxa_pure_virtual () from /usr/lib64/libstdc++.so.6
  #6  0x00002b465f13ff9a in boost::function2<void, qpid::sys::AsynchIO&, qpid::sys::Socket const&, std::allocator<boost::function_base> >::operator() (this=0x0, a0=..., a1=...)
      at /usr/include/boost/function/function_template.hpp:576
  #7  0x00002b465f23e7aa in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (this=0x0, a0=...)
      at /usr/include/boost/function/function_template.hpp:576
  #8  0x00002b465f23daa8 in qpid::sys::DispatchHandle::processEvent (this=0x2b4664002988, type=DISCONNECTED) at qpid/sys/DispatchHandle.cpp:291
  #9  0x00002b465f14b604 in process (this=0x15be7e40) at qpid/sys/Poller.h:131
  #10 qpid::sys::Poller::run (this=0x15be7e40) at qpid/sys/epoll/EpollPoller.cpp:524
  #11 0x00002b465f1425ba in qpid::sys::(anonymous namespace)::runRunnable (p=0x201a) at qpid/sys/posix/Thread.cpp:35
  #12 0x00000034e6a0683d in start_thread () from /lib64/libpthread.so.0
  #13 0x00000034e62d503d in clone () from /lib64/libc.so.6
  
  Thread 2 (Thread 8235):
  #0  0x00000034e62d5001 in clone () from /lib64/libc.so.6
  #1  0x00000034e6a06760 in ?? () from /lib64/libpthread.so.0
  #2  0x00002b4668a00940 in ?? ()
  #3  0x0000000000000000 in ?? ()
  
  Thread 1 (Thread 0x2b4660fbf940 (LWP 8220)):
  #0  0x00000034e626f534 in malloc_consolidate () from /lib64/libc.so.6
  #1  0x00000034e6271c7c in _int_malloc () from /lib64/libc.so.6
  #2  0x00000034e6273f6e in malloc () from /lib64/libc.so.6
  #3  0x00000034eaebd25d in operator new(unsigned long) () from /usr/lib64/libstdc++.so.6
  #4  0x00000034eae9b861 in std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) ()
    from /usr/lib64/libstdc++.so.6
  #5  0x00000034eae9c23b in std::basic_string<char, std::char_traits<char>, std::allocator<char> >::_Rep::_M_clone(std::allocator<char> const&, unsigned long) ()
    from /usr/lib64/libstdc++.so.6
  #6  0x00000034eae9cb45 in std::basic_string<char, std::char_traits<char>, std::allocator<char> >::reserve(unsigned long) () from /usr/lib64/libstdc++.so.6
  #7  0x00000034eae960c5 in std::basic_stringbuf<char, std::char_traits<char>, std::allocator<char> >::overflow(int) () from /usr/lib64/libstdc++.so.6
  #8  0x00000034eae9ad1d in std::basic_streambuf<char, std::char_traits<char> >::xsputn(char const*, long) () from /usr/lib64/libstdc++.so.6
  #9  0x00000034eae90311 in std::basic_ostream<char, std::char_traits<char> >& std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*) ()
    from /usr/lib64/libstdc++.so.6
  #10 0x00002b465edde2db in operator<< <char [17]> (this=0x2b4664043c20, msg="Connection refused") at ../include/qpid/Msg.h:63
  #11 qpid::client::TCPConnector::connectFailed (this=0x2b4664043c20, msg="Connection refused") at qpid/client/TCPConnector.cpp:135
  #12 0x00002b465f1402ca in boost::function3<void, qpid::sys::Socket const&, int, std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::allocator<boost::function_base> >::operator() (this=0x2b4664000078, a0=..., a1=1677724144, a2=Traceback (most recent call last):
    File "/usr/share/gdb/python/libstdcxx/v6/printers.py", line 467, in to_string
      header = ptr.cast(reptype) - 1
  RuntimeError: Cannot access memory at address 0x3ffffffffffffff9
  ) at /usr/include/boost/function/function_template.hpp:576
  #13 0x00002b465f139414 in qpid::sys::posix::AsynchConnector::connComplete (this=0x2b4664044060, h=...) at qpid/sys/posix/AsynchIO.cpp:229
  #14 0x00002b465f23e7aa in boost::function1<void, qpid::sys::DispatchHandle&, std::allocator<boost::function_base> >::operator() (this=0x2b4664000078, a0=...)
      at /usr/include/boost/function/function_template.hpp:576
  #15 0x00002b465f23daa8 in qpid::sys::DispatchHandle::processEvent (this=0x2b4664044068, type=DISCONNECTED) at qpid/sys/DispatchHandle.cpp:291
  #16 0x00002b465f14b604 in process (this=0x15be7e40) at qpid/sys/Poller.h:131
  #17 qpid::sys::Poller::run (this=0x15be7e40) at qpid/sys/epoll/EpollPoller.cpp:524
  #18 0x00002b465f1425ba in qpid::sys::(anonymous namespace)::runRunnable (p=0x2b4664000020) at qpid/sys/posix/Thread.cpp:35
  #19 0x00000034e6a0683d in start_thread () from /lib64/libpthread.so.0
  #20 0x00000034e62d503d in clone () from /lib64/libc.so.6

This behavior is detected on RHEL-5.9-Server-RC-2.1 i386/x86_64. In total 4 attempts = 4 cre files (1x for i386, 3x for x86_64).

It looks the problem is not in qpid lib, but in glibc/libstdc++.
I'd like someone to double-check that and if that is the case move to RHEL side.


Version-Release number of selected component (if applicable):
compat-libgcc-296-2.96-138
gcc-4.1.2-54.el5
gcc-c++-4.1.2-54.el5
glibc-2.5-107
glibc-2.5-107
glibc-common-2.5-107
glibc-devel-2.5-107
glibc-headers-2.5-107
libgcc-4.1.2-54.el5
libgcc-4.1.2-54.el5
python-qpid-0.18-4.el5
python-qpid-qmf-0.18-9.el5
qpid-cpp-client-0.18-10.el5
qpid-cpp-client-devel-0.18-10.el5
qpid-cpp-client-devel-docs-0.18-10.el5
qpid-cpp-client-rdma-0.18-10.el5
qpid-cpp-client-ssl-0.18-10.el5
qpid-cpp-mrg-debuginfo-0.18-10.el5
qpid-cpp-server-0.18-10.el5
qpid-cpp-server-cluster-0.18-10.el5
qpid-cpp-server-devel-0.18-10.el5
qpid-cpp-server-rdma-0.18-10.el5
qpid-cpp-server-ssl-0.18-10.el5
qpid-cpp-server-store-0.18-10.el5
qpid-cpp-server-xml-0.18-10.el5
qpid-java-client-0.18-5.el5
qpid-java-common-0.18-5.el5
qpid-java-example-0.18-5.el5
qpid-jca-0.18-5.el5
qpid-jca-xarecovery-0.18-5.el5
qpid-jca-zip-0.18-5.el5
qpid-qmf-0.18-9.el5
qpid-qmf-debuginfo-0.18-9.el5
qpid-qmf-devel-0.18-9.el5
qpid-tests-0.18-2.el5
qpid-tools-0.18-7.el5
rh-qpid-cpp-tests-0.18-10.el5
ruby-qpid-qmf-0.18-9.el5

How reproducible:
hard, 2%

Steps to Reproduce:
Follow steps bug 804752 comment 13.
Running
  ulimit -c unlimited
  ./bz804752 100
  
Actual results:
Client crashing.

Expected results:
Client not crashing.

Additional info:

Comment 1 Frantisek Reznicek 2012-12-04 16:59:17 UTC
Created attachment 657645 [details]
Crash dumps

Comment 2 Justin Ross 2012-12-04 19:46:21 UTC
Andrew, can you rule up or down on whether this is a qpid defect?

Comment 3 Andrew Stitcher 2012-12-06 16:46:20 UTC
I think the relevant thread is actually thread 3. That seems to be the place that is asserting.

I think that the stacktrace including malloc_consolidate() is ared herring.

the real problem seems to be calling a pure virtual.

Comment 4 Justin Ross 2012-12-06 20:08:27 UTC
This is indeed a qpid bug, a low frequency crasher.  I'm moving this out to 2.4.  We can bring it back to 2.3 if new information raises its frequency or new resources become available to fix it.

Comment 5 Andrew Stitcher 2013-04-25 15:59:39 UTC
*** Bug 767344 has been marked as a duplicate of this bug. ***

Comment 6 Andrew Stitcher 2013-04-25 16:09:43 UTC
So far I've failed to reproduce this bug.

In principle the cause of this bug is likely to be that the object being called is in the process of being deleted on a different thread whilst being called on this one.

This would be a violation of the basic operating principle for a connection in that everything operating on a single connection is serialised.

Comment 7 Andrew Stitcher 2013-04-29 15:19:03 UTC
*** Bug 795352 has been marked as a duplicate of this bug. ***

Comment 8 Justin Ross 2013-04-29 18:47:39 UTC
Andrew has been unable to reproduce the crash.

-> CLOSED WORKSFORME

Comment 9 Andrew Stitcher 2013-05-02 20:29:37 UTC
*** Bug 672388 has been marked as a duplicate of this bug. ***