Skip to content

Commit

Permalink
refactor: Use new logrus.Logger instead of default
Browse files Browse the repository at this point in the history
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: GoogleContainerTools#7131
  • Loading branch information
halvards committed Mar 15, 2022
1 parent 31c725a commit c0b8c5d
Show file tree
Hide file tree
Showing 17 changed files with 171 additions and 99 deletions.
10 changes: 6 additions & 4 deletions integration/binpack/binpack.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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
Expand Down
9 changes: 4 additions & 5 deletions integration/binpack/binpack_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
7 changes: 3 additions & 4 deletions integration/build_dependencies_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,6 @@ import (
"testing"

"github.com/google/uuid"
"github.com/sirupsen/logrus"

"github.com/GoogleContainerTools/skaffold/integration/skaffold"
)
Expand Down Expand Up @@ -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")
}
}
Expand Down Expand Up @@ -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)
}
}
Expand Down
3 changes: 1 addition & 2 deletions integration/build_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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")
}
})
Expand Down
9 changes: 4 additions & 5 deletions integration/dev_dependencies_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,6 @@ import (
"testing"
"time"

"github.com/sirupsen/logrus"
"k8s.io/apimachinery/pkg/util/wait"

"github.com/GoogleContainerTools/skaffold/integration/skaffold"
Expand Down Expand Up @@ -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() &&
Expand Down
5 changes: 2 additions & 3 deletions integration/dev_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down
7 changes: 3 additions & 4 deletions integration/modules_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,6 @@ import (
"testing"
"time"

"github.com/sirupsen/logrus"
"k8s.io/apimachinery/pkg/util/wait"

"github.com/GoogleContainerTools/skaffold/integration/skaffold"
Expand Down Expand Up @@ -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
Expand Down
6 changes: 2 additions & 4 deletions integration/port_forward_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)

Expand All @@ -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)
}
}

Expand Down
17 changes: 8 additions & 9 deletions integration/skaffold/helper.go
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@ import (
"testing"
"time"

"github.com/sirupsen/logrus"
"github.com/spf13/cobra"

"github.com/GoogleContainerTools/skaffold/cmd/skaffold/app/cmd"
Expand Down Expand Up @@ -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 {
Expand All @@ -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)
Expand All @@ -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)
Expand All @@ -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)
Expand All @@ -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
}

Expand All @@ -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()
Expand All @@ -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
}

Expand Down

0 comments on commit c0b8c5d

Please sign in to comment.