GH-41149: [C++][Acero] Fix asof join race #41614

zanmato1984 · 2024-05-10T05:53:37Z

Rationale for this change

Sporadic asof join test failures have been frequently and annoyingly observed in pyarrow CI, as recorded in #40675 and #41149.

Turns out the root causes are the same - a logical race (as opposed to physical race which can be detected by sanitizers). By injecting special delay in various places in asof join, as shown in zanmato1984@ea3b24c, the issue can be reproduced almost 100%. And I have put some descriptions in that commit to explain how the race happens.

What changes are included in this PR?

Eliminate the logical race of emptiness by combining multiple call-sites of Empty().

Are these changes tested?

Include the UT to reproduce the issue.

Are there any user-facing changes?

None.

This PR contains a "Critical Fix".
In #40675 and #41149 , incorrect results are produced.

GitHub Issue: [C++][Python] Sporadic asof_join failures in PyArrow #41149
Also closes [C++][Python] Sporadic asof join test failure #40675

github-actions · 2024-05-10T05:54:02Z

Thanks for opening a pull request!

If this is not a minor PR. Could you open an issue for this pull request on GitHub? https://github.com/apache/arrow/issues/new/choose

Opening GitHub issues ahead of time contributes to the Openness of the Apache Arrow project.

Then could you also rename the pull request title in the following format?

GH-${GITHUB_ISSUE_ID}: [${COMPONENT}] ${SUMMARY}

or

MINOR: [${COMPONENT}] ${SUMMARY}

In the case of PARQUET issues on JIRA the title also supports:

PARQUET-${JIRA_ISSUE_ID}: [${COMPONENT}] ${SUMMARY}

See also:

zanmato1984 · 2024-05-10T07:39:32Z

@ursabot please benchmark

ursabot · 2024-05-10T07:39:38Z

Benchmark runs are scheduled for commit 223951e. Watch https://buildkite.com/apache-arrow and https://conbench.ursa.dev for updates. A comment will be posted here when the runs are complete.

conbench-apache-arrow · 2024-05-10T11:05:58Z

Thanks for your patience. Conbench analyzed the 7 benchmarking runs that have been run so far on PR commit 223951e.

There were 60 benchmark results indicating a performance regression:

Pull Request Run on test-mac-arm at 2024-05-10 09:19:32Z
- CopyEmptyVector (C++) with params=<SMALL_VECTOR(std::string)>, source=cpp-micro, suite=arrow-small-vector-benchmark
- BM_RleDecoding (C++) with params=65536/16, source=cpp-micro, suite=parquet-column-io-benchmark
and 58 more (see the report linked below)

The full Conbench report has more details.

zanmato1984 · 2024-05-10T15:58:46Z

@ursabot please benchmark

ursabot · 2024-05-10T15:58:52Z

Benchmark runs are scheduled for commit ade727e. Watch https://buildkite.com/apache-arrow and https://conbench.ursa.dev for updates. A comment will be posted here when the runs are complete.

zanmato1984 · 2024-05-10T18:26:36Z

@ursabot please benchmark

ursabot · 2024-05-10T18:26:45Z

Benchmark runs are scheduled for commit 606f48c. Watch https://buildkite.com/apache-arrow and https://conbench.ursa.dev for updates. A comment will be posted here when the runs are complete.

github-actions · 2024-05-10T18:30:01Z

⚠️ GitHub issue #41149 has been automatically assigned in GitHub to PR creator.

zanmato1984 · 2024-05-10T18:49:19Z

Hi @jorisvandenbossche @pitrou @westonpace , would you please help to take a look? This fix can bring python CI peace. Thanks.

conbench-apache-arrow · 2024-05-10T19:25:42Z

Thanks for your patience. Conbench analyzed the 7 benchmarking runs that have been run so far on PR commit ade727e.

There were 62 benchmark results indicating a performance regression:

Pull Request Run on ursa-thinkcentre-m75q at 2024-05-10 17:58:53Z
- ValidateSmallAscii (C++) with source=cpp-micro, suite=arrow-utf8-util-benchmark
- AsOfJoinOverhead (C++) with params=left_freq:400/left_cols:20/left_ids:100/batch_size:4000/num_right_tables:1/right_freq:400/right_cols:20/right_ids:100/real_time, source=cpp-micro, suite=arrow-acero-asof-join-benchmark
and 60 more (see the report linked below)

The full Conbench report has more details.

conbench-apache-arrow · 2024-05-10T21:45:58Z

Thanks for your patience. Conbench analyzed the 7 benchmarking runs that have been run so far on PR commit 606f48c.

There were 64 benchmark results indicating a performance regression:

Pull Request Run on test-mac-arm at 2024-05-10 19:35:34Z
- BM_RleDecoding (C++) with params=65536/16, source=cpp-micro, suite=parquet-column-io-benchmark
- ShortVectorInsertAtEnd (C++) with params=<STD_VECTOR(int)>, source=cpp-micro, suite=arrow-small-vector-benchmark
and 62 more (see the report linked below)

The full Conbench report has more details.

pitrou

It is hard to understand why this fixes the issue at all. The comments talk about an "atomic call" but I fail to see what is atomic here. This might even work by chance...

pitrou · 2024-05-13T13:13:50Z

cpp/src/arrow/acero/asof_join_node.cc

@@ -548,8 +548,10 @@ class InputState {
  // true when the queue is empty and, when memo may have future entries (the case of a
  // positive tolerance), when the memo is empty.
  // used when checking whether RHS is up to date with LHS.
-  bool CurrentEmpty() const {
-    return memo_.no_future_ ? Empty() : memo_.times_.empty() && Empty();
+  // NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the


Suggested change

// NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the

// NOTE: The emptiness must be decided by an atomic call to Empty() in caller, due to the

Also, what do you call "atomic" here? I don't see any synchronization around calls to Empty.

"single call" might be a better description.

Changed to "single call". Thanks for suggesting the new naming.

pitrou · 2024-05-13T13:14:32Z

cpp/src/arrow/acero/asof_join_node.cc

+  // NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the
+  // potential race with Push(), see GH-41614.
+  bool CurrentEmpty(bool empty) const {
+    return memo_.no_future_ ? empty : memo_.times_.empty() && empty;


Can you add parentheses to make sure operator precedence is not mistaken?

pitrou · 2024-05-13T13:17:51Z

cpp/src/arrow/acero/asof_join_node.cc

+  // Advances the RHS as far as possible to be up to date for the current LHS timestamp.
+  // Returns a pair of booleans. The first is if any RHS has advanced. The second is if
+  // all RHS are up to date for LHS.
+  Result<std::pair<bool, bool>> UpdateRhsAndCheckUpToDateWithLhs() {


Can you return a struct with explanatory member names instead?

cpp/src/arrow/acero/asof_join_node_test.cc

westonpace

I think if I understand correctly you are saying that the value returned by rhs.Empty could change (from true to false I presume?) between the UpdateRhs call and the IsUpToDateWithLhsRow call and this becomes a logic bug?

It might be easier / simpler to wrap some part of ProcessInner in a mutex that is also wrapped around state modification done by the parts of the code that add data. However, I realize that may have performance impact.

westonpace · 2024-05-13T13:38:18Z

cpp/src/arrow/acero/asof_join_node.cc

@@ -548,8 +548,10 @@ class InputState {
  // true when the queue is empty and, when memo may have future entries (the case of a
  // positive tolerance), when the memo is empty.
  // used when checking whether RHS is up to date with LHS.
-  bool CurrentEmpty() const {
-    return memo_.no_future_ ? Empty() : memo_.times_.empty() && Empty();
+  // NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the


"single call" might be a better description.

westonpace · 2024-05-13T13:39:26Z

cpp/src/arrow/acero/asof_join_node.cc

+  // NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the
+  // potential race with Push(), see GH-41614.
+  bool CurrentEmpty(bool empty) const {
+    return memo_.no_future_ ? empty : memo_.times_.empty() && empty;


Does the memo_.times_.empty() value need to be obtained in a single call as well?

Honestly I can't tell for 100% sure. But from my understanding of the code so far, we are good. Unlike the race happening on the queue_, between one side being Push and the other being Process, the memo_ seems only to be manipulated by the Process thread which is in good sync with itself.

zanmato1984 · 2024-05-13T14:38:26Z

It is hard to understand why this fixes the issue at all. The comments talk about an "atomic call" but I fail to see what is atomic here. This might even work by chance...

Thanks for looking. And sorry about the bad wording - I should've come up with a better name than "atomic call". But the issue this PR is trying to fix is carefully studied and the fix is not by chance. Maybe I should've put this more explicitly than in the PR description, the issue can be 100% reproduced by injecting special delay as shown in this commit
zanmato1984@ea3b24c, so the reason is clear enough.

I shall explain it more:
Suppose the left batch is pushed to asof join node at time 100:
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL1398
Then at time 200 the Process thread starts and in turn calls ProcessInner:
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL1034
Within ProcessInner, it first advances the right batch (necessary for emitting results) (still time 200, and it sees empty right batch):
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL967
Then at time 300 the right batch is pushed to asof join node:
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL1398
At last, time 400, ProcessInner checks if the right batch is up-to-date with the left batch (if yes, emits result):
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL974
which it should not be the case because the right batch is not advanced at time 200 (because it is not pushed yet). But in IsUpToDateWithLhsRow, it checks for emptiness again:
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL942
and
zanmato1984@ea3b24c#diff-5493b6ae7ea2a4d5cfb581034c076e9c4be7608382168de6d1301ef67b6c01eeL552
And this time, it's not empty (as the right batch is already pushed) and ProcessInner thinks "Great, you're up-to-date and let's emit some results".

As you can see this is a logical race about the right batch's emptiness between Push and ProcessInner. My original attempt to explain the fix is (improperly) describing it as an "atomic call". But as Weston suggested, maybe "single call" is better. And hope this explanation could give you more confidence on this fix :)

zanmato1984 · 2024-05-13T14:48:07Z

I think if I understand correctly you are saying that the value returned by rhs.Empty could change (from true to false I presume?) between the UpdateRhs call and the IsUpToDateWithLhsRow call and this becomes a logic bug?

Thank you Weston. Your presumption is correct. I've explained the issue in more detail in my previous reply to Antoine.

It might be easier / simpler to wrap some part of ProcessInner in a mutex that is also wrapped around state modification done by the parts of the code that add data. However, I realize that may have performance impact.

Actually I was trying to fix it using mutex, here is a single-mutex version 223951e (#41614) and a double-mutex version ade727e (#41614), both showing a up to 10% performance regression (disclaimer: it could also be the case that I'm bad at interpreting the ursabot's benchmark report). This forces me to think of a lockless fix (the current one). But if the performance down is acceptable when code complexity is a consideration, I'm totally fine to go back to the mutex solution (maybe the double-mutex one is a fair tradeoff). Any recommendation?

westonpace

I'm happy with this fix once @pitrou is content. Thanks for digging into these tricky issues.

pitrou

Thanks for the update @zanmato1984 !

conbench-apache-arrow · 2024-05-15T02:15:57Z

After merging your PR, Conbench analyzed the 7 benchmarking runs that have been run so far on merge-commit 8f27e26.

There were no benchmark performance regressions. 🎉

The full Conbench report has more details. It also includes information about 9 possible false positives for unstable benchmarks that are known to sometimes produce them.

zanmato1984 added 2 commits May 10, 2024 13:50

Test to repro

b01a03e

Fix

223951e

zanmato1984 requested a review from westonpace as a code owner May 10, 2024 05:53

github-actions bot added Component: C++ awaiting review Awaiting review labels May 10, 2024

zanmato1984 closed this May 10, 2024

Another repro

a499690

Use double locking

ade727e

zanmato1984 changed the title ~~Test to repro~~ GH-41149: [C++][Acero] Fix asof join race May 10, 2024

zanmato1984 reopened this May 10, 2024

zanmato1984 marked this pull request as draft May 10, 2024 15:59

zanmato1984 added 4 commits May 11, 2024 01:23

Lockless solution

a4a3b1d

Fix

6427ce2

Refine

6bedcb2

Format

606f48c

zanmato1984 added the Critical Fix Bugfixes for security vulnerabilities, crashes, or invalid data. label May 10, 2024

zanmato1984 marked this pull request as ready for review May 10, 2024 18:46

zanmato1984 mentioned this pull request May 10, 2024

[C++][Python] Sporadic asof join test failure #40675

Closed

pitrou requested changes May 13, 2024

View reviewed changes

github-actions bot added awaiting committer review Awaiting committer review and removed awaiting review Awaiting review labels May 13, 2024

westonpace reviewed May 13, 2024

View reviewed changes

github-actions bot added awaiting changes Awaiting changes awaiting review Awaiting review and removed awaiting committer review Awaiting committer review awaiting review Awaiting review awaiting changes Awaiting changes labels May 13, 2024

zanmato1984 added 2 commits May 13, 2024 22:53

Fix comment about "atomic call"

532d5e5

Parentheses to disambiguate operator precedence

7d15875

github-actions bot added awaiting committer review Awaiting committer review and removed awaiting review Awaiting review labels May 13, 2024

zanmato1984 added 3 commits May 13, 2024 23:53

Use meaningful struct instead of std::pair

104024e

More comments on test cases

843216e

Fix typo

1b4b21a

westonpace approved these changes May 14, 2024

View reviewed changes

github-actions bot added awaiting merge Awaiting merge and removed awaiting committer review Awaiting committer review labels May 14, 2024

pitrou approved these changes May 14, 2024

View reviewed changes

pitrou merged commit 8f27e26 into apache:main May 14, 2024
39 of 40 checks passed

pitrou removed the awaiting merge Awaiting merge label May 14, 2024

pitrou mentioned this pull request May 14, 2024

[C++][Python] Sporadic asof_join failures in PyArrow #41149

Closed

github-actions bot added the awaiting committer review Awaiting committer review label May 14, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

GH-41149: [C++][Acero] Fix asof join race #41614

GH-41149: [C++][Acero] Fix asof join race #41614

zanmato1984 commented May 10, 2024 •

edited

github-actions bot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

github-actions bot commented May 10, 2024

zanmato1984 commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

pitrou left a comment

pitrou May 13, 2024

pitrou May 13, 2024

westonpace May 13, 2024

zanmato1984 May 13, 2024

pitrou May 13, 2024

zanmato1984 May 13, 2024

pitrou May 13, 2024

zanmato1984 May 13, 2024

westonpace left a comment •

edited

westonpace May 13, 2024

westonpace May 13, 2024

zanmato1984 May 13, 2024 •

edited

zanmato1984 commented May 13, 2024

zanmato1984 commented May 13, 2024 •

edited

westonpace left a comment

pitrou left a comment

conbench-apache-arrow bot commented May 15, 2024

	// NOTE: The emptiness must be decided by an atomic all to Empty() in caller, due to the
	// NOTE: The emptiness must be decided by an atomic call to Empty() in caller, due to the

GH-41149: [C++][Acero] Fix asof join race #41614

GH-41149: [C++][Acero] Fix asof join race #41614

Conversation

zanmato1984 commented May 10, 2024 • edited

Rationale for this change

What changes are included in this PR?

Are these changes tested?

Are there any user-facing changes?

github-actions bot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

zanmato1984 commented May 10, 2024

ursabot commented May 10, 2024

github-actions bot commented May 10, 2024

zanmato1984 commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

conbench-apache-arrow bot commented May 10, 2024

pitrou left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

westonpace left a comment • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zanmato1984 May 13, 2024 • edited

Choose a reason for hiding this comment

zanmato1984 commented May 13, 2024

zanmato1984 commented May 13, 2024 • edited

westonpace left a comment

Choose a reason for hiding this comment

pitrou left a comment

Choose a reason for hiding this comment

conbench-apache-arrow bot commented May 15, 2024

zanmato1984 commented May 10, 2024 •

edited

westonpace left a comment •

edited

zanmato1984 May 13, 2024 •

edited

zanmato1984 commented May 13, 2024 •

edited