TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun #5658

XinruZhang · 2022-10-18T20:39:00Z

Changes

I'm openning this PR as a tentative solution to address #5653:

TL;DR: TestWaitCustomTask_PipelineRun/Wait_Task_Retries_on_Timeout has been flaky for a while. This PR stops the PipelineRun reconciler from cancelling Run when it detects that the task-level Timeout configured for the Run has passed, which will address the flake (similar to #5134 which addresses TestPipelineRunTimeout).

Some other useful information, many thanks to @abayer, @lbernick and @jerop:

Run should only be canceled when
- The PipelineRun as a whole has timed out, either due to PipelineRun.Spec.Timeout's value or PipelineRun.Spec.Timeouts.Pipeline's value.
- It's a non-finally PipelineTask, PipelineRun.Spec.Timeouts.Tasks is set, and that value has elapsed.
- It's a finally PipelineTask, PipelineRun.Spec.Timeouts.Finally is set, and that value has elapsed.
For TaskRun, pipelinerun reconciler don't cancel it when it times out.

This change only applies to task-level Timeout, i.e. when PipelineTask.Timeout is set for a Run.

cc @pritidesai Will this commit have any other side effect?

Submitter Checklist

As the author of this PR, please check off the items in this checklist:

Has Docs included if any changes are user facing
Has Tests included if any functionality added or changed
Follows the commit message standard
Meets the Tekton contributor standards (including
functionality, content, code)
Has a kind label. You can add one by adding a comment on this PR that contains /kind <type>. Valid types are bug, cleanup, design, documentation, feature, flake, misc, question, tep
Release notes block below has been updated with any user facing changes (API changes, bug fixes, changes requiring upgrade notices or deprecation warnings)
Release notes contains the string "action required" if the change requires additional action from users switching to the new release

Release Notes

ACTION REQUIRED: Starting from this release, Custom Task Runs controllers need to implement the `Timeout` on your own,  PipelineRun reconciler would not set `Run.Spec.Status == RunCancelled` upon Run timeout.

XinruZhang · 2022-10-18T20:40:41Z

/kind flake

tekton-robot · 2022-10-18T20:43:59Z

The following is the coverage report on the affected files.
Say /test pull-tekton-pipeline-go-coverage to re-run this coverage report

File	Old Coverage	New Coverage	Delta
pkg/reconciler/pipelinerun/pipelinerun.go	85.2%	85.6%	0.4

tekton-robot · 2022-10-19T19:52:32Z

The following is the coverage report on the affected files.
Say /test pull-tekton-pipeline-go-coverage to re-run this coverage report

File	Old Coverage	New Coverage	Delta
pkg/reconciler/pipelinerun/pipelinerun.go	85.0%	85.4%	0.4

abayer · 2022-10-19T19:56:02Z

Run should only be canceled when its uplevel PipelineRun is timed out

A clarification: a Run is cancelled for timing out when any of the following are true:

The PipelineRun as a whole has timed out, either due to PipelineRun.Spec.Timeout's value or PipelineRun.Spec.Timeouts.Pipeline's value.
It's a non-finally PipelineTask, PipelineRun.Spec.Timeouts.Tasks is set, and that value has elapsed.
It's a finally PipelineTask, PipelineRun.Spec.Timeouts.Finally is set, and that value has elapsed.

jerop

Thank you @XinruZhang for looking into this flake!

Please update the release notes to reflect that, with this change, implementors of Runs would have to fully implement Run timeouts themselves - PipelineRun reconciler would not set Run.Spec.Status == RunCancelled upon Run timeout

Might be also worth clarifying that this change applies only to task-level timeouts, which should be handled by run reconcilers for custom tasks, in the same way that taskrun reconcilers handles task-level timeouts for tasks (since #5134)

Pipeline-level timeouts continue to work as is - through cancelling TaskRuns and Runs:

pipeline/pkg/reconciler/pipelinerun/timeout.go

Lines 129 to 136 in 58fd07c

    
           for _, runName := range runNames { 
        
           	logger.Infof("cancelling Run %s for timeout", runName) 
        
           	if err := timeoutRun(ctx, runName, pr.Namespace, clientSet); err != nil { 
        
           		errs = append(errs, fmt.Errorf("Failed to patch Run `%s` with cancellation: %s", runName, err).Error()) 
        
           		continue 
        
           	} 
        
           }

A similar change (#5134) addressed flakiness in TestPipelineRunTimeout

cc @tektoncd/core-maintainers

XinruZhang · 2022-10-20T12:48:21Z

Appreciate all the info @jerop! Updated the PR description and release note.

lbernick

A more descriptive commit message could be something like "Remove PipelineRun cancelation of Runs when Pipeline Task timeout is reached"

pkg/reconciler/pipelinerun/pipelinerun_test.go

tekton-robot · 2022-10-20T14:36:04Z

The following is the coverage report on the affected files.
Say /test pull-tekton-pipeline-go-coverage to re-run this coverage report

File	Old Coverage	New Coverage	Delta
pkg/reconciler/pipelinerun/pipelinerun.go	85.0%	85.4%	0.4

jerop

Thank you for investigating and addressing this flake @XinruZhang!

I support this change, but will wait for @ScrapCodes (who may depend on this functionality) to chime in - @tektoncd/core-maintainers please take a look

For future reference, the wait custom task that we use for testing has fully implemented timeouts itself (can serve as an example of not relying on pipelinerun reconciler) -

pipeline/test/custom-task-ctrls/wait-task/pkg/reconciler/reconciler.go

Lines 101 to 139 in b648a5b

    
           timeout := r.GetTimeout() 
        
           if duration == timeout { 
        
           	r.Status.MarkRunFailed("InvalidTimeOut", "Spec.Timeout shouldn't equal duration") 
        
           	return nil 
        
           } 
        
           elapsed := c.Clock.Since(r.Status.StartTime.Time) 
        
           // Custom Task is running and not timed out 
        
           if r.Status.StartTime != nil && elapsed <= duration && elapsed <= timeout { 
        
           	logger.Infof("The Custom Task Run %s is running", r.GetName()) 
        
           	waitTime := duration.Nanoseconds() 
        
           	if timeout.Nanoseconds() < waitTime { 
        
           		waitTime = timeout.Nanoseconds() 
        
           	} 
        
           	return controller.NewRequeueAfter(time.Duration(waitTime)) 
        
           } 
        
           if r.Status.StartTime != nil && elapsed > duration && elapsed <= timeout { 
        
           	logger.Infof("The Custom Task Run %v finished", r.GetName()) 
        
           	r.Status.CompletionTime = &metav1.Time{Time: c.Clock.Now()} 
        
           	r.Status.MarkRunSucceeded("DurationElapsed", "The wait duration has elapsed") 
        
           	return nil 
        
           } 
        
           // Custom Task timed out 
        
           if r.Status.StartTime != nil && elapsed > timeout { 
        
           	logger.Infof("The Custom Task Run %v timed out", r.GetName()) 
        
           	r.Status.CompletionTime = &metav1.Time{Time: c.Clock.Now()} 
        
           	r.Status.MarkRunFailed("TimedOut", WaitTaskCancelledByRunTimeoutMsg) 
        
           	// Retry if the current RetriesStatus hasn't reached the retries limit 
        
           	if r.Spec.Retries > len(r.Status.RetriesStatus) { 
        
           		logger.Infof("Run timed out, retrying... %#v", r.Status) 
        
           		retryRun(r) 
        
           		return controller.NewRequeueImmediately() 
        
           	} 
        
           	return nil 
        
           }

lbernick · 2022-10-25T12:51:56Z

pkg/reconciler/pipelinerun/pipelinerun_test.go

@@ -1772,7 +1765,7 @@ status:
 			}, {
 				Operation: "add",
 				Path:      "/spec/statusMessage",
-				Value:     string(v1alpha1.RunCancelledByPipelineMsg),


can this constant be removed?

I feel It's better if we keep it same as other test cases. Oh actually, we may want to update the previous one as v1alpha1.RunReasonCancelled, nice catch!

sorry, I meant can RunCancelledByPipelineMsg be removed from the v1alpha1 package?

Oh yes, you are totally right, sorry I should've asked. We'll need to move all related usage of v1alpha1.Run to v1beta1 later on as part of #5153, added #5153 (comment) to make sure this will happen.

…reached TestWaitCustomTask_PipelineRun/Wait_Task_Retries_on_Timeout has been flaky for a while. This commit stops the PipelineRun reconciler from cancelling Run when it detects that the task-level Timeout configured for the Run has passed, which will address the flake (similar to tektoncd#5134 which addresses TestPipelineRunTimeout).

tekton-robot · 2022-10-25T13:35:41Z

The following is the coverage report on the affected files.
Say /test pull-tekton-pipeline-go-coverage to re-run this coverage report

File	Old Coverage	New Coverage	Delta
pkg/reconciler/pipelinerun/pipelinerun.go	85.0%	85.4%	0.4

jerop

/lgtm

tekton-robot · 2022-10-25T17:36:45Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: jerop, lbernick

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [jerop,lbernick]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

jerop · 2022-10-25T17:46:03Z

/test tekton-pipeline-unit-tests

cloud events flake

ScrapCodes · 2022-10-26T17:21:57Z

@jerop and @XinruZhang I was wondering, without this feature how will custom task controller "reconcile" and take action on timed-out task. Basically, this processTimeout causes them to trigger reconcile.

XinruZhang · 2022-10-26T17:46:05Z

Hi Prashant, thanks for keeping eye on this issue!

If the Run controller handles the timeout correctly -- mark the Run as Failed on timeout, then we wouldn't have any problem.
If the Run controller doesn't implement the TimeOut functionality, the entire PipelineRun will eventually fail on pipeline-level timeout.

ScrapCodes · 2022-10-27T04:21:58Z

Hi Xinru,
Thanks!, that part is understood. Suppose a custom task is performing an action and is stuck for some reason. The custom task controller will not get to "reconcile" it until it is updated in someway.
The reconcile is triggered not periodically but whenever there is an update. I need to test this out, to be sure.

XinruZhang · 2022-10-27T14:49:24Z

Oh I see, great point! After thinking more about it, I think that would be a concern of Custom Run controller right? A custom controller can requeue a key after a period of time, similar to

pipeline/test/custom-task-ctrls/wait-task/pkg/reconciler/reconciler.go

Lines 108 to 116 in db4c05c

    
           // Custom Task is running and not timed out 
        
           if r.Status.StartTime != nil && elapsed <= duration && elapsed <= timeout { 
        
           	logger.Infof("The Custom Task Run %s is running", r.GetName()) 
        
           	waitTime := duration.Nanoseconds() 
        
           	if timeout.Nanoseconds() < waitTime { 
        
           		waitTime = timeout.Nanoseconds() 
        
           	} 
        
           	return controller.NewRequeueAfter(time.Duration(waitTime)) 
        
           }

ScrapCodes · 2022-10-27T16:10:32Z

~~Is this scalable? when number of objects are large. Do you think the overhead of examining a large number of run object by custom task controller, every object's "timeout time" can impact performance?~~

This is already used by pipeline controller, so we are good.

tekton-robot added release-note-none Denotes a PR that doesnt merit a release note. size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Oct 18, 2022

tekton-robot requested review from dibyom and jerop October 18, 2022 20:39

tekton-robot added the kind/flake Categorizes issue or PR as related to a flakey test label Oct 18, 2022

XinruZhang marked this pull request as draft October 18, 2022 20:48

tekton-robot added the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Oct 18, 2022

XinruZhang force-pushed the flaky-custom-run-test branch from 6afa586 to 19d451c Compare October 19, 2022 17:12

XinruZhang marked this pull request as ready for review October 19, 2022 19:46

tekton-robot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Oct 19, 2022

tekton-robot requested a review from abayer October 19, 2022 19:46

jerop reviewed Oct 19, 2022

View reviewed changes

tekton-robot added release-note-action-required Denotes a PR that introduces potentially breaking changes that require user action. and removed release-note-none Denotes a PR that doesnt merit a release note. labels Oct 20, 2022

lbernick reviewed Oct 20, 2022

View reviewed changes

pkg/reconciler/pipelinerun/pipelinerun_test.go Outdated Show resolved Hide resolved

XinruZhang force-pushed the flaky-custom-run-test branch from 19d451c to 37d3bb3 Compare October 20, 2022 14:31

jerop reviewed Oct 20, 2022

View reviewed changes

jerop added this to the Pipelines v0.41 milestone Oct 25, 2022

lbernick approved these changes Oct 25, 2022

View reviewed changes

tekton-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 25, 2022

XinruZhang force-pushed the flaky-custom-run-test branch from 37d3bb3 to a1da340 Compare October 25, 2022 13:29

jerop approved these changes Oct 25, 2022

View reviewed changes

tekton-robot assigned jerop Oct 25, 2022

tekton-robot added the lgtm Indicates that a PR is ready to be merged. label Oct 25, 2022

tekton-robot merged commit 867fe2d into tektoncd:main Oct 25, 2022

This was referenced Nov 8, 2022

TEP-0002: Move Cancellation of Custom Task to be Required tektoncd/community#872

Closed

Propose to make some modifications on top of TEP-0002 tektoncd/community#873

Closed

XinruZhang mentioned this pull request Nov 17, 2022

TEP-0114: Cancellation is required tektoncd/community#881

Merged

jerop changed the title ~~Resolve the Flaky Test - TestWaitCustomTask_PipelineRun~~ TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun Nov 28, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun #5658

TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun #5658

XinruZhang commented Oct 18, 2022 •

edited

Loading

XinruZhang commented Oct 18, 2022

tekton-robot commented Oct 18, 2022

tekton-robot commented Oct 19, 2022

abayer commented Oct 19, 2022

jerop left a comment •

edited

Loading

XinruZhang commented Oct 20, 2022

lbernick left a comment

tekton-robot commented Oct 20, 2022

jerop left a comment

lbernick Oct 25, 2022

XinruZhang Oct 25, 2022

lbernick Oct 25, 2022

XinruZhang Oct 25, 2022

tekton-robot commented Oct 25, 2022

jerop left a comment

tekton-robot commented Oct 25, 2022

jerop commented Oct 25, 2022

ScrapCodes commented Oct 26, 2022 •

edited

Loading

XinruZhang commented Oct 26, 2022 •

edited

Loading

ScrapCodes commented Oct 27, 2022

XinruZhang commented Oct 27, 2022

ScrapCodes commented Oct 27, 2022 •

edited

Loading

	for _, runName := range runNames {
	logger.Infof("cancelling Run %s for timeout", runName)

	if err := timeoutRun(ctx, runName, pr.Namespace, clientSet); err != nil {
	errs = append(errs, fmt.Errorf("Failed to patch Run `%s` with cancellation: %s", runName, err).Error())
	continue
	}
	}

	timeout := r.GetTimeout()
	if duration == timeout {
	r.Status.MarkRunFailed("InvalidTimeOut", "Spec.Timeout shouldn't equal duration")
	return nil
	}
	elapsed := c.Clock.Since(r.Status.StartTime.Time)

	// Custom Task is running and not timed out
	if r.Status.StartTime != nil && elapsed <= duration && elapsed <= timeout {
	logger.Infof("The Custom Task Run %s is running", r.GetName())
	waitTime := duration.Nanoseconds()
	if timeout.Nanoseconds() < waitTime {
	waitTime = timeout.Nanoseconds()
	}
	return controller.NewRequeueAfter(time.Duration(waitTime))
	}

	if r.Status.StartTime != nil && elapsed > duration && elapsed <= timeout {
	logger.Infof("The Custom Task Run %v finished", r.GetName())
	r.Status.CompletionTime = &metav1.Time{Time: c.Clock.Now()}
	r.Status.MarkRunSucceeded("DurationElapsed", "The wait duration has elapsed")
	return nil
	}

	// Custom Task timed out
	if r.Status.StartTime != nil && elapsed > timeout {
	logger.Infof("The Custom Task Run %v timed out", r.GetName())
	r.Status.CompletionTime = &metav1.Time{Time: c.Clock.Now()}
	r.Status.MarkRunFailed("TimedOut", WaitTaskCancelledByRunTimeoutMsg)

	// Retry if the current RetriesStatus hasn't reached the retries limit
	if r.Spec.Retries > len(r.Status.RetriesStatus) {
	logger.Infof("Run timed out, retrying... %#v", r.Status)
	retryRun(r)
	return controller.NewRequeueImmediately()
	}

	return nil
	}

TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun #5658

TEP-0114: Resolve the Flaky Test - TestWaitCustomTask_PipelineRun #5658

Conversation

XinruZhang commented Oct 18, 2022 • edited Loading

Changes

Submitter Checklist

Release Notes

XinruZhang commented Oct 18, 2022

tekton-robot commented Oct 18, 2022

tekton-robot commented Oct 19, 2022

abayer commented Oct 19, 2022

jerop left a comment • edited Loading

Choose a reason for hiding this comment

XinruZhang commented Oct 20, 2022

lbernick left a comment

Choose a reason for hiding this comment

tekton-robot commented Oct 20, 2022

jerop left a comment

Choose a reason for hiding this comment

lbernick Oct 25, 2022

Choose a reason for hiding this comment

XinruZhang Oct 25, 2022

Choose a reason for hiding this comment

lbernick Oct 25, 2022

Choose a reason for hiding this comment

XinruZhang Oct 25, 2022

Choose a reason for hiding this comment

tekton-robot commented Oct 25, 2022

jerop left a comment

Choose a reason for hiding this comment

tekton-robot commented Oct 25, 2022

jerop commented Oct 25, 2022

ScrapCodes commented Oct 26, 2022 • edited Loading

XinruZhang commented Oct 26, 2022 • edited Loading

ScrapCodes commented Oct 27, 2022

XinruZhang commented Oct 27, 2022

ScrapCodes commented Oct 27, 2022 • edited Loading

XinruZhang commented Oct 18, 2022 •

edited

Loading

jerop left a comment •

edited

Loading

ScrapCodes commented Oct 26, 2022 •

edited

Loading

XinruZhang commented Oct 26, 2022 •

edited

Loading

ScrapCodes commented Oct 27, 2022 •

edited

Loading