Fix PipelineRun reconciler panic for computed timeouts

Prior to this commit, log lines in the pipelinerun reconciler assumed that if a pipelineRun had reached its tasks timeout, `spec.timeouts.tasks` was set, rather than computed from `spec.timeouts.pipeline` and `spec.timeouts.finally`, and likewise for the finally timeout. This commit updates log messages to avoid the controller panic, and adds tests for this fix.
tektoncd · Jul 10, 2023 · e256fc0 · e256fc0
1 parent 7b23f93
commit e256fc0
Show file tree

Hide file tree

Showing 2 changed files with 181 additions and 113 deletions.
diff --git a/pkg/reconciler/pipelinerun/pipelinerun.go b/pkg/reconciler/pipelinerun/pipelinerun.go
@@ -554,10 +554,12 @@ func (c *Reconciler) reconcile(ctx context.Context, pr *v1.PipelineRun, getPipel
 	if pr.Status.FinallyStartTime != nil {
 		pipelineRunFacts.TimeoutsState.FinallyStartTime = &pr.Status.FinallyStartTime.Time
 	}
-	if tasksTimeout := pr.TasksTimeout(); tasksTimeout != nil {
+	tasksTimeout := pr.TasksTimeout()
+	if tasksTimeout != nil {
 		pipelineRunFacts.TimeoutsState.TasksTimeout = &tasksTimeout.Duration
 	}
-	if finallyTimeout := pr.FinallyTimeout(); finallyTimeout != nil {
+	finallyTimeout := pr.FinallyTimeout()
+	if finallyTimeout != nil {
 		pipelineRunFacts.TimeoutsState.FinallyTimeout = &finallyTimeout.Duration
 	}
 	if pipelineTimeout := pr.PipelineTimeout(ctx); pipelineTimeout != 0 {
@@ -636,7 +638,7 @@ func (c *Reconciler) reconcile(ctx context.Context, pr *v1.PipelineRun, getPipel
 				}
 			}
 			if tasksToTimeOut.Len() > 0 {
-				logger.Infof("PipelineRun tasks timeout of %s reached, cancelling tasks", pr.Spec.Timeouts.Tasks.Duration.String())
+				logger.Debugf("PipelineRun tasks timeout of %s reached, cancelling tasks", tasksTimeout)
 				errs := timeoutPipelineTasksForTaskNames(ctx, logger, pr, c.PipelineClientSet, tasksToTimeOut)
 				if len(errs) > 0 {
 					errString := strings.Join(errs, "\n")
@@ -653,7 +655,7 @@ func (c *Reconciler) reconcile(ctx context.Context, pr *v1.PipelineRun, getPipel
 			}
 		}
 		if tasksToTimeOut.Len() > 0 {
-			logger.Infof("PipelineRun finally timeout of %s reached, cancelling finally tasks", pr.Spec.Timeouts.Finally.Duration.String())
+			logger.Debugf("PipelineRun finally timeout of %s reached, cancelling finally tasks", finallyTimeout)
 			errs := timeoutPipelineTasksForTaskNames(ctx, logger, pr, c.PipelineClientSet, tasksToTimeOut)
 			if len(errs) > 0 {
 				errString := strings.Join(errs, "\n")

diff --git a/pkg/reconciler/pipelinerun/pipelinerun_test.go b/pkg/reconciler/pipelinerun/pipelinerun_test.go
@@ -2570,15 +2570,33 @@ spec:
     taskRef:
       name: hello-world
 `)}
-	prs := []*v1.PipelineRun{parse.MustParseV1PipelineRun(t, `
+	ts := []*v1.Task{simpleHelloWorldTask}
+	trs := []*v1.TaskRun{mustParseTaskRunWithObjectMeta(t, taskRunObjectMeta("test-pipeline-run-with-timeout-hello-world-1", "foo", "test-pipeline-run-with-timeout",
+		"test-pipeline", "hello-world-1", false), `
+spec:
+  serviceAccountName: test-sa
+  taskRef:
+    name: hello-world
+    kind: Task
+status:
+  conditions:
+  - lastTransitionTime: null
+    status: "Unknown"
+    type: Succeeded
+`)}
+
+	tcs := []struct {
+		name string
+		pr   *v1.PipelineRun
+	}{{
+		name: "tasks timeout specified",
+		pr: parse.MustParseV1PipelineRun(t, `
 metadata:
   name: test-pipeline-run-with-timeout
   namespace: foo
 spec:
   pipelineRef:
     name: test-pipeline
-  taskRunTemplate:
-    serviceAccountName: test-sa
   timeouts:
     tasks: 2m
 status:
@@ -2587,63 +2605,69 @@ status:
   - name: test-pipeline-run-with-timeout-hello-world-1
     pipelineTaskName: hello-world-1
     kind: TaskRun
-`)}
-	ts := []*v1.Task{simpleHelloWorldTask}
-
-	trs := []*v1.TaskRun{mustParseTaskRunWithObjectMeta(t, taskRunObjectMeta("test-pipeline-run-with-timeout-hello-world-1", "foo", "test-pipeline-run-with-timeout",
-		"test-pipeline", "hello-world-1", false), `
+`),
+	}, {
+		name: "tasks timeout calculated",
+		pr: parse.MustParseV1PipelineRun(t, `
+metadata:
+  name: test-pipeline-run-with-timeout
+  namespace: foo
 spec:
-  serviceAccountName: test-sa
-  taskRef:
-    name: hello-world
-    kind: Task
+  pipelineRef:
+    name: test-pipeline
+  timeouts:
+    pipeline: 4m
+    finally: 2m
 status:
-  conditions:
-  - lastTransitionTime: null
-    status: "Unknown"
-    type: Succeeded
-`)}
-
-	d := test.Data{
-		PipelineRuns: prs,
-		Pipelines:    ps,
-		Tasks:        ts,
-		TaskRuns:     trs,
-	}
-	prt := newPipelineRunTest(t, d)
-	defer prt.Cancel()
+  startTime: "2021-12-31T23:57:00Z"
+  childReferences:
+  - name: test-pipeline-run-with-timeout-hello-world-1
+    pipelineTaskName: hello-world-1
+    kind: TaskRun
+`),
+	}}
+	for _, tc := range tcs {
+		d := test.Data{
+			PipelineRuns: []*v1.PipelineRun{tc.pr},
+			Pipelines:    ps,
+			Tasks:        ts,
+			TaskRuns:     trs,
+		}
+		prt := newPipelineRunTest(t, d)
+		defer prt.Cancel()
 
-	wantEvents := []string{
-		"Normal Started",
-	}
-	reconciledRun, clients := prt.reconcileRun("foo", "test-pipeline-run-with-timeout", wantEvents, false)
+		wantEvents := []string{
+			"Normal Started",
+		}
+		reconciledRun, clients := prt.reconcileRun("foo", "test-pipeline-run-with-timeout", wantEvents, false)
 
-	if reconciledRun.Status.CompletionTime != nil {
-		t.Errorf("Expected nil CompletionTime on PipelineRun but was %s", reconciledRun.Status.CompletionTime)
-	}
+		if reconciledRun.Status.CompletionTime != nil {
+			t.Errorf("Expected nil CompletionTime on PipelineRun but was %s", reconciledRun.Status.CompletionTime)
+		}
 
-	// The PipelineRun should be running.
-	if reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason != v1.PipelineRunReasonRunning.String() {
-		t.Errorf("Expected PipelineRun to be running, but condition reason is %s", reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason)
-	}
+		// The PipelineRun should be running.
+		if reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason != v1.PipelineRunReasonRunning.String() {
+			t.Errorf("Expected PipelineRun to be running, but condition reason is %s", reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason)
+		}
 
-	// Check that there is a skipped task for the expected reason
-	if len(reconciledRun.Status.SkippedTasks) != 1 {
-		t.Errorf("expected one skipped task, found %d", len(reconciledRun.Status.SkippedTasks))
-	} else if reconciledRun.Status.SkippedTasks[0].Reason != v1.TasksTimedOutSkip {
-		t.Errorf("expected skipped reason to be '%s', but was '%s", v1.TasksTimedOutSkip, reconciledRun.Status.SkippedTasks[0].Reason)
-	}
+		// Check that there is a skipped task for the expected reason
+		if len(reconciledRun.Status.SkippedTasks) != 1 {
+			t.Errorf("expected one skipped task, found %d", len(reconciledRun.Status.SkippedTasks))
+		} else if reconciledRun.Status.SkippedTasks[0].Reason != v1.TasksTimedOutSkip {
+			t.Errorf("expected skipped reason to be '%s', but was '%s", v1.TasksTimedOutSkip, reconciledRun.Status.SkippedTasks[0].Reason)
+		}
 
-	updatedTaskRun, err := clients.Pipeline.TektonV1().TaskRuns("foo").Get(context.Background(), trs[0].Name, metav1.GetOptions{})
-	if err != nil {
-		t.Fatalf("error getting updated TaskRun: %#v", err)
-	}
+		updatedTaskRun, err := clients.Pipeline.TektonV1().TaskRuns("foo").Get(context.Background(), trs[0].Name, metav1.GetOptions{})
+		if err != nil {
+			t.Fatalf("error getting updated TaskRun: %#v", err)
+		}
 
-	if updatedTaskRun.Spec.Status != v1.TaskRunSpecStatusCancelled {
-		t.Errorf("expected existing TaskRun Spec.Status to be set to %s, but was %s", v1.TaskRunSpecStatusCancelled, updatedTaskRun.Spec.Status)
-	}
-	if updatedTaskRun.Spec.StatusMessage != v1.TaskRunCancelledByPipelineTimeoutMsg {
-		t.Errorf("expected existing TaskRun Spec.StatusMessage to be set to %s, but was %s", v1.TaskRunCancelledByPipelineTimeoutMsg, updatedTaskRun.Spec.StatusMessage)
+		if updatedTaskRun.Spec.Status != v1.TaskRunSpecStatusCancelled {
+			t.Errorf("expected existing TaskRun Spec.Status to be set to %s, but was %s", v1.TaskRunSpecStatusCancelled, updatedTaskRun.Spec.Status)
+		}
+		if updatedTaskRun.Spec.StatusMessage != v1.TaskRunCancelledByPipelineTimeoutMsg {
+			t.Errorf("expected existing TaskRun Spec.StatusMessage to be set to %s, but was %s", v1.TaskRunCancelledByPipelineTimeoutMsg, updatedTaskRun.Spec.StatusMessage)
+		}
 	}
 }
 
@@ -2668,15 +2692,38 @@ spec:
     taskRef:
       name: hello-world
 `)}
-	prs := []*v1.PipelineRun{parse.MustParseV1PipelineRun(t, `
+	prName := "test-pipeline-run-with-timeout"
+	ts := []*v1.Task{simpleHelloWorldTask}
+	trs := []*v1.TaskRun{
+		getTaskRun(
+			t,
+			"test-pipeline-run-with-timeout-hello-world",
+			prName,
+			ps[0].Name,
+			"hello-world",
+			corev1.ConditionTrue,
+		),
+		mustParseTaskRunWithObjectMeta(t, taskRunObjectMeta("test-pipeline-run-with-timeout-finaltask-1", "foo", "test-pipeline-run-with-timeout",
+			"test-pipeline", "finaltask-1", false), `
+spec:
+  serviceAccountName: test-sa
+  taskRef:
+    name: hello-world
+    kind: Task
+`)}
+
+	tcs := []struct {
+		name string
+		pr   *v1.PipelineRun
+	}{{
+		name: "finally timeout specified",
+		pr: parse.MustParseV1PipelineRun(t, fmt.Sprintf(`
 metadata:
-  name: test-pipeline-run-with-timeout
+  name: %s
   namespace: foo
 spec:
   pipelineRef:
     name: test-pipeline-with-finally
-  taskRunTemplate:
-    serviceAccountName: test-sa
   timeouts:
     finally: 15m
 status:
@@ -2701,66 +2748,85 @@ status:
       - lastTransitionTime: null
         status: "Unknown"
         type: Succeeded
-`)}
-	ts := []*v1.Task{simpleHelloWorldTask}
-	trs := []*v1.TaskRun{
-		getTaskRun(
-			t,
-			"test-pipeline-run-with-timeout-hello-world",
-			prs[0].Name,
-			ps[0].Name,
-			"hello-world",
-			corev1.ConditionTrue,
-		),
-		mustParseTaskRunWithObjectMeta(t, taskRunObjectMeta("test-pipeline-run-with-timeout-finaltask-1", "foo", "test-pipeline-run-with-timeout",
-			"test-pipeline", "finaltask-1", false), `
+`, prName)),
+	}, {
+		name: "finally timeout calculated",
+		pr: parse.MustParseV1PipelineRun(t, fmt.Sprintf(`
+metadata:
+  name: %s
+  namespace: foo
 spec:
-  serviceAccountName: test-sa
-  taskRef:
-    name: hello-world
-    kind: Task
-`)}
-
-	d := test.Data{
-		PipelineRuns: prs,
-		Pipelines:    ps,
-		Tasks:        ts,
-		TaskRuns:     trs,
-	}
-	prt := newPipelineRunTest(t, d)
-	defer prt.Cancel()
+  pipelineRef:
+    name: test-pipeline-with-finally
+  timeouts:
+    tasks: 5m
+    pipeline: 20m
+status:
+  finallyStartTime: "2021-12-31T23:44:59Z"
+  startTime: "2021-12-31T23:40:00Z"
+  childReferences:
+  - name: test-pipeline-run-with-timeout-hello-world
+    apiVersion: tekton.dev/v1
+    kind: TaskRun
+    pipelineTaskName: task1
+    status:
+      conditions:
+      - lastTransitionTime: null
+        status: "True"
+        type: Succeeded
+  - name: test-pipeline-run-with-timeout-finaltask-1
+    apiVersion: tekton.dev/v1
+    kind: TaskRun
+    pipelineTaskName: finaltask-1
+    status:
+      conditions:
+      - lastTransitionTime: null
+        status: "Unknown"
+        type: Succeeded
+`, prName)),
+	}}
+	for _, tc := range tcs {
+		d := test.Data{
+			PipelineRuns: []*v1.PipelineRun{tc.pr},
+			Pipelines:    ps,
+			Tasks:        ts,
+			TaskRuns:     trs,
+		}
+		prt := newPipelineRunTest(t, d)
+		defer prt.Cancel()
 
-	wantEvents := []string{
-		"Normal Started",
-	}
-	reconciledRun, clients := prt.reconcileRun("foo", "test-pipeline-run-with-timeout", wantEvents, false)
+		wantEvents := []string{
+			"Normal Started",
+		}
+		reconciledRun, clients := prt.reconcileRun("foo", "test-pipeline-run-with-timeout", wantEvents, false)
 
-	if reconciledRun.Status.CompletionTime != nil {
-		t.Errorf("Expected a nil CompletionTime on running PipelineRun but was %s", reconciledRun.Status.CompletionTime.String())
-	}
+		if reconciledRun.Status.CompletionTime != nil {
+			t.Errorf("Expected a nil CompletionTime on running PipelineRun but was %s", reconciledRun.Status.CompletionTime.String())
+		}
 
-	// The PipelineRun should be running.
-	if reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason != v1.PipelineRunReasonRunning.String() {
-		t.Errorf("Expected PipelineRun to be running, but condition reason is %s", reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason)
-	}
+		// The PipelineRun should be running.
+		if reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason != v1.PipelineRunReasonRunning.String() {
+			t.Errorf("Expected PipelineRun to be running, but condition reason is %s", reconciledRun.Status.GetCondition(apis.ConditionSucceeded).Reason)
+		}
 
-	// Check that there is a skipped task for the expected reason
-	if len(reconciledRun.Status.SkippedTasks) != 1 {
-		t.Errorf("expected one skipped task, found %d", len(reconciledRun.Status.SkippedTasks))
-	} else if reconciledRun.Status.SkippedTasks[0].Reason != v1.FinallyTimedOutSkip {
-		t.Errorf("expected skipped reason to be '%s', but was '%s", v1.FinallyTimedOutSkip, reconciledRun.Status.SkippedTasks[0].Reason)
-	}
+		// Check that there is a skipped task for the expected reason
+		if len(reconciledRun.Status.SkippedTasks) != 1 {
+			t.Errorf("expected one skipped task, found %d", len(reconciledRun.Status.SkippedTasks))
+		} else if reconciledRun.Status.SkippedTasks[0].Reason != v1.FinallyTimedOutSkip {
+			t.Errorf("expected skipped reason to be '%s', but was '%s", v1.FinallyTimedOutSkip, reconciledRun.Status.SkippedTasks[0].Reason)
+		}
 
-	updatedTaskRun, err := clients.Pipeline.TektonV1().TaskRuns("foo").Get(context.Background(), trs[1].Name, metav1.GetOptions{})
-	if err != nil {
-		t.Fatalf("error getting updated TaskRun: %#v", err)
-	}
+		updatedTaskRun, err := clients.Pipeline.TektonV1().TaskRuns("foo").Get(context.Background(), trs[1].Name, metav1.GetOptions{})
+		if err != nil {
+			t.Fatalf("error getting updated TaskRun: %#v", err)
+		}
 
-	if updatedTaskRun.Spec.Status != v1.TaskRunSpecStatusCancelled {
-		t.Errorf("expected existing TaskRun Spec.Status to be set to %s, but was %s", v1.TaskRunSpecStatusCancelled, updatedTaskRun.Spec.Status)
-	}
-	if updatedTaskRun.Spec.StatusMessage != v1.TaskRunCancelledByPipelineTimeoutMsg {
-		t.Errorf("expected existing TaskRun Spec.StatusMessage to be set to %s, but was %s", v1.TaskRunCancelledByPipelineTimeoutMsg, updatedTaskRun.Spec.StatusMessage)
+		if updatedTaskRun.Spec.Status != v1.TaskRunSpecStatusCancelled {
+			t.Errorf("expected existing TaskRun Spec.Status to be set to %s, but was %s", v1.TaskRunSpecStatusCancelled, updatedTaskRun.Spec.Status)
+		}
+		if updatedTaskRun.Spec.StatusMessage != v1.TaskRunCancelledByPipelineTimeoutMsg {
+			t.Errorf("expected existing TaskRun Spec.StatusMessage to be set to %s, but was %s", v1.TaskRunCancelledByPipelineTimeoutMsg, updatedTaskRun.Spec.StatusMessage)
+		}
 	}
 }