fix(log): Send Go std log to logrus, and output ggcr logs

pkg/skaffold/output/log/log.go

@@ -20,7 +20,9 @@ import (
 	"context"
 	"fmt"
 	"io"
+	stdlog "log"
 
+	ggcrlogs "github.com/google/go-containerregistry/pkg/logs"
 	"github.com/sirupsen/logrus"
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/constants"
@@ -96,5 +98,47 @@ func SetupLogs(stdErr io.Writer, level string, timestamp bool, hook logrus.Hook)
 		FullTimestamp: timestamp,
 	})
 	logrus.AddHook(hook)
+	setupStdLog(logrus.StandardLogger(), lvl)
+	setupGGCRLogging(logrus.StandardLogger(), lvl)
 	return nil
 }
+
+// setupStdLog writes Go's standard library `log` messages to logrus at Info level.
+//
+// This function uses SetFlags() to standardize the output format.
+//
+// TODO(halvards) Add *stdlog.Logger argument (from stdlog.Default) when the build moves to Go >= 1.16.
+// We can't unit test this function in isolation when we're modifying the singleton stdlog instance.
+func setupStdLog(logger *logrus.Logger, lvl logrus.Level) {
+	stdlog.SetFlags(0)
+	if lvl >= logrus.InfoLevel {
+		stdlog.SetOutput(logger.WriterLevel(logrus.InfoLevel))
+	}
+}
+
+// setupGGCRLogging enables go-containerregistry logging, mapping its levels to logrus.
+//
+// The mapping is:
+// - ggcr Warn -> logrus Error
+// - ggcr Progress -> logrus Info
+// - ggcr Debug -> logrus Trace
+//
+// The reasons for this mapping are:
+// - `ggcr` defines `Warn` as "non-fatal errors": https://github.com/google/go-containerregistry/blob/main/pkg/logs/logs.go#L24
+// - `ggcr` `Debug` logging is _very_ verbose and includes HTTP requests and responses, with non-sensitive headers and non-binary payloads.
+//
+// This function uses SetFlags() to standardize the output format.
+func setupGGCRLogging(logger *logrus.Logger, lvl logrus.Level) {
+	if lvl >= logrus.ErrorLevel {
+		ggcrlogs.Warn.SetOutput(logger.WriterLevel(logrus.ErrorLevel))
+		ggcrlogs.Warn.SetFlags(0)
+	}
+	if lvl >= logrus.InfoLevel {
+		ggcrlogs.Progress.SetOutput(logger.WriterLevel(logrus.InfoLevel))
+		ggcrlogs.Progress.SetFlags(0)
+	}
+	if lvl >= logrus.TraceLevel {
+		ggcrlogs.Debug.SetOutput(logger.WriterLevel(logrus.TraceLevel))
+		ggcrlogs.Debug.SetFlags(0)
+	}
+}

pkg/skaffold/output/log/log_test.go

@@ -20,6 +20,7 @@ import (
 	"context"
 	"testing"
 
+	ggcrlogs "github.com/google/go-containerregistry/pkg/logs"
 	"github.com/sirupsen/logrus"
 
 	"github.com/GoogleContainerTools/skaffold/pkg/skaffold/constants"
@@ -89,3 +90,64 @@ func TestKanikoLogLevel(t *testing.T) {
 		testutil.CheckDeepEqual(t, test.expected, kanikoLevel)
 	}
 }
+
+func TestSetupGGCRLogging(t *testing.T) {
+	tests := []struct {
+		description           string
+		logLevel              logrus.Level
+		expectWarnEnabled     bool
+		expectProgressEnabled bool
+		expectDebugEnabled    bool
+	}{
+		{
+			description: "fatal log level disables ggcr logging",
+			logLevel:    logrus.FatalLevel,
+		},
+		{
+			description:       "error log level enables ggcr warn logging",
+			logLevel:          logrus.ErrorLevel,
+			expectWarnEnabled: true,
+		},
+		{
+			description:       "warn log level enables ggcr warn logging",
+			logLevel:          logrus.WarnLevel,
+			expectWarnEnabled: true,
+		},
+		{
+			description:           "info log level enables ggcr warn and progress logging",
+			logLevel:              logrus.InfoLevel,
+			expectWarnEnabled:     true,
+			expectProgressEnabled: true,
+		},
+		{
+			description:           "debug log level enables ggcr warn and progress logging",
+			logLevel:              logrus.DebugLevel,
+			expectWarnEnabled:     true,
+			expectProgressEnabled: true,
+		},
+		{
+			description:           "trace log level enables ggcr warn and progress and debug logging",
+			logLevel:              logrus.TraceLevel,
+			expectWarnEnabled:     true,
+			expectProgressEnabled: true,
+			expectDebugEnabled:    true,
+		},
+	}
+	for _, test := range tests {
+		testutil.Run(t, test.description, func(t *testutil.T) {
+			setupGGCRLogging(logrus.New(), test.logLevel)
+			t.CheckDeepEqual(test.expectWarnEnabled, ggcrlogs.Enabled(ggcrlogs.Warn))
+			t.CheckDeepEqual(test.expectProgressEnabled, ggcrlogs.Enabled(ggcrlogs.Progress))
+			t.CheckDeepEqual(test.expectDebugEnabled, ggcrlogs.Enabled(ggcrlogs.Debug))
+			if test.expectWarnEnabled {
+				t.CheckDeepEqual(0, ggcrlogs.Warn.Flags())
+			}
+			if test.expectProgressEnabled {
+				t.CheckDeepEqual(0, ggcrlogs.Progress.Flags())
+			}
+			if test.expectDebugEnabled {
+				t.CheckDeepEqual(0, ggcrlogs.Debug.Flags())
+			}
+		})
+	}
+}