Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-1890

Race between ~BufferedBlockMgr() destructor and WriteComplete()

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Blocker
    • Resolution: Fixed
    • Affects Version/s: Product Backlog
    • Fix Version/s: Impala 2.2
    • Component/s: None
    • Labels:
      None

      Description

      We were looking on the code on the BufferedBlockMgr destructor and noticed that it acquires lock_ . The comment above it says that it is for synchronizing with WriteComplete(), see code below, which makes no sense. Because if there is indeed a race and the destructor wins, then the loser (the disk-io thread that executes the WriteComplete() callback) is going to access invalid or reset memory. While I was adding some dchecks about it, Dan managed to hit the problem in his S3 tests, after he fixed IMPALA-1863.

      This problem looks very related to IMPALA-1873, probably a different manifestation of the same error. Filling it as a different JIRA as it is a slightly different stack.

      The code of the BufferedBlockMgr destructor with the lock_ and the comment about WriteComplete():

        // Grab this lock to synchronize with io threads in WriteComplete(). We need those
        // to finish to ensure that memory buffers remain valid for any in-progress writes.
        lock_guard<mutex> lock(lock_);
        // Delete tmp files.
        BOOST_FOREACH(TmpFileMgr::File& file, tmp_files_) {
          file.Remove();
        }
        tmp_files_.clear();
      
        // Free memory resources.
        BOOST_FOREACH(BufferDescriptor* buffer, all_io_buffers_) {
          mem_tracker_->Release(buffer->len);
          delete[] buffer->buffer;
        }
        DCHECK_EQ(mem_tracker_->consumption(), 0);
        mem_tracker_->UnregisterFromParent();
        mem_tracker_.reset();
      }
      

      The stack trace Dan hit:

      #3  0x0000003a6982bad0 in __assert_fail () from /lib64/libc.so.6
      #4  0x0000000000f3c0cd in boost::scoped_ptr<impala::MemTracker>::operator-> (this=0x9611248) at /usr/include/boost/smart_ptr/scoped_ptr.hpp:97
      #5  0x0000000000f90772 in impala::BufferedBlockMgr::DebugInternal (this=0x9611200) at /home/dhecht/src/Impala/be/src/runtime/buffered-block-mgr.cc:1078
      #6  0x0000000000f8d3dc in impala::BufferedBlockMgr::WriteComplete (this=0x9611200, block=0x20ea7440, write_status=...) at /home/dhecht/src/Impala/be/src/runtime/buffered-block-mgr.cc:754
      #7  0x0000000000f9c6e0 in boost::_mfi::mf2<void, impala::BufferedBlockMgr, impala::BufferedBlockMgr::Block*, impala::Status const&>::operator() (this=0x83fb160, p=0x9611200, a1=0x20ea7440, a2=...)
          at /usr/include/boost/bind/mem_fn_template.hpp:280
      #8  0x0000000000f9c375 in boost::_bi::list3<boost::_bi::value<impala::BufferedBlockMgr*>, boost::_bi::value<impala::BufferedBlockMgr::Block*>, boost::arg<1> >::operator()<boost::_mfi::mf2<void, impala::BufferedBlockMgr, impala::BufferedBlockMgr::Block*, impala::Status const&>, boost::_bi::list1<impala::Status const&> > (this=0x83fb170, f=..., a=...) at /usr/include/boost/bind/bind.hpp:392
      #9  0x0000000000f9bb7e in boost::_bi::bind_t<boost::_bi::unspecified, boost::_mfi::mf2<void, impala::BufferedBlockMgr, impala::BufferedBlockMgr::Block*, impala::Status const&>, boost::_bi::list3<boost::_bi::value<impala::BufferedBlockMgr*>, boost::_bi::value<impala::BufferedBlockMgr::Block*>, boost::arg<1> > >::operator()<impala::Status> (this=0x83fb160, a1=...)
          at /usr/include/boost/bind/bind_template.hpp:47
      #10 0x0000000000f9b1f4 in boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<boost::_bi::unspecified, boost::_mfi::mf2<void, impala::BufferedBlockMgr, impala::BufferedBlockMgr::Block*, impala::Status const&>, boost::_bi::list3<boost::_bi::value<impala::BufferedBlockMgr*>, boost::_bi::value<impala::BufferedBlockMgr::Block*>, boost::arg<1> > >, void, impala::Status const&>::invoke (
          function_obj_ptr=..., a0=...) at /usr/include/boost/function/function_template.hpp:153
      #11 0x0000000000fafe16 in boost::function1<void, impala::Status const&>::operator() (this=0x1cb62e50, a0=...) at /usr/include/boost/function/function_template.hpp:1013
      #12 0x0000000000fa9cab in impala::DiskIoMgr::HandleWriteFinished (this=0x5dd45a0, writer=0x949c1e0, write_range=0x1cb62e00, write_status=...) at /home/dhecht/src/Impala/be/src/runtime/disk-io-mgr.cc:858
      #13 0x0000000000fab7c7 in impala::DiskIoMgr::Write (this=0x5dd45a0, writer_context=0x949c1e0, write_range=0x1cb62e00) at /home/dhecht/src/Impala/be/src/runtime/disk-io-mgr.cc:1053
      #14 0x0000000000faa63a in impala::DiskIoMgr::WorkLoop (this=0x5dd45a0, disk_queue=0x85ae460) at /home/dhecht/src/Impala/be/src/runtime/disk-io-mgr.cc:940
      
      
      ---The mem-tracker has already been freed:---
      
      (gdb) f 6
      #6  0x0000000000f8d3dc in impala::BufferedBlockMgr::WriteComplete (this=0x9611200, block=0x20ea7440, write_status=...) at /home/dhecht/src/Impala/be/src/runtime/buffered-block-mgr.cc:754
      754       DCHECK(Validate()) << endl << DebugInternal();
      (gdb) p mem_tracker_
      $3 = {
        px = 0x0
      }
      

        Attachments

          Activity

            People

            • Assignee:
              ippokratis Ippokratis Pandis
              Reporter:
              ippokratis Ippokratis Pandis
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: