From 63069575ba7f2a324e0b61c593ccf80cb0339f02 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Tue, 17 Sep 2019 09:53:58 -0700 Subject: [PATCH 1/3] Decrease logging level: the extra spam hurts rather than helps --- test/integration/docker_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/integration/docker_test.go b/test/integration/docker_test.go index 629033ca5b..5eec348fd2 100644 --- a/test/integration/docker_test.go +++ b/test/integration/docker_test.go @@ -37,7 +37,7 @@ func TestDockerFlags(t *testing.T) { defer CleanupWithLogs(t, profile, cancel) // Use the most verbose logging for the simplest test. If it fails, something is very wrong. - args := append([]string{"start", "-p", profile, "--wait=false", "--docker-env=FOO=BAR", "--docker-env=BAZ=BAT", "--docker-opt=debug", "--docker-opt=icc=true", "--alsologtostderr", "-v=8"}, StartArgs()...) + args := append([]string{"start", "-p", profile, "--wait=false", "--docker-env=FOO=BAR", "--docker-env=BAZ=BAT", "--docker-opt=debug", "--docker-opt=icc=true", "--alsologtostderr", "-v=5"}, StartArgs()...) rr, err := Run(t, exec.CommandContext(ctx, Target(), args...)) if err != nil { t.Errorf("%s failed: %v", rr.Args, err) From 3e0721b9c0379f627b953c7ca05880f8dceb4d30 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Tue, 17 Sep 2019 09:54:25 -0700 Subject: [PATCH 2/3] Tee logs at -v=8 to reduce duplicated content --- pkg/minikube/command/ssh_runner.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/minikube/command/ssh_runner.go b/pkg/minikube/command/ssh_runner.go index 95f3cada48..01fd780e97 100644 --- a/pkg/minikube/command/ssh_runner.go +++ b/pkg/minikube/command/ssh_runner.go @@ -81,13 +81,13 @@ func teeSSH(s *ssh.Session, cmd string, outB io.Writer, errB io.Writer) error { wg.Add(2) go func() { - if err := util.TeePrefix(util.ErrPrefix, errPipe, errB, glog.V(2).Infof); err != nil { + if err := util.TeePrefix(util.ErrPrefix, errPipe, errB, glog.V(8).Infof); err != nil { glog.Errorf("tee stderr: %v", err) } wg.Done() }() go func() { - if err := util.TeePrefix(util.OutPrefix, outPipe, outB, glog.V(2).Infof); err != nil { + if err := util.TeePrefix(util.OutPrefix, outPipe, outB, glog.V(8).Infof); err != nil { glog.Errorf("tee stdout: %v", err) } wg.Done() From c9bf5a162af359c64bc49679e46ad027b049df84 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Tue, 17 Sep 2019 09:54:48 -0700 Subject: [PATCH 3/3] Redirect machine driver logs to glog --- cmd/minikube/cmd/root.go | 13 ------------- cmd/minikube/main.go | 37 +++++++++++++++++++++++++++++++------ 2 files changed, 31 insertions(+), 19 deletions(-) diff --git a/cmd/minikube/cmd/root.go b/cmd/minikube/cmd/root.go index 5c0d274f29..11bc57b907 100644 --- a/cmd/minikube/cmd/root.go +++ b/cmd/minikube/cmd/root.go @@ -19,13 +19,11 @@ package cmd import ( goflag "flag" "fmt" - "io/ioutil" "os" "runtime" "strings" "github.com/docker/machine/libmachine" - "github.com/docker/machine/libmachine/log" "github.com/golang/glog" "github.com/pkg/errors" "github.com/spf13/cobra" @@ -71,17 +69,6 @@ var RootCmd = &cobra.Command{ } } - // Log level 3 or greater enables libmachine logs - if !glog.V(3) { - log.SetOutWriter(ioutil.Discard) - log.SetErrWriter(ioutil.Discard) - } - - // Log level 7 or greater enables debug level logs - if glog.V(7) { - log.SetDebug(true) - } - logDir := pflag.Lookup("log_dir") if !logDir.Changed { if err := logDir.Value.Set(constants.MakeMiniPath("logs")); err != nil { diff --git a/cmd/minikube/main.go b/cmd/minikube/main.go index ba4dc77f53..b3162c7613 100644 --- a/cmd/minikube/main.go +++ b/cmd/minikube/main.go @@ -21,12 +21,15 @@ import ( "fmt" "log" "os" + "regexp" "strconv" // initflag must be imported before any other minikube pkg. // Fix for https://github.com/kubernetes/minikube/issues/4866 _ "k8s.io/minikube/pkg/initflag" + mlog "github.com/docker/machine/libmachine/log" + "github.com/golang/glog" "github.com/pkg/profile" "k8s.io/minikube/cmd/minikube/cmd" @@ -38,8 +41,13 @@ import ( const minikubeEnableProfile = "MINIKUBE_ENABLE_PROFILING" +var ( + machineLogErrorRe = regexp.MustCompile(`(?i) (failed|error|fatal)`) + machineLogWarningRe = regexp.MustCompile(`(?i)warning`) +) + func main() { - captureStdLogMessages() + bridgeLogMessages() defer glog.Flush() if os.Getenv(minikubeEnableProfile) == "1" { @@ -53,16 +61,18 @@ func main() { cmd.Execute() } -// captureStdLogMessages arranges for messages written to the Go "log" package's to appear in glog -func captureStdLogMessages() { +// bridgeLogMessages bridges non-glog logs into glog +func bridgeLogMessages() { log.SetFlags(log.Lshortfile) - log.SetOutput(logBridge{}) + log.SetOutput(stdLogBridge{}) + mlog.SetErrWriter(machineLogBridge{}) + mlog.SetOutWriter(machineLogBridge{}) } -type logBridge struct{} +type stdLogBridge struct{} // Write parses the standard logging line and passes its components to glog -func (lb logBridge) Write(b []byte) (n int, err error) { +func (lb stdLogBridge) Write(b []byte) (n int, err error) { // Split "d.go:23: message" into "d.go", "23", and "message". parts := bytes.SplitN(b, []byte{':'}, 3) if len(parts) != 3 || len(parts[0]) < 1 || len(parts[2]) < 1 { @@ -80,3 +90,18 @@ func (lb logBridge) Write(b []byte) (n int, err error) { glog.Infof("stdlog: %s:%d %s", file, line, text) return len(b), nil } + +// libmachine log bridge +type machineLogBridge struct{} + +// Write passes machine driver logs to glog +func (lb machineLogBridge) Write(b []byte) (n int, err error) { + if machineLogErrorRe.Match(b) { + glog.Errorf("libmachine: %s", b) + } else if machineLogWarningRe.Match(b) { + glog.Warningf("libmachine: %s", b) + } else { + glog.Infof("libmachine: %s", b) + } + return len(b), nil +}