refactor: Use new logrus.Logger instead of default

Use a new logrus.Logger instance instead of the default logrus singleton. Relying on the default singleton is problematic when dependencies (or transitive dependencies) also use logrus. When code paths in these dependencies modify the default singleton, it also impacts Skaffold logging. I ran into this issue while trying to upgrade the `ko` dependency to v0.10, and there was unwanted error-level log output messages from `amazon-ecr-credential-helper`. Context: - ko-build/ko#586 - awslabs/amazon-ecr-credential-helper#309 This change also moves us closer to not leaking the logger implementation dependency outside the `output/log` package. Tracking: #7131
GoogleContainerTools · Mar 15, 2022 · c0b8c5d · c0b8c5d
1 parent 31c725a
commit c0b8c5d
Show file tree

Hide file tree

Showing 17 changed files with 171 additions and 99 deletions.
diff --git a/integration/binpack/binpack.go b/integration/binpack/binpack.go
@@ -17,10 +17,11 @@ limitations under the License.
 package binpack
 
 import (
+	"context"
 	"fmt"
 	"sort"
 
-	"github.com/sirupsen/logrus"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/output/log"
 )
 
 type timing struct {
@@ -124,10 +125,11 @@ func Partitions() (map[string]int, int) {
 			result[timing.name] = len(bins) - 1
 		}
 	}
-	if logrus.GetLevel() == logrus.TraceLevel {
-		logrus.Trace("Partitions: ")
+	if log.IsTraceLevelEnabled() {
+		ctx := context.TODO()
+		log.Entry(ctx).Trace("Partitions: ")
 		for i, b := range bins {
-			logrus.Tracef("P%d %s\n", i, b.String())
+			log.Entry(ctx).Tracef("P%d %s\n", i, b.String())
 		}
 	}
 	return result, len(bins) - 1

diff --git a/integration/binpack/binpack_test.go b/integration/binpack/binpack_test.go
@@ -20,15 +20,14 @@ import (
 	"fmt"
 	"testing"
 
-	"github.com/sirupsen/logrus"
-
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/output/log"
 	"github.com/GoogleContainerTools/skaffold/testutil"
 )
 
 func TestPartitions(t *testing.T) {
-	level := logrus.GetLevel()
-	defer logrus.SetLevel(level)
-	logrus.SetLevel(logrus.TraceLevel)
+	level := log.GetLevel()
+	defer log.SetLevel(level)
+	log.SetLevel(log.TraceLevel)
 	partitions, lastPartition := Partitions()
 	testutil.CheckDeepEqual(t, len(partitions), len(timings))
 	var bins []bin

diff --git a/integration/build_dependencies_test.go b/integration/build_dependencies_test.go
@@ -22,7 +22,6 @@ import (
 	"testing"
 
 	"github.com/google/uuid"
-	"github.com/sirupsen/logrus"
 
 	"github.com/GoogleContainerTools/skaffold/integration/skaffold"
 )
@@ -85,7 +84,7 @@ func TestBuildDependenciesOrder(t *testing.T) {
 				if out, err := skaffold.Build(test.args...).InDir("testdata/build-dependencies").RunWithCombinedOutput(t); err == nil {
 					t.Fatal("expected build to fail")
 				} else if !strings.Contains(string(out), test.failure) {
-					logrus.Info("build output: ", string(out))
+					t.Log("build output: ", string(out))
 					t.Fatalf("build failed but for wrong reason")
 				}
 			}
@@ -152,12 +151,12 @@ func TestBuildDependenciesCache(t *testing.T) {
 
 			for i := 1; i <= 4; i++ {
 				if !contains(test.rebuilt, i) && !strings.Contains(log, fmt.Sprintf("image%d: Found Locally", i)) {
-					logrus.Info("build output: ", string(out))
+					t.Log("build output: ", string(out))
 					t.Fatalf("expected image%d to be cached", i)
 				}
 
 				if contains(test.rebuilt, i) && !strings.Contains(log, fmt.Sprintf("image%d: Not found. Building", i)) {
-					logrus.Info("build output: ", string(out))
+					t.Log("build output: ", string(out))
 					t.Fatalf("expected image%d to be rebuilt", i)
 				}
 			}

diff --git a/integration/build_test.go b/integration/build_test.go
@@ -25,7 +25,6 @@ import (
 	"time"
 
 	"4d63.com/tz"
-	"github.com/sirupsen/logrus"
 
 	"github.com/GoogleContainerTools/skaffold/integration/skaffold"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/build/jib"
@@ -136,7 +135,7 @@ func TestExpectedBuildFailures(t *testing.T) {
 			if out, err := skaffold.Build(test.args...).InDir(test.dir).RunWithCombinedOutput(t); err == nil {
 				t.Fatal("expected build to fail")
 			} else if !strings.Contains(string(out), test.expected) {
-				logrus.Info("build output: ", string(out))
+				t.Log("build output: ", string(out))
 				t.Fatalf("build failed but for wrong reason")
 			}
 		})

diff --git a/integration/dev_dependencies_test.go b/integration/dev_dependencies_test.go
@@ -20,7 +20,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/sirupsen/logrus"
 	"k8s.io/apimachinery/pkg/util/wait"
 
 	"github.com/GoogleContainerTools/skaffold/integration/skaffold"
@@ -51,10 +50,10 @@ func TestDev_WithDependencies(t *testing.T) {
 			newDep2 := client.GetDeployment("app2")
 			newDep3 := client.GetDeployment("app3")
 			newDep4 := client.GetDeployment("app4")
-			logrus.Infof("app1 - old gen: %d, new gen: %d", dep1.GetGeneration(), newDep1.GetGeneration())
-			logrus.Infof("app2 - old gen: %d, new gen: %d", dep2.GetGeneration(), newDep2.GetGeneration())
-			logrus.Infof("app3 - old gen: %d, new gen: %d", dep3.GetGeneration(), newDep3.GetGeneration())
-			logrus.Infof("app4 - old gen: %d, new gen: %d", dep4.GetGeneration(), newDep4.GetGeneration())
+			t.Logf("app1 - old gen: %d, new gen: %d", dep1.GetGeneration(), newDep1.GetGeneration())
+			t.Logf("app2 - old gen: %d, new gen: %d", dep2.GetGeneration(), newDep2.GetGeneration())
+			t.Logf("app3 - old gen: %d, new gen: %d", dep3.GetGeneration(), newDep3.GetGeneration())
+			t.Logf("app4 - old gen: %d, new gen: %d", dep4.GetGeneration(), newDep4.GetGeneration())
 			return dep1.GetGeneration() != newDep1.GetGeneration() &&
 				dep2.GetGeneration() != newDep2.GetGeneration() &&
 				dep3.GetGeneration() != newDep3.GetGeneration() &&

diff --git a/integration/dev_test.go b/integration/dev_test.go
@@ -28,7 +28,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/sirupsen/logrus"
 	appsv1 "k8s.io/api/apps/v1"
 	"k8s.io/apimachinery/pkg/util/wait"
 	"k8s.io/client-go/tools/clientcmd"
@@ -76,7 +75,7 @@ func TestDevNotification(t *testing.T) {
 			// Make sure the old Deployment and the new Deployment are different
 			err := wait.PollImmediate(time.Millisecond*500, 1*time.Minute, func() (bool, error) {
 				newDep := client.GetDeployment(testDev)
-				logrus.Infof("old gen: %d, new gen: %d", dep.GetGeneration(), newDep.GetGeneration())
+				t.Logf("old gen: %d, new gen: %d", dep.GetGeneration(), newDep.GetGeneration())
 				return dep.GetGeneration() != newDep.GetGeneration(), nil
 			})
 			failNowIfError(t, err)
@@ -248,7 +247,7 @@ func verifyDeployment(t *testing.T, entries chan *proto.LogEntry, client *NSKube
 	// Make sure the old Deployment and the new Deployment are different
 	err = wait.Poll(time.Millisecond*500, 1*time.Minute, func() (bool, error) {
 		newDep := client.GetDeployment(testDev)
-		logrus.Infof("old gen: %d, new gen: %d", dep.GetGeneration(), newDep.GetGeneration())
+		t.Logf("old gen: %d, new gen: %d", dep.GetGeneration(), newDep.GetGeneration())
 		return dep.GetGeneration() != newDep.GetGeneration(), nil
 	})
 	failNowIfError(t, err)

diff --git a/integration/modules_test.go b/integration/modules_test.go
@@ -20,7 +20,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/sirupsen/logrus"
 	"k8s.io/apimachinery/pkg/util/wait"
 
 	"github.com/GoogleContainerTools/skaffold/integration/skaffold"
@@ -49,9 +48,9 @@ func TestModules_BuildDependency(t *testing.T) {
 			newDep1 := client.GetDeployment("app1")
 			newDep2 := client.GetDeployment("app2")
 			newDep3 := client.GetDeployment("app3")
-			logrus.Infof("app1 - old gen: %d, new gen: %d", dep1.GetGeneration(), newDep1.GetGeneration())
-			logrus.Infof("app2 - old gen: %d, new gen: %d", dep2.GetGeneration(), newDep2.GetGeneration())
-			logrus.Infof("app3 - old gen: %d, new gen: %d", dep3.GetGeneration(), newDep3.GetGeneration())
+			t.Logf("app1 - old gen: %d, new gen: %d", dep1.GetGeneration(), newDep1.GetGeneration())
+			t.Logf("app2 - old gen: %d, new gen: %d", dep2.GetGeneration(), newDep2.GetGeneration())
+			t.Logf("app3 - old gen: %d, new gen: %d", dep3.GetGeneration(), newDep3.GetGeneration())
 			return dep1.GetGeneration() != newDep1.GetGeneration() &&
 				dep2.GetGeneration() != newDep2.GetGeneration() &&
 				dep3.GetGeneration() != newDep3.GetGeneration(), nil

diff --git a/integration/port_forward_test.go b/integration/port_forward_test.go
@@ -19,14 +19,13 @@ package integration
 import (
 	"testing"
 
-	"github.com/sirupsen/logrus"
-
 	"github.com/GoogleContainerTools/skaffold/integration/skaffold"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/config"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/constants"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubectl"
 	kubectx "github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/context"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/kubernetes/portforward"
+	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/output/log"
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/runner/runcontext"
 )
 
@@ -53,8 +52,7 @@ func TestPortForward(t *testing.T) {
 			},
 		}, "")
 
-		logrus.SetLevel(logrus.TraceLevel)
-		portforward.SimulateDevCycle(t, kubectlCLI, ns.Name)
+		portforward.SimulateDevCycle(t, kubectlCLI, ns.Name, log.TraceLevel)
 	}
 }
 

diff --git a/integration/skaffold/helper.go b/integration/skaffold/helper.go
@@ -27,7 +27,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 
 	"github.com/GoogleContainerTools/skaffold/cmd/skaffold/app/cmd"
@@ -229,7 +228,7 @@ func (b *RunBuilder) runForked(t *testing.T, out io.Writer) {
 
 	cmd := b.cmd(ctx)
 	cmd.Stdout = out
-	logrus.Infof("Running %s in %s", cmd.Args, cmd.Dir)
+	t.Logf("Running %s in %s", cmd.Args, cmd.Dir)
 
 	start := time.Now()
 	if err := cmd.Start(); err != nil {
@@ -238,7 +237,7 @@ func (b *RunBuilder) runForked(t *testing.T, out io.Writer) {
 
 	go func() {
 		cmd.Wait()
-		logrus.Infof("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
+		t.Logf("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
 	}()
 
 	waitAndTriggerStacktrace(ctx, t, cmd.Process)
@@ -260,7 +259,7 @@ func (b *RunBuilder) Run(t *testing.T) error {
 	t.Helper()
 
 	cmd := b.cmd(context.Background())
-	logrus.Infof("Running %s in %s", cmd.Args, cmd.Dir)
+	t.Logf("Running %s in %s", cmd.Args, cmd.Dir)
 
 	if err := cmd.Run(); err != nil {
 		return fmt.Errorf("skaffold %q: %w", b.command, err)
@@ -273,7 +272,7 @@ func (b *RunBuilder) StartWithProcess(t *testing.T) (*os.Process, error) {
 	t.Helper()
 
 	cmd := b.cmd(context.Background())
-	logrus.Infof("Running %s in %s", cmd.Args, cmd.Dir)
+	t.Logf("Running %s in %s", cmd.Args, cmd.Dir)
 
 	if err := cmd.Start(); err != nil {
 		return nil, fmt.Errorf("skaffold %q: %w", b.command, err)
@@ -287,14 +286,14 @@ func (b *RunBuilder) RunWithCombinedOutput(t *testing.T) ([]byte, error) {
 
 	cmd := b.cmd(context.Background())
 	cmd.Stdout, cmd.Stderr = nil, nil
-	logrus.Infof("Running %s in %s", cmd.Args, cmd.Dir)
+	t.Logf("Running %s in %s", cmd.Args, cmd.Dir)
 
 	start := time.Now()
 	out, err := cmd.CombinedOutput()
 	if err != nil {
 		return out, fmt.Errorf("skaffold %q: %w", b.command, err)
 	}
-	logrus.Infof("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
+	t.Logf("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
 	return out, nil
 }
 
@@ -306,7 +305,7 @@ func (b *RunBuilder) RunOrFailOutput(t *testing.T) []byte {
 
 	cmd := b.cmd(context.Background())
 	cmd.Stdout, cmd.Stderr = nil, nil
-	logrus.Infof("Running %s in %s", cmd.Args, cmd.Dir)
+	t.Logf("Running %s in %s", cmd.Args, cmd.Dir)
 
 	start := time.Now()
 	out, err := cmd.Output()
@@ -316,7 +315,7 @@ func (b *RunBuilder) RunOrFailOutput(t *testing.T) []byte {
 		}
 		t.Fatalf("skaffold %s: %v, %s", b.command, err, out)
 	}
-	logrus.Infof("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
+	t.Logf("Ran %s in %v", cmd.Args, timeutil.Humanize(time.Since(start)))
 	return out
 }