[fix][txn] fix txn coordinator recover handle committing and aborting txn race condition. #19201

thetumbled · 2023-01-12T04:32:44Z

Fixes #19200

Motivation

transaction lasted for long time and will not be aborted, which cause TB's MaxReadPosition do not move and will not take snapshot. With an old snapshot, TB will read a lot of entry while doing recovery.
In worst cases, there are 30 minutes of unavailable time with Topics.

Modifications

~~make CoordinatorNotFoundException retryable.~~
avoid concurrent execution.

Verifying this change

Make sure that the change passes the CI checks.

(Please pick either of the following options)

This change is a trivial rework / code cleanup without any test coverage.

Does this pull request potentially affect one of the following parts:

If the box was checked, please highlight the changes

Documentation

doc
doc-required
doc-not-needed
doc-complete

Matching PR in forked repository

PR in forked repository: thetumbled#12

thetumbled · 2023-01-12T06:18:12Z

Maybe there is a better way to fix it?
for example, move following code

stores.put(tcId, store);

from org.apache.pulsar.broker.TransactionMetadataStoreService#handleTcClientConnect to org.apache.pulsar.transaction.coordinator.TransactionLogReplayCallback#replayComplete

congbobo184 · 2023-01-13T12:29:45Z

if the TC does not exist in the broker, the op doesn't need to retry. #18924 may has fix this problem

thetumbled · 2023-01-13T12:51:34Z

if the TC does not exist in the broker, the op doesn't need to retry. #18924 may has fix this problem

I have include this PR in my test enviroment, and exceptions above have been throwed. That PR do not gurantee that TC have been put into stores map before executing handleCommittingAndAbortingTransaction because of concurrent executing.
TC may exist in the broker, but just not been put into stores map.

congbobo184 · 2023-01-15T16:49:01Z

@thetumbled

pulsar/pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

Lines 136 to 137 in 246c270

    
           openTransactionMetadataStore(tcId).thenAccept((store) -> internalPinnedExecutor.execute(() -> { 
        
               stores.put(tcId, store);

the future thenAccept change the executing thread, so the problem has never been truth fixed.

so its better to change code like this can slove this problem

                        openTransactionMetadataStore(tcId).thenAccept((store) -> {
                            stores.put(tcId, store);
                            internalPinnedExecutor.execute(() -> {

thetumbled · 2023-01-16T04:27:23Z

@thetumbled

pulsar/pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

Lines 136 to 137 in 246c270

openTransactionMetadataStore(tcId).thenAccept((store) -> internalPinnedExecutor.execute(() -> {

stores.put(tcId, store);

the future thenAccept change the executing thread, so the problem has never been truth fixed.
so its better to change code like this can slove this problem
                        openTransactionMetadataStore(tcId).thenAccept((store) -> {
                            stores.put(tcId, store);
                            internalPinnedExecutor.execute(() -> {

good idea. i have changed the patch.

codelipenghui · 2023-01-16T08:55:33Z

@thetumbled It looks like the change is not about the issue that you described in the PR details. When reading the motivation of the PR, I thought it was related to the transaction buffer snapshot, but after checking the changes, it looks like the fix is for the transaction coordinator.

thetumbled · 2023-01-16T09:01:35Z

@thetumbled It looks like the change is not about the issue that you described in the PR details. When reading the motivation of the PR, I thought it was related to the transaction buffer snapshot, but after checking the changes, it looks like the fix is for the transaction coordinator.

When I was troubleshooting why transaction recovery took a long time, I found that the root cause is some transactions cannot be terminated though exceeding timeout, which leads to subsequent phenomena.

codelipenghui · 2023-01-28T12:54:14Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

-                            completableFuture.complete(null);
-                            tcLoadSemaphore.release();
-                        })).exceptionally(e -> {
+                                completableFuture.complete(null);


@congbobo184 @thetumbled Sorry, I didn't get the key point of the problem. The completableFuture is completed by the same thread of executing stores.put(tcId, store); Why will we have race condition here? The client-side should send the end transaction command after completing the TC connect stage.

There are two thread pools org.apache.pulsar.transaction.coordinator.impl.MLTransactionMetadataStore#internalPinnedExecutor and org.apache.pulsar.broker.TransactionMetadataStoreService#internalPinnedExecutor. They are different.

Yes, but before we complete the completableFuture here, we have added the item to the map. Why the subsequent request is not able to get from the map? The subsequent request only happened after the completableFuture was done, right? And the map is a ConcurrentHashMap, so what is the race condition here? Could you please provide more details about the race condition? How does it happen?

The completableFuture return by openTransactionMetadataStore(tcId) is completed by following code in thread MLTransactionMetadataStore#internalPinnedExecutor.

**completableFuture.complete(MLTransactionMetadataStore.this);** recoverTracker.handleCommittingAndAbortingTransaction();

Once the completableFuture is completed, stores.put will be executed in another thread TransactionMetadataStoreService#internalPinnedExecutor.

openTransactionMetadataStore(tcId).thenAccept((store) -> internalPinnedExecutor.execute(() -> { stores.put(tcId, store);

So, we may execute recoverTracker.handleCommittingAndAbortingTransaction() before execute stores.put(tcId, store).

Essentially this is a circular dependency problem.

TransactionMetadataStoreService.handleTcClientConnect -> MLTransactionMetadataStore.init -> TransactionRecoverTracker.handleCommittingAndAbortingTransaction -> TransactionMetadataStoreService.handleTcClientConnect

It looks like we need to ensure some state is changed in TransactionMetadataStoreService during init MLTransactionMetadataStore.

IMO, we should refactor this part finally to move the recoverTracker.handleCommittingAndAbortingTransaction(); to the TransactionMetadataStoreService to decouple the mutual state dependence.

@congbobo184 @liangyepianzhou WDYT?

It's hard to understand why the map put operation should be executed out of the internalPinnedExecutor while reading the code. This may present challenges for future maintenance.

openTransactionMetadataStore(tcId) can return MutablePair<store, recoverTracker> or after openTransactionMetadataStore(tcId) then init return the recoverTracker. I prefer to use the second way, in this way the logical more clear, after store init the tracker need to do something to handle the legacy the committing and abort transactions.

the first solution is more concise, and i have implement it.
As for the second approach, do you means that move init method out of openTransactionMetadataStore method?

yes, in the second way can completely decoupled. @codelipenghui WDYT?

Sorry, I haven't got the point of openTransactionMetadataStore(tcId) then init return the recoverTracker, @congbobo184 Can you share the link?

pulsar/pulsar-transaction/coordinator/src/main/java/org/apache/pulsar/transaction/coordinator/impl/MLTransactionMetadataStore.java

Line 108 in 3bab099

public CompletableFuture<TransactionMetadataStore> init(TransactionRecoverTracker recoverTracker) {

change to public CompletableFuture<TransactionRecoverTracker> init()

openTransactionMetadataStore(tcId) only return the store,

then the store can add a interface public CompletableFuture<TransactionRecoverTracker> init(),

TransactionMetadataStoreService can invoke the store.init() return TransactionRecoverTracker

init completely, recoverTracker can do

pulsar/pulsar-transaction/coordinator/src/main/java/org/apache/pulsar/transaction/coordinator/TransactionRecoverTracker.java

Line 47 in 3bab099

void appendOpenTransactionToTimeoutTracker();

pulsar/pulsar-transaction/coordinator/src/main/java/org/apache/pulsar/transaction/coordinator/TransactionRecoverTracker.java

Line 52 in 3bab099

void handleCommittingAndAbortingTransaction();

in the TransactionMetadataStoreService

…ice to decouple the mutual state dependence.

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

codelipenghui

Looks good to me now.
I just left some minor comments.

...inator/src/main/java/org/apache/pulsar/transaction/coordinator/TransactionMetadataStore.java

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

codelipenghui · 2023-01-30T09:49:47Z

@congbobo184 @liangyepianzhou Please help review again.

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

codecov-commenter · 2023-01-30T11:39:48Z

Codecov Report

Merging #19201 (c7c2455) into master (4b0dc9a) will increase coverage by 11.74%.
The diff coverage is 47.36%.

@@              Coverage Diff              @@
##             master   #19201       +/-   ##
=============================================
+ Coverage     48.96%   60.71%   +11.74%     
- Complexity     7300    25533    +18233     
=============================================
  Files           424     1895     +1471     
  Lines         45473   137527    +92054     
  Branches       4672    15099    +10427     
=============================================
+ Hits          22268    83503    +61235     
- Misses        20698    46300    +25602     
- Partials       2507     7724     +5217

Flag	Coverage Δ
systests	`24.80% <0.00%> (?)`
unittests	`58.80% <47.36%> (+9.83%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
...va/org/apache/pulsar/broker/service/ServerCnx.java	`52.23% <ø> (+9.39%)`	⬆️
...n/coordinator/impl/MLTransactionMetadataStore.java	`75.64% <ø> (ø)`
...pulsar/broker/TransactionMetadataStoreService.java	`58.69% <47.36%> (+6.73%)`	⬆️
...ice/streamingdispatch/PendingReadEntryRequest.java	`0.00% <0.00%> (-68.19%)`	⬇️
...ervice/streamingdispatch/StreamingEntryReader.java	`0.00% <0.00%> (-60.24%)`	⬇️
...istentStreamingDispatcherSingleActiveConsumer.java	`0.00% <0.00%> (-50.52%)`	⬇️
...ersistentStreamingDispatcherMultipleConsumers.java	`0.00% <0.00%> (-45.55%)`	⬇️
...ker/loadbalance/impl/LeastLongTermMessageRate.java	`73.33% <0.00%> (-20.00%)`	⬇️
...lsar/broker/loadbalance/impl/ThresholdShedder.java	`27.04% <0.00%> (-3.28%)`	⬇️
...balance/impl/SimpleResourceAllocationPolicies.java	`51.42% <0.00%> (-2.86%)`	⬇️
... and 1591 more

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java

… txn race condition. (#19201) Fixes #19200 transaction lasted for long time and will not be aborted, which cause TB's MaxReadPosition do not move and will not take snapshot. With an old snapshot, TB will read a lot of entry while doing recovery. In worst cases, there are 30 minutes of unavailable time with Topics. avoid concurrent execution.

… txn race condition. (#19201) Fixes #19200 transaction lasted for long time and will not be aborted, which cause TB's MaxReadPosition do not move and will not take snapshot. With an old snapshot, TB will read a lot of entry while doing recovery. In worst cases, there are 30 minutes of unavailable time with Topics. avoid concurrent execution. (cherry picked from commit 96f4161)

… txn race condition. (apache#19201) Fixes apache#19200 transaction lasted for long time and will not be aborted, which cause TB's MaxReadPosition do not move and will not take snapshot. With an old snapshot, TB will read a lot of entry while doing recovery. In worst cases, there are 30 minutes of unavailable time with Topics. avoid concurrent execution. (cherry picked from commit 96f4161) (cherry picked from commit 5dd13ec)

coderzc · 2023-03-02T09:58:23Z

@thetumbled Can you help cherry-pick this PR to branch-2.9?

thetumbled · 2023-03-02T10:03:06Z

@thetumbled Can you help cherry-pick this PR to branch-2.9?

ok.

…ng and aborting txn race condition. #19201 (#19699) Cherry-pick: #19201

…ng and aborting txn race condition. apache#19201 (apache#19699) Cherry-pick: apache#19201

fix timeout transaction.

dfe8e70

github-actions bot added the doc-not-needed Your PR changes do not impact docs label Jan 12, 2023

thetumbled mentioned this pull request Jan 12, 2023

[fix] [broker] fix timeout transaction. thetumbled/pulsar#12

Closed

change patch way.

3ff9ceb

codelipenghui assigned congbobo184 and thetumbled and unassigned congbobo184 Jan 16, 2023

codelipenghui added this to the 2.12.0 milestone Jan 16, 2023

codelipenghui added release/2.11.1 release/2.9.5 release/2.10.4 labels Jan 16, 2023

codelipenghui requested review from congbobo184 and liangyepianzhou and removed request for liangyepianzhou January 16, 2023 08:47

congbobo184 changed the title ~~[fix] [broker] fix timeout transaction.~~ [fix][txn] fix txn coordinator recover handle committing and aborting txn race condition. Jan 16, 2023

congbobo184 approved these changes Jan 16, 2023

View reviewed changes

liangyepianzhou approved these changes Jan 16, 2023

View reviewed changes

codelipenghui requested changes Jan 28, 2023

View reviewed changes

thetumbled added 2 commits January 30, 2023 14:38

change patch way, move recoverTracker to TransactionMetadataStoreServ…

1cf93c2

…ice to decouple the mutual state dependence.

fix.

2a8f405

codelipenghui reviewed Jan 30, 2023

View reviewed changes

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java Outdated Show resolved Hide resolved

change.

426883f

codelipenghui reviewed Jan 30, 2023

View reviewed changes

...inator/src/main/java/org/apache/pulsar/transaction/coordinator/TransactionMetadataStore.java Outdated Show resolved Hide resolved

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java Show resolved Hide resolved

fix.

e9f2f30

thetumbled force-pushed the fixbug_TransactionTimeout branch from 449d962 to e9f2f30 Compare January 30, 2023 09:25

codelipenghui approved these changes Jan 30, 2023

View reviewed changes

codelipenghui added the ready-to-test label Jan 30, 2023

congbobo184 reviewed Jan 30, 2023

View reviewed changes

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java Outdated Show resolved Hide resolved

thetumbled added 2 commits January 30, 2023 18:15

fix.

1a1e07b

fix check.

d5199ae

congbobo184 reviewed Jan 31, 2023

View reviewed changes

pulsar-broker/src/main/java/org/apache/pulsar/broker/TransactionMetadataStoreService.java Show resolved Hide resolved

fix.

c7c2455

congbobo184 merged commit 96f4161 into apache:master Feb 1, 2023

Technoboy- added the cherry-picked/branch-2.11 label Feb 8, 2023

liangyepianzhou added the cherry-picked/branch-2.10 label Feb 9, 2023

thetumbled mentioned this pull request Mar 3, 2023

[cherry-pick][branch-2.9] fix txn coordinator recover handle committing and aborting txn race condition. #19201 #19699

Merged

4 tasks

coderzc pushed a commit that referenced this pull request Mar 3, 2023

[cherry-pick][branch-2.9] fix txn coordinator recover handle committi…

24584a3

…ng and aborting txn race condition. #19201 (#19699) Cherry-pick: #19201

coderzc added the cherry-picked/branch-2.9 Archived: 2.9 is end of life label Mar 3, 2023

Annavar-satish pushed a commit to pandio-com/pulsar that referenced this pull request Mar 6, 2023

[cherry-pick][branch-2.9] fix txn coordinator recover handle committi…

88c87a1

…ng and aborting txn race condition. apache#19201 (apache#19699) Cherry-pick: apache#19201

[fix][txn] fix txn coordinator recover handle committing and aborting txn race condition. #19201

[fix][txn] fix txn coordinator recover handle committing and aborting txn race condition. #19201

Uh oh!

Conversation

thetumbled commented Jan 12, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Motivation

Modifications

Verifying this change

Does this pull request potentially affect one of the following parts:

Documentation

Matching PR in forked repository

Uh oh!

thetumbled commented Jan 12, 2023

Uh oh!

congbobo184 commented Jan 13, 2023

Uh oh!

thetumbled commented Jan 13, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

congbobo184 commented Jan 15, 2023

Uh oh!

thetumbled commented Jan 16, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

codelipenghui commented Jan 16, 2023

Uh oh!

thetumbled commented Jan 16, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

codelipenghui Jan 28, 2023

Choose a reason for hiding this comment

Uh oh!

thetumbled Jan 29, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

codelipenghui Jan 29, 2023

Choose a reason for hiding this comment

Uh oh!

thetumbled Jan 29, 2023

Choose a reason for hiding this comment

Uh oh!

codelipenghui Jan 29, 2023

Choose a reason for hiding this comment

Uh oh!

congbobo184 Jan 30, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thetumbled Jan 30, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

congbobo184 Jan 30, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

codelipenghui Jan 30, 2023

Choose a reason for hiding this comment

Uh oh!

congbobo184 Jan 30, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

codelipenghui left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

codelipenghui commented Jan 30, 2023

Uh oh!

Uh oh!

codecov-commenter commented Jan 30, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

Uh oh!

coderzc commented Mar 2, 2023

Uh oh!

thetumbled commented Jan 12, 2023 •

edited

Loading

thetumbled commented Jan 13, 2023 •

edited

Loading

thetumbled commented Jan 16, 2023 •

edited

Loading

thetumbled commented Jan 16, 2023 •

edited

Loading

thetumbled Jan 29, 2023 •

edited

Loading

congbobo184 Jan 30, 2023 •

edited

Loading

thetumbled Jan 30, 2023 •

edited

Loading

congbobo184 Jan 30, 2023 •

edited

Loading

codecov-commenter commented Jan 30, 2023 •

edited

Loading