[QPID-2481] Deadlock in Qpid 0.6

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 0.6
• Fix Version/s: 0.7
• Component/s: C++ Broker

Environment

64 bit; gcc (Debian 4.3.2-1.1) 4.3.2; Linux search-eu002a 2.6.32.8-CORE2_64 #1 SMP Wed Feb 10 15:49:58 CET 2010 x86_64 GNU/Linux; cpp-qpid 0.6

• Assignee: Ted Ross
• Reporter: Daniel Etzold
• Created: 06/Apr/10 11:11
• Updated: 29/Jul/13 18:52
• Resolved: 30/Aug/10 19:06

Description

Hi,

I think I've found a deadlock while running the cpp broker 0.6. Since strace does not report any activity in the borker I attached with the gdb. Here's the gdb output:

Listing of threads:

(gdb) info thr
10 Thread 0x417f9950 (LWP 5061) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
9 Thread 0x41ffa950 (LWP 5062) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
8 Thread 0x427fb950 (LWP 5063) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
7 Thread 0x42ffc950 (LWP 5064) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
6 Thread 0x437fd950 (LWP 5065) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
5 Thread 0x40e3c950 (LWP 5066) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0

• 4 Thread 0x43ffe950 (LWP 5067) 0x00007f3655944176 in pthread_rwlock_rdlock () from /lib/libpthread.so.0
  3 Thread 0x447ff950 (LWP 5068) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
  2 Thread 0x45000950 (LWP 5069) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
  1 Thread 0x7f3657f21770 (LWP 5060) 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0

When switching to thread 4 and examining the mutex I found that the mutex's owner is thread 6 (__writer = 5065).

(gdb) thr 4
[Switching to thread 4 (Thread 0x43ffe950 (LWP 5067))]#0 0x00007f3655944176 in pthread_rwlock_rdlock () from /lib/libpthread.so.0
(gdb) bt
#0 0x00007f3655944176 in pthread_rwlock_rdlock () from /lib/libpthread.so.0
#1 0x00007f3657981b80 in qpid::sys::RWlock::rlock (this=0x178bcf8) at ../include/qpid/sys/posix/Mutex.h:141
#2 0x00007f3657981e2d in ScopedRlock (this=0x43fec700, l=@0x178bcf8) at ../include/qpid/sys/Mutex.h:53
#3 0x00007f3657a3f52c in qpid::broker::TopicExchange::route (this=0x178bcc0, msg=@0x43fec850, routingKey=@0x43fecb40) at qpid/broker/TopicExchange.cpp:300
#4 0x00007f3657a6a5ee in qpid::broker::ManagementExchange::route (this=0x178bcb0, msg=@0x43fec850, routingKey=@0x43fecb40, args=0x0)
at qpid/management/ManagementExchange.cpp:52
#5 0x00007f3657a4e635 in qpid::management::ManagementAgent::sendBuffer (this=0x7f3657ef0010, buf=@0x43fecad0, length=138, exchange=
{px = 0x43fecb10, pn = {pi_ = 0x8a43fec870}}, routingKey=
{static npos = 18446744073709551615, _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> =

{<No data fields>}, <No data fields>}, _M _p = 0x43fecb40 "¨Ü016\025\v6\177"}}) at qpid/management/ManagementAgent.cpp:317
#6 0x00007f3657a58c55 in qpid::management::ManagementAgent::addObject (this=0x7f3657ef0010, object=0x7f35be205680, persistId=0, publishNow=true)
at qpid/management/ManagementAgent.cpp:207
#7 0x00007f365793fc42 in Connection (this=0x7f35be242900, out_=0x7f35be23b228, broker_=@0x17816a0, mgmtId_=@0x7f364c59b0e8, ssf=0, isLink_=false, objectId=0)
at qpid/broker/Connection.cpp:101
#8 0x00007f36579fb1bc in qpid::broker::SecureConnectionFactory::create (this=0x1787ef0, v={major_ = 0 '\0', minor_ = 10 '\n'}, out=@0x7f364c59b0e0,
id=@0x7f364c59b0e8, conn_ssf=0) at qpid/broker/SecureConnectionFactory.cpp:50
#9 0x00007f365741eabe in qpid::sys::AsynchIOHandler::readbuff (this=0x7f364c59b0e0, buff=0x7f363996fbb0) at qpid/sys/AsynchIOHandler.cpp:147
#10 0x00007f3657a6d74f in boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::operator() (
this=0x7f35be2447a0, p=0x7f364c59b0e0, a1=@0x7f35be244640, a2=0x7f363996fbb0) at /usr/include/boost/bind/mem_fn_template.hpp:274
#11 0x00007f3657a6ebdb in boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> >::operator()<boost::_mfi::mf2<void, qpid ::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list2<qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*&> > (
this=0x7f35be2447b0, f=@0x7f35be2447a0, a=@0x43ffd850) at /usr/include/boost/bind.hpp:371
#12 0x00007f3657a6ec4f in boost::_bi::bind_t<void, boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost ::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >::operator()<qpid::sys::AsynchIO, qpid::sys::AsynchIOBufferBase*> (
this=0x7f35be2447a0, a1=@0x7f35be244640, a2=@0x43ffd888) at /usr/include/boost/bind/bind_template.hpp:61
#13 0x00007f3657a6eca1 in boost::detail::function::void_function_obj_invoker2<boost::_bi::bind_t<void, boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sy s::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, void, qpid::sys ::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=@0x7f35be2447a0, a0=@0x7f35be244640, a1=0x7f363996fbb0)
at /usr/include/boost/function/function_template.hpp:152
#14 0x00007f36572ce1f9 in boost::function2<void, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::operator() (this=0x7f35be244798, a0=@0x7f35be244640,
a1=0x7f363996fbb0) at /usr/include/boost/function/function_template.hpp:989
#15 0x00007f36572c3c56 in qpid::sys::posix::AsynchIO::readable (this=0x7f35be244640, h=@0x7f35be244648) at qpid/sys/posix/AsynchIO.cpp:435
#16 0x00007f36572cbc87 in boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>::operator() (this=0x7f35be244660, p=0x7f35be244640,
a1=@0x7f35be244648) at /usr/include/boost/bind/mem_fn_template.hpp:162
#17 0x00007f36572cc7c5 in boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> >::operator()<boost::_mfi::mf1<void, qpid::sys::posix::A synchIO, qpid::sys::DispatchHandle&>, boost::_bi::list1<qpid::sys::DispatchHandle&> > (this=0x7f35be244670, f=@0x7f35be244660, a=@0x43ffdc40)
at /usr/include/boost/bind.hpp:292
#18 0x00007f36572cc82f in boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::v alue<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >::operator()<qpid::sys::DispatchHandle> (this=0x7f35be244660, a1=@0x7f35be244648)
at /usr/include/boost/bind/bind_template.hpp:32
#19 0x00007f36572cc879 in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sy s::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (
function_obj_ptr=@0x7f35be244660, a0=@0x7f35be244648) at /usr/include/boost/function/function_template.hpp:152
#20 0x00007f36574288a3 in boost::function1<void, qpid::sys::DispatchHandle&>::operator() (this=0x7f35be244658, a0=@0x7f35be244648)
at /usr/include/boost/function/function_template.hpp:989
#21 0x00007f3657420afb in qpid::sys::DispatchHandle::processEvent (this=0x7f35be244648, type=qpid::sys::Poller::READABLE) at qpid/sys/DispatchHandle.cpp:278
#22 0x00007f36572dccf2 in qpid::sys::Poller::Event::process (this=0x43ffde20) at ./qpid/sys/Poller.h:123
#23 0x00007f36572dc23b in qpid::sys::Poller::run (this=0x17809d0) at qpid/sys/epoll/EpollPoller.cpp:483
#24 0x00007f36574288f7 in qpid::sys::Dispatcher::run (this=0x7fffcd3894b0) at qpid/sys/Dispatcher.cpp:37
#25 0x00007f36572d2743 in runRunnable (p=0x7fffcd3894b0) at qpid/sys/posix/Thread.cpp:35
#26 0x00007f3655940fc7 in start_thread () from /lib/libpthread.so.0
#27 0x00007f3655c255ad in clone () from /lib/libc.so.6
#28 0x0000000000000000 in ?? ()
(gdb) frame 1
#1 0x00007f3657981b80 in qpid::sys::RWlock::rlock (this=0x178bcf8) at ../include/qpid/sys/posix/Mutex.h:141
141 ../include/qpid/sys/posix/Mutex.h: No such file or directory.
in ../include/qpid/sys/posix/Mutex.h
(gdb) p *this
$12 = {<boost::noncopyable_::noncopyable> = {<No data fields>}

, rwlock = {_data = {_lock = 0, __nr_readers = 0, __readers_wakeup = 1, __writer_wakeup = 0,
__nr_readers_queued = 1, __nr_writers_queued = 0, __writer = 5065, __shared = 0, __pad1 = 0, __pad2 = 0, __flags = 0},
__size = "\000\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000ÉÜ023", '\0' <repeats 26 times>, "6\177\000",
__align = 0}}

Switching to thread 6 we can see that the mutex owner is thread 4 (__owner = 5067).

(gdb) thr 6
[Switching to thread 6 (Thread 0x437fd950 (LWP 5065))]#0 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
(gdb) bt
#0 0x00007f3655947384 in __lll_lock_wait () from /lib/libpthread.so.0
#1 0x00007f3655942c0b in _L_lock_312 () from /lib/libpthread.so.0
#2 0x00007f3655942631 in pthread_mutex_lock () from /lib/libpthread.so.0
#3 0x00007f36578bcc76 in qpid::sys::Mutex::lock (this=0x7f3657ef00f0) at ../include/qpid/sys/posix/Mutex.h:116
#4 0x00007f36578bcf23 in ScopedLock (this=0x437fa590, l=@0x7f3657ef00f0) at ../include/qpid/sys/Mutex.h:33
#5 0x00007f3657a4cac2 in qpid::management::ManagementAgent::allocateId (this=0x7f3657ef0010, object=0x7f35b1c13c10) at qpid/management/ManagementAgent.cpp:1288
#6 0x00007f3657975542 in Binding (this=0x7f35b1c13c10, key=@0x437fa820, _queue={px = 0x437fa780, pn = {pi = 0x437fa820}}, parent=0x178bd30, _args=
{values = {_M_t = {_M_impl = {<std::allocator<std::Rb_tree_node<std::pair<const std::basic_string<char, std::char_traits<char>, std::allocator<char> >, boost::shared_ptr<qpid::framing::FieldValue> > > >> = {<_gnu_cxx::new_allocator<std::_Rb_tree_node<std::pair<const std::basic_string<char, std::char_traits<ch ar>, std::allocator<char> >, boost::shared_ptr<qpid::framing::FieldValue> > > >> =

{<No data fields>}, <No data fields>}, _M_key_compare = {<std::binary_function< std::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::basic_string<char, std::char_traits<char>, std::allocator<char> >, bool>> = {<No data fields>}, <No data fields>}, _M_header = {_M_color = 24689968, _M_parent = 0x437fa780, _M_left = 0x437fa820, _M_right = 0x7f35b1c13c10}, _M_node_count = 0}}}},
origin=@0x437fa830) at qpid/broker/Exchange.cpp:328
#7 0x00007f3657a402f6 in qpid::broker::TopicExchange::bind (this=0x178bcc0, queue={px = 0x437fa8c0, pn = {pi_ = 0x178bcc0}}, routingKey=@0x437faa20,
args=0x7f35b1c0e888) at qpid/broker/TopicExchange.cpp:209
#8 0x00007f3657a6a45f in qpid::broker::ManagementExchange::bind (this=0x178bcb0, queue={px = 0x437faa50, pn = {pi_ = 0x178bcb0}}, routingKey=@0x437faa20,
args=0x7f35b1c0e888) at qpid/management/ManagementExchange.cpp:60
#9 0x00007f3657a1dc9b in qpid::broker::SessionAdapter::ExchangeHandlerImpl::bind (this=0x7f35b1c0b800, queueName=@0x7f35b1c0e870, exchangeName=@0x7f35b1c0e878,
routingKey=@0x7f35b1c0e880, arguments=@0x7f35b1c0e888) at qpid/broker/SessionAdapter.cpp:189
#10 0x00007f36573206c8 in qpid::framing::ExchangeBindBody::invoke<qpid::framing::AMQP_ServerOperations::ExchangeHandler> (this=0x7f35b1c0e860,
invocable=@0x7f35b1c0b800) at ./qpid/framing/ExchangeBindBody.h:88
#11 0x00007f3657319316 in qpid::framing::AMQP_ServerOperations::ExchangeHandler::Invoker::visit (this=0x437fada0, body=@0x7f35b1c0e860)
at qpid/framing/ServerInvoker.cpp:642
#12 0x00007f3657328121 in qpid::framing::ExchangeBindBody::accept (this=0x7f35b1c0e860, v=@0x437fada0) at ./qpid/framing/ExchangeBindBody.h:92
#13 0x00007f365731b3b8 in qpid::framing::AMQP_ServerOperations::Invoker::visit (this=0x437fae50, body=@0x7f35b1c0e860) at qpid/framing/ServerInvoker.cpp:353
#14 0x00007f3657328121 in qpid::framing::ExchangeBindBody::accept (this=0x7f35b1c0e860, v=@0x437fae50) at ./qpid/framing/ExchangeBindBody.h:92
#15 0x00007f3657a3c975 in qpid::framing::invoke<qpid::broker::SessionAdapter> (target=@0x7f35b1c0b7e8, body=@0x7f35b1c0e860) at ./qpid/framing/Invoker.h:67
#16 0x00007f3657a35e43 in qpid::broker::SessionState::handleCommand (this=0x7f35b1c0b4b0, method=0x7f35b1c0e860, id=@0x437fb100)
at qpid/broker/SessionState.cpp:197
#17 0x00007f3657a362b8 in qpid::broker::SessionState::handleIn (this=0x7f35b1c0b4b0, frame=@0x437fbce0) at qpid/broker/SessionState.cpp:329
#18 0x00007f3657a3af3b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(q pid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x7f35b1c0b640, t=@0x437fbce0)
at ./qpid/framing/Handler.h:67
#19 0x00007f36573d59da in qpid::amqp_0_10::SessionHandler::handleIn (this=0x7f35b1c0c770, f=@0x437fbce0) at qpid/amqp_0_10/SessionHandler.cpp:93
#20 0x00007f3657a3af3b in qpid::framing::Handler<qpid::framing::AMQFrame&>::MemFunRef<qpid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface, &(q pid::framing::Handler<qpid::framing::AMQFrame&>::InOutHandlerInterface::handleIn(qpid::framing::AMQFrame&))>::handle (this=0x7f35b1c0c780, t=@0x437fbce0)
at ./qpid/framing/Handler.h:67
#21 0x00007f365794110b in qpid::framing::Handler<qpid::framing::AMQFrame&>::operator() (this=0x7f35b1c0c780, t=@0x437fbce0) at ./qpid/framing/Handler.h:42
#22 0x00007f365794dec1 in qpid::broker::ConnectionHandler::handle (this=0x7f35b1c10120, frame=@0x437fbce0) at qpid/broker/ConnectionHandler.cpp:70
#23 0x00007f365793e4e8 in qpid::broker::Connection::received (this=0x7f35b1c0ff40, frame=@0x437fbce0) at qpid/broker/Connection.cpp:138
#24 0x00007f36578ffb36 in qpid::amqp_0_10::Connection::decode (this=0x7f35b1c602b0, buffer=0x7f35be3822c0 "\017\001", size=71)
at qpid/amqp_0_10/Connection.cpp:58
#25 0x00007f36579f9fff in qpid::broker::SecureConnection::decode (this=0x7f35b1a42fe0, buffer=0x7f35be3822c0 "\017\001", size=71)
at qpid/broker/SecureConnection.cpp:42
#26 0x00007f365741e59d in qpid::sys::AsynchIOHandler::readbuff (this=0x7f35be206e80, buff=0x7f35be0fe6b0) at qpid/sys/AsynchIOHandler.cpp:134
#27 0x00007f3657a6d74f in boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::operator() (
this=0x7f35be209090, p=0x7f35be206e80, a1=@0x7f35be208f30, a2=0x7f35be0fe6b0) at /usr/include/boost/bind/mem_fn_template.hpp:274
#28 0x00007f3657a6ebdb in boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> >::operator()<boost::_mfi::mf2<void, qpid ::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list2<qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*&> > (
this=0x7f35be2090a0, f=@0x7f35be209090, a=@0x437fc850) at /usr/include/boost/bind.hpp:371
#29 0x00007f3657a6ec4f in boost::_bi::bind_t<void, boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost ::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >::operator()<qpid::sys::AsynchIO, qpid::sys::AsynchIOBufferBase*> (
this=0x7f35be209090, a1=@0x7f35be208f30, a2=@0x437fc888) at /usr/include/boost/bind/bind_template.hpp:61
#30 0x00007f3657a6eca1 in boost::detail::function::void_function_obj_invoker2<boost::_bi::bind_t<void, boost::_mfi::mf2<void, qpid::sys::AsynchIOHandler, qpid::sy s::AsynchIO&, qpid::sys::AsynchIOBufferBase*>, boost::_bi::list3<boost::_bi::value<qpid::sys::AsynchIOHandler*>, boost::arg<1>, boost::arg<2> > >, void, qpid::sys ::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::invoke (function_obj_ptr=@0x7f35be209090, a0=@0x7f35be208f30, a1=0x7f35be0fe6b0)
at /usr/include/boost/function/function_template.hpp:152
#31 0x00007f36572ce1f9 in boost::function2<void, qpid::sys::AsynchIO&, qpid::sys::AsynchIOBufferBase*>::operator() (this=0x7f35be209088, a0=@0x7f35be208f30,
a1=0x7f35be0fe6b0) at /usr/include/boost/function/function_template.hpp:989
#32 0x00007f36572c3c56 in qpid::sys::posix::AsynchIO::readable (this=0x7f35be208f30, h=@0x7f35be208f38) at qpid/sys/posix/AsynchIO.cpp:435
#33 0x00007f36572cbc87 in boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>::operator() (this=0x7f35be208f50, p=0x7f35be208f30,
a1=@0x7f35be208f38) at /usr/include/boost/bind/mem_fn_template.hpp:162
#34 0x00007f36572cc7c5 in boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> >::operator()<boost::_mfi::mf1<void, qpid::sys::posix::A synchIO, qpid::sys::DispatchHandle&>, boost::_bi::list1<qpid::sys::DispatchHandle&> > (this=0x7f35be208f60, f=@0x7f35be208f50, a=@0x437fcc40)
at /usr/include/boost/bind.hpp:292
#35 0x00007f36572cc82f in boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sys::DispatchHandle&>, boost::_bi::list2<boost::_bi::v alue<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >::operator()<qpid::sys::DispatchHandle> (this=0x7f35be208f50, a1=@0x7f35be208f38)
at /usr/include/boost/bind/bind_template.hpp:32
#36 0x00007f36572cc879 in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf1<void, qpid::sys::posix::AsynchIO, qpid::sy s::DispatchHandle&>, boost::_bi::list2<boost::_bi::value<qpid::sys::posix::AsynchIO*>, boost::arg<1> > >, void, qpid::sys::DispatchHandle&>::invoke (
--Type <return> to continue, or q <return> to quit--q
function_obj_Quit
(gdb) frame 3
#3 0x00007f36578bcc76 in qpid::sys::Mutex::lock (this=0x7f3657ef00f0) at ../include/qpid/sys/posix/Mutex.h:116
116 ../include/qpid/sys/posix/Mutex.h: No such file or directory.
in ../include/qpid/sys/posix/Mutex.h
(gdb) p *this
$13 = {<boost::noncopyable_::noncopyable> = {<No data fields>}

, mutex = {_data = {_lock = 2, __count = 1, __owner = 5067, __nusers = 1, __kind = 1,
_spins = 0, __list = {_prev = 0x0, __next = 0x0}},
__size = "\002\000\000\000\001\000\000\000ËÜ023\000\000\001\000\000\000\001", '\0' <repeats 22 times>, __align = 4294967298}}

Let's summarize:

[5067] thread 4 tries a readlock on the mutex (which is already (write)locked by thread 6)
[5065] thread 6 tries a lock on the mutex (which is already owned/locked by thread 4)

I experience such things quiet often.

Regards,
Daniel