Fixes bug with FateInterleavingIT.testInterleaving

[kevinrr888]

When working on #5130, I noticed that FateInterleavingIT.testInterleaving would sometimes fail. Realized it is a bug existing in main. This is how the test was functioning:
3 Repos to execute (FirstOp then SecondOp then LastOp) for each FateId (3 FateIds)
Each Op would have 3 steps:

• isReady() returning a deferral of 100ms, allowing other FateIds to be worked on
• isReady() executed some time after the 100ms deferral returning a deferral of 0ms (it is ready)
• call() the op is complete after this step

It seems that this test was trying to ensure that an interleave would occur every time after the first isReady(). I could be wrong, but I don't think this is guaranteed to happen (and I did not always see it happen). I can provide an example of a failure trace if desired.
For example, the test would ensure that we only saw FirstOp.call for all 3 FateIds before any other calls. However, this does not always occur.
I changed this test to no longer ensure that an interleave always occurs, just that it occurs at least once. I also ensure the correct order of operations still occur (interleaving should have no effect on the order of operations for a given FateId)

If we do expect an interleave to always occur after the first isReady(), this is not the correct fix, and there may be a problem with the FATE code...

[dlmarion]

It seems that this test was trying to ensure that an interleave would occur every time after the first isReady()

The test wasn't really created to ensure that interleaving would occur, but I created it to show that the interleaving of Fate operations was how Fate worked by default. Fate tries to advance all operations instead of working on one operation to completion before moving to the next operation. I had a PR that modified Fate to allow it to operate in an interleaving or non-interleaving mode, but it was closed based on the feedback. With the addition of thread pools per operation types, maybe it makes sense to have some operations execute in a non-interleaving fashion (run to completion), like create table or something.

[kevinrr888]

The test wasn't really created to ensure that interleaving would occur, but I created it to show that the interleaving of Fate operations was how Fate worked by default. Fate tries to advance all operations instead of working on one operation to completion before moving to the next operation

I was seeing, for example:

The test would check that all fate ops occurred before the next set of fate ops across all fate ids. For example, it would ensure FateId1, 2, and 3 would all execute FirstOp.call before any calls to SecondOp.call. This did not always occur causing failures as seen in the trace above.

Is this an expected behavior? As the test is right now, either it needs to be changed or the code it is testing needs to be changed.

[dlmarion]

I'm wondering if the recent Fate changes changed the execution order logic. For example, if you look at ZooStore.reserve in the 3.1 code (which I'm assuming was very similar to the code before the major Fate changes in 4.0, it includes some logic to make sure that the next operation that is reserved is after the last one.

accumulo/core/src/main/java/org/apache/accumulo/core/fate/ZooStore.java

Lines 159 to 164 in d0fb7f5

	// this check makes reserve pick up where it left off, so that it cycles through all as
	// it is repeatedly called.... failing to do so can lead to
	// starvation where fate ops that sort higher and hold a lock are never reserved.
	if (txdir.compareTo(lastReserved) <= 0) {
	continue;
	}

It looks like the new logic for selecting the next thing to work on is in AbstractFateStore.runnable and I'm not seeing anything like that.

[dlmarion]

Looking at your image, it appears that the code is not interleaving at all. The FateInterleavingIT class that is in 4.0 now has been modified from it's original. The original is in #3852. I'm going to try and apply that to 3.1, removing the non-interleaving test, to see what happens.

[kevinrr888]

Looking at your image, it appears that the code is not interleaving at all.

How so? There's one FATE thread executing these ops and it jumps back and forth between the 3 FateIds, is that not what is meant by "interleaving"?

[dlmarion]

Maybe I'm misunderstanding your image. If you have 3 Fate ops and 1 Fate thread, then the execution order would have been the following in past versions of the code:

FirstOp.isReady
SecondOp.isReady
ThirdOp.isReady
FirstOp.call
SecondOp.call
ThirdOp.call

The Fate thread is making sure that all transactions make progress. I'm used the word "interleave" as in to mix, or alternate. Whereas in a non-interleaving or non-alternating scenario the Fate thread would run each Fate operation to completion before starting on the next Fate operation. In the non-alternating scenario, it would look like:

FirstOp.isReady
FirstOp.call
SecondOp.isReady
SecondOp.call
ThirdOp.isReady
ThirdOp.call

[kevinrr888]

If you have 3 Fate ops and 1 Fate thread, then the execution order would have been the following in past versions of the code:
FirstOp.isReady
SecondOp.isReady
ThirdOp.isReady
FirstOp.call
SecondOp.call
ThirdOp.call

How would SecondOp.isReady be called before FirstOp.call? FirstOp.call returns SecondOp, so SecondOp.isReady has to execute after FirstOp.call

[kevinrr888]

I'm wondering if the recent Fate changes changed the execution order logic. For example, if you look at ZooStore.reserve in the 3.1 code (which I'm assuming was very similar to the code before the major Fate changes in 4.0, it includes some logic to make sure that the next operation that is reserved is after the last one.

Yeah, its possible something has been lost/broken, which was the main motivation for this PR.

[dlmarion]

Sorry, you are right, it's been a while since I wrote this test. So, it should be that all of the FirstOp's would complete, then all of the SecondOps would complete, then all of the ThirdOps should complete. I just backported the test to 3.1 and ran it and the tracking table contains:

1735919276619 TXID:3759954868187127084: [] 1735919276640 false -> FirstOp::isReady
1735919277144 TXID:3759954868187127084: [] 1735919277146 false -> FirstOp::call
1735919277660 TXID:8428227940724651079: [] 1735919277663 false -> FirstOp::isReady
1735919278166 TXID:8428227940724651079: [] 1735919278168 false -> FirstOp::call
1735919278672 TXID:1009699229530621992: [] 1735919278675 false -> FirstOp::isReady
1735919279178 TXID:1009699229530621992: [] 1735919279180 false -> FirstOp::call
1735919279684 TXID:3759954868187127084: [] 1735919279687 false -> SecondOp::isReady
1735919280188 TXID:3759954868187127084: [] 1735919280191 false -> SecondOp::call
1735919280695 TXID:8428227940724651079: [] 1735919280697 false -> SecondOp::isReady
1735919281199 TXID:8428227940724651079: [] 1735919281201 false -> SecondOp::call
1735919281704 TXID:1009699229530621992: [] 1735919281707 false -> SecondOp::isReady
1735919282208 TXID:1009699229530621992: [] 1735919282210 false -> SecondOp::call
1735919282714 TXID:3759954868187127084: [] 1735919282716 false -> LastOp::isReady
1735919283217 TXID:3759954868187127084: [] 1735919283220 false -> LastOp::call
1735919283728 TXID:8428227940724651079: [] 1735919283731 false -> LastOp::isReady
1735919284232 TXID:8428227940724651079: [] 1735919284234 false -> LastOp::call
1735919284744 TXID:1009699229530621992: [] 1735919284746 false -> LastOp::isReady
1735919285248 TXID:1009699229530621992: [] 1735919285250 false -> LastOp::call

[dlmarion]

Backported FateInterleavingIT to 3.1 in #5223

[kevinrr888]

Yeah, that looks like the expected order.
Again, I only saw this failure occasionally on 4.0, but it doesn't seem like something that should ever be failing. This failure may also be occurring in 3.x, I haven't run the test there to see.

Wondering if something is not working as expected in FATE, or something is wrong with the test (which is what I attempted to change in this PR).

[dlmarion]

Looking at:

accumulo/core/src/main/java/org/apache/accumulo/core/fate/AbstractFateStore.java

Lines 182 to 203 in b63690a

	try (Stream<FateIdStatus> inProgress = getTransactions(IN_PROGRESS_SET);
	Stream<FateIdStatus> other = getTransactions(OTHER_RUNNABLE_SET)) {
	// read the in progress transaction first and then everything else in order to process those
	// first
	var transactions = Stream.concat(inProgress, other);
	transactions.filter(fateIdStatus -> isRunnable(fateIdStatus.getStatus()))
	.filter(fateIdStatus -> {
	var fateId = fateIdStatus.getFateId();
	var deferredTime = deferred.get(fateId);
	if (deferredTime != null) {
	if (deferredTime.isExpired()) {
	deferred.remove(fateId);
	} else {
	return false;
	}
	}
	return fateIdStatus.getFateReservation().isEmpty();
	}).forEach(fateIdStatus -> {
	seen.incrementAndGet();
	idConsumer.accept(fateIdStatus.getFateId());
	});
	}

If the inProgress set is empty, I don't see anything that prevents the transaction selected from other to have a transaction id greater than the previously selected transaction id.

[keith-turner]

The fate code in 4.0 will run as many steps as possible in a fate op as long as isReady keeps returning zero. The code in 3.1 and 2.1 will only run a single step at a time and switch to something else even if the next step isReady.

Since this test has a single fate thread for the case of when 0 is always returned for isReady then it should never interleave. For the case where isReady returns non zero it should interleave if possible, but it is not guaranteed to happen in the strict way this test is looking for. I ran the test and saw a situation like the following happen.

1. Test thread adds Fate1
2. Test thread adds Fate2
3. Fate threads looks for work, sees Fate1 and Fate2 and run their isReady methods. So the clock is already counting down on those.
4. Test thread adds Fate3
5. Fate threads looks for work and sees Fate1,Fate2,Fate3.

In the above situation the fact that the fate threads saw some of the work before all of the work was added throws off what the test is looking for. Another thing that I saw throw off the test was fate operations taking longer than they slept for. For example the isReady method sleeps for 50ms, but it could actually take 400ms to run which has a cascading impact on the expectations of the test.

I think the test is trying to ensure that when isReady returns non zero that fate does switch to work other things. However the way its doing it is to strict so it does seem good to relax it. Since this test is dealing w/ multithreading something like the following could happen (although it has a really low probability).

1. Test thread adds Fate1
2. Fate threads runs Fate1 through all of its steps.
3. Test threads adds Fate2
4. Fate threads runs Fate2 through all of its steps
5. Test threads adds Fate3
6. Fate threads runs Fate3 through all of its steps

In this example if the test thread is running really slowly and fate threads are running fast then no interleaving would happen and that would not indicate a bug in the code. This could happen on an overloaded test server.

Maybe for the interleaving test the Fate.isReady calls could only return 0 when its seen the other two have executed isReady. Like Fate1 step1 would only return 0 for is ready if its seen Fate2 and Fate3 have run isReady. Then if the code was not switching between fate ops that were returning non-zero of isReady the test wold get stuck forever. That may be overkill though, changing the test look for some interleaving is probably good. Normally some interleaving will happen.

[keith-turner]

Wondering if it would be better to relax this and look for any interleaving of FateIds in the sequence of operations. This would increment the interleave counter in more cases.

Suggested change

	if (prevOp != null && prevOp.getValue().contains("isReady1")
	&& !currOp.equals(new AbstractMap.SimpleImmutableEntry<>(prevOp.getKey(),
	prevOp.getValue().replace('1', '2')))) {
	interleaves++;
	}
	// is the current operation passed its first step?
	boolean passedFirtStep = !currStep.equals(expRunOrder.get(0));
	// was the previous op a different fate id?
	boolean prevFateIdDiffered = prevOp != null && !prevOp.getKey().equals(fateId);
	if(passedFirstStep && prevFateIdDiffered){
	interleaves++;
	}

[kevinrr888]

Added, this is quite a bit easier to read too

[dlmarion]

I wonder if the best solution here is to remove FateInterleavingIT in main and close #5223 (backport to 3.1). FateInterleavingIT was created as part of PR #3852 where I wanted to change the default behavior of some Fate operations such that they would run to competion. Since that time and the introduction of FateInterleavingIT the Fate implementation has changed and the default behavior has changed. If we want to create a test for the expected execution order of Fate transactions, then we should likely create that and remove FateInterleavingIT. If we don't need a test for the expected execution order, then we should remove FateInterleavingIT and not fix it. In both cases, FateInterleavingIT is OBE and should be removed. I think we have sufficient coverage ensuring that Fate transactions complete, so this is really about the execution order.

[keith-turner]

. If we want to create a test for the expected execution order of Fate transactions, then we should likely create that and remove FateInterleavingIT.

Testing execution order is really nice and the changes to this test are adding that. If fate called Repo.call after Repo.isReady returned non zero it would be nice to catch that bug and the changes in this test would have chance of doing that. So testing the following is good and the changes in this PR are doing that with the comparisons to the new expRunOrder list.

1. Fate should call Repo.isReady as long it returns non zero
2. Fate should always call Repo.isReady at least once before Repo.call
3. Only when Fate sees zero returned by Repo.isReady it should execute Repo.call.

Testing not interleaving and interleaving is also nice. However, only the not interleaving case can be tested deterministically in 4.0. For the case where isReady always returns zero we should never see interleaving and we should see things happen in the expected order per fate op. For the case were isReady is returning non-zero the fate threads should switch to work on something else, but that may not be observed because of timing issues. So maybe we should test execution order and non interleaving and chuck the interleaving test. Does seem the name of the test should change to be FateExecutionOrderIT or something like that.

[kevinrr888]

Based on the discussion, it seems like:

1. This failure is a problem with the test, not the FATE code which is good news
2. We are unsure what to do about FateInterleavingIT. I personally think it would be best to keep FateInterleavingIT. It is testing an aspect of FATE that is otherwise not tested. Since the FATE code has since changed to no longer adhere to the strict constraints this test originally assumed, we should just update the test like in this PR, not remove the test entirely. FATE should still be interleaving at least sometimes when isReady returns > 0 and FATE should be executing the operations in the correct order per fateop, interleaving or not. We would lose this functionality check if this test is removed.
3. Should we remove the interleaving test keeping the non-interleaving test? I think we should still be testing this. In this PR, we just ensure an interleave occurs at least once. This is highly unlikely to fail (and we can decrease the likelihood of failure even more by running this test with more FateIds if we want). Seeing a test failure for this would much more likely mean that something is wrong with the functionality of FATE, which we would lose if we don't test this case. We could also go with the solution Keith proposed here for the interleaving test.
4. Rename the test? I think renaming the test to FateExecutionOrderIT is a good idea.

[keith-turner]

The use of a List here is really subtle in its importance to verify the correctness of the observed data. A comment would be good to make its importance more prominent.

Suggested change

	var expectedVals = List.of("FirstNonInterleavingOp::isReady", "FirstNonInterleavingOp::call",
	// In addition to ensuring the expected fate operations happened also want to ensure they happened in a specific order, this why a List was used.
	var expectedVals = List.of("FirstNonInterleavingOp::isReady", "FirstNonInterleavingOp::call",

[keith-turner]

Should we remove the interleaving test keeping the non-interleaving test? I think we should still be testing this

Could keep the test for now and see if it causes problems and remove it later if it does. Could add a comment linking to this PR.

[kevinrr888]

This PR is now up to date with requested changes.
Let me know if any further changes are desired or if there are still concerns.

[dlmarion]

@kevinrr888 - I merged #5223 into 3.1, then I removed the FateExecutionOrderIT file on the merge to main. Please rename FateInterleavingIT to FateExecutionOrderIT in this PR.

[kevinrr888]

@dlmarion I was holding off on re-reviewing that until this received approval, that way we could better decide what the backport would look like. I looked over the merged PR, and it seems it is missing an interleaving test. testDefaultInterleaving is the only test but that only has ops with isReady() calls which always return 0, so interleaving will never occur (EDIT: or maybe the FATE interleaving functionality is different on 3.1?). Is there a reason not to include an interleaving test in 3.1? Also, I think #5223 (comment) would still be important to include to ensure isReady() calls always come before call() calls.

I merged #5223 into 3.1, then I removed the FateExecutionOrderIT file on the merge to main. Please rename FateInterleavingIT to FateExecutionOrderIT in this PR.

Thank you, I have renamed it in this PR.

EDIT2:

The fate code in 4.0 will run as many steps as possible in a fate op as long as isReady keeps returning zero. The code in 3.1 and 2.1 will only run a single step at a time and switch to something else even if the next step isReady.

From earlier comment from Keith, so my comments on the missing interleaving test can be ignored.

[dlmarion]

@kevinrr888 - Just read your prior comment (and edits). We are good? I think the test in 3.1 is good as-is, as it tests the fate execution order in 3.1. The fate execution order in 4.0 is different. But in both branches, even though the order is different, there is only one way it works. The reason that the test name in 3.1 is testDefaultInterleaving is because I copied this from a test in PR where I was trying to create two ways Fate execution order could work. I will put up a PR for 3.1 that just changes the name of the test method to remove any confusion.

[dlmarion]

@kevinrr888 - test method rename in #5280

[kevinrr888]

Yes all good. Only thing is maybe could add this: #5223 (comment). This would catch the case where call() occurs before isReady() if that were to somehow ever occur from drastically wrong changes to FATE. Leaving as is is fine too.
I think the rename is good.