Skip to content

Commit

Permalink
Replace unreliable waitForTaskTreeNextFinishedRun
Browse files Browse the repository at this point in the history
This method caused various tests to fail occasionally. So it was
replaced by waitForRootActivityCompletion. (Later it may be unified
with waitForTaskActivityCompleted.)

Related changes:
- Fixed ActivityProgressInformationBuilder: it was failing in some
transient conditions.

Unrelated changes:
- Fixed (manually run) TestLdapAssociationPerformance.
  • Loading branch information
mederly committed Mar 14, 2022
1 parent 9e9b80b commit 68e2324
Show file tree
Hide file tree
Showing 14 changed files with 202 additions and 219 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -161,7 +161,7 @@ private ChildrenContinuation continuationFromFullState() {
}

private @NotNull ChildrenContinuation continuationFromDelegatedActivityState(ObjectReferenceType delegateTaskRef) {
TaskType delegateTask = getSubtask(delegateTaskRef);
TaskType delegateTask = getSubtaskIfResolvable(delegateTaskRef);
if (delegateTask == null) {
return continuation(
currentUnknown());
Expand All @@ -188,7 +188,7 @@ private ActivityProgressInformation currentUnknown() {
return unknown(activityIdentifier, activityPath);
}

private TaskType getSubtask(ObjectReferenceType subtaskRef) {
private TaskType getSubtaskIfResolvable(ObjectReferenceType subtaskRef) {
String subTaskOid = subtaskRef != null ? subtaskRef.getOid() : null;
if (subTaskOid == null) {
return null;
Expand All @@ -199,6 +199,9 @@ private TaskType getSubtask(ObjectReferenceType subtaskRef) {
}
try {
return resolver.resolve(subTaskOid);
} catch (UnsupportedOperationException e) {
LOGGER.debug("The resolver does not support resolution of subtasks. Subtask OID: {}", subTaskOid);
return null;
} catch (ObjectNotFoundException | SchemaException e) {
LoggingUtils.logException(LOGGER, "Couldn't retrieve subtask {} of {}", e, subTaskOid, task);
return null;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,14 +20,17 @@
@Experimental
public interface TaskResolver {

@NotNull TaskType resolve(String oid) throws SchemaException, ObjectNotFoundException;
/**
* @throws UnsupportedOperationException if this resolver does not support resolution of tasks
*/
@NotNull TaskType resolve(String oid) throws SchemaException, ObjectNotFoundException, UnsupportedOperationException;

/**
* Does nothing: in its typical use it assumes that all children are pre-resolved.
*/
static TaskResolver empty() {
return oid -> {
throw new IllegalStateException("Found unresolved subtask " + oid);
throw new UnsupportedOperationException("Found unresolved subtask " + oid);
};
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -258,7 +258,7 @@ public void test100Synchronize() throws Exception {
if (DISTRIBUTION == Distribution.MULTITHREADED) {
waitForTaskFinish(getSyncTaskOid(), true, 600000);
} else {
waitForTaskTreeNextFinishedRun(getSyncTaskOid(), 600000);
waitForRootActivityCompletion(getSyncTaskOid(), 600000);
}

// THEN
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -216,7 +216,7 @@ public void test100Synchronize() throws Exception {
if (DISTRIBUTION == Distribution.MULTITHREADED) {
waitForTaskFinish(getSyncTaskOid(), true, 600000);
} else {
waitForTaskTreeNextFinishedRun(getSyncTaskOid(), 600000);
waitForRootActivityCompletion(getSyncTaskOid(), 600000);
}

// THEN
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,15 +7,15 @@

package com.evolveum.midpoint.model.intest.sync;

import javax.xml.datatype.XMLGregorianCalendar;

import com.evolveum.midpoint.model.api.ModelPublicConstants;
import com.evolveum.midpoint.schema.result.OperationResult;
import com.evolveum.midpoint.schema.util.task.ActivityPath;
import com.evolveum.midpoint.schema.util.task.ActivityStateUtil;
import com.evolveum.midpoint.task.api.Task;
import com.evolveum.midpoint.test.util.TestUtil;
import com.evolveum.midpoint.util.exception.*;

import javax.xml.datatype.XMLGregorianCalendar;
import com.evolveum.midpoint.util.exception.ObjectNotFoundException;
import com.evolveum.midpoint.util.exception.SchemaException;

/**
* TODO
Expand All @@ -31,13 +31,18 @@ protected String getValidityScannerTaskFileName() {

@Override
protected void waitForValidityTaskFinish() throws Exception {
waitForTaskTreeNextFinishedRun(TASK_VALIDITY_SCANNER_OID, DEFAULT_TASK_WAIT_TIMEOUT);
waitForNextRootActivityCompletion(TASK_VALIDITY_SCANNER_OID, DEFAULT_TASK_WAIT_TIMEOUT);
}

@Override
protected void waitForValidityNextRunAssertSuccess() throws Exception {
OperationResult result = waitForTaskTreeNextFinishedRun(TASK_VALIDITY_SCANNER_OID, DEFAULT_TASK_WAIT_TIMEOUT);
TestUtil.assertSuccess(result);
Task completed = waitForNextRootActivityCompletion(TASK_VALIDITY_SCANNER_OID, DEFAULT_TASK_WAIT_TIMEOUT);
// Because of implementation reasons, we won't check the operation result of the task and all its subtasks.
// We simply check the number of errors here.
assertTask(completed, "after")
.rootActivityStateOverview()
.assertSuccess()
.assertNoErrors();
displayValidityScannerState();
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -70,10 +70,6 @@ private String getUserName(int i) {

@Test
public void test100FullRun() throws Exception {
given();
Task task = getTestTask();
OperationResult result = task.getResult();

when();

runTaskTreeAndWaitForFinish(getReconciliationTaskOid(), 30000);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -500,8 +500,8 @@ public void test210PartitionedMultinodeReconciliationWithAllFailuresEnabled() th
// 3rd account is already broken

when();
var taskBefore = addTask(TASK_RECONCILIATION_PARTITIONED_MULTINODE, result);
waitForTaskTreeNextFinishedRun(taskBefore.asObjectable(), 60000, result, true);
addTask(TASK_RECONCILIATION_PARTITIONED_MULTINODE, result);
waitForRootActivityCompletion(TASK_RECONCILIATION_PARTITIONED_MULTINODE.oid, 60000);

then();
// @formatter:off
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
import org.apache.commons.lang.StringUtils;
import org.apache.commons.lang.mutable.MutableInt;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;
import org.opends.server.types.DirectoryException;
import org.opends.server.types.Entry;
import org.springframework.beans.factory.annotation.Autowired;
Expand Down Expand Up @@ -3438,134 +3439,92 @@ public void timeout() {
return freshTask;
}

// BEWARE of race conditions: if the task starts "by itself", lastRunFinishTimestamp can be updated before waiting starts
protected OperationResult waitForTaskTreeNextFinishedRun(String rootTaskOid, int timeout) throws Exception {
final OperationResult waitResult = new OperationResult(AbstractIntegrationTest.class + ".waitForTaskTreeNextFinishedRun");
Task origRootTask = taskManager.getTaskWithResult(rootTaskOid, waitResult);
return waitForTaskTreeNextFinishedRun(origRootTask.getUpdatedTaskObject().asObjectable(), timeout, waitResult, true);
protected void runTaskTreeAndWaitForFinish(String rootTaskOid, int timeout) throws Exception {
OperationResult result = getTestOperationResult();
Task origRootTask = taskManager.getTask(rootTaskOid, null, result);
restartTask(rootTaskOid, result);
waitForRootActivityCompletion(
rootTaskOid,
origRootTask.getRootActivityCompletionTimestamp(),
timeout);
}

protected OperationResult runTaskTreeAndWaitForFinish(String rootTaskOid, int timeout) throws Exception {
protected void resumeTaskTreeAndWaitForFinish(String rootTaskOid, int timeout) throws Exception {
final OperationResult waitResult = new OperationResult(AbstractIntegrationTest.class + ".runTaskTreeAndWaitForFinish");
Task origRootTask = taskManager.getTaskWithResult(rootTaskOid, waitResult);
restartTask(rootTaskOid, waitResult);
return waitForTaskTreeNextFinishedRun(origRootTask.getUpdatedTaskObject().asObjectable(), timeout, waitResult, true);
taskManager.resumeTaskTree(rootTaskOid, waitResult);
waitForRootActivityCompletion(
rootTaskOid,
origRootTask.getRootActivityCompletionTimestamp(),
timeout);
}

protected OperationResult resumeTaskTreeAndWaitForFinish(String rootTaskOid, int timeout) throws Exception {
final OperationResult waitResult = new OperationResult(AbstractIntegrationTest.class + ".runTaskTreeAndWaitForFinish");
Task origRootTask = taskManager.getTaskWithResult(rootTaskOid, waitResult);
taskManager.resumeTaskTree(rootTaskOid, waitResult);
return waitForTaskTreeNextFinishedRun(origRootTask.getUpdatedTaskObject().asObjectable(), timeout, waitResult, false);
/**
* Simplified version of {@link #waitForRootActivityCompletion(String, XMLGregorianCalendar, int)}.
*
* To be used on tasks that are scheduled to be run in regular intervals. (So it needs not be absolutely precise:
* if the task realization completes between the method is started and the current completion timestamp is determined,
* it's no problem: the task will be started again in the near future.)
*
* @return root task in the moment of completion
*/
protected Task waitForNextRootActivityCompletion(@NotNull String rootTaskOid, int timeout) throws CommonException {
OperationResult result = getTestOperationResult();
XMLGregorianCalendar currentCompletionTimestamp = taskManager.getTaskWithResult(rootTaskOid, result)
.getRootActivityCompletionTimestamp();
return waitForRootActivityCompletion(rootTaskOid, currentCompletionTimestamp, timeout);
}

// a bit experimental
protected OperationResult waitForTaskTreeNextFinishedRun(TaskType origRootTask, int timeout, OperationResult waitResult,
boolean checkRootTaskLastStartTimestamp) throws Exception {
long origLastRunStartTimestamp = XmlTypeConverter.toMillis(origRootTask.getLastRunStartTimestamp());
long origLastRunFinishTimestamp = XmlTypeConverter.toMillis(origRootTask.getLastRunFinishTimestamp());
/**
* Simplified version of {@link #waitForRootActivityCompletion(String, XMLGregorianCalendar, int)}.
*
* To be used on tasks that were _not_ executed before. I.e. we are happy with any task completion.
*/
protected void waitForRootActivityCompletion(@NotNull String rootTaskOid, int timeout) throws CommonException {
waitForRootActivityCompletion(rootTaskOid, null, timeout);
}

long start = System.currentTimeMillis();
AtomicBoolean triggered = new AtomicBoolean(false);
OperationResult aggregateResult = new OperationResult("aggregate");
/**
* Waits for the completion of the root activity realization. Useful for task trees.
*
* TODO reconcile with {@link #waitForTaskActivityCompleted(String, long, OperationResult, long)}
*
* @param lastKnownCompletionTimestamp The completion we know about - and are _not_ interested in. If null,
* we are interested in any completion.
*/
protected Task waitForRootActivityCompletion(
@NotNull String rootTaskOid,
@Nullable XMLGregorianCalendar lastKnownCompletionTimestamp,
int timeout) throws CommonException {
OperationResult waitResult = getTestOperationResult();
Task freshRootTask = taskManager.getTaskWithResult(rootTaskOid, waitResult);
argCheck(freshRootTask.getParent() == null, "Non-root task: %s", freshRootTask);
Checker checker = () -> {
Task freshRootTask = taskManager.getTaskWithResult(origRootTask.getOid(), waitResult);

displayValue("task tree", TaskDebugUtil.dumpTaskTree(freshRootTask, waitResult));

long waiting = (System.currentTimeMillis() - start) / 1000;
String description =
freshRootTask.getName().getOrig() + " [es:" + freshRootTask.getExecutionState() + ", rs:" +
freshRootTask.getResultStatus() + ", p:" + freshRootTask.getLegacyProgress() + ", n:" +
freshRootTask.getNode() + "] (waiting for: " + waiting + " seconds)";
// was the whole task tree refreshed at least once after we were called?
long lastRunStartTimestamp = or0(freshRootTask.getLastRunStartTimestamp());
long lastRunFinishTimestamp = or0(freshRootTask.getLastRunFinishTimestamp());

if (!triggered.get() &&
checkRootTaskLastStartTimestamp &&
(lastRunStartTimestamp == origLastRunStartTimestamp
|| lastRunFinishTimestamp == origLastRunFinishTimestamp
|| lastRunStartTimestamp >= lastRunFinishTimestamp)) {
display("Current root task run has not been completed yet: " + description
+ "\n lastRunStartTimestamp=" + lastRunStartTimestamp
+ ", origLastRunStartTimestamp=" + origLastRunStartTimestamp
+ ", lastRunFinishTimestamp=" + lastRunFinishTimestamp
+ ", origLastRunFinishTimestamp=" + origLastRunFinishTimestamp);
return false;
}
triggered.set(true);

aggregateResult.getSubresults().clear();
// TODO: Could Subtasks be from previous runs?
// TODO: Could we miss runs where all subtasks are completed?
List<? extends Task> allSubtasks = freshRootTask.listSubtasksDeeply(waitResult);
for (Task subtask : allSubtasks) {
try {
subtask.refresh(waitResult); // quick hack to get operation results
} catch (ObjectNotFoundException e) {
logger.warn("Task {} does not exist any more", subtask);
}
}
if (!checkRootTaskLastStartTimestamp && allSubtasks.isEmpty()) {
display("No subtasks yet (?) => continuing waiting: " + description);
return false;
}

List<? extends Task> subtasks = TaskUtil.getLeafTasks(allSubtasks);
Task failedTask = null;
for (Task subtask : subtasks) {
/*
var subtaskStartTime = or0(subtask.getLastRunStartTimestamp());
if (subtaskStartTime < lastRunStartTimestamp) {
display("Subtask was started before we started waiting: " + description, subtask);
return false;
}
*/
// This is just to display the progress (we don't have the completion timestamp there)
assertProgress(rootTaskOid, "waiting for activity completion")
.display();

if (subtask.getSchedulingState() == TaskSchedulingStateType.READY) {
display("Found ready subtasks during waiting => continuing waiting: " + description, subtask);
return false;
}
if (subtask.getSchedulingState() == TaskSchedulingStateType.WAITING) {
display("Found waiting subtasks during waiting => continuing waiting: " + description, subtask);
return false;
}
OperationResult subtaskResult = subtask.getResult();
if (subtaskResult == null) {
display("No subtask operation result during waiting => continuing waiting: " + description, subtask);
return false;
}
if (subtaskResult.getStatus() == OperationResultStatus.IN_PROGRESS) {
display("Found 'in_progress' subtask operation result during waiting => continuing waiting: " + description, subtask);
return false;
}
if (subtaskResult.getStatus() == OperationResultStatus.UNKNOWN) {
display("Found 'unknown' subtask operation result during waiting => continuing waiting: " + description, subtask);
return false;
}
aggregateResult.addSubresult(subtaskResult);
if (subtaskResult.isError()) {
failedTask = subtask;
}
}
if (failedTask != null) {
display("Found 'error' subtask operation result during waiting => done waiting: " + description, failedTask);
return true;
}
if (freshRootTask.getSchedulingState() == TaskSchedulingStateType.WAITING) {
display("Found WAITING root task during wait for next finished run => continuing waiting: " + description);
return false;
}
return true; // all executive subtasks are closed
// Now do the real check now
freshRootTask.refresh(waitResult);
var rootState = freshRootTask.getActivityStateOrClone(ActivityPath.empty());
return rootState != null
&& rootState.getRealizationState() == ActivityRealizationStateType.COMPLETE
&& isDifferent(lastKnownCompletionTimestamp, rootState.getRealizationEndTimestamp());
};

IntegrationTestTools.waitFor("Waiting for task tree " + origRootTask + " next finished run", checker, timeout, DEFAULT_TASK_TREE_SLEEP_TIME);
Task freshTask = taskManager.getTaskWithResult(origRootTask.getOid(), waitResult);
logger.debug("Final root task:\n{}", freshTask.debugDump());
aggregateResult.computeStatusIfUnknown();
IntegrationTestTools.waitFor("Waiting for task tree " + freshRootTask + " next finished run",
checker, timeout, DEFAULT_TASK_TREE_SLEEP_TIME);
// We must NOT update the task. It should be in the "completed" state. (Because the task may be recurring,
// so updating could get the state from a subsequent run.)
logger.debug("Final root task:\n{}", freshRootTask.debugDump());
stabilize(); // TODO needed?
return aggregateResult;
return freshRootTask;
}

private boolean isDifferent(@Nullable XMLGregorianCalendar lastKnownTimestamp, XMLGregorianCalendar realTimestamp) {
return lastKnownTimestamp == null
|| !lastKnownTimestamp.equals(realTimestamp);
}

public void waitForCaseClose(CaseType aCase) throws Exception {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3252,8 +3252,8 @@ protected boolean runsInIdea() {
* Waits a little before asserting task status. This is to enable task manager to write e.g. operationStatus
* after task operation result status indicates that the handler has finished.
*/
protected void stabilize() throws InterruptedException {
Thread.sleep(500);
protected void stabilize() {
MiscUtil.sleepCatchingInterruptedException(500);
}

protected ShadowAsserter<Void> assertSelectedAccountByName(Collection<PrismObject<ShadowType>> accounts, String name) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -172,4 +172,18 @@ public ActivityStateOverviewAsserter<RA> assertPersistence(ActivityStatePersiste
assertThat(information.getPersistence()).as("persistence").isEqualTo(expected);
return this;
}

public ActivityStateOverviewAsserter<RA> assertErrors(int expected) {
assertThat(getErrors()).as("# of errors").isEqualTo(expected);
return this;
}

public ActivityStateOverviewAsserter<RA> assertNoErrors() {
return assertErrors(0);
}

public int getErrors() {
ItemsProgressInformation info = ItemsProgressInformation.fromOverview(information);
return info != null ? info.getErrors() : 0;
}
}

0 comments on commit 68e2324

Please sign in to comment.