ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks #9842

westonpace · 2021-03-29T21:34:41Z

From a deadlocked run...

#0  0x00007f8a5d48dccd in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f8a5d486f05 in pthread_mutex_lock () from /lib64/libpthread.so.0
#2  0x00007f8a566e7e89 in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#3  0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#4  0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#5  0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#6  0x00007f8a566e827d in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#7  0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#8  0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#9  0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so
#10 0x00007f8a566e74b1 in arrow::fs::(anonymous namespace)::TreeWalker::DoWalk() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so

The callback ListObjectsV2Handler is being called recursively and the mutex is non-reentrant thus deadlock.

To fix it I got rid of the mutex on TreeWalker by using arrow::util::internal::TaskGroup instead of manually tracking the #/status of in-flight requests.

github-actions · 2021-03-30T05:19:07Z

https://issues.apache.org/jira/browse/ARROW-12040

pitrou · 2021-03-30T09:52:25Z

Hmm, I'd rather not use TaskGroup here, because it will have to be undone when implementing streaming GetFileInfo (ARROW-11924).

westonpace · 2021-03-30T14:34:15Z

I think it would end up using something very similar if not exactly TaskGroup in order to know when to write the end token to the generator. Something like

task_group_.FinishAsync().Then([producer] {
  producer.Close();
});

Did you have an alternative approach in mind?

pitrou · 2021-03-30T16:09:50Z

I was thinking that this would make producing a stream of futures more difficult, but perhaps that's not the case actually.

jonkeane · 2021-03-30T17:01:55Z

It looks like the test that is hanging now is https://github.com/apache/arrow/blob/master/r/tests/testthat/test-dataset.R#L1345-L1367 which interestingly is skipped on windows reported in ARROW-9651. They might be different problems / solutions, but in case it provides clues about what might be going on.

westonpace · 2021-03-31T03:34:34Z

@jonkeane That second failure I have tracked now under ARROW-12161

@pitrou Future::All, Future::AllCompleted, and Future::Any (not sure if we've made this yet) are all related but none of them are really usable here since it is a recursive operation. I think some sort of future-centric solution could be devised but I don't see at the moment how it would be any nicer that TaskGroup.

westonpace · 2021-04-05T14:59:55Z

I rebased and got rid of the R build changes (which have since been addressed by ARROW-12143)

westonpace · 2021-04-06T02:07:03Z

@pitrou R3.5 failure is known and unrelated. JNI failure & Travis failure appear to be spurious failures. Consider review/merge.

pitrou · 2021-04-06T09:44:41Z

cpp/src/arrow/filesystem/s3fs.cc

- return;
- }
- maybe_fut->AddCallback(*this);
+ auto cb = *this;


If you're capturing *this by value then you don't need to capture req and walker as well.

Removed the extraneous captures.

pitrou · 2021-04-06T09:51:54Z

cpp/src/arrow/filesystem/s3fs.cc

- Future<> future_;
- std::atomic<int32_t> num_in_flight_;
+ std::shared_ptr<TaskGroup> task_group_;
+ util::Mutex mutex_;


Is there a reason not to use std::mutex here?

Nope. For some reason I thought the old implementation was using it. I've switched it back to std::mutex.

…tasks in flight. This makes the walker thread safe so we can get rid of the mutex ARROW-12040: Slight cleanup

…arious handlers as they are not thread safe

westonpace · 2021-04-07T07:43:32Z

I believe I've addressed the PR comments, CI is green. This is ready for re-review/merge.

pitrou

+1

pitrou · 2021-04-07T09:02:37Z

@github-actions crossbow submit -g r

github-actions · 2021-04-07T10:21:39Z

Revision: df50ffe

Submitted crossbow builds: ursacomputing/crossbow @ actions-274

Task	Status
conda-linux-gcc-py36-cpu-r36
conda-linux-gcc-py37-cpu-r40
conda-osx-clang-py36-r36
conda-osx-clang-py37-r40
conda-win-vs2017-py36-r36
conda-win-vs2017-py37-r40
homebrew-r-autobrew
test-r-install-local
test-r-linux-as-cran
test-r-minimal-build
test-r-rhub-ubuntu-gcc-release
test-r-rocker-r-base-latest
test-r-rstudio-r-base-3.6-bionic
test-r-rstudio-r-base-3.6-centos7-devtoolset-8
test-r-rstudio-r-base-3.6-centos8
test-r-rstudio-r-base-3.6-opensuse15
test-r-rstudio-r-base-3.6-opensuse42
test-r-version-compatibility
test-r-versions
test-ubuntu-18.04-r-sanitizer

pitrou · 2021-04-07T13:51:23Z

Thanks a lot @westonpace , I'm merging now.

From a deadlocked run... ``` #0 0x00007f8a5d48dccd in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007f8a5d486f05 in pthread_mutex_lock () from /lib64/libpthread.so.0 #2 0x00007f8a566e7e89 in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #3 0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #4 0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #5 0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #6 0x00007f8a566e827d in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #7 0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #8 0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #9 0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #10 0x00007f8a566e74b1 in arrow::fs::(anonymous namespace)::TreeWalker::DoWalk() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so ``` The callback `ListObjectsV2Handler` is being called recursively and the mutex is non-reentrant thus deadlock. To fix it I got rid of the mutex on `TreeWalker` by using `arrow::util::internal::TaskGroup` instead of manually tracking the #/status of in-flight requests. Closes apache#9842 from westonpace/bugfix/arrow-12040 Lead-authored-by: Weston Pace <weston.pace@gmail.com> Co-authored-by: Antoine Pitrou <antoine@python.org> Signed-off-by: Antoine Pitrou <antoine@python.org>

From a deadlocked run... ``` #0 0x00007f8a5d48dccd in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007f8a5d486f05 in pthread_mutex_lock () from /lib64/libpthread.so.0 #2 0x00007f8a566e7e89 in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #3 0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #4 0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #5 0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #6 0x00007f8a566e827d in arrow::internal::FnOnce<void ()>::FnImpl<arrow::Future<Aws::Utils::Outcome<Aws::S3::Model::ListObjectsV2Result, Aws::S3::S3Error> >::Callback<arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler> >::invoke() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so #7 0x00007f8a5650efa0 in arrow::FutureImpl::AddCallback(arrow::internal::FnOnce<void ()>) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so apache#8 0x00007f8a566e67a9 in arrow::fs::(anonymous namespace)::TreeWalker::ListObjectsV2Handler::SpawnListObjectsV2() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so apache#9 0x00007f8a566e723f in arrow::fs::(anonymous namespace)::TreeWalker::WalkChild(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, int) () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so apache#10 0x00007f8a566e74b1 in arrow::fs::(anonymous namespace)::TreeWalker::DoWalk() () from /arrow/r/check/arrow.Rcheck/arrow/libs/arrow.so ``` The callback `ListObjectsV2Handler` is being called recursively and the mutex is non-reentrant thus deadlock. To fix it I got rid of the mutex on `TreeWalker` by using `arrow::util::internal::TaskGroup` instead of manually tracking the #/status of in-flight requests. Closes apache#9842 from westonpace/bugfix/arrow-12040 Lead-authored-by: Weston Pace <weston.pace@gmail.com> Co-authored-by: Antoine Pitrou <antoine@python.org> Signed-off-by: Antoine Pitrou <antoine@python.org>

westonpace force-pushed the bugfix/arrow-12040 branch from 524f5e0 to 0a556a6 Compare March 29, 2021 22:29

github-actions bot added the Component: C++ label Mar 30, 2021

github-actions bot added the Component: R label Mar 30, 2021

westonpace force-pushed the bugfix/arrow-12040 branch from 26a7da3 to 83b5bab Compare April 5, 2021 14:57

pitrou reviewed Apr 6, 2021

View reviewed changes

westonpace added 3 commits April 6, 2021 11:44

ARROW-12040: Switch to using task group instead of manually tracking …

d8d7bcd

…tasks in flight. This makes the walker thread safe so we can get rid of the mutex ARROW-12040: Slight cleanup

ARROW-12040: The mutex is still necessary to guard the calls to the v…

d81ebc2

…arious handlers as they are not thread safe

ARROW-12040: Addressing comments from PR

e362029

westonpace force-pushed the bugfix/arrow-12040 branch from 073ed9c to e362029 Compare April 6, 2021 21:50

westonpace requested a review from pitrou April 7, 2021 07:43

Nit: remove unused include

df50ffe

pitrou approved these changes Apr 7, 2021

View reviewed changes

pitrou changed the title ~~ARROW-12040: [R] [CI] [C++] test-r-rstudio-r-base-3.6-opensuse15 timing out during tests~~ ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks Apr 7, 2021

pitrou closed this in be8892e Apr 7, 2021

westonpace deleted the bugfix/arrow-12040 branch April 14, 2021 20:18

asfimport mentioned this pull request Apr 7, 2021

[R] [CI] [C++] test-r-rstudio-r-base-3.6-opensuse15 timing out during tests #27869

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks #9842

ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks #9842

westonpace commented Mar 29, 2021

github-actions bot commented Mar 30, 2021

pitrou commented Mar 30, 2021

westonpace commented Mar 30, 2021

pitrou commented Mar 30, 2021

jonkeane commented Mar 30, 2021

westonpace commented Mar 31, 2021

westonpace commented Apr 5, 2021

westonpace commented Apr 6, 2021

pitrou Apr 6, 2021

westonpace Apr 6, 2021

pitrou Apr 6, 2021

westonpace Apr 6, 2021

westonpace commented Apr 7, 2021

pitrou left a comment

pitrou commented Apr 7, 2021

github-actions bot commented Apr 7, 2021

pitrou commented Apr 7, 2021

ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks #9842

ARROW-12040: [C++] Fix potential deadlock in recursive S3 walks #9842

Conversation

westonpace commented Mar 29, 2021

github-actions bot commented Mar 30, 2021

pitrou commented Mar 30, 2021

westonpace commented Mar 30, 2021

pitrou commented Mar 30, 2021

jonkeane commented Mar 30, 2021

westonpace commented Mar 31, 2021

westonpace commented Apr 5, 2021

westonpace commented Apr 6, 2021

pitrou Apr 6, 2021

Choose a reason for hiding this comment

westonpace Apr 6, 2021

Choose a reason for hiding this comment

pitrou Apr 6, 2021

Choose a reason for hiding this comment

westonpace Apr 6, 2021

Choose a reason for hiding this comment

westonpace commented Apr 7, 2021

pitrou left a comment

Choose a reason for hiding this comment

pitrou commented Apr 7, 2021

github-actions bot commented Apr 7, 2021

pitrou commented Apr 7, 2021