Ceph » rgw

Recently, we encountered an deadlock in librgw

the backtrace is as follows

#0 0x00002abda963054d in _lll_lock_wait () from /lib64/libpthread.so.0
#1 0x00002abda962be9b in _L_lock_883 () from /lib64/libpthread.so.0
#2 0x00002abda962bd68 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3 0x000000000041b5b8 in __gthread_mutex_lock (_mutex=0x2e89aa8) at /opt/rh/devtoolset-8/root/usr/include/c++/8/x86_64-redhat-linux/bits/gthr-default.h:748
#4 0x000000000041c7ca in std::mutex::lock (this=0x2e89aa8) at /opt/rh/devtoolset-8/root/usr/include/c++/8/bits/std_mutex.h:103
#5 0x00002abda9ea9368 in cohort::lru::TreeX<rgw::RGWFileHandle, boost::intrusive::rbtree<rgw::RGWFileHandle, boost::intrusive::compare<rgw::RGWFileHandle::FhLT>, boost::intrusive::member_hook<rgw::RGWFileHandle, boost::intrusive::set_member_hook<boost::intrusive::link_mode<(boost::intrusive::link_mode_type)1> >, &rgw::RGWFileHandle::fh_hook> >, rgw::RGWFileHandle::FhLT, rgw::RGWFileHandle::FhEQ, rgw::fh_key, std::mutex>::remove (this=0x304d940, hk=480853490109323950, v=0x42c5600, flags=<optimized out>)
at /opt/rh/devtoolset-8/root/usr/include/c++/8/x86_64-redhat-linux/bits/gthr-default.h:778
#6 0x00002abda9e87f4b in rgw::RGWFileHandle::~RGWFileHandle (this=0x42c5600, __in_chrg=<optimized out>) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:1149
#7 0x00002abda9e88009 in rgw::RGWFileHandle::~RGWFileHandle (this=0x42c5600, __in_chrg=<optimized out>) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:1145
#8 0x00002abda9e87fea in rgw::RGWLibFS::unref (fh=<optimized out>, this=<optimized out>) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.h:1164
#9 rgw::RGWFileHandle::~RGWFileHandle (this=0x6dfbc00, __in_chrg=<optimized out>) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:1160
#10 0x00002abda9eac62f in rgw::RGWFileHandle::Factory::recycle (o=0x6dfbc00, this=<synthetic pointer>) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.h:797
#11 cohort::lru::LRU<std::mutex>::insert (flags=<synthetic pointer>: <optimized out>, edge=cohort::lru::Edge::MRU, fac=<synthetic pointer>, this=0x304d968) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/common/cohort_lru.h:241
#12 rgw::RGWLibFS::lookup_fh (this=this@entry=0x304d700, parent=parent@entry=0x2ff6c00, name=name@entry=0x930c268 "26747372849751816", flags=flags@entry=4) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.h:1123
#13 0x00002abda9e89b4d in rgw::RGWLibFS::stat_leaf (this=0x304d700, parent=0x2ff6c00, path=0x930c268 "26747372849751816", type=RGW_FS_TYPE_NIL, flags=2048) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:178
#14 0x00002abda9e8d568 in rgw_lookup (rgw_fs=<optimized out>, parent_fh=<optimized out>, path=<optimized out>, fh=0x2abdeb8b4718, st=<optimized out>, mask=<optimized out>, flags=12) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:2037
#15 0x0000000000413524 in generic_lookup (parent_fh=0x2ff6c30, name=0x930c268 "26747372849751816", e=0x2abdeb8b4800, vfs_lookup=false) at librgw_fs_ll.cc:35
#16 0x0000000000418803 in rgwfs_readdir_cb (name=0x930c268 "26747372849751816", arg=0xe399c70, offset=13938821575985575922, st=0x2abdeb8b4a70, mask=120, flags=8) at librgw_fs_ll.cc:483
#17 0x00002abda9eab225 in rgw::RGWReaddirRequest::operator() (type=1 '\001', fsz=127815217, t=..., marker=..., name=..., this=0x2abdeb8b5730) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.h:1548
#18 rgw::RGWReaddirRequest::send_response (this=0x2abdeb8b5730) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.h:1587
#19 0x00002abda9e7742d in rgw::RGWLibProcess::process_request (this=0x2089b00, req=0x2abdeb8b5730, io=0x2abdeb8b5430) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/librgw.cc:322
#20 0x00002abda9e77ea5 in rgw::RGWLibProcess::process_request (this=0x2089b00, req=req@entry=0x2abdeb8b5730) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/librgw.cc:170
#21 0x00002abda9e8b90d in rgw::RGWLibFrontend::execute_req (this=<optimized out>, req=0x2abdeb8b5730) at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_lib_frontend.h:98
#22 rgw::RGWFileHandle::readdir (this=0x2ff6c00, rcb=0x4182d6 <rgwfs_readdir_cb(char const*, void*, unsigned long, stat*, unsigned int, unsigned int)>, cb_arg=0xe399c70, offset=..., eof=0x2abdeb8b5b5f, flags=<optimized out>)
at /usr/src/debug/ceph-14.2.9-796-gf3f3cdfe87/src/rgw/rgw_file.cc:1291
#23 0x00002abda9e91328 in rgw_readdir2 (rgw_fs=<optimized out>, parent_fh=<optimized out>, name=0x198ec000 "26747372849611767", rcb=0x4182d6 <rgwfs_readdir_cb(char const*, void*, unsigned long, stat*, unsigned int, unsigned int)>, cb_arg=0xe399c70,
eof=0x2abdeb8b5b5f, flags=1) at /opt/rh/devtoolset-8/root/usr/include/c++/8/new:169
#24 0x0000000000418e41 in rgwfuse_ll_readdir (req=0x1d60f680, ino=12840767141037193770, size=4096, off=-1843404761571147083, fi=0x2abdeb8b5bb0) at librgw_fs_ll.cc:523
#25 0x00002abda93fbebd in do_readdir (req=<optimized out>, nodeid=<optimized out>, inarg=<optimized out>) at ../lib/fuse_lowlevel.c:1499
#26 0x00002abda93fdec0 in fuse_session_process_buf_int (se=0x209e000, buf=0xcd394c0, ch=<optimized out>) at ../lib/fuse_lowlevel.c:2660
#27 0x00002abda93f9f01 in fuse_do_work (data=0xcd394a0) at ../lib/fuse_loop_mt.c:163
#28 0x00002abda9629ea5 in start_thread () from /lib64/libpthread.so.0
#29 0x00002abdab6c18dd in clone () from /lib64/libc.so.6

It seems that the root cause is:

the lookup_fh method tried to find an existing fh for the target file, during which it acquired the lock of the partition which would hold the fh for that file;
when the lookup fails, it tries to insert a new fh, during which a recycle happened;
the object to be recycled happens to be in the same partition, and the remove of that object tries to acquire the lock of that same partition, as fh_cache's mutex is not a recursive one, the deadlock came up.