[C++] Sporadic DCHECK failure in arrow-dataset-scanner-test (2)

[asfimport]

Just got this sporadic assertion error:

[ RUN      ] TestScannerThreading/TestScanner.CountRowsWithMetadata/3Threaded2d16b1024r
/home/antoine/arrow/dev/cpp/src/arrow/util/future.cc:331:  Check failed: !IsFutureFinished(state_) Future already marked finished

Stack trace:

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff4a24859 in __GI_abort () at abort.c:79
#2  0x00007ffff56f635c in arrow::util::CerrLog::~CerrLog (this=0x55555586b330, __in_chrg=<optimized out>) at /home/antoine/arrow/dev/cpp/src/arrow/util/logging.cc:72
#3  0x00007ffff56f6378 in arrow::util::CerrLog::~CerrLog (this=0x55555586b330, __in_chrg=<optimized out>) at /home/antoine/arrow/dev/cpp/src/arrow/util/logging.cc:74
#4  0x00007ffff56f66dd in arrow::util::ArrowLog::~ArrowLog (this=0x7fffebffd970, __in_chrg=<optimized out>) at /home/antoine/arrow/dev/cpp/src/arrow/util/logging.cc:250
#5  0x00007ffff56c7af1 in arrow::ConcreteFutureImpl::DoMarkFinishedOrFailed (this=0x55555585e910, state=arrow::FutureState::SUCCESS)
    at /home/antoine/arrow/dev/cpp/src/arrow/util/future.cc:331
#6  0x00007ffff56c70e7 in arrow::ConcreteFutureImpl::DoMarkFinished (this=0x55555585e910) at /home/antoine/arrow/dev/cpp/src/arrow/util/future.cc:232
#7  0x00007ffff56c8288 in arrow::FutureImpl::MarkFinished (this=0x55555585e910) at /home/antoine/arrow/dev/cpp/src/arrow/util/future.cc:409
#8  0x00007ffff564e4f7 in arrow::Future<arrow::internal::Empty>::DoMarkFinished (this=0x555555896bf0, res=...) at /home/antoine/arrow/dev/cpp/src/arrow/util/future.h:725
#9  0x00007ffff564c198 in arrow::Future<arrow::internal::Empty>::MarkFinished<arrow::internal::Empty, void> (this=0x555555896bf0, s=...)
    at /home/antoine/arrow/dev/cpp/src/arrow/util/future.h:476
#10 0x00007ffff599d045 in arrow::compute::(anonymous namespace)::ScalarAggregateNode::Finish (this=0x555555896b60)
    at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/aggregate_node.cc:255
#11 0x00007ffff599c422 in arrow::compute::(anonymous namespace)::ScalarAggregateNode::InputReceived (this=0x555555896b60, input=0x5555559077c0, batch=...)
    at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/aggregate_node.cc:176
#12 0x00007ffff59c8567 in operator() (__closure=0x7fffebffdd40) at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/exec_plan.cc:531
#13 0x00007ffff59c873a in arrow::compute::MapNode::SubmitTask(std::function<arrow::Result<arrow::compute::ExecBatch> (arrow::compute::ExecBatch)>, arrow::compute::ExecBatch) (this=0x5555559077c0, map_fn=..., batch=...) at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/exec_plan.cc:535
#14 0x00007ffff5a97524 in arrow::compute::(anonymous namespace)::ProjectNode::InputReceived (this=0x5555559077c0, input=0x555555913150, batch=...)
    at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/project_node.cc:111
#15 0x00007ffff5aa3da2 in operator() (__closure=0x7fffa000aba0) at /home/antoine/arrow/dev/cpp/src/arrow/compute/exec/source_node.cc:119
#16 0x00007ffff5aaa56f in std::__invoke_impl<arrow::Status, arrow::compute::(anonymous namespace)::SourceNode::StartProducing()::<lambda()>::<lambda(arrow::util::optional<arrow::compute::ExecBatch>&)>::<lambda()>&>(std::__invoke_other, struct {...} &) (__f=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:60
#17 0x00007ffff5aa943c in std::__invoke_r<arrow::Status, arrow::compute::(anonymous namespace)::SourceNode::StartProducing()::<lambda()>::<lambda(arrow::util::optional<arrow::compute::ExecBatch>&)>::<lambda()>&>(struct {...} &) (__fn=...) at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:115
#18 0x00007ffff5aa79ca in std::_Function_handler<arrow::Status(), arrow::compute::(anonymous namespace)::SourceNode::StartProducing()::<lambda()>::<lambda(arrow::util::optional<arrow::compute::ExecBatch>&)>::<lambda()> >::_M_invoke(const std::_Any_data &) (__functor=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/std_function.h:292
#19 0x00007ffff59ca6b5 in std::function<arrow::Status ()>::operator()() const (this=0x55555593e700)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/std_function.h:622
#20 0x00007ffff59df33b in arrow::detail::ContinueFuture::operator()<std::function<arrow::Status ()>&, , arrow::Status, arrow::Future<arrow::internal::Empty> >(arrow::Future<arrow::internal::Empty>, std::function<arrow::Status ()>&) const (this=0x55555593e6f8, next=..., f=...) at /home/antoine/arrow/dev/cpp/src/arrow/util/future.h:150
#21 0x00007ffff59df19f in std::__invoke_impl<void, arrow::detail::ContinueFuture&, arrow::Future<arrow::internal::Empty>&, std::function<arrow::Status ()>&>(std::__invoke_other, arrow::detail::ContinueFuture&, arrow::Future<arrow::internal::Empty>&, std::function<arrow::Status ()>&) (__f=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:60
#22 0x00007ffff59def33 in std::__invoke<arrow::detail::ContinueFuture&, arrow::Future<arrow::internal::Empty>&, std::function<arrow::Status ()>&>(arrow::detail::ContinueFuture&, arrow::Future<arrow::internal::Empty>&, std::function<arrow::Status ()>&) (__fn=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:95
#23 0x00007ffff59deb86 in std::_Bind<arrow::detail::ContinueFuture (arrow::Future<arrow::internal::Empty>, std::function<arrow::Status ()>)>::__call<void, , 0ul, 1ul>(std::tuple<>&&, std::_Index_tuple<0ul, 1ul>) (this=0x55555593e6f8, __args=...) at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/functional:416
#24 0x00007ffff59de809 in std::_Bind<arrow::detail::ContinueFuture (arrow::Future<arrow::internal::Empty>, std::function<arrow::Status ()>)>::operator()<, void>() (
    this=0x55555593e6f8) at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/functional:499
#25 0x00007ffff59de650 in arrow::internal::FnOnce<void ()>::FnImpl<std::_Bind<arrow::detail::ContinueFuture (arrow::Future<arrow::internal::Empty>, std::function<arrow::Status ()>)> >::invoke() (this=0x55555593e6f0) at /home/antoine/arrow/dev/cpp/src/arrow/util/functional.h:152
#26 0x00007ffff5714b51 in arrow::internal::FnOnce<void ()>::operator()() && (this=0x7fffebffe1d0) at /home/antoine/arrow/dev/cpp/src/arrow/util/functional.h:140
#27 0x00007ffff5712bef in arrow::internal::WorkerLoop (state=std::shared_ptr<struct arrow::internal::ThreadPool::State> (use count 49, weak count 0) = {...}, it=Traceback (most recent call last):
  File "/usr/share/gcc/python/libstdcxx/v6/printers.py", line 339, in to_string
    node = self.val['_M_node'].cast(self.nodetype.pointer()).dereference()
AttributeError: 'NoneType' object has no attribute 'pointer'

) at /home/antoine/arrow/dev/cpp/src/arrow/util/thread_pool.cc:247
#28 0x00007ffff5713b24 in operator() (__closure=0x7fffec004f58) at /home/antoine/arrow/dev/cpp/src/arrow/util/thread_pool.cc:418
#29 0x00007ffff571af82 in std::__invoke_impl<void, arrow::internal::ThreadPool::LaunchWorkersUnlocked(int)::<lambda()> >(std::__invoke_other, struct {...} &&) (__f=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:60
#30 0x00007ffff571af37 in std::__invoke<arrow::internal::ThreadPool::LaunchWorkersUnlocked(int)::<lambda()> >(struct {...} &&) (__fn=...)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/bits/invoke.h:95
#31 0x00007ffff571aee4 in std::thread::_Invoker<std::tuple<arrow::internal::ThreadPool::LaunchWorkersUnlocked(int)::<lambda()> > >::_M_invoke<0>(std::_Index_tuple<0>) (
    this=0x7fffec004f58) at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/thread:264
#32 0x00007ffff571ada4 in std::thread::_Invoker<std::tuple<arrow::internal::ThreadPool::LaunchWorkersUnlocked(int)::<lambda()> > >::operator()(void) (this=0x7fffec004f58)
    at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/thread:271
#33 0x00007ffff571ad08 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<arrow::internal::ThreadPool::LaunchWorkersUnlocked(int)::<lambda()> > > >::_M_run(void)
    (this=0x7fffec004f50) at /home/antoine/miniconda3/envs/pyarrow/x86_64-conda-linux-gnu/include/c++/10.3.0/thread:215
#34 0x00007ffff4d0baa3 in std::execute_native_thread_routine (__p=<optimized out>) at ../../../../../libstdc++-v3/src/c++11/thread.cc:82
#35 0x00007ffff42fc609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#36 0x00007ffff4b21133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Other threads are idling.

Reporter: Antoine Pitrou / @pitrou

_{Note: This issue was originally created as ARROW-17128. Please see the migration documentation for further details.}

[asfimport]

Antoine Pitrou / @pitrou:
cc @westonpace

[assignUser]

I have not seen this recently, do you think this is still an issue @pitrou ? In any case it is not a blocker :)

[pitrou]

Well, hard crashes can be considered blockers, but in this case the issue is old and some sizable changes might have been committed since then. @westonpace What do you think?

[westonpace]

Yep, everything here has changed considerably. I don't remember fixing this exact error but a lot of this handling changed when we moved to the async scheduler for tasks. On the other hand, I don't recall seeing any CI crashes on this test in the past month or two.

This particular code path (marking a node finished) will soon be going away (but not before the release).

I think we should close this as "likely fixed"

[pitrou]

Ok, let's close then!