From 0cb52c61cef5d42d9e90e9c2aad379f26fe4c49d Mon Sep 17 00:00:00 2001
From: Karl Isenberg <karlisenberg@google.com>
Date: Fri, 15 Apr 2022 16:03:18 -0700
Subject: [PATCH] chore: Log events at -v=3 for e2e tests

- Events are critical to understanding progress and debugging issues
  in e2e tests.
- Change events to log at level 3 instead of just level 5.
- Change the events string format to reduce verbosity.
- Hide the "Error" in the event string when there's no error.
  This reduces unnecessary highlighting of lines in Prow test logs.
---
 Makefile                        |  2 +-
 pkg/apply/event/event.go        | 42 +++++++++++++++++++++++----------
 pkg/apply/taskrunner/context.go |  2 +-
 3 files changed, 32 insertions(+), 14 deletions(-)

diff --git a/Makefile b/Makefile
index 14ea89f3..ce82dc25 100644
--- a/Makefile
+++ b/Makefile
@@ -70,7 +70,7 @@ test:
 
 test-e2e: $(MYGOBIN)/ginkgo $(MYGOBIN)/kind
 	kind delete cluster --name=cli-utils-e2e && kind create cluster --name=cli-utils-e2e --wait 5m
-	$(GOPATH)/bin/ginkgo ./test/e2e/...
+	$(GOPATH)/bin/ginkgo -v ./test/e2e/... -- -v 3
 
 .PHONY: test-e2e-focus
 test-e2e-focus: $(MYGOBIN)/ginkgo $(MYGOBIN)/kind
diff --git a/pkg/apply/event/event.go b/pkg/apply/event/event.go
index 671873db..7feda98e 100644
--- a/pkg/apply/event/event.go
+++ b/pkg/apply/event/event.go
@@ -74,7 +74,6 @@ type Event struct {
 // String returns a string suitable for logging
 func (e Event) String() string {
 	var sb strings.Builder
-	sb.WriteString("Event{ ")
 	switch e.Type {
 	case InitType:
 		sb.WriteString(e.InitEvent.String())
@@ -95,7 +94,6 @@ func (e Event) String() string {
 	case ValidationType:
 		sb.WriteString(e.ValidationEvent.String())
 	}
-	sb.WriteString(" }")
 	return sb.String()
 }
 
@@ -221,8 +219,12 @@ type ApplyEvent struct {
 
 // String returns a string suitable for logging
 func (ae ApplyEvent) String() string {
-	return fmt.Sprintf("ApplyEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
-		ae.GroupName, ae.Status, ae.Identifier, ae.Error)
+	if ae.Error != nil {
+		return fmt.Sprintf("ApplyEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
+			ae.GroupName, ae.Status, ae.Identifier, ae.Error)
+	}
+	return fmt.Sprintf("ApplyEvent{ GroupName: %q, Status: %q, Identifier: %q }",
+		ae.GroupName, ae.Status, ae.Identifier)
 }
 
 type StatusEvent struct {
@@ -242,8 +244,12 @@ func (se StatusEvent) String() string {
 			gen = se.PollResourceInfo.Resource.GetGeneration()
 		}
 	}
-	return fmt.Sprintf("StatusEvent{ Status: %q, Generation: %d, Identifier: %q, Error: %q }",
-		status, gen, se.Identifier, se.Error)
+	if se.Error != nil {
+		return fmt.Sprintf("StatusEvent{ Status: %q, Generation: %d, Identifier: %q, Error: %q }",
+			status, gen, se.Identifier, se.Error)
+	}
+	return fmt.Sprintf("StatusEvent{ Status: %q, Generation: %d, Identifier: %q }",
+		status, gen, se.Identifier)
 }
 
 //go:generate stringer -type=PruneEventStatus -linecomment
@@ -266,8 +272,12 @@ type PruneEvent struct {
 
 // String returns a string suitable for logging
 func (pe PruneEvent) String() string {
-	return fmt.Sprintf("PruneEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
-		pe.GroupName, pe.Status, pe.Identifier, pe.Error)
+	if pe.Error != nil {
+		return fmt.Sprintf("PruneEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
+			pe.GroupName, pe.Status, pe.Identifier, pe.Error)
+	}
+	return fmt.Sprintf("PruneEvent{ GroupName: %q, Status: %q, Identifier: %q }",
+		pe.GroupName, pe.Status, pe.Identifier)
 }
 
 //go:generate stringer -type=DeleteEventStatus -linecomment
@@ -290,8 +300,12 @@ type DeleteEvent struct {
 
 // String returns a string suitable for logging
 func (de DeleteEvent) String() string {
-	return fmt.Sprintf("DeleteEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
-		de.GroupName, de.Status, de.Identifier, de.Error)
+	if de.Error != nil {
+		return fmt.Sprintf("DeleteEvent{ GroupName: %q, Status: %q, Identifier: %q, Error: %q }",
+			de.GroupName, de.Status, de.Identifier, de.Error)
+	}
+	return fmt.Sprintf("DeleteEvent{ GroupName: %q, Status: %q, Identifier: %q }",
+		de.GroupName, de.Status, de.Identifier)
 }
 
 type ValidationEvent struct {
@@ -301,6 +315,10 @@ type ValidationEvent struct {
 
 // String returns a string suitable for logging
 func (ve ValidationEvent) String() string {
-	return fmt.Sprintf("ValidationEvent{ Identifiers: %+v, Error: %q }",
-		ve.Identifiers, ve.Error)
+	if ve.Error != nil {
+		return fmt.Sprintf("ValidationEvent{ Identifiers: %+v, Error: %q }",
+			ve.Identifiers, ve.Error)
+	}
+	return fmt.Sprintf("ValidationEvent{ Identifiers: %+v }",
+		ve.Identifiers)
 }
diff --git a/pkg/apply/taskrunner/context.go b/pkg/apply/taskrunner/context.go
index f8763e24..705ced4a 100644
--- a/pkg/apply/taskrunner/context.go
+++ b/pkg/apply/taskrunner/context.go
@@ -63,7 +63,7 @@ func (tc *TaskContext) SetGraph(g *graph.Graph) {
 
 // SendEvent sends an event on the event channel
 func (tc *TaskContext) SendEvent(e event.Event) {
-	klog.V(5).Infof("sending event: %s", e)
+	klog.V(3).Infof("Sending event: %v", e)
 	tc.eventChannel <- e
 }