Account for finally TaskRun retries in PR timeouts

Prior to this commit, the PipelineRun reconciler did not account for time elapsed during a finally
TaskRun's retries when setting its timeout. This resulted in `pipelinerun.timeouts.finally` not being
respected when a finally TaskRun was retried.

This commit updates the finally TaskRun's timeout to account for time elapsed during retries.

Co-authored-by: Jerop Kipruto jerop@google.com

docs/pipelineruns.md

@@ -533,6 +533,10 @@ The `timeout` value is a `duration` conforming to Go's
 values are `1h30m`, `1h`, `1m`, and `60s`. If you set the global timeout to 0, all `PipelineRuns`
 that do not have an individual timeout set will fail immediately upon encountering an error.
 
+`timeouts.tasks` includes time spent during the `Retries` of the `Pipeline`'s tasks,
+and `timeouts.finally` includes time spent during the `Retries` of the `Pipeline`'s `finally` tasks.
+`timeout` and `timeouts.pipeline` include time spent during both the `Retries` of tasks and `finally` tasks.
+
 ## Monitoring execution status
 
 As your `PipelineRun` executes, its `status` field accumulates information on the execution of each `TaskRun`

docs/pipelines.md

@@ -799,6 +799,8 @@ spec:
         name: build-push
       timeout: "0h1m30s"
 ```
+If a `Task` within a `Pipeline` declares [`Retries`](#using-the-retries-and-retry-count-variable-substitutions),
+the same `Timeout` will be used for each `Retry`; that is, each time the `Task` is retried, the `Timeout` resets.
 
 ## Using variable substitution
 

pkg/reconciler/pipelinerun/pipelinerun.go

@@ -1017,14 +1017,21 @@ func combineTaskRunAndTaskSpecAnnotations(pr *v1beta1.PipelineRun, pipelineTask
 func getFinallyTaskRunTimeout(ctx context.Context, pr *v1beta1.PipelineRun, rprt *resources.ResolvedPipelineRunTask, c clock.Clock) *metav1.Duration {
 	taskRunTimeout := calculateTaskRunTimeout(pr.PipelineTimeout(ctx), pr, rprt, c)
 	finallyTimeout := pr.FinallyTimeout()
-	// Return the smaller of taskRunTimeout and finallyTimeout
-	// This works because all finally tasks run in parallel, so there is no need to consider time spent by other finally tasks
-	// TODO(#4071): Account for time spent since finally task was first started (i.e. retries)
 	if finallyTimeout == nil || finallyTimeout.Duration == apisconfig.NoTimeoutDuration {
 		return taskRunTimeout
 	}
-	if finallyTimeout.Duration < taskRunTimeout.Duration {
-		return finallyTimeout
+	// Return the smaller of taskRunTimeout and finallyTimeRemaining.
+	// This takes into account the time elapsed during retries of the finally TaskRun, but does not take into account
+	// time spent by other finally TaskRuns since they are executed in parallel.
+	finallyTimeRemaining := finallyTimeout.Duration
+	firstAttemptStartTime := rprt.FirstAttemptStartTime(c)
+	if firstAttemptStartTime != nil {
+		elapsed := c.Since(firstAttemptStartTime.Time)
+		finallyTimeRemaining -= elapsed
+	}
+
+	if finallyTimeRemaining < taskRunTimeout.Duration {
+		return &metav1.Duration{Duration: finallyTimeRemaining}
 	}
 	return taskRunTimeout
 }

pkg/reconciler/pipelinerun/pipelinerun_test.go

@@ -4078,6 +4078,39 @@ func TestGetTaskRunTimeout(t *testing.T) {
 			},
 		},
 		expected: &metav1.Duration{Duration: 10 * time.Minute},
+	}, {
+		name: "taskrun with retries",
+		pr: &v1beta1.PipelineRun{
+			ObjectMeta: baseObjectMeta(prName, ns),
+			Spec: v1beta1.PipelineRunSpec{
+				PipelineRef: &v1beta1.PipelineRef{Name: p},
+				Timeouts: &v1beta1.TimeoutFields{
+					Pipeline: &metav1.Duration{Duration: 40 * time.Minute},
+					Tasks:    &metav1.Duration{Duration: 20 * time.Minute},
+				},
+			},
+			Status: v1beta1.PipelineRunStatus{
+				PipelineRunStatusFields: v1beta1.PipelineRunStatusFields{
+					StartTime: &metav1.Time{Time: now.Add(-10 * time.Minute)},
+				},
+			},
+		},
+		rprt: &resources.ResolvedPipelineRunTask{
+			PipelineTask: &v1beta1.PipelineTask{},
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: nil,
+						RetriesStatus: []v1beta1.TaskRunStatus{{
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime: &metav1.Time{Time: now.Add(-5 * time.Minute)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		expected: &metav1.Duration{Duration: 10 * time.Minute},
 	},
 	}
 
@@ -4286,6 +4319,39 @@ func TestGetFinallyTaskRunTimeout(t *testing.T) {
 			},
 		},
 		expected: &metav1.Duration{Duration: 20 * time.Minute},
+	}, {
+		name: "finally taskrun with retries",
+		pr: &v1beta1.PipelineRun{
+			ObjectMeta: baseObjectMeta(prName, ns),
+			Spec: v1beta1.PipelineRunSpec{
+				PipelineRef: &v1beta1.PipelineRef{Name: p},
+				Timeouts: &v1beta1.TimeoutFields{
+					Pipeline: &metav1.Duration{Duration: 40 * time.Minute},
+					Finally:  &metav1.Duration{Duration: 20 * time.Minute},
+				},
+			},
+			Status: v1beta1.PipelineRunStatus{
+				PipelineRunStatusFields: v1beta1.PipelineRunStatusFields{
+					StartTime: &metav1.Time{Time: now.Add(-10 * time.Minute)},
+				},
+			},
+		},
+		rprt: &resources.ResolvedPipelineRunTask{
+			PipelineTask: &v1beta1.PipelineTask{},
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: nil,
+						RetriesStatus: []v1beta1.TaskRunStatus{{
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime: &metav1.Time{Time: now.Add(-5 * time.Minute)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		expected: &metav1.Duration{Duration: 15 * time.Minute},
 	},
 	}
 

pkg/reconciler/pipelinerun/resources/pipelinerunresolution.go

@@ -27,9 +27,11 @@ import (
 	"github.com/tektoncd/pipeline/pkg/apis/pipeline/v1alpha1"
 	"github.com/tektoncd/pipeline/pkg/apis/pipeline/v1beta1"
 	resourcev1alpha1 "github.com/tektoncd/pipeline/pkg/apis/resource/v1alpha1"
+	"github.com/tektoncd/pipeline/pkg/clock"
 	"github.com/tektoncd/pipeline/pkg/list"
 	"github.com/tektoncd/pipeline/pkg/reconciler/taskrun/resources"
 	"k8s.io/apimachinery/pkg/api/errors"
+	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"knative.dev/pkg/apis"
 )
 
@@ -174,6 +176,49 @@ func (t ResolvedPipelineRunTask) IsStarted() bool {
 	return t.TaskRun != nil && t.TaskRun.Status.GetCondition(apis.ConditionSucceeded) != nil
 }
 
+// FirstAttemptStartTime returns the start time of the first time the ResolvedPipelineRunTask was attempted.
+// Returns nil if no attempt has been started.
+func (t *ResolvedPipelineRunTask) FirstAttemptStartTime(c clock.Clock) *metav1.Time {
+	var startTime *metav1.Time
+
+	if t.IsCustomTask() {
+		r := t.Run
+		if r == nil {
+			return nil
+		}
+		startTime = r.Status.StartTime
+		if startTime.IsZero() {
+			if len(r.Status.RetriesStatus) == 0 {
+				return startTime
+			}
+			startTime = &metav1.Time{Time: c.Now()}
+		}
+		for _, retry := range r.Status.RetriesStatus {
+			if retry.StartTime.Time.Before(startTime.Time) {
+				startTime = retry.StartTime
+			}
+		}
+		return startTime
+	}
+	tr := t.TaskRun
+	if tr == nil {
+		return nil
+	}
+	startTime = tr.Status.StartTime
+	if startTime.IsZero() {
+		if len(tr.Status.RetriesStatus) == 0 {
+			return startTime
+		}
+		startTime = &metav1.Time{Time: c.Now()}
+	}
+	for _, retry := range tr.Status.RetriesStatus {
+		if retry.StartTime.Time.Before(startTime.Time) {
+			startTime = retry.StartTime
+		}
+	}
+	return startTime
+}
+
 // IsConditionStatusFalse returns true when a task has succeeded condition with status set to false
 // it includes task failed after retries are exhausted, cancelled tasks, and time outs
 func (t ResolvedPipelineRunTask) IsConditionStatusFalse() bool {

pkg/reconciler/pipelinerun/resources/pipelinerunresolution_test.go

@@ -21,6 +21,7 @@ import (
 	"errors"
 	"fmt"
 	"testing"
+	"time"
 
 	"github.com/google/go-cmp/cmp"
 	"github.com/google/go-cmp/cmp/cmpopts"
@@ -3508,3 +3509,191 @@ func TestGetRunName(t *testing.T) {
 		})
 	}
 }
+
+func TestResolvedPipelineRunTask_FirstAttemptStartTime(t *testing.T) {
+	tcs := []struct {
+		name string
+		rprt *ResolvedPipelineRunTask
+		want *metav1.Time
+	}{{
+		name: "TaskRun not started",
+		rprt: &ResolvedPipelineRunTask{
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: nil,
+					},
+				},
+			},
+		},
+		want: nil,
+	}, {
+		name: "TaskRun on first attempt",
+		rprt: &ResolvedPipelineRunTask{
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now},
+	}, {
+		name: "TaskRun completed first attempt",
+		rprt: &ResolvedPipelineRunTask{
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: nil,
+						RetriesStatus: []v1beta1.TaskRunStatus{{
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-10 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-10 * time.Second)},
+	}, {
+		name: "TaskRun on second attempt",
+		rprt: &ResolvedPipelineRunTask{
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+						RetriesStatus: []v1beta1.TaskRunStatus{{
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-10 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-6 * time.Second)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-10 * time.Second)},
+	}, {
+		name: "TaskRun on third attempt (multiple retries)",
+		rprt: &ResolvedPipelineRunTask{
+			TaskRun: &v1beta1.TaskRun{
+				Status: v1beta1.TaskRunStatus{
+					TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+						RetriesStatus: []v1beta1.TaskRunStatus{{
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-11 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-6 * time.Second)},
+							},
+						}, {
+							TaskRunStatusFields: v1beta1.TaskRunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-20 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-12 * time.Second)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-20 * time.Second)},
+	}, {
+		name: "Run not started",
+		rprt: &ResolvedPipelineRunTask{
+			CustomTask: true,
+			Run: &v1alpha1.Run{
+				Status: v1alpha1.RunStatus{
+					RunStatusFields: v1alpha1.RunStatusFields{
+						StartTime: nil,
+					},
+				},
+			},
+		},
+		want: nil,
+	}, {
+		name: "Run on first attempt",
+		rprt: &ResolvedPipelineRunTask{
+			CustomTask: true,
+			Run: &v1alpha1.Run{
+				Status: v1alpha1.RunStatus{
+					RunStatusFields: v1alpha1.RunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now},
+	}, {
+		name: "Run completed first attempt",
+		rprt: &ResolvedPipelineRunTask{
+			CustomTask: true,
+			Run: &v1alpha1.Run{
+				Status: v1alpha1.RunStatus{
+					RunStatusFields: v1alpha1.RunStatusFields{
+						StartTime: nil,
+						RetriesStatus: []v1alpha1.RunStatus{{
+							RunStatusFields: v1alpha1.RunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-10 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-10 * time.Second)},
+	}, {
+		name: "Run on second attempt",
+		rprt: &ResolvedPipelineRunTask{
+			CustomTask: true,
+			Run: &v1alpha1.Run{
+				Status: v1alpha1.RunStatus{
+					RunStatusFields: v1alpha1.RunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+						RetriesStatus: []v1alpha1.RunStatus{{
+							RunStatusFields: v1alpha1.RunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-10 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-6 * time.Second)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-10 * time.Second)},
+	}, {
+		name: "Run on third attempt (multiple retries)",
+		rprt: &ResolvedPipelineRunTask{
+			CustomTask: true,
+			Run: &v1alpha1.Run{
+				Status: v1alpha1.RunStatus{
+					RunStatusFields: v1alpha1.RunStatusFields{
+						StartTime: &metav1.Time{Time: now},
+						RetriesStatus: []v1alpha1.RunStatus{{
+							RunStatusFields: v1alpha1.RunStatusFields{
+								StartTime:      &metav1.Time{Time: now.Add(-11 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-6 * time.Second)},
+							},
+						}, {
+							RunStatusFields: v1alpha1.RunStatusFields{
+
+								StartTime:      &metav1.Time{Time: now.Add(-20 * time.Second)},
+								CompletionTime: &metav1.Time{Time: now.Add(-12 * time.Second)},
+							},
+						}},
+					},
+				},
+			},
+		},
+		want: &metav1.Time{Time: now.Add(-20 * time.Second)},
+	}}
+	for _, tc := range tcs {
+		t.Run(tc.name, func(t *testing.T) {
+			got := tc.rprt.FirstAttemptStartTime(testClock{})
+			if cmp.Diff(tc.want, got) != "" {
+				t.Errorf("Unexpected value for FirstAttemptStartTime: want %v, got %v", tc.want, got)
+			}
+		})
+	}
+}