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

tmp-file-mgr.h:263] Check failed: !write_in_flight_

    Details

      Description

      While running a stress test, Impala hit a DCHECK:

      259   class WriteHandle {
      260    public:
      261     // The write must be destroyed by FileGroup::DestroyWriteHandle().
      262     ~WriteHandle() {
      263       DCHECK(!write_in_flight_);
      264       DCHECK(is_cancelled_);
      265     }
      
      #6  0x000000000282d98e in google::LogMessageFatal::~LogMessageFatal() ()
      #7  0x000000000138bbd7 in impala::TmpFileMgr::WriteHandle::~WriteHandle (this=0x7f1b46dae5a0, __in_chrg=<value optimized out>)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.h:263
      #8  0x000000000138ef0a in std::default_delete<impala::TmpFileMgr::WriteHandle>::operator() (this=0x7f244fd296b0,
          __ptr=0x7f1b46dae5a0)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/bits/unique_ptr.h:76
      #9  0x000000000138d209 in std::unique_ptr<impala::TmpFileMgr::WriteHandle, std::default_delete<impala::TmpFileMgr::WriteHandle> >::~unique_ptr (this=0x7f244fd296b0, __in_chrg=<value optimized out>)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/bits/unique_ptr.h:236
      #10 0x00000000013887de in impala::TmpFileMgr::FileGroup::Write (this=0x7f187d5472a0, buffer=..., cb=..., handle=0x7f155340e718)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:377
      #11 0x00000000013992b2 in impala::BufferedBlockMgr::WriteUnpinnedBlock (this=0x7f1b1906ea80, block=0x7f155340e6e0)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:752
      #12 0x0000000001398bd4 in impala::BufferedBlockMgr::WriteUnpinnedBlocks (this=0x7f1b1906ea80)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:737
      #13 0x000000000139cbbb in impala::BufferedBlockMgr::FindBufferForBlock (this=0x7f1b1906ea80, block=0x7f113936c5d0,
          in_mem=0x7f244fd29f0f) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:1026
      #14 0x00000000013954df in impala::BufferedBlockMgr::GetNewBlock (this=0x7f1b1906ea80, client=0x7f18225a7980, unpin_block=0x0,
          block=0x7f244fd2a1d8, len=8388608) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:442
      #15 0x000000000199b904 in impala::BufferedTupleStream::NewWriteBlock (this=0x7f1d84310940, block_len=8388608,
          null_indicators_size=0, got_block=0x7f244fd2a47f)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-tuple-stream.cc:246
      #16 0x000000000199af09 in impala::BufferedTupleStream::SwitchToIoBuffers (this=0x7f1d84310940, got_buffer=0x7f244fd2a47f)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-tuple-stream.cc:185
      #17 0x00000000017ee8e3 in impala::PhjBuilder::AppendRowStreamFull (this=0x7f14a820e540, stream=0x7f1d84310940,
          row=0x7f1698a7acd0, status=0x7f244fd2a660)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-builder.cc:277
      #18 0x00007f25408e0fa3 in impala::PhjBuilder::ProcessBuildBatch ()
      #19 0x00000000017ed7de in impala::PhjBuilder::Send (this=0x7f14a820e540, state=0x7f15977e9c00, batch=0xd6e91a80)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-builder.cc:174
      #20 0x00000000017cdf9f in impala::BlockingJoinNode::SendBuildInputToSink<false> (this=0x7f14999be300, state=0x7f15977e9c00,
          build_sink=0x7f14a820e540) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/blocking-join-node.cc:287
      #21 0x00000000017cc08a in impala::BlockingJoinNode::ProcessBuildInputAndOpenProbe (this=0x7f14999be300, state=0x7f15977e9c00,
          build_sink=0x7f14a820e540) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/blocking-join-node.cc:233
      #22 0x000000000176db9a in impala::PartitionedHashJoinNode::Open (this=0x7f14999be300, state=0x7f15977e9c00)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-node.cc:182
      #23 0x00000000017cc136 in impala::BlockingJoinNode::ProcessBuildInputAndOpenProbe (this=0x7f12e7926a00, state=0x7f15977e9c00,
          build_sink=0x7f12d20e3640) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/blocking-join-node.cc:235
      #24 0x000000000176db9a in impala::PartitionedHashJoinNode::Open (this=0x7f12e7926a00, state=0x7f15977e9c00)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-node.cc:182
      #25 0x00000000017cc136 in impala::BlockingJoinNode::ProcessBuildInputAndOpenProbe (this=0x7f12e7925880, state=0x7f15977e9c00,
          build_sink=0x7f18a6442c40) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/blocking-join-node.cc:235
      #26 0x000000000176db9a in impala::PartitionedHashJoinNode::Open (this=0x7f12e7925880, state=0x7f15977e9c00)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-node.cc:182
      #27 0x00000000017cc136 in impala::BlockingJoinNode::ProcessBuildInputAndOpenProbe (this=0x7f202baf0000, state=0x7f15977e9c00,
          build_sink=0x10f605480) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/blocking-join-node.cc:235
      #28 0x000000000176db9a in impala::PartitionedHashJoinNode::Open (this=0x7f202baf0000, state=0x7f15977e9c00)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-hash-join-node.cc:182
      #29 0x000000000174cc12 in impala::PartitionedAggregationNode::Open (this=0x7f1f2383f840, state=0x7f15977e9c00)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/exec/partitioned-aggregation-node.cc:318
      #30 0x00000000019eda6c in impala::PlanFragmentExecutor::OpenInternal (this=0x7f1e6c8cbab0)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/plan-fragment-executor.cc:325
      #31 0x00000000019ed4a8 in impala::PlanFragmentExecutor::Open (this=0x7f1e6c8cbab0)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/plan-fragment-executor.cc:297
      #32 0x00000000019e755f in impala::FragmentInstanceState::Exec (this=0x7f1e6c8cb800)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/fragment-instance-state.cc:65
      #33 0x00000000019f2c4d in impala::QueryExecMgr::ExecFInstance (this=0xe268340, fis=0x7f1e6c8cb800)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/query-exec-mgr.cc:100
      #34 0x00000000019f6198 in boost::_mfi::mf1<void, impala::QueryExecMgr, impala::FragmentInstanceState*>::operator() (
          this=0x7f12d0ff99e0, p=0xe268340, a1=0x7f1e6c8cb800)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/mem_fn_template.hpp:165
      #35 0x00000000019f603b in boost::_bi::list2<boost::_bi::value<impala::QueryExecMgr*>, boost::_bi::value<impala::FragmentInstanceState*> >::operator()<boost::_mfi::mf1<void, impala::QueryExecMgr, impala::FragmentInstanceState*>, boost::_bi::list0> (
          this=0x7f12d0ff99f0, f=..., a=...)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:313
      #36 0x00000000019f5cff in boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::QueryExecMgr, impala::FragmentInstanceState*>, boost::_bi::list2<boost::_bi::value<impala::QueryExecMgr*>, boost::_bi::value<impala::FragmentInstanceState*> > >::operator() (
          this=0x7f12d0ff99e0)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20
      #37 0x00000000019f57d6 in boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::QueryExecMgr, impala::FragmentInstanceState*>, boost::_bi::list2<boost::_bi::value<impala::QueryExecMgr*>, boost::_bi::value<impala::FragmentInstanceState*> > >, void>::invoke (function_obj_ptr=...)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:153
      #38 0x000000000134c614 in boost::function0<void>::operator() (this=0x7f244fd2cc40)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:767
      #39 0x00000000015f580f in impala::Thread::SuperviseThread (name=..., category=..., functor=..., thread_started=0x7f1a72857870)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/util/thread.cc:317
      #40 0x00000000015fc7e8 in boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> >::operator()<void (*)(const std::basic_string<char>&, const std::basic_string<char>&, boost::function<void()>, impala::Promise<long int>*), boost::_bi::list0>(boost::_bi::type<void>, void (*&)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> > &, const std::basic_string<char, std::char_traits<char>, std::allocator<char> > &, boost::function<void()>, impala::Promise<long> *), boost::_bi::list0 &, int) (this=0x7f12d34b63c0,
          f=@0x7f12d34b63b8, a=...)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:457
      #41 0x00000000015fc72b in boost::_bi::bind_t<void, void (*)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, boost::function<void()>, impala::Promise<long int>*), boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> > >::operator()(void) (this=0x7f12d34b63b8)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20
      #42 0x00000000015fc686 in boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, boost::function <void()>, impala::Promise<long int>*), boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> > > >::run(void) (this=0x7f12d34b6200)
          at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/detail/thread.hpp:116
      #43 0x0000000001a5bc4a in thread_proxy ()
      #44 0x00000035202079d1 in start_thread () from /lib64/libpthread.so.0
      #45 0x000000351fee88fd in clone () from /lib64/libc.so.6
      

      Commit: IMPALA-3401: Suppress blocks of content devoted to Cloudera Manager. (4 days ago) <John Russell>

        Activity

        Hide
        tarmstrong Tim Armstrong added a comment -

        IMPALA-4748: crash in TmpFileMgr when hitting process mem limit

        The bug is that FileGroup didn't correctly handle its 'io_ctx_'
        being asynchronously cancelled: it left the WriteHandle in an
        invalid state. This could happen when the process memory limit
        was exceeded.

        I fixed this in two ways (either of which would be sufficient
        to avoid this exact crash):

        • Fix the error handling in TmpFileMgr so that things are left
          in a valid state on the error path.
        • Stop DiskIoMgr from asynchronously cancelling I/O contexts
          with no associated MemTracker. The mem_limit check and error
          propagation is necessary when DiskIoMgr will allocate memory
          on behalf of the client, but is not necessary when it is not
          allocating memory for the client - it just added a redundant
          error propagation mechanism.

        Testing:
        This scenario should no longer be possible for BufferedBlockMgr
        since DiskIoMgr won't cancel its I/O context, since it has no
        associated MemTracker. However, to test that errors on this path
        are correctly handled, I added a simple unit test to TmpFileMgr
        that forces cancellation of the I/O context.

        Change-Id: Ib0a624212bc17f7824e6d14ad143c0d5894206f8
        Reviewed-on: http://gerrit.cloudera.org:8080/5683
        Reviewed-by: Tim Armstrong <tarmstrong@cloudera.com>
        Tested-by: Impala Public Jenkins

        Show
        tarmstrong Tim Armstrong added a comment - IMPALA-4748 : crash in TmpFileMgr when hitting process mem limit The bug is that FileGroup didn't correctly handle its 'io_ctx_' being asynchronously cancelled: it left the WriteHandle in an invalid state. This could happen when the process memory limit was exceeded. I fixed this in two ways (either of which would be sufficient to avoid this exact crash): Fix the error handling in TmpFileMgr so that things are left in a valid state on the error path. Stop DiskIoMgr from asynchronously cancelling I/O contexts with no associated MemTracker. The mem_limit check and error propagation is necessary when DiskIoMgr will allocate memory on behalf of the client, but is not necessary when it is not allocating memory for the client - it just added a redundant error propagation mechanism. Testing: This scenario should no longer be possible for BufferedBlockMgr since DiskIoMgr won't cancel its I/O context, since it has no associated MemTracker. However, to test that errors on this path are correctly handled, I added a simple unit test to TmpFileMgr that forces cancellation of the I/O context. Change-Id: Ib0a624212bc17f7824e6d14ad143c0d5894206f8 Reviewed-on: http://gerrit.cloudera.org:8080/5683 Reviewed-by: Tim Armstrong <tarmstrong@cloudera.com> Tested-by: Impala Public Jenkins
        Hide
        mikesbrown Michael Brown added a comment -

        This happens reliably. I realize you're working on it, but it's probably best to label this as broken-build since the stress test doesn't get very far before hitting it.

        Show
        mikesbrown Michael Brown added a comment - This happens reliably. I realize you're working on it, but it's probably best to label this as broken-build since the stress test doesn't get very far before hitting it.
        Hide
        tarmstrong Tim Armstrong added a comment -

        This asynchronous cancellation also doesn't really make a lot of sense for TmpFileMgr's use of DiskIoMgr, since DiskIoMgr doesn't allocate any memory on behalf of TmpFileMgr. We could just remove the free_buffer_mem_tracker_->AnyLimitExceeded(); check and only check the memory limit when a reader provided a MemTracker*.

        Show
        tarmstrong Tim Armstrong added a comment - This asynchronous cancellation also doesn't really make a lot of sense for TmpFileMgr's use of DiskIoMgr, since DiskIoMgr doesn't allocate any memory on behalf of TmpFileMgr. We could just remove the free_buffer_mem_tracker_->AnyLimitExceeded(); check and only check the memory limit when a reader provided a MemTracker*.
        Hide
        tarmstrong Tim Armstrong added a comment -

        I understand the immediate cause of the DCHECK - the io_ctx_ for the FileGroup was cancelled, which results in taking the error path in WriteHandle::Write(), which results in hitting the DCHECK when tmp_handle is destroyed.

        I found another backtrace in the core that is the smoking gun - the io_ctx_ was cancelled because we hit the process memory limit (DiskIoMgr does this).

        Thread 3109 (Thread 0x7f267b305700 (LWP 136300)):
        #0  0x000000352020e264 in __lll_lock_wait () from /lib64/libpthread.so.0
        #1  0x0000003520209508 in _L_lock_854 () from /lib64/libpthread.so.0
        #2  0x00000035202093d7 in pthread_mutex_lock () from /lib64/libpthread.so.0
        #3  0x0000000001184e55 in pthread_mutex_lock (this=0x7f1b1906ead0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/pthread/mutex.hpp:62
        #4  boost::mutex::lock (this=0x7f1b1906ead0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/pthread/mutex.hpp:116
        #5  0x000000000118e7a4 in boost::lock_guard<boost::mutex>::lock_guard (this=0x7f267b303fc0, m_=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/lock_guard.hpp:38
        #6  0x0000000001399795 in impala::BufferedBlockMgr::WriteComplete (this=0x7f1b1906ea80, block=0x7f155340f1e0, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:782
        #7  0x0000000001398e48 in impala::BufferedBlockMgr::<lambda(const impala::Status&)>::operator()(const impala::Status &) const (__closure=0x7f105d9a30b0, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:752
        #8  0x000000000139f903 in std::_Function_handler<void(const impala::Status&), impala::BufferedBlockMgr::WriteUnpinnedBlock(impala::BufferedBlockMgr::Block*)::<lambda(const impala::Status&)> >::_M_invoke(const std::_Any_data &, const impala::Status &) (__functor=..., __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2039
        #9  0x000000000138d82b in std::function<void(const impala::Status&)>::operator()(const impala::Status &) const (this=0x7f267b304300, __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2439
        #10 0x000000000138a739 in impala::TmpFileMgr::WriteHandle::WriteComplete (this=0x7f1b46dae690, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:549
        #11 0x0000000001389713 in impala::TmpFileMgr::FileGroup::WriteComplete (this=0x7f187d5472a0, handle=0x7f1b46dae690, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:448
        #12 0x00000000013883ca in impala::TmpFileMgr::FileGroup::<lambda(const impala::Status&)>::operator()(const impala::Status &) const (__closure=0x7f20b8325420, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:371
        #13 0x000000000138b0e1 in std::_Function_handler<void(const impala::Status&), impala::TmpFileMgr::FileGroup::Write(impala::MemRange, impala::TmpFileMgr::WriteDoneCallback, std::unique_ptr<impala::TmpFileMgr::WriteHandle>*)::<lambda(const impala::Status&)> >::_M_invoke(const std::_Any_data &, const impala::Status &) (__functor=..., __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2039
        #14 0x000000000138d82b in std::function<void(const impala::Status&)>::operator()(const impala::Status &) const (this=0xec4f100, __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2439
        #15 0x00000000013edea5 in impala::DiskIoRequestContext::Cancel (this=0x7f1a1fc5f840, status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr-reader-context.cc:86
        #16 0x00000000013de0a5 in impala::DiskIoMgr::GetNextRequestRange (this=0xd3a1500, disk_queue=0xdb7e3a0, range=0x7f267b304810, request_context=0x7f267b304818) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr.cc:887
        #17 0x00000000013df440 in impala::DiskIoMgr::WorkLoop (this=0xd3a1500, disk_queue=0xdb7e3a0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr.cc:1055
        #18 0x00000000013ebfe6 in boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>::operator() (this=0xf978120, p=0xd3a1500, a1=0xdb7e3a0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/mem_fn_template.hpp:165
        #19 0x00000000013ebc23 in boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> >::operator()<boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list0> (this=0xf978130, f=..., a=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:313
        #20 0x00000000013eb379 in boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> > >::operator() (this=0xf978120) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20
        #21 0x00000000013ea7d7 in boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> > >, void>::invoke (function_obj_ptr=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:153
        #22 0x000000000134c614 in boost::function0<void>::operator() (this=0x7f267b304c40) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:767
        #23 0x00000000015f580f in impala::Thread::SuperviseThread (name=..., category=..., functor=..., thread_started=0x7fff6b3bc400) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/util/thread.cc:317
        #24 0x00000000015fc7e8 in boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> >::operator()<void (*)(const std::basic_string<char>&, const std::basic_string<char>&, boost::function<void()>, impala::Promise<long int>*), boost::_bi::list0>(boost::_bi::type<void>, void (*&)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> > &, const std::basic_string<char, std::char_traits<char>, std::allocator<char> > &, boost::function<void()>, impala::Promise<long> *), boost::_bi::list0 &, int) (this=0xf96b5c0, f=@0xf96b5b8, a=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:457
        #25 0x00000000015fc72b in boost::_bi::bind_t<void, void (*)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, boost::function<void()>, impala::Promise<long int>*), boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> > >::operator()(void) (this=0xf96b5b8) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20
        #26 0x00000000015fc686 in boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, const std::basic_string<char, std::char_traits<char>, std::allocator<char> >&, boost::function<void()>, impala::Promise<long int>*), boost::_bi::list4<boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<std::basic_string<char, std::char_traits<char>, std::allocator<char> > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise<long int>*> > > >::run(void) (this=0xf96b400) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/detail/thread.hpp:116
        #27 0x0000000001a5bc4a in thread_proxy ()
        #28 0x00000035202079d1 in start_thread () from /lib64/libpthread.so.0
        #29 0x000000351fee88fd in clone () from /lib64/libc.so.6
        
        
        Show
        tarmstrong Tim Armstrong added a comment - I understand the immediate cause of the DCHECK - the io_ctx_ for the FileGroup was cancelled, which results in taking the error path in WriteHandle::Write(), which results in hitting the DCHECK when tmp_handle is destroyed. I found another backtrace in the core that is the smoking gun - the io_ctx_ was cancelled because we hit the process memory limit (DiskIoMgr does this). Thread 3109 ( Thread 0x7f267b305700 (LWP 136300)): #0 0x000000352020e264 in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x0000003520209508 in _L_lock_854 () from /lib64/libpthread.so.0 #2 0x00000035202093d7 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x0000000001184e55 in pthread_mutex_lock ( this =0x7f1b1906ead0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/pthread/mutex.hpp:62 #4 boost::mutex::lock ( this =0x7f1b1906ead0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/pthread/mutex.hpp:116 #5 0x000000000118e7a4 in boost::lock_guard<boost::mutex>::lock_guard ( this =0x7f267b303fc0, m_=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/lock_guard.hpp:38 #6 0x0000000001399795 in impala::BufferedBlockMgr::WriteComplete ( this =0x7f1b1906ea80, block=0x7f155340f1e0, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:782 #7 0x0000000001398e48 in impala::BufferedBlockMgr::<lambda( const impala::Status&)>:: operator ()( const impala::Status &) const (__closure=0x7f105d9a30b0, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/buffered-block-mgr.cc:752 #8 0x000000000139f903 in std::_Function_handler<void( const impala::Status&), impala::BufferedBlockMgr::WriteUnpinnedBlock(impala::BufferedBlockMgr::Block*)::<lambda( const impala::Status&)> >::_M_invoke( const std::_Any_data &, const impala::Status &) (__functor=..., __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2039 #9 0x000000000138d82b in std::function<void( const impala::Status&)>:: operator ()( const impala::Status &) const ( this =0x7f267b304300, __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2439 #10 0x000000000138a739 in impala::TmpFileMgr::WriteHandle::WriteComplete ( this =0x7f1b46dae690, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:549 #11 0x0000000001389713 in impala::TmpFileMgr::FileGroup::WriteComplete ( this =0x7f187d5472a0, handle=0x7f1b46dae690, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:448 #12 0x00000000013883ca in impala::TmpFileMgr::FileGroup::<lambda( const impala::Status&)>:: operator ()( const impala::Status &) const (__closure=0x7f20b8325420, write_status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/tmp-file-mgr.cc:371 #13 0x000000000138b0e1 in std::_Function_handler<void( const impala::Status&), impala::TmpFileMgr::FileGroup::Write(impala::MemRange, impala::TmpFileMgr::WriteDoneCallback, std::unique_ptr<impala::TmpFileMgr::WriteHandle>*)::<lambda( const impala::Status&)> >::_M_invoke( const std::_Any_data &, const impala::Status &) (__functor=..., __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2039 #14 0x000000000138d82b in std::function<void( const impala::Status&)>:: operator ()( const impala::Status &) const ( this =0xec4f100, __args#0=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/gcc-4.9.2/include/c++/4.9.2/functional:2439 #15 0x00000000013edea5 in impala::DiskIoRequestContext::Cancel ( this =0x7f1a1fc5f840, status=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr-reader-context.cc:86 #16 0x00000000013de0a5 in impala::DiskIoMgr::GetNextRequestRange ( this =0xd3a1500, disk_queue=0xdb7e3a0, range=0x7f267b304810, request_context=0x7f267b304818) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr.cc:887 #17 0x00000000013df440 in impala::DiskIoMgr::WorkLoop ( this =0xd3a1500, disk_queue=0xdb7e3a0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/runtime/disk-io-mgr.cc:1055 #18 0x00000000013ebfe6 in boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>:: operator () ( this =0xf978120, p=0xd3a1500, a1=0xdb7e3a0) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/mem_fn_template.hpp:165 #19 0x00000000013ebc23 in boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> >:: operator ()<boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list0> ( this =0xf978130, f=..., a=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:313 #20 0x00000000013eb379 in boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> > >:: operator () ( this =0xf978120) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20 #21 0x00000000013ea7d7 in boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf1<void, impala::DiskIoMgr, impala::DiskIoMgr::DiskQueue*>, boost::_bi::list2<boost::_bi::value<impala::DiskIoMgr*>, boost::_bi::value<impala::DiskIoMgr::DiskQueue*> > >, void>::invoke (function_obj_ptr=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:153 #22 0x000000000134c614 in boost::function0<void>:: operator () ( this =0x7f267b304c40) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/function/function_template.hpp:767 #23 0x00000000015f580f in impala:: Thread ::SuperviseThread (name=..., category=..., functor=..., thread_started=0x7fff6b3bc400) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/be/src/util/thread.cc:317 #24 0x00000000015fc7e8 in boost::_bi::list4<boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise< long int >*> >:: operator ()<void (*)( const std::basic_string< char >&, const std::basic_string< char >&, boost::function<void()>, impala::Promise< long int >*), boost::_bi::list0>(boost::_bi::type<void>, void (*&)( const std::basic_string< char , std::char_traits< char >, std::allocator< char > > &, const std::basic_string< char , std::char_traits< char >, std::allocator< char > > &, boost::function<void()>, impala::Promise< long > *), boost::_bi::list0 &, int ) ( this =0xf96b5c0, f=@0xf96b5b8, a=...) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind.hpp:457 #25 0x00000000015fc72b in boost::_bi::bind_t<void, void (*)( const std::basic_string< char , std::char_traits< char >, std::allocator< char > >&, const std::basic_string< char , std::char_traits< char >, std::allocator< char > >&, boost::function<void()>, impala::Promise< long int >*), boost::_bi::list4<boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise< long int >*> > >:: operator ()(void) ( this =0xf96b5b8) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/bind/bind_template.hpp:20 #26 0x00000000015fc686 in boost::detail::thread_data<boost::_bi::bind_t<void, void (*)( const std::basic_string< char , std::char_traits< char >, std::allocator< char > >&, const std::basic_string< char , std::char_traits< char >, std::allocator< char > >&, boost::function<void()>, impala::Promise< long int >*), boost::_bi::list4<boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<std::basic_string< char , std::char_traits< char >, std::allocator< char > > >, boost::_bi::value<boost::function<void()> >, boost::_bi::value<impala::Promise< long int >*> > > >::run(void) ( this =0xf96b400) at /usr/src/debug/impala-2.7.0-cdh5.11.0-SNAPSHOT/toolchain/boost-1.57.0/include/boost/thread/detail/thread.hpp:116 #27 0x0000000001a5bc4a in thread_proxy () #28 0x00000035202079d1 in start_thread () from /lib64/libpthread.so.0 #29 0x000000351fee88fd in clone () from /lib64/libc.so.6

          People

          • Assignee:
            tarmstrong Tim Armstrong
            Reporter:
            mikesbrown Michael Brown
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development