Project

General

Profile

Bug #50467

Reproducible crash in radosgw (nautilus and later)

Added by Jan Harkes 25 days ago. Updated 3 days ago.

Status:
Pending Backport
Priority:
Normal
Assignee:
Target version:
-
% Done:

0%


Description

Reproducible on my end at least... Whenever I try to update my radosgw daemons from mimic to nautilus,
they predictably fail on one of the first requests they handle. The backtrace in the crash report wasn't
terribly useful (attached as rgw.crash). Even with increased logging there really was nothing obvious
(attached as rgw.log)

I've sort of ignore the problem because mimic release was still working fine and I figured it was such a
reproducible bug, you guys would probably find and fix it. But it has been a while and even the latest
release still crashes, so I grabbed the debug symbols and ran radosgw under gdb to get some better info.

In gdb, I find that the actual problem appears to be the following

tcmalloc: large alloc 93825032937472 bytes == (nil) @  0x7ffff7b961e7 0x7fffeea67815 0x7fffeeae5497 0x555555a3704f
0x555555c5f823 0x555555c8933c 0x555555c895b9 0x555555c08d4c 0x555555930210 0x555555933278 0x55555587b4c7
0x55555587c9d9 0x555555e563ef

# my attempt at getting a backtrace follows...
(gdb) info symbol 0x7ffff7b961e7                                                                                                           
tc_malloc + 455 in section google_malloc of /usr/lib/x86_64-linux-gnu/libtcmalloc.so.4                                                     
(gdb) info symbol 0x7fffeea67815                                                                                                           
operator new(unsigned long) + 21 in section .text of /usr/lib/ceph/libceph-common.so.0                                                     
(gdb) info symbol 0x7fffeeae5497                                                                                                           
std::__cxx11::basic_string<char, std::char_traits<char>,
  std::allocator<char> >::_M_assign(std::__cxx11::basic_string<char,
  std::char_traits<char>, std::allocator<char> > const&) + 167 in section .text of /usr/lib/ceph/libceph-common.so.0                                         
(gdb) info symbol 0x555555a3704f                                                                                                           
RGWObjManifest::obj_iterator::update_location() + 431 in section .text of /usr/bin/radosgw                                                 
(gdb) info symbol 0x555555c5f823
RGWObjManifest::obj_iterator::operator++() + 307 in section .text of /usr/bin/radosgw                                                      
(gdb) info symbol 0x555555c8933c
RGWRados::iterate_obj(RGWObjectCtx&, RGWBucketInfo const&, rgw_obj const&, long, long,
  unsigned long, int (*)(rgw_raw_obj const&, long, long, long, bool, RGWObjState*, void*), void*) + 2412 in section .text of /usr/bin/radosgw                                                     
(gdb) info symbol 0x555555c895b9
RGWRados::Object::Read::iterate(long, long, RGWGetDataCB*) + 393 in section .text of /usr/bin/radosgw                                      
(gdb) info symbol 0x555555c08d4c
RGWGetObj::execute() + 3132 in section .text of /usr/bin/radosgw

Because tc_malloc doesn't have debug symbols and it is called from many places, I haven't been able to
get a good conditional breakpoint, so a lot of the following stack dumps are taken while single stepping
trying to find which code is called before we fail, but may not always be a failure.

So it turns out my daemons reliably crash while fetching a 12 byte testfile that I pull periodically with
Nagios to check if the servers are working. And when I step through I find that we crash the second time
we hit src/rgw/rgw\_rados.cc:7050

  if (astate->has_manifest) {
    /* now get the relevant object stripe */
    RGWObjManifest::obj_iterator iter = astate->manifest.obj_find(ofs);

    RGWObjManifest::obj_iterator obj_end = astate->manifest.obj_end();

>>> for (; iter != obj_end && ofs <= end; ++iter) {
      off_t stripe_ofs = iter.get_stripe_ofs();
      off_t next_stripe_ofs = stripe_ofs + iter.get_stripe_size();

      while (ofs < next_stripe_ofs && ofs <= end) {
        read_obj = iter.get_location().get_raw_obj(this);
        uint64_t read_len = std::min(len, iter.get_stripe_size() - (ofs - stripe_ofs));
        read_ofs = iter.location_ofs() + (ofs - stripe_ofs);

Both times iter and obj_end are the same (content-wise, pointers are different). At the second
iteration ofs is 12 and end is 11. However we never actually get to test that condition as
\++iter is called first and we end up in RGWObjManifest::obj\_iterator::operator++().

Here manifest->explicit_obj is true, and as we enter the function explicit_iter is

$2 = {first = 0, second = {loc = {bucket = {tenant = "", name = "test", marker = "default.1021717.1",
bucket_id = "default.1021717.1", explicit_placement = {data_pool = {name = ".rgw.buckets", ns = ""},
data_extra_pool = {name = "", ns = ""}, index_pool = {name = ".rgw.buckets.index", ns = ""}},
oid = ".bucket.meta.test:default.1021717.1"}, key = {name = "testfile", instance = "", ns = ""},
in_extra_data = false, index_hash_source = ""}, loc_ofs = 0, size = 12}}

Then ++explicit_iter is called and explicit_iter becomes

$3 = {first = 1, second = {loc = {bucket = {tenant = <error: Cannot access memory at address 0xc>,
name = <error reading variable: Cannot create a lazy string with address 0x0, and a non-zero length.>,
marker = <error reading variable: Cannot create a lazy string with address 0x0, and a non-zero length.>,
bucket_id = <error reading variable: Cannot create a lazy string with address 0x0, and a non-zero length.>,
explicit_placement = {data_pool = {name = <error reading variable: Cannot create a lazy string with address 0x0,
and a non-zero length.>, ns = <error: Cannot access memory at address 0x7374656b>},
data_extra_pool = {name = <error reading variable: Cannot create a lazy string with address 0x0,
and a non-zero length.>, ns = <error reading variable: Cannot create a lazy string with address 0x0,
and a non-zero length.>}, index_pool = {name = <error reading variable: Cannot create a lazy string with
address 0x0, and a non-zero length.>, ns = <error reading variable: Cannot create a lazy string with
address 0x0, and a non-zero length.>}}, oid = <error reading variable: Cannot create a lazy string with
address 0x0, and a non-zero length.>}, key = {name = <error reading variable: Cannot create a lazy string
with address 0x0, and a non-zero length.>, instance = <error reading variable: Cannot create a lazy string
with address 0x0, and a non-zero length.>, ns = <error reading variable: Cannot create a lazy string with
address 0x0, and a non-zero length.>}, in_extra_data = false, index_hash_source = <error reading variable:
Cannot create a lazy string with address 0x0, and a non-zero length.>}, loc_ofs = 0, size = 12}}

And we end up crashing in RGWObjManifest::obj_iterator::update_location() where location is set to the
uninitialized state in explicit_iter->second.loc.

Let me know if you need me to try to get some more data.

rgw.crash (2.92 KB) Jan Harkes, 04/21/2021 03:21 PM

rgw.log View (157 KB) Jan Harkes, 04/21/2021 03:21 PM


Related issues

Copied to rgw - Backport #50677: octopus: Reproducible crash in radosgw (nautilus and later) New
Copied to rgw - Backport #50678: nautilus: Reproducible crash in radosgw (nautilus and later) New
Copied to rgw - Backport #50679: pacific: Reproducible crash in radosgw (nautilus and later) New

History

#1 Updated by Jan Harkes 25 days ago

I wonder if this was introduced by

commit 5e4201daba625887311c2ff60deb8ac7b5d61f43
rgw: add support for storage class

because that commit removes the following check in the obj_iterator::operator++.

@@ -221,11 +224,6 @@ void RGWObjManifest::obj_iterator::operator++()
   if (manifest->explicit_objs) {
     ++explicit_iter;

-    if (explicit_iter == manifest->objs.end()) {
-      ofs = manifest->obj_size;
-      return;
-    }
-
     update_explicit_pos();

     update_location();

#2 Updated by Jan Harkes 25 days ago

Actually that particular change should not have make a difference because the increment of explicit_iter already happened by the time the removed test is performed.

#3 Updated by Jan Harkes 25 days ago

Ignore my comment #2 because it is in fact the reason for the regression.
manifest->objs is a std::map and the end function returns an iterator that points past the end.

I rebuild locally with the following change, I also set stripe_size to 0 to roughly match what
update_explicit_pos would have done, and the resulting radosgw has been running successfully
with no crashes even when fetching the testfile objects.

diff --git a/src/rgw/rgw_rados.cc b/src/rgw/rgw_rados.cc
index 4d3ae0b865..b6cc1d82b7 100644
--- a/src/rgw/rgw_rados.cc
+++ b/src/rgw/rgw_rados.cc
@@ -207,6 +207,12 @@ void RGWObjManifest::obj_iterator::operator++()
   if (manifest->explicit_objs) {
     ++explicit_iter;

+    if (explicit_iter == manifest->objs.end()) {
+      ofs = manifest->obj_size;
+      stripe_size = 0;
+      return;
+    }
+
     update_explicit_pos();

     update_location();

#4 Updated by Casey Bodley 24 days ago

  • Assignee set to Mark Kogan

#5 Updated by Casey Bodley 24 days ago

  • Status changed from New to In Progress

#6 Updated by Mark Kogan 20 days ago

  • Pull request ID set to 41028

#7 Updated by Casey Bodley 10 days ago

  • Status changed from In Progress to Pending Backport
  • Backport set to nautilus octopus pacific

#8 Updated by Backport Bot 10 days ago

  • Copied to Backport #50677: octopus: Reproducible crash in radosgw (nautilus and later) added

#9 Updated by Backport Bot 10 days ago

  • Copied to Backport #50678: nautilus: Reproducible crash in radosgw (nautilus and later) added

#10 Updated by Backport Bot 10 days ago

  • Copied to Backport #50679: pacific: Reproducible crash in radosgw (nautilus and later) added

#11 Updated by Loïc Dachary 3 days ago

  • Target version deleted (v14.2.20)

Also available in: Atom PDF