Fix STDOUT and STDERR direction based on Log.* calls

Signed-off-by: Nathan LeClaire <nathan.leclaire@gmail.com>

cmd/machine.go

@@ -88,7 +88,6 @@ func main() {
 		return
 	}
 
-	log.Logger = log.NewLogrusMachineLogger()
 	setDebugOutputLevel()
 	cli.AppHelpTemplate = AppHelpTemplate
 	cli.CommandHelpTemplate = CommandHelpTemplate

commands/config.go

@@ -2,6 +2,7 @@ package commands
 
 import (
 	"fmt"
+	"os"
 
 	"github.com/docker/machine/libmachine"
 	"github.com/docker/machine/libmachine/check"
@@ -11,7 +12,7 @@ import (
 func cmdConfig(c CommandLine, api libmachine.API) error {
 	// Ensure that log messages always go to stderr when this command is
 	// being run (it is intended to be run in a subshell)
-	log.RedirectStdOutToStdErr()
+	log.SetOut(os.Stderr)
 
 	if len(c.Args()) != 1 {
 		return ErrExpectedOneMachine

commands/env.go

@@ -50,7 +50,7 @@ func cmdEnv(c CommandLine, api libmachine.API) error {
 
 	// Ensure that log messages always go to stderr when this command is
 	// being run (it is intended to be run in a subshell)
-	log.RedirectStdOutToStdErr()
+	log.SetOut(os.Stderr)
 
 	if c.Bool("unset") {
 		shellCfg, err = shellCfgUnset(c, api)

libmachine/drivers/plugin/localbinary/plugin_test.go

@@ -81,11 +81,13 @@ func TestExecServer(t *testing.T) {
 	logReader, logWriter := io.Pipe()
 
 	log.SetDebug(true)
-	log.SetOutput(logWriter)
+	log.SetOut(logWriter)
+	log.SetErr(logWriter)
 
 	defer func() {
 		log.SetDebug(false)
-		log.SetOutput(os.Stderr)
+		log.SetOut(os.Stdout)
+		log.SetErr(os.Stderr)
 	}()
 
 	stdoutReader, stdoutWriter := io.Pipe()

libmachine/log/fmt_machine_logger.go

@@ -4,12 +4,15 @@ import (
 	"fmt"
 	"io"
 	"os"
+	"sync"
 )
 
 type FmtMachineLogger struct {
 	out         io.Writer
 	err         io.Writer
 	debug       bool
+	historyLock *sync.Mutex
+	history     []string
 }
 
 // NewFmtMachineLogger creates a MachineLogger implementation used by the drivers
@@ -18,66 +21,91 @@ func NewFmtMachineLogger() MachineLogger {
 		out:         os.Stdout,
 		err:         os.Stderr,
 		debug:       false,
+		historyLock: &sync.Mutex{},
+		history:     []string{},
 	}
 }
 
-func (ml *FmtMachineLogger) RedirectStdOutToStdErr() {
-	ml.out = ml.err
-}
-
 func (ml *FmtMachineLogger) SetDebug(debug bool) {
 	ml.debug = debug
 }
 
-func (ml *FmtMachineLogger) SetOutput(out io.Writer) {
+func (ml *FmtMachineLogger) SetOut(out io.Writer) {
 	ml.out = out
-	ml.err = out
+}
+
+func (ml *FmtMachineLogger) SetErr(err io.Writer) {
+	ml.err = err
 }
 
 func (ml *FmtMachineLogger) Debug(args ...interface{}) {
+	ml.record(args...)
 	if ml.debug {
 		fmt.Fprintln(ml.err, args...)
 	}
 }
 
 func (ml *FmtMachineLogger) Debugf(fmtString string, args ...interface{}) {
+	ml.recordf(fmtString, args...)
 	if ml.debug {
 		fmt.Fprintf(ml.err, fmtString+"\n", args...)
 	}
 }
 
 func (ml *FmtMachineLogger) Error(args ...interface{}) {
-	fmt.Fprintln(ml.out, args...)
+	ml.record(args...)
+	fmt.Fprintln(ml.err, args...)
 }
 
 func (ml *FmtMachineLogger) Errorf(fmtString string, args ...interface{}) {
-	fmt.Fprintf(ml.out, fmtString+"\n", args...)
+	ml.recordf(fmtString, args...)
+	fmt.Fprintf(ml.err, fmtString+"\n", args...)
 }
 
 func (ml *FmtMachineLogger) Info(args ...interface{}) {
+	ml.record(args...)
 	fmt.Fprintln(ml.out, args...)
 }
 
 func (ml *FmtMachineLogger) Infof(fmtString string, args ...interface{}) {
+	ml.recordf(fmtString, args...)
 	fmt.Fprintf(ml.out, fmtString+"\n", args...)
 }
 
 func (ml *FmtMachineLogger) Fatal(args ...interface{}) {
-	fmt.Fprintln(ml.out, args...)
+	ml.record(args...)
+	fmt.Fprintln(ml.err, args...)
+	os.Exit(1)
 }
 
 func (ml *FmtMachineLogger) Fatalf(fmtString string, args ...interface{}) {
-	fmt.Fprintf(ml.out, fmtString+"\n", args...)
+	ml.recordf(fmtString, args...)
+	fmt.Fprintf(ml.err, fmtString+"\n", args...)
+	os.Exit(1)
 }
 
 func (ml *FmtMachineLogger) Warn(args ...interface{}) {
+	ml.record(args...)
 	fmt.Fprintln(ml.out, args...)
 }
 
 func (ml *FmtMachineLogger) Warnf(fmtString string, args ...interface{}) {
+	ml.recordf(fmtString, args...)
 	fmt.Fprintf(ml.out, fmtString+"\n", args...)
 }
 
 func (ml *FmtMachineLogger) History() []string {
-	return []string{}
+	return ml.history
+}
+
+func (ml *FmtMachineLogger) record(args ...interface{}) {
+	ml.historyLock.Lock()
+	defer ml.historyLock.Unlock()
+	ml.history = append(ml.history, fmt.Sprint(args...))
+}
+
+func (ml *FmtMachineLogger) recordf(fmtString string, args ...interface{}) {
+	ml.historyLock.Lock()
+	defer ml.historyLock.Unlock()
+	ml.history = append(ml.history, fmt.Sprintf(fmtString, args...))
 }

libmachine/log/fmt_machine_logger_test.go

@@ -1,21 +1,67 @@
 package log
 
 import (
+	"bufio"
+	"io"
+	"io/ioutil"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
 )
 
-func TestFmtDebug(t *testing.T) {
+func captureOutput(testLogger MachineLogger, lambda func()) string {
+	pipeReader, pipeWriter := io.Pipe()
+	scanner := bufio.NewScanner(pipeReader)
+	testLogger.SetOut(pipeWriter)
+	go lambda()
+	scanner.Scan()
+	return scanner.Text()
+}
+
+func captureError(testLogger MachineLogger, lambda func()) string {
+	pipeReader, pipeWriter := io.Pipe()
+	scanner := bufio.NewScanner(pipeReader)
+	testLogger.SetErr(pipeWriter)
+	go lambda()
+	scanner.Scan()
+	return scanner.Text()
+}
+
+func TestSetDebugToTrue(t *testing.T) {
+	testLogger := NewFmtMachineLogger().(*FmtMachineLogger)
+	testLogger.SetDebug(true)
+	assert.Equal(t, true, testLogger.debug)
+}
+
+func TestSetDebugToFalse(t *testing.T) {
+	testLogger := NewFmtMachineLogger().(*FmtMachineLogger)
+	testLogger.SetDebug(true)
+	testLogger.SetDebug(false)
+	assert.Equal(t, false, testLogger.debug)
+}
+
+func TestSetOut(t *testing.T) {
+	testLogger := NewFmtMachineLogger().(*FmtMachineLogger)
+	testLogger.SetOut(ioutil.Discard)
+	assert.Equal(t, ioutil.Discard, testLogger.out)
+}
+
+func TestSetErr(t *testing.T) {
+	testLogger := NewFmtMachineLogger().(*FmtMachineLogger)
+	testLogger.SetErr(ioutil.Discard)
+	assert.Equal(t, ioutil.Discard, testLogger.err)
+}
+
+func TestDebug(t *testing.T) {
 	testLogger := NewFmtMachineLogger()
 	testLogger.SetDebug(true)
 
-	result := captureOutput(testLogger, func() { testLogger.Debug("debug") })
+	result := captureError(testLogger, func() { testLogger.Debug("debug") })
 
 	assert.Equal(t, result, "debug")
 }
 
-func TestFmtInfo(t *testing.T) {
+func TestInfo(t *testing.T) {
 	testLogger := NewFmtMachineLogger()
 
 	result := captureOutput(testLogger, func() { testLogger.Info("info") })
@@ -23,7 +69,7 @@ func TestFmtInfo(t *testing.T) {
 	assert.Equal(t, result, "info")
 }
 
-func TestFmtWarn(t *testing.T) {
+func TestWarn(t *testing.T) {
 	testLogger := NewFmtMachineLogger()
 
 	result := captureOutput(testLogger, func() { testLogger.Warn("warn") })
@@ -31,10 +77,21 @@ func TestFmtWarn(t *testing.T) {
 	assert.Equal(t, result, "warn")
 }
 
-func TestFmtError(t *testing.T) {
+func TestError(t *testing.T) {
 	testLogger := NewFmtMachineLogger()
 
-	result := captureOutput(testLogger, func() { testLogger.Error("error") })
+	result := captureError(testLogger, func() { testLogger.Error("error") })
 
 	assert.Equal(t, result, "error")
 }
+
+func TestEntriesAreCollected(t *testing.T) {
+	testLogger := NewFmtMachineLogger()
+	testLogger.Debug("debug")
+	testLogger.Info("info")
+	testLogger.Error("error")
+	assert.Equal(t, 3, len(testLogger.History()))
+	assert.Equal(t, "debug", testLogger.History()[0])
+	assert.Equal(t, "info", testLogger.History()[1])
+	assert.Equal(t, "error", testLogger.History()[2])
+}

libmachine/log/log.go

@@ -8,17 +8,13 @@ import (
 const redactedText = "<REDACTED>"
 
 var (
-	Logger MachineLogger
+	logger = NewFmtMachineLogger()
 
 	// (?s) enables '.' to match '\n' -- see https://golang.org/pkg/regexp/syntax/
 	certRegex = regexp.MustCompile("(?s)-----BEGIN CERTIFICATE-----.*-----END CERTIFICATE-----")
 	keyRegex  = regexp.MustCompile("(?s)-----BEGIN RSA PRIVATE KEY-----.*-----END RSA PRIVATE KEY-----")
 )
 
-func init() {
-	Logger = NewFmtMachineLogger()
-}
-
 func stripSecrets(original []string) []string {
 	stripped := []string{}
 	for _, line := range original {
@@ -29,59 +25,58 @@ func stripSecrets(original []string) []string {
 	return stripped
 }
 
-// RedirectStdOutToStdErr prevents any log from corrupting the output
-func RedirectStdOutToStdErr() {
-	Logger.RedirectStdOutToStdErr()
-}
-
 func Debug(args ...interface{}) {
-	Logger.Debug(args...)
+	logger.Debug(args...)
 }
 
 func Debugf(fmtString string, args ...interface{}) {
-	Logger.Debugf(fmtString, args...)
+	logger.Debugf(fmtString, args...)
 }
 
 func Error(args ...interface{}) {
-	Logger.Error(args...)
+	logger.Error(args...)
 }
 
 func Errorf(fmtString string, args ...interface{}) {
-	Logger.Errorf(fmtString, args...)
+	logger.Errorf(fmtString, args...)
 }
 
 func Info(args ...interface{}) {
-	Logger.Info(args...)
+	logger.Info(args...)
 }
 
 func Infof(fmtString string, args ...interface{}) {
-	Logger.Infof(fmtString, args...)
+	logger.Infof(fmtString, args...)
 }
 
 func Fatal(args ...interface{}) {
-	Logger.Fatal(args...)
+	logger.Fatal(args...)
 }
 
 func Fatalf(fmtString string, args ...interface{}) {
-	Logger.Fatalf(fmtString, args...)
+	logger.Fatalf(fmtString, args...)
 }
 
 func Warn(args ...interface{}) {
-	Logger.Warn(args...)
+	logger.Warn(args...)
 }
 
 func Warnf(fmtString string, args ...interface{}) {
-	Logger.Warnf(fmtString, args...)
+	logger.Warnf(fmtString, args...)
 }
 
 func SetDebug(debug bool) {
-	Logger.SetDebug(debug)
+	logger.SetDebug(debug)
 }
 
-func SetOutput(out io.Writer) {
+func SetOut(out io.Writer) {
-	Logger.SetOutput(out)
+	logger.SetOut(out)
+}
+
+func SetErr(err io.Writer) {
+	logger.SetErr(err)
 }
 
 func History() []string {
-	return stripSecrets(Logger.History())
+	return stripSecrets(logger.History())
 }

libmachine/log/logrus_machine_logger.go

@@ -1,112 +0,0 @@
-package log
-
-import (
-	"io"
-
-	"fmt"
-
-	"sync"
-
-	"github.com/Sirupsen/logrus"
-)
-
-type LogrusMachineLogger struct {
-	history     []string
-	historyLock sync.Locker
-	logger      *logrus.Logger
-}
-
-// NewLogrusMachineLogger creates the MachineLogger implementation used by the docker-machine
-func NewLogrusMachineLogger() MachineLogger {
-	logrusLogger := logrus.New()
-	logrusLogger.Level = logrus.InfoLevel
-	logrusLogger.Formatter = new(MachineFormatter)
-	return &LogrusMachineLogger{[]string{}, &sync.Mutex{}, logrusLogger}
-}
-
-// RedirectStdOutToStdErr prevents any log from corrupting the output
-func (ml *LogrusMachineLogger) RedirectStdOutToStdErr() {
-	ml.logger.Level = logrus.ErrorLevel
-}
-
-func (ml *LogrusMachineLogger) SetDebug(debug bool) {
-	if debug {
-		ml.logger.Level = logrus.DebugLevel
-	} else {
-		ml.logger.Level = logrus.InfoLevel
-	}
-}
-
-func (ml *LogrusMachineLogger) SetOutput(out io.Writer) {
-	ml.logger.Out = out
-}
-
-func (ml *LogrusMachineLogger) Logger() *logrus.Logger {
-	return ml.logger
-}
-
-func (ml *LogrusMachineLogger) Debug(args ...interface{}) {
-	ml.record(args...)
-	ml.logger.Debug(args...)
-}
-
-func (ml *LogrusMachineLogger) Debugf(fmtString string, args ...interface{}) {
-	ml.recordf(fmtString, args...)
-	ml.logger.Debugf(fmtString, args...)
-}
-
-func (ml *LogrusMachineLogger) Error(args ...interface{}) {
-	ml.record(args...)
-	ml.logger.Error(args...)
-}
-
-func (ml *LogrusMachineLogger) Errorf(fmtString string, args ...interface{}) {
-	ml.recordf(fmtString, args...)
-	ml.logger.Errorf(fmtString, args...)
-}
-
-func (ml *LogrusMachineLogger) Info(args ...interface{}) {
-	ml.record(args...)
-	ml.logger.Info(args...)
-}
-
-func (ml *LogrusMachineLogger) Infof(fmtString string, args ...interface{}) {
-	ml.recordf(fmtString, args...)
-	ml.logger.Infof(fmtString, args...)
-}
-
-func (ml *LogrusMachineLogger) Fatal(args ...interface{}) {
-	ml.record(args...)
-	ml.logger.Fatal(args...)
-}
-
-func (ml *LogrusMachineLogger) Fatalf(fmtString string, args ...interface{}) {
-	ml.recordf(fmtString, args...)
-	ml.logger.Fatalf(fmtString, args...)
-}
-
-func (ml *LogrusMachineLogger) Warn(args ...interface{}) {
-	ml.record(args...)
-	ml.logger.Warn(args...)
-}
-
-func (ml *LogrusMachineLogger) Warnf(fmtString string, args ...interface{}) {
-	ml.recordf(fmtString, args...)
-	ml.logger.Warnf(fmtString, args...)
-}
-
-func (ml *LogrusMachineLogger) History() []string {
-	return ml.history
-}
-
-func (ml *LogrusMachineLogger) record(args ...interface{}) {
-	ml.historyLock.Lock()
-	defer ml.historyLock.Unlock()
-	ml.history = append(ml.history, fmt.Sprint(args...))
-}
-
-func (ml *LogrusMachineLogger) recordf(fmtString string, args ...interface{}) {
-	ml.historyLock.Lock()
-	defer ml.historyLock.Unlock()
-	ml.history = append(ml.history, fmt.Sprintf(fmtString, args...))
-}

libmachine/log/logrus_machine_logger_test.go

@@ -1,89 +0,0 @@
-package log
-
-import (
-	"testing"
-
-	"bufio"
-	"io"
-
-	"github.com/Sirupsen/logrus"
-	"github.com/stretchr/testify/assert"
-)
-
-func TestDefaultLevelIsInfo(t *testing.T) {
-	testLogger := NewLogrusMachineLogger().(*LogrusMachineLogger)
-	assert.Equal(t, testLogger.Logger().Level, logrus.InfoLevel)
-}
-
-func TestSetDebugToTrue(t *testing.T) {
-	testLogger := NewLogrusMachineLogger().(*LogrusMachineLogger)
-	testLogger.SetDebug(true)
-	assert.Equal(t, testLogger.Logger().Level, logrus.DebugLevel)
-}
-
-func TestSetDebugToFalse(t *testing.T) {
-	testLogger := NewLogrusMachineLogger().(*LogrusMachineLogger)
-	testLogger.SetDebug(true)
-	testLogger.SetDebug(false)
-	assert.Equal(t, testLogger.Logger().Level, logrus.InfoLevel)
-}
-
-func TestSetSilenceOutput(t *testing.T) {
-	testLogger := NewLogrusMachineLogger().(*LogrusMachineLogger)
-	testLogger.RedirectStdOutToStdErr()
-	assert.Equal(t, testLogger.Logger().Level, logrus.ErrorLevel)
-}
-
-func TestDebugOutput(t *testing.T) {
-	testLogger := NewLogrusMachineLogger()
-	testLogger.SetDebug(true)
-
-	result := captureOutput(testLogger, func() { testLogger.Debug("debug") })
-
-	assert.Equal(t, result, "debug")
-}
-
-func TestInfoOutput(t *testing.T) {
-	testLogger := NewLogrusMachineLogger()
-
-	result := captureOutput(testLogger, func() { testLogger.Info("info") })
-
-	assert.Equal(t, result, "info")
-}
-
-func TestWarnOutput(t *testing.T) {
-	testLogger := NewLogrusMachineLogger()
-
-	result := captureOutput(testLogger, func() { testLogger.Warn("warn") })
-
-	assert.Equal(t, result, "warn")
-}
-
-func TestErrorOutput(t *testing.T) {
-	testLogger := NewLogrusMachineLogger()
-
-	result := captureOutput(testLogger, func() { testLogger.Error("error") })
-
-	assert.Equal(t, result, "error")
-}
-
-func TestEntriesAreCollected(t *testing.T) {
-	testLogger := NewLogrusMachineLogger()
-	testLogger.RedirectStdOutToStdErr()
-	testLogger.Debug("debug")
-	testLogger.Info("info")
-	testLogger.Error("error")
-	assert.Equal(t, 3, len(testLogger.History()))
-	assert.Equal(t, "debug", testLogger.History()[0])
-	assert.Equal(t, "info", testLogger.History()[1])
-	assert.Equal(t, "error", testLogger.History()[2])
-}
-
-func captureOutput(testLogger MachineLogger, lambda func()) string {
-	pipeReader, pipeWriter := io.Pipe()
-	scanner := bufio.NewScanner(pipeReader)
-	testLogger.SetOutput(pipeWriter)
-	go lambda()
-	scanner.Scan()
-	return scanner.Text()
-}

libmachine/log/machine_formatter.go

@@ -1,19 +0,0 @@
-package log
-
-import (
-	"bytes"
-
-	"github.com/Sirupsen/logrus"
-)
-
-type MachineFormatter struct {
-}
-
-func (d *MachineFormatter) Format(entry *logrus.Entry) ([]byte, error) {
-	b := &bytes.Buffer{}
-
-	b.WriteString(entry.Message)
-	b.WriteByte('\n')
-
-	return b.Bytes(), nil
-}

libmachine/log/machine_formatter_test.go

@@ -1,17 +0,0 @@
-package log
-
-import (
-	"testing"
-
-	"github.com/Sirupsen/logrus"
-	"github.com/stretchr/testify/assert"
-)
-
-func TestWrite(t *testing.T) {
-	entry := logrus.NewEntry(logrus.New())
-	entry.Message = "foobar"
-	formatter := MachineFormatter{}
-	bytes, err := formatter.Format(entry)
-	assert.Nil(t, err)
-	assert.Equal(t, string(bytes[:]), "foobar\n")
-}

libmachine/log/machine_logger.go

@@ -3,11 +3,10 @@ package log
 import "io"
 
 type MachineLogger interface {
-	RedirectStdOutToStdErr()
-
 	SetDebug(debug bool)
 
-	SetOutput(io.Writer)
+	SetOut(io.Writer)
+	SetErr(io.Writer)
 
 	Debug(args ...interface{})
 	Debugf(fmtString string, args ...interface{})