[fix][broker] ManagedCursor: mark delete no callback when create meta-ledger fail

[poorbarcode]

Fixes: #16711

Motivation

If the meta-ledger fails to be initialized when mark delete is executed, the callback of mark delete will not execute anymore. this case will occur in 1/1000 probability. You can reproduce it by doing this: "Run unit test ManagedCursorTest.markDeleteWithZKErrors 1000 times".

This problem also makes unit test ManagedCursorTest.markDeleteWithZKErrors flaky. #16711

When the problem occurs, the actual execution process is as follows:

Flow-1. The process we expect

Time	cursor mark deleted	meta thread
1	synchronized pendingMarkDeleteOps
2	check meta-ledger state
3	do create ledger
4	append to pending requests queue
4		synchronized pendingMarkDeleteOps( High light )
5		create ledger fail
6		loop pending requests, and fail callback

Flow-2. The process we did not expect. However, Thread cursor mark deleted and meta thread may be assigned to the same thread, the actual maybe execution process is as follows:

Time	cursor mark deleted/meta thread
1	synchronized pendingMarkDeleteOps
2	check meta-ledger state
3	do create ledger
4	synchronized pendingMarkDeleteOps ( High light ) reentrant lock by the same thread, which we did not expect
5	create ledger fail
6	loop pending requests, and fail callback
7	append to pending requests queue
8	waiting callback...
9	waiting callback...

• Each column means the individual threads.
• Column Time is used only to indicate the order of each step, not the actual time.
• The important steps are explained below:

step-4: If the ledger fails to be created, will trigger a "fail back" for the pending requests, and the requests that have not been queued will be ignored.

pulsar/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java

Lines 2570 to 2577 in c217b8f

	public void operationFailed(ManagedLedgerException exception) {
	log.error("[{}][{}] Metadata ledger creation failed", ledger.getName(), name, exception);
	synchronized (pendingMarkDeleteOps) {
	while (!pendingMarkDeleteOps.isEmpty()) {
	MarkDeleteEntry entry = pendingMarkDeleteOps.poll();
	entry.callback.markDeleteFailed(exception, entry.ctx);
	}

step-5 ( High light ): If the meta ledger needs to be created, create ledger will be triggered first and the current request will be put into the pending requests queue. It is possible that create ledger fail has been completed before the request is put into the queue, so this request will not get the callback anymore( see flow2 above ).

pulsar/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java

Lines 1870 to 1876 in c217b8f

	case NoLedger:
	// We need to create a new ledger to write into
	startCreatingNewMetadataLedger();
	// fall through
	case SwitchingLedger:
	pendingMarkDeleteOps.add(mdEntry);
	break;

Modifications

• Selected plain ( High light )
  Makes put request into the pending queue executed before create ledger.

• Rejected plan
  Makes put request into the pending queue and create ledger execute serially. Why rejected this plan? Because plan-1 fewer changes.

Documentation

Check the box below or label this PR directly.

Need to update docs?

• doc-required
  (Your PR needs to update docs and you will update later)

• doc-not-needed
  (Please explain why)

• doc
  (Your PR contains doc changes)

• doc-complete
  (Docs have been already added)

[poorbarcode]

@315157973 @codelipenghui @rdhabalia Could you take a look.

[codelipenghui]

step-5 ( High light ): If the meta ledger needs to be created, create ledger will be triggered first and the current request will be put into the pending requests queue. It is possible that step 4 has been completed before the request is put into the queue, so this request will not get the callback anymore.

We have synchronized (pendingMarkDeleteOps) for both create cursor failure and internalAsyncMarkDelete, if triggered the ledger creation means the left thread got the lock and the right thread can only get the lock after the mdEntry is added to the pendingMarkDeleteOps , no?

[poorbarcode]

Hi @codelipenghui

We have synchronized (pendingMarkDeleteOps) for both create cursor failure and internalAsyncMarkDelete, if triggered the ledger creation means the left thread got the lock and the right thread can only get the lock after the mdEntry is added to the pendingMarkDeleteOps , no?

According to your tips, I found a new problem: see Flow-2 above. And I have modified the Motivation.

@codelipenghui @Technoboy- @mattisonchao Could you review this PR again?

[codelipenghui]

Nice catch!

[keyboardbobo]

I also encountered a similar scenario here. The pendingMarkDeleteOps has accumulated tens of thousands of requests, and the cursor status has always been CreatingLedger, and the retention cannot be executed, resulting in the situation that the disk space cannot be reclaimed. I don't know if it's the same problem?

[poorbarcode]

@keyboardbobo

and the cursor status has always been CreatingLedger

In ManagedCursorImpl, there has not any stat names creatingLedger, I think you perhaps say ManagedCursorImpl.SwitchingLedger? Otherwise, maybe you say ManagedLedgerImpl.CreatingLedger?

I also encountered a similar scenario here. The pendingMarkDeleteOps has accumulated tens of thousands of requests, and the cursor status has always been CreatingLedger, and the retention cannot be executed, resulting in the situation that the disk space cannot be reclaimed. I don't know if it's the same problem?

• If you want to say ManagedCursorImpl.SwitchingLedger. I am afraid not. The stat of ManagedCursor will change like this(even if create ledger failure, it will not stay at SwitchingLedger), and I'll keep checking the code to see if there's anything else:

NoLedger --> SwitchingLedger --> open ledger failure --> NoLedger --> SwitchingLedger .... loop

• If you want to say ManagedLedgerImpl.CreatingLedger. Could you provide more information? It is best to submit an issue.

[mattisonchao]

Nice catch!

[poorbarcode]

/pulsarbot rerun-failure-checks

[keyboardbobo]

@poorbarcode
This is the result of the dump after the problem. As for what caused it, I am still analyzing it. If you have any ideas, please remind me

[poorbarcode]

/pulsarbot rerun-failure-checks

[poorbarcode]

Hi @keyboardbobo

If you have any ideas, please remind me

Thank you for the information，I have open a issue #16859, We can discuss there.