From c76a6ad90d191c837dfb0b1c00e494866512ba9f Mon Sep 17 00:00:00 2001 From: Andrea Frittoli Date: Sun, 5 Apr 2020 11:21:25 +0100 Subject: [PATCH] Emit events for all TaskRun lifecycle events Emit events for additional TaskRun lifecyle events: - taskrun started - taskrun running - taskrun timeout Fix the logic in events.go to compare semantic equality as opposed to raw pointer equality. Fix broken EmitEvents unit tests and extend them to cover new functionality. Extend reconcile test to verify new events are sent. To do so, get the event recorder from the context when creating the controller - if avaialble. This allows using the fake recorder for testing instead of having to look for event related actions in the fake client go action list. Add documentation on events. Fixes #2328 Work towards #2082 --- docs/events.md | 39 ++++ docs/pipelineruns.md | 2 + docs/taskruns.md | 1 + pkg/reconciler/event.go | 31 ++- pkg/reconciler/event_test.go | 107 +++++++-- pkg/reconciler/taskrun/controller.go | 2 + .../cloudevent/cloud_event_controller.go | 3 +- pkg/reconciler/taskrun/taskrun.go | 20 +- pkg/reconciler/taskrun/taskrun_test.go | 220 ++++++++++++++---- 9 files changed, 339 insertions(+), 86 deletions(-) create mode 100644 docs/events.md diff --git a/docs/events.md b/docs/events.md new file mode 100644 index 00000000000..add381754cc --- /dev/null +++ b/docs/events.md @@ -0,0 +1,39 @@ + +# Events + +Tekton runtime resources, specifically `TaskRuns` and `PipelineRuns`, +emit events when they are executed, so that users can monitor their lifecycle +and react to it. Tekton emits [kubernetes events](https://kubernetes.io/docs/reference/generated/kubernetes-api/v1.18/#event-v1-core), that can be retrieve from the resource via +`kubectl describe [resource]`. + +No events are emitted for `Conditions` today (https://github.com/tektoncd/pipeline/issues/2461). + +## TaskRuns + +`TaskRun` events are generated for the following `Reasons`: +- `Started`: this is triggered the first time the `TaskRun` is picked by the + reconciler from its work queue, so it only happens if web-hook validation was + successful. Note that this event does not imply that a step started executing, + as several conditions must be met first: + - task and bound resource validation must be successful + - attached conditions must run successfully + - the `Pod` associated to the `TaskRun` must be successfully scheduled +- `Succeeded`: this is triggered once all steps in the `TaskRun` are executed + successfully, including post-steps injected by Tekton. +- `Failed`: this is triggered if the `TaskRun` is completed, but not successfully. + Causes of failure may be: one the steps failed, the `TaskRun` was cancelled or + the `TaskRun` timed out. + +## PipelineRuns + +`PipelineRun` events are generated for the following `Reasons`: +- `Succeeded`: this is triggered once all `Tasks` reachable via the DAG are + executed successfully. +- `Failed`: this is triggered if the `PipelineRun` is completed, but not + successfully. Causes of failure may be: one the `Tasks` failed or the + `PipelineRun` was cancelled. diff --git a/docs/pipelineruns.md b/docs/pipelineruns.md index 07c7614df04..5a3cab00a0b 100644 --- a/docs/pipelineruns.md +++ b/docs/pipelineruns.md @@ -18,6 +18,8 @@ weight: 4 - [Specifying `LimitRange` values](#specifying-limitrange-values) - [Configuring a failure timeout](#configuring-a-failure-timeout) - [Cancelling a `PipelineRun`](#cancelling-a-pipelinerun) +- [Events](events.md#pipelineruns) + ## Overview diff --git a/docs/taskruns.md b/docs/taskruns.md index 68ca1790196..fa564c222eb 100644 --- a/docs/taskruns.md +++ b/docs/taskruns.md @@ -22,6 +22,7 @@ weight: 2 - [Monitoring `Steps`](#monitoring-steps) - [Monitoring `Results`](#monitoring-results) - [Cancelling a `TaskRun`](#cancelling-a-taskrun) +- [Events](events.md#taskruns) - [Code examples](#code-examples) - [Example `TaskRun` with a referenced `Task`](#example-taskrun-with-a-referenced-task) - [Example `TaskRun` with an embedded `Task`](#example-taskrun-with-an-embedded-task) diff --git a/pkg/reconciler/event.go b/pkg/reconciler/event.go index e35560b88ef..515e6cf1387 100644 --- a/pkg/reconciler/event.go +++ b/pkg/reconciler/event.go @@ -17,6 +17,7 @@ package reconciler import ( corev1 "k8s.io/api/core/v1" + "k8s.io/apimachinery/pkg/api/equality" "k8s.io/apimachinery/pkg/runtime" "k8s.io/client-go/tools/record" "knative.dev/pkg/apis" @@ -27,20 +28,38 @@ const ( EventReasonSucceded = "Succeeded" // EventReasonFailed is the reason set for events about unsuccessful completion of TaskRuns / PipelineRuns EventReasonFailed = "Failed" + // EventReasonStarted is the reason set for events about the start of TaskRuns / PipelineRuns + EventReasonStarted = "Started" ) -// EmitEvent emits success or failed event for object -// if afterCondition is different from beforeCondition +// EmitEvent emits an event for object if afterCondition is different from beforeCondition +// +// Status "ConditionUnknown": +// beforeCondition == nil, emit EventReasonStarted +// beforeCondition != nil, emit afterCondition.Reason +// +// Status "ConditionTrue": emit EventReasonSucceded +// Status "ConditionFalse": emit EventReasonFailed +// func EmitEvent(c record.EventRecorder, beforeCondition *apis.Condition, afterCondition *apis.Condition, object runtime.Object) { - if beforeCondition != afterCondition && afterCondition != nil { - // Create events when the obj result is in. + if !equality.Semantic.DeepEqual(beforeCondition, afterCondition) && afterCondition != nil { + // If the condition changed, and the target condition is not empty, we send an event switch afterCondition.Status { case corev1.ConditionTrue: c.Event(object, corev1.EventTypeNormal, EventReasonSucceded, afterCondition.Message) - case corev1.ConditionUnknown: - c.Event(object, corev1.EventTypeNormal, afterCondition.Reason, afterCondition.Message) case corev1.ConditionFalse: c.Event(object, corev1.EventTypeWarning, EventReasonFailed, afterCondition.Message) + case corev1.ConditionUnknown: + if beforeCondition == nil { + // If the condition changed, the status is "unknown", and there was no condition before, + // we emit the "Started event". We ignore further updates of the "unknown" status. + c.Event(object, corev1.EventTypeNormal, EventReasonStarted, "") + } else { + // If the condition changed, the status is "unknown", and there was a condition before, + // we emit an event that matches the reason and message of the condition. + // This is used for instance to signal the transition from "started" to "running" + c.Event(object, corev1.EventTypeNormal, afterCondition.Reason, afterCondition.Message) + } } } } diff --git a/pkg/reconciler/event_test.go b/pkg/reconciler/event_test.go index f6c464c23c7..17ff4fbfff0 100644 --- a/pkg/reconciler/event_test.go +++ b/pkg/reconciler/event_test.go @@ -21,38 +21,45 @@ import ( "time" corev1 "k8s.io/api/core/v1" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/client-go/tools/record" "knative.dev/pkg/apis" ) func TestEmitEvent(t *testing.T) { testcases := []struct { - name string - before *apis.Condition - after *apis.Condition - expectEvent bool + name string + before *apis.Condition + after *apis.Condition + expectEvent bool + expectedEvent string }{{ - name: "unknown to true", + name: "unknown to true with message", before: &apis.Condition{ Type: apis.ConditionSucceeded, Status: corev1.ConditionUnknown, }, after: &apis.Condition{ - Type: apis.ConditionSucceeded, - Status: corev1.ConditionTrue, + Type: apis.ConditionSucceeded, + Status: corev1.ConditionTrue, + Message: "all done", }, - expectEvent: true, + expectEvent: true, + expectedEvent: "Normal Succeeded all done", }, { name: "true to true", before: &apis.Condition{ - Type: apis.ConditionSucceeded, - Status: corev1.ConditionTrue, + Type: apis.ConditionSucceeded, + Status: corev1.ConditionTrue, + LastTransitionTime: apis.VolatileTime{Inner: metav1.NewTime(time.Now())}, }, after: &apis.Condition{ - Type: apis.ConditionSucceeded, - Status: corev1.ConditionTrue, + Type: apis.ConditionSucceeded, + Status: corev1.ConditionTrue, + LastTransitionTime: apis.VolatileTime{Inner: metav1.NewTime(time.Now().Add(5 * time.Minute))}, }, - expectEvent: false, + expectEvent: false, + expectedEvent: "", }, { name: "false to false", before: &apis.Condition{ @@ -63,7 +70,24 @@ func TestEmitEvent(t *testing.T) { Type: apis.ConditionSucceeded, Status: corev1.ConditionFalse, }, - expectEvent: false, + expectEvent: false, + expectedEvent: "", + }, { + name: "unknown to unknown", + before: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionUnknown, + Reason: "", + Message: "", + }, + after: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionUnknown, + Reason: "foo", + Message: "bar", + }, + expectEvent: true, + expectedEvent: "Normal foo bar", }, { name: "true to nil", after: nil, @@ -71,7 +95,8 @@ func TestEmitEvent(t *testing.T) { Type: apis.ConditionSucceeded, Status: corev1.ConditionTrue, }, - expectEvent: true, + expectEvent: false, + expectedEvent: "", }, { name: "nil to true", before: nil, @@ -79,7 +104,40 @@ func TestEmitEvent(t *testing.T) { Type: apis.ConditionSucceeded, Status: corev1.ConditionTrue, }, - expectEvent: true, + expectEvent: true, + expectedEvent: "Normal Succeeded ", + }, { + name: "nil to unknown with message", + before: nil, + after: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionUnknown, + Message: "just starting", + }, + expectEvent: true, + expectedEvent: "Normal Started ", + }, { + name: "unknown to false with message", + before: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionUnknown, + }, + after: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionFalse, + Message: "really bad", + }, + expectEvent: true, + expectedEvent: "Warning Failed really bad", + }, { + name: "nil to false", + before: nil, + after: &apis.Condition{ + Type: apis.ConditionSucceeded, + Status: corev1.ConditionFalse, + }, + expectEvent: true, + expectedEvent: "Warning Failed ", }} for _, ts := range testcases { @@ -90,12 +148,21 @@ func TestEmitEvent(t *testing.T) { select { case event := <-fr.Events: - if ts.expectEvent && event == "" { - t.Errorf("Expected event but got empty for %s", ts.name) + if event == "" { + // The fake recorder reported empty, it should not happen + t.Fatalf("Expected event but got empty for %s", ts.name) } - case <-timer.C: if !ts.expectEvent { - t.Errorf("Unexpected event but got for %s", ts.name) + // The fake recorder reported an event which we did not expect + t.Errorf("Unxpected event \"%s\" but got one for %s", event, ts.name) + } + if !(event == ts.expectedEvent) { + t.Errorf("Expected event \"%s\" but got \"%s\" instead for %s", ts.expectedEvent, event, ts.name) + } + case <-timer.C: + if ts.expectEvent { + // The fake recorder did not report, the timer timeout expired + t.Errorf("Expected event but got none for %s", ts.name) } } } diff --git a/pkg/reconciler/taskrun/controller.go b/pkg/reconciler/taskrun/controller.go index 4642b801947..14dd9f1908a 100644 --- a/pkg/reconciler/taskrun/controller.go +++ b/pkg/reconciler/taskrun/controller.go @@ -44,6 +44,7 @@ const ( resyncPeriod = 10 * time.Hour ) +// NewController instantiates a new controller.Impl from knative.dev/pkg/controller func NewController(images pipeline.Images) func(context.Context, configmap.Watcher) *controller.Impl { return func(ctx context.Context, cmw configmap.Watcher) *controller.Impl { logger := logging.FromContext(ctx) @@ -66,6 +67,7 @@ func NewController(images pipeline.Images) func(context.Context, configmap.Watch ConfigMapWatcher: cmw, ResyncPeriod: resyncPeriod, Logger: logger, + Recorder: controller.GetEventRecorder(ctx), } entrypointCache, err := pod.NewEntrypointCache(kubeclientset) diff --git a/pkg/reconciler/taskrun/resources/cloudevent/cloud_event_controller.go b/pkg/reconciler/taskrun/resources/cloudevent/cloud_event_controller.go index 04fde4fbc85..694a3ebe2fc 100644 --- a/pkg/reconciler/taskrun/resources/cloudevent/cloud_event_controller.go +++ b/pkg/reconciler/taskrun/resources/cloudevent/cloud_event_controller.go @@ -66,8 +66,7 @@ func cloudEventDeliveryFromTargets(targets []string) []v1alpha1.CloudEventDelive } // SendCloudEvents is used by the TaskRun controller to send cloud events once -// the TaskRun is complete. `tr` is used to obtain the list of targets but also -// to construct the body of the +// the TaskRun is complete. `tr` is used to obtain the list of targets func SendCloudEvents(tr *v1alpha1.TaskRun, ceclient CEClient, logger *zap.SugaredLogger) error { logger = logger.With(zap.String("taskrun", tr.Name)) diff --git a/pkg/reconciler/taskrun/taskrun.go b/pkg/reconciler/taskrun/taskrun.go index 079dcaf824b..f5cc0b51ec0 100644 --- a/pkg/reconciler/taskrun/taskrun.go +++ b/pkg/reconciler/taskrun/taskrun.go @@ -103,11 +103,16 @@ func (c *Reconciler) Reconcile(ctx context.Context, key string) error { // If the TaskRun is just starting, this will also set the starttime, // from which the timeout will immediately begin counting down. - tr.Status.InitializeConditions() - // In case node time was not synchronized, when controller has been scheduled to other nodes. - if tr.Status.StartTime.Sub(tr.CreationTimestamp.Time) < 0 { - c.Logger.Warnf("TaskRun %s createTimestamp %s is after the taskRun started %s", tr.GetRunKey(), tr.CreationTimestamp, tr.Status.StartTime) - tr.Status.StartTime = &tr.CreationTimestamp + if !tr.HasStarted() { + tr.Status.InitializeConditions() + // In case node time was not synchronized, when controller has been scheduled to other nodes. + if tr.Status.StartTime.Sub(tr.CreationTimestamp.Time) < 0 { + c.Logger.Warnf("TaskRun %s createTimestamp %s is after the taskRun started %s", tr.GetRunKey(), tr.CreationTimestamp, tr.Status.StartTime) + tr.Status.StartTime = &tr.CreationTimestamp + } + // Emit events + afterCondition := tr.Status.GetCondition(apis.ConditionSucceeded) + reconciler.EmitEvent(c.Recorder, nil, afterCondition, tr) } // If the TaskRun is complete, run some post run fixtures when applicable @@ -200,7 +205,6 @@ func (c *Reconciler) Reconcile(ctx context.Context, key string) error { if err = c.reconcile(ctx, tr, taskSpec, rtr); err != nil { c.Logger.Errorf("Reconcile error: %v", err.Error()) } - // Emit events (only when ConditionSucceeded was changed) after := tr.Status.GetCondition(apis.ConditionSucceeded) reconciler.EmitEvent(c.Recorder, before, after, tr) @@ -337,6 +341,9 @@ func (c *Reconciler) reconcile(ctx context.Context, tr *v1alpha1.TaskRun, if k8serrors.IsNotFound(err) { // Keep going, this will result in the Pod being created below. } else if err != nil { + // This is considered a transient error, so we return error, do not update + // the task run condition, and return an error which will cause this key to + // be requeued for reconcile. c.Logger.Errorf("Error getting pod %q: %v", tr.Status.PodName, err) return err } @@ -401,7 +408,6 @@ func (c *Reconciler) reconcile(ctx context.Context, tr *v1alpha1.TaskRun, } c.Logger.Infof("Successfully reconciled taskrun %s/%s with status: %#v", tr.Name, tr.Namespace, tr.Status.GetCondition(apis.ConditionSucceeded)) - return nil } diff --git a/pkg/reconciler/taskrun/taskrun_test.go b/pkg/reconciler/taskrun/taskrun_test.go index 53d66a2cd52..682a700f297 100644 --- a/pkg/reconciler/taskrun/taskrun_test.go +++ b/pkg/reconciler/taskrun/taskrun_test.go @@ -48,6 +48,7 @@ import ( fakekubeclientset "k8s.io/client-go/kubernetes/fake" ktesting "k8s.io/client-go/testing" "k8s.io/client-go/tools/cache" + "k8s.io/client-go/tools/record" "knative.dev/pkg/apis" duckv1beta1 "knative.dev/pkg/apis/duck/v1beta1" "knative.dev/pkg/configmap" @@ -271,6 +272,34 @@ func getTaskRunController(t *testing.T, d test.Data) (test.Assets, func()) { }, cancel } +func checkEvents(fr *record.FakeRecorder, testName string, wantEvents []string) error { + // We need a timer to handle the case in which we receive fewer events than + // we expect, so we only hit the timeout in case of failure of the test. + timer := time.NewTimer(1 * time.Second) + foundEvents := []string{} + for ii := 0; ii < len(wantEvents)+1; ii++ { + // We loop over all the events that we expect. Once they are all received + // we exit the loop. If we never receive enough events, the timeout takes us + // out of the loop. + select { + case event := <-fr.Events: + foundEvents = append(foundEvents, event) + if ii > len(wantEvents)-1 { + return fmt.Errorf("Received event \"%s\" for %s but not more expected", event, testName) + } + wantEvent := wantEvents[ii] + if !(strings.HasPrefix(event, wantEvent)) { + return fmt.Errorf("Expected event \"%s\" but got \"%s\" instead for %s", wantEvent, event, testName) + } + case <-timer.C: + if len(foundEvents) > len(wantEvents) { + return fmt.Errorf("Received %d events for %s but %d expected. Found events: %#v", len(foundEvents), testName, len(wantEvents), foundEvents) + } + } + } + return nil +} + func TestReconcile_ExplicitDefaultSA(t *testing.T) { taskRunSuccess := tb.TaskRun("test-taskrun-run-success", tb.TaskRunNamespace("foo"), tb.TaskRunSpec( tb.TaskRunTaskRef(simpleTask.Name, tb.TaskRefAPIVersion("a1")), @@ -574,11 +603,14 @@ func TestReconcile(t *testing.T) { name string taskRun *v1alpha1.TaskRun wantPod *corev1.Pod - wantEvents int + wantEvents []string }{{ - name: "success", - taskRun: taskRunSuccess, - wantEvents: 1, + name: "success", + taskRun: taskRunSuccess, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-run-success-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -616,9 +648,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "serviceaccount", - taskRun: taskRunWithSaSuccess, - wantEvents: 1, + name: "serviceaccount", + taskRun: taskRunWithSaSuccess, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-sa-run-success-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -657,9 +692,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "params", - taskRun: taskRunSubstitution, - wantEvents: 1, + name: "params", + taskRun: taskRunSubstitution, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-substitution-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -740,9 +778,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "taskrun-with-taskspec", - taskRun: taskRunWithTaskSpec, - wantEvents: 1, + name: "taskrun-with-taskspec", + taskRun: taskRunWithTaskSpec, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-taskspec-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -798,9 +839,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "success-with-cluster-task", - taskRun: taskRunWithClusterTask, - wantEvents: 1, + name: "success-with-cluster-task", + taskRun: taskRunWithClusterTask, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-cluster-task-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -839,9 +883,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "taskrun-with-resource-spec-task-spec", - taskRun: taskRunWithResourceSpecAndTaskSpec, - wantEvents: 1, + name: "taskrun-with-resource-spec-task-spec", + taskRun: taskRunWithResourceSpecAndTaskSpec, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-resource-spec-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -896,9 +943,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "taskrun-with-pod", - taskRun: taskRunWithPod, - wantEvents: 1, + name: "taskrun-with-pod", + taskRun: taskRunWithPod, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-pod-pod-abcde", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -935,9 +985,12 @@ func TestReconcile(t *testing.T) { ), ), }, { - name: "taskrun-with-credentials-variable-default-tekton-home", - taskRun: taskRunWithCredentialsVariable, - wantEvents: 1, + name: "taskrun-with-credentials-variable-default-tekton-home", + taskRun: taskRunWithCredentialsVariable, + wantEvents: []string{ + "Normal Started ", + "Normal Running Not all Steps", + }, wantPod: tb.Pod("test-taskrun-with-credentials-variable-pod-9l9zj", tb.PodNamespace("foo"), tb.PodAnnotation(podconvert.ReleaseAnnotation, podconvert.ReleaseAnnotationValue), @@ -993,7 +1046,10 @@ func TestReconcile(t *testing.T) { t.Fatal(err) } - if err := c.Reconciler.Reconcile(context.Background(), getRunName(tc.taskRun)); err != nil { + reconciler := c.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) + + if err := reconciler.Reconcile(context.Background(), getRunName(tc.taskRun)); err != nil { t.Errorf("expected no error. Got error %v", err) } if len(clients.Kube.Actions()) == 0 { @@ -1038,15 +1094,9 @@ func TestReconcile(t *testing.T) { t.Fatalf("Expected actions to be logged in the kubeclient, got none") } - actions := clients.Kube.Actions() - var eventCount = 0 - for _, action := range actions { - if action.GetVerb() == "create" && action.GetResource().Resource == "events" { - eventCount++ - } - } - if d := cmp.Diff(tc.wantEvents, eventCount); d != "" { - t.Errorf("Event count does not match (-want, +got): %s. ", d) + err = checkEvents(fr, tc.name, tc.wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) } }) } @@ -1194,17 +1244,26 @@ func TestReconcileInvalidTaskRuns(t *testing.T) { } testcases := []struct { - name string - taskRun *v1alpha1.TaskRun - reason string + name string + taskRun *v1alpha1.TaskRun + reason string + wantEvents []string }{{ name: "task run with no task", taskRun: noTaskRun, reason: podconvert.ReasonFailedResolution, + wantEvents: []string{ + "Normal Started ", + "Warning Failed ", + }, }, { name: "task run with wrong ref", taskRun: withWrongRef, reason: podconvert.ReasonFailedResolution, + wantEvents: []string{ + "Normal Started ", + "Warning Failed ", + }, }} for _, tc := range testcases { @@ -1213,24 +1272,28 @@ func TestReconcileInvalidTaskRuns(t *testing.T) { defer cancel() c := testAssets.Controller clients := testAssets.Clients - err := c.Reconciler.Reconcile(context.Background(), getRunName(tc.taskRun)) - // Events are sent in a goroutine, let's sleep a bit to make sure they're - // captured by the fake client-go action list - time.Sleep(100 * time.Millisecond) + reconciler := c.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) + err := reconciler.Reconcile(context.Background(), getRunName(tc.taskRun)) + // When a TaskRun is invalid and can't run, we don't want to return an error because // an error will tell the Reconciler to keep trying to reconcile; instead we want to stop // and forget about the Run. if err != nil { t.Errorf("Did not expect to see error when reconciling invalid TaskRun but saw %q", err) } + + // Check actions and events actions := clients.Kube.Actions() - if len(actions) != 2 || - actions[0].GetVerb() != "list" || - actions[0].GetResource().Resource != "namespaces" || - actions[1].GetVerb() != "create" || - actions[1].GetResource().Resource != "events" { - t.Errorf("expected two actions (list namespaces + event) created by the reconciler, got %+v", actions) + if len(actions) != 1 || actions[0].Matches("namespaces", "list") { + t.Errorf("expected one action (list namespaces) created by the reconciler, got %d. Actions: %#v", len(actions), actions) } + + err = checkEvents(fr, tc.name, tc.wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) + } + // Since the TaskRun is invalid, the status should say it has failed condition := tc.taskRun.Status.GetCondition(apis.ConditionSucceeded) if condition == nil || condition.Status != corev1.ConditionFalse { @@ -1314,8 +1377,10 @@ func TestReconcilePodUpdateStatus(t *testing.T) { defer cancel() c := testAssets.Controller clients := testAssets.Clients + reconciler := c.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) - if err := c.Reconciler.Reconcile(context.Background(), getRunName(taskRun)); err != nil { + if err := reconciler.Reconcile(context.Background(), getRunName(taskRun)); err != nil { t.Fatalf("Unexpected error when Reconcile() : %v", err) } newTr, err := clients.Pipeline.TektonV1alpha1().TaskRuns(taskRun.Namespace).Get(taskRun.Name, metav1.GetOptions{}) @@ -1354,6 +1419,16 @@ func TestReconcilePodUpdateStatus(t *testing.T) { }, newTr.Status.GetCondition(apis.ConditionSucceeded), ignoreLastTransitionTime); d != "" { t.Errorf("Did not get expected condition (-want, +got): %v", d) } + + wantEvents := []string{ + "Normal Started ", + "Normal Running Not all Steps", + "Normal Succeeded", + } + err = checkEvents(fr, "test-reconcile-pod-updateStatus", wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) + } } func TestReconcileOnCompletedTaskRun(t *testing.T) { @@ -1409,8 +1484,10 @@ func TestReconcileOnCancelledTaskRun(t *testing.T) { defer cancel() c := testAssets.Controller clients := testAssets.Clients + reconciler := c.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) - if err := c.Reconciler.Reconcile(context.Background(), getRunName(taskRun)); err != nil { + if err := reconciler.Reconcile(context.Background(), getRunName(taskRun)); err != nil { t.Fatalf("Unexpected error when reconciling completed TaskRun : %v", err) } newTr, err := clients.Pipeline.TektonV1alpha1().TaskRuns(taskRun.Namespace).Get(taskRun.Name, metav1.GetOptions{}) @@ -1427,12 +1504,22 @@ func TestReconcileOnCancelledTaskRun(t *testing.T) { if d := cmp.Diff(expectedStatus, newTr.Status.GetCondition(apis.ConditionSucceeded), ignoreLastTransitionTime); d != "" { t.Fatalf("Did not get expected condition (-want, +got): %v", d) } + + wantEvents := []string{ + "Normal Started", + "Warning Failed TaskRun \"test-taskrun-run-cancelled\" was cancelled", + } + err = checkEvents(fr, "test-reconcile-on-cancelled-taskrun", wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) + } } func TestReconcileTimeouts(t *testing.T) { type testCase struct { taskRun *v1alpha1.TaskRun expectedStatus *apis.Condition + wantEvents []string } testcases := []testCase{ @@ -1454,6 +1541,9 @@ func TestReconcileTimeouts(t *testing.T) { Reason: "TaskRunTimeout", Message: `TaskRun "test-taskrun-timeout" failed to finish within "10s"`, }, + wantEvents: []string{ + "Warning Failed ", + }, }, { taskRun: tb.TaskRun("test-taskrun-default-timeout-60-minutes", tb.TaskRunNamespace("foo"), @@ -1471,6 +1561,9 @@ func TestReconcileTimeouts(t *testing.T) { Reason: "TaskRunTimeout", Message: `TaskRun "test-taskrun-default-timeout-60-minutes" failed to finish within "1h0m0s"`, }, + wantEvents: []string{ + "Warning Failed ", + }, }, { taskRun: tb.TaskRun("test-taskrun-nil-timeout-default-60-minutes", tb.TaskRunNamespace("foo"), @@ -1489,6 +1582,9 @@ func TestReconcileTimeouts(t *testing.T) { Reason: "TaskRunTimeout", Message: `TaskRun "test-taskrun-nil-timeout-default-60-minutes" failed to finish within "1h0m0s"`, }, + wantEvents: []string{ + "Warning Failed ", + }, }} for _, tc := range testcases { @@ -1500,6 +1596,8 @@ func TestReconcileTimeouts(t *testing.T) { defer cancel() c := testAssets.Controller clients := testAssets.Clients + reconciler := c.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) if err := c.Reconciler.Reconcile(context.Background(), getRunName(tc.taskRun)); err != nil { t.Fatalf("Unexpected error when reconciling completed TaskRun : %v", err) @@ -1512,6 +1610,10 @@ func TestReconcileTimeouts(t *testing.T) { if d := cmp.Diff(tc.expectedStatus, condition, ignoreLastTransitionTime); d != "" { t.Fatalf("Did not get expected condition (-want, +got): %v", d) } + err = checkEvents(fr, tc.taskRun.Name, tc.wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) + } } } @@ -2179,6 +2281,7 @@ func TestReconcileTaskResourceResolutionAndValidation(t *testing.T) { desc string d test.Data wantFailedReason string + wantEvents []string }{{ desc: "Fail ResolveTaskResources", d: test.Data{ @@ -2200,6 +2303,10 @@ func TestReconcileTaskResourceResolutionAndValidation(t *testing.T) { PipelineResources: nil, }, wantFailedReason: podconvert.ReasonFailedResolution, + wantEvents: []string{ + "Normal Started ", + "Warning Failed", + }, }, { desc: "Fail ValidateResolvedTaskResources", d: test.Data{ @@ -2218,14 +2325,20 @@ func TestReconcileTaskResourceResolutionAndValidation(t *testing.T) { PipelineResources: nil, }, wantFailedReason: podconvert.ReasonFailedValidation, + wantEvents: []string{ + "Normal Started ", + "Warning Failed", + }, }} { t.Run(tt.desc, func(t *testing.T) { names.TestingSeed() testAssets, cancel := getTaskRunController(t, tt.d) defer cancel() clients := testAssets.Clients + reconciler := testAssets.Controller.Reconciler.(*Reconciler) + fr := reconciler.Recorder.(*record.FakeRecorder) - if err := testAssets.Controller.Reconciler.Reconcile(context.Background(), getRunName(tt.d.TaskRuns[0])); err != nil { + if err := reconciler.Reconcile(context.Background(), getRunName(tt.d.TaskRuns[0])); err != nil { t.Errorf("expected no error reconciling valid TaskRun but got %v", err) } @@ -2239,6 +2352,11 @@ func TestReconcileTaskResourceResolutionAndValidation(t *testing.T) { t.Errorf("Expected TaskRun to \"%s\" but it did not. Final conditions were:\n%#v", tt.wantFailedReason, tr.Status.Conditions) } } + + err = checkEvents(fr, tt.desc, tt.wantEvents) + if !(err == nil) { + t.Errorf(err.Error()) + } }) } }