Merge pull request #844 from BenTheElder/moar-logs-2

more logging / error cleanup

cmd/kind/kind.go

@@ -34,8 +34,6 @@ import (
 	"sigs.k8s.io/kind/pkg/log"
 )
 
-const defaultLevel = "warning"
-
 // Flags for the kind command
 type Flags struct {
 	LogLevel  string
@@ -61,7 +59,7 @@ func NewCommand() *cobra.Command {
 	cmd.PersistentFlags().StringVar(
 		&flags.LogLevel,
 		"loglevel",
-		defaultLevel,
+		"",
 		"DEPRECATED: see -v instead",
 	)
 	cmd.PersistentFlags().Int32VarP(
@@ -106,7 +104,7 @@ func runE(flags *Flags, cmd *cobra.Command) error {
 	if flags.Quiet {
 		globals.SetLogger(log.NoopLogger{})
 	} else {
-		globals.UseDefaultLogger(log.Level(flags.Verbosity))
+		globals.UseCLILogger(os.Stderr, log.Level(flags.Verbosity))
 	}
 	// warn about deprecated flag if used
 	if setLogLevel {

pkg/globals/logger.go

@@ -14,16 +14,18 @@ See the License for the specific language governing permissions and
 limitations under the License.
 */
 
-// package globals will be deleted in a future commit
+// Package globals will be deleted in a future commit
 // this package contains globals that we've not yet re-worked to not be globals
 package globals
 
 import (
+	"io"
 	"sync"
 
 	"sigs.k8s.io/kind/pkg/log"
 
-	"sigs.k8s.io/kind/pkg/internal/util/logger"
+	"sigs.k8s.io/kind/pkg/internal/util/cli"
+	"sigs.k8s.io/kind/pkg/internal/util/env"
 )
 
 // TODO: consider threading through a logger instead of using a global logger
@@ -40,12 +42,15 @@ func SetLogger(l log.Logger) {
 	globalLogger = l
 }
 
-// UseDefaultLogger sets the global logger to kind's default logger
-// with SetLogger
+// UseCLILogger sets the global logger to the kind CLI's default stderr logger
+// if writer is a tty, the CLI spinner will be enabled
 //
 // Not to be confused with the default if not set of log.NoopLogger
-func UseDefaultLogger(verbosity log.Level) {
-	SetLogger(logger.NewDefault(verbosity))
+func UseCLILogger(writer io.Writer, verbosity log.Level) {
+	if env.IsTerminal(writer) {
+		writer = cli.NewSpinner(writer)
+	}
+	SetLogger(cli.NewLogger(writer, verbosity))
 }
 
 // GetLogger returns the standard logger used by this package

pkg/internal/util/cli/logger.go

@@ -14,63 +14,56 @@ See the License for the specific language governing permissions and
 limitations under the License.
 */
 
-package logger
+package cli
 
 import (
 	"bytes"
 	"fmt"
 	"io"
-	"os"
 	"sync"
 
 	"sigs.k8s.io/kind/pkg/log"
-
-	"sigs.k8s.io/kind/pkg/internal/util/env"
 )
 
-// Default is the default log.Logger implementation
-type Default struct {
+// Logger is the kind cli's log.Logger implementation
+type Logger struct {
 	Verbosity log.Level
 	io.Writer
 	writeMu sync.Mutex
-	// for later use in adding colored output etc...
-	// we collect this in NewDefault before any writer wrapping may occur
-	isTerm bool
 }
 
-var _ log.Logger = &Default{}
+var _ log.Logger = &Logger{}
 
-// NewDefault returns a new Default logger with the given verbosity
-func NewDefault(verbosity log.Level) *Default {
-	return &Default{
+// NewLogger returns a new Logger with the given verbosity
+func NewLogger(writer io.Writer, verbosity log.Level) *Logger {
+	return &Logger{
 		Verbosity: verbosity,
-		Writer:    os.Stderr,
-		isTerm:    env.IsTerminal(os.Stderr),
+		Writer:    writer,
 	}
 }
 
-func (d *Default) Write(p []byte) (n int, err error) {
+func (l *Logger) Write(p []byte) (n int, err error) {
 	// TODO: line oriented instead?
 	// For now we make a single per-message write call from the rest of the logger
 	// intentionally to effectively do this one level up
-	d.writeMu.Lock()
-	defer d.writeMu.Unlock()
-	return d.Writer.Write(p)
+	l.writeMu.Lock()
+	defer l.writeMu.Unlock()
+	return l.Writer.Write(p)
 }
 
 // TODO: prefix log lines with metadata (log level? timestamp?)
 
-func (d *Default) print(message string) {
+func (l *Logger) print(message string) {
 	buf := bytes.NewBufferString(message)
 	if buf.Bytes()[buf.Len()-1] != '\n' {
 		buf.WriteByte('\n')
 	}
 	// TODO: should we handle this somehow??
 	// Who logs for the logger? 🤔
-	_, _ = d.Write(buf.Bytes())
+	_, _ = l.Write(buf.Bytes())
 }
 
-func (d *Default) printf(format string, args ...interface{}) {
+func (l *Logger) printf(format string, args ...interface{}) {
 	var buf bytes.Buffer
 	fmt.Fprintf(&buf, format, args...)
 	if buf.Bytes()[buf.Len()-1] != '\n' {
@@ -78,56 +71,56 @@ func (d *Default) printf(format string, args ...interface{}) {
 	}
 	// TODO: should we handle this somehow??
 	// Who logs for the logger? 🤔
-	_, _ = d.Write(buf.Bytes())
+	_, _ = l.Write(buf.Bytes())
 }
 
 // Warn is part of the log.Logger interface
-func (d *Default) Warn(message string) {
-	d.print(message)
+func (l *Logger) Warn(message string) {
+	l.print(message)
 }
 
 // Warnf is part of the log.Logger interface
-func (d *Default) Warnf(format string, args ...interface{}) {
-	d.printf(format, args...)
+func (l *Logger) Warnf(format string, args ...interface{}) {
+	l.printf(format, args...)
 }
 
 // Error is part of the log.Logger interface
-func (d *Default) Error(message string) {
-	d.print(message)
+func (l *Logger) Error(message string) {
+	l.print(message)
 }
 
 // Errorf is part of the log.Logger interface
-func (d *Default) Errorf(format string, args ...interface{}) {
-	d.printf(format, args...)
+func (l *Logger) Errorf(format string, args ...interface{}) {
+	l.printf(format, args...)
 }
 
 // V is part of the log.Logger interface
-func (d *Default) V(level log.Level) log.InfoLogger {
-	return defaultInfo{
-		logger:  d,
-		enabled: level <= d.Verbosity,
+func (l *Logger) V(level log.Level) log.InfoLogger {
+	return infoLogger{
+		logger:  l,
+		enabled: level <= l.Verbosity,
 	}
 }
 
-type defaultInfo struct {
-	logger  *Default
+type infoLogger struct {
+	logger  *Logger
 	enabled bool
 }
 
-func (d defaultInfo) Enabled() bool {
-	return d.enabled
+func (i infoLogger) Enabled() bool {
+	return i.enabled
 }
 
-func (d defaultInfo) Info(message string) {
-	if !d.enabled {
+func (i infoLogger) Info(message string) {
+	if !i.enabled {
 		return
 	}
-	d.logger.print(message)
+	i.logger.print(message)
 }
 
-func (d defaultInfo) Infof(format string, args ...interface{}) {
-	if !d.enabled {
+func (i infoLogger) Infof(format string, args ...interface{}) {
+	if !i.enabled {
 		return
 	}
-	d.logger.printf(format, args...)
+	i.logger.printf(format, args...)
 }

pkg/internal/util/cli/spinner.go

@@ -42,11 +42,9 @@ var spinnerFrames = []string{
 	"⠊⠁",
 }
 
-// spinner is a simple and efficient CLI loading spinner used by kind
+// Spinner is a simple and efficient CLI loading spinner used by kind
 // It is simplistic and assumes that the line length will not change.
-// It is best used indirectly via log.Status (see parent package)
-type spinner struct {
-	frames []string
+type Spinner struct {
 	stop   chan struct{}
 	ticker *time.Ticker
 	writer io.Writer
@@ -56,10 +54,12 @@ type spinner struct {
 	suffix string
 }
 
-// Newspinner initializes and returns a new spinner that will write to
-func newSpinner(w io.Writer) *spinner {
-	return &spinner{
-		frames: spinnerFrames,
+// spinner implements writer
+var _ io.Writer = &Spinner{}
+
+// NewSpinner initializes and returns a new Spinner that will write to w
+func NewSpinner(w io.Writer) *Spinner {
+	return &Spinner{
 		stop:   make(chan struct{}, 1),
 		ticker: time.NewTicker(time.Millisecond * 100),
 		mu:     &sync.Mutex{},
@@ -68,24 +68,24 @@ func newSpinner(w io.Writer) *spinner {
 }
 
 // SetPrefix sets the prefix to print before the spinner
-func (s *spinner) SetPrefix(prefix string) {
+func (s *Spinner) SetPrefix(prefix string) {
 	s.mu.Lock()
 	s.prefix = prefix
 	s.mu.Unlock()
 }
 
 // SetSuffix sets the suffix to print after the spinner
-func (s *spinner) SetSuffix(suffix string) {
+func (s *Spinner) SetSuffix(suffix string) {
 	s.mu.Lock()
 	s.suffix = suffix
 	s.mu.Unlock()
 }
 
 // Start starts the spinner running
-func (s *spinner) Start() {
+func (s *Spinner) Start() {
 	go func() {
 		for {
-			for _, frame := range s.frames {
+			for _, frame := range spinnerFrames {
 				select {
 				case <-s.stop:
 					return
@@ -102,6 +102,18 @@ func (s *spinner) Start() {
 }
 
 // Stop signals the spinner to stop
-func (s *spinner) Stop() {
+func (s *Spinner) Stop() {
 	s.stop <- struct{}{}
 }
+
+// Write implements io.Writer, interrupting the spinner and writing to
+// the inner writer
+func (s *Spinner) Write(p []byte) (n int, err error) {
+	s.Stop()
+	if _, err := s.writer.Write([]byte("\r")); err != nil {
+		return 0, err
+	}
+	n, err = s.writer.Write(p)
+	s.Start()
+	return n, err
+}

pkg/internal/util/cli/status.go

@@ -18,67 +18,35 @@ package cli
 
 import (
 	"fmt"
-	"io"
 
 	"sigs.k8s.io/kind/pkg/log"
-
-	"sigs.k8s.io/kind/pkg/internal/util/env"
-	"sigs.k8s.io/kind/pkg/internal/util/logger"
 )
 
 // Status is used to track ongoing status in a CLI, with a nice loading spinner
 // when attached to a terminal
 type Status struct {
-	spinner *spinner
+	spinner *Spinner
 	status  string
 	logger  log.Logger
 }
 
 // StatusForLogger returns a new status object for the logger l,
-// if l is the kind default logger it will inject a wrapped writer into it
-// and if we've already attached one it will return the previous status
+// if l is the kind cli logger and the writer is a Spinner, that spinner
+// will be used for the status
 func StatusForLogger(l log.Logger) *Status {
 	s := &Status{
 		logger: l,
 	}
-	if v, ok := l.(*logger.Default); ok {
-		// Be re-entrant and only attach one spinner
-		// TODO: how do we handle concurrent spinner instances !?
-		// IE: library usage + the default logger ...
-		if v2, ok := v.Writer.(*FriendlyWriter); ok {
-			return v2.status
-		}
-		// otherwise wrap the logger's writer for the first time
-		if env.IsTerminal(v.Writer) {
-			s.spinner = newSpinner(v.Writer)
-			v.Writer = &FriendlyWriter{
-				status: s,
-				inner:  v.Writer,
-			}
+	// if we're using the CLI logger, check for if it has a spinner setup
+	// and wire the status to that
+	if v, ok := l.(*Logger); ok {
+		if v2, ok := v.Writer.(*Spinner); ok {
+			s.spinner = v2
 		}
 	}
 	return s
 }
 
-// FriendlyWriter is used to wrap another Writer to make it toggle the
-// status spinner before and after writes so that they do not collide
-type FriendlyWriter struct {
-	status *Status
-	inner  io.Writer
-}
-
-var _ io.Writer = &FriendlyWriter{}
-
-func (ww *FriendlyWriter) Write(p []byte) (n int, err error) {
-	ww.status.spinner.Stop()
-	if _, err := ww.inner.Write([]byte("\r")); err != nil {
-		return 0, err
-	}
-	n, err = ww.inner.Write(p)
-	ww.status.spinner.Start()
-	return n, err
-}
-
 // Start starts a new phase of the status, if attached to a terminal
 // there will be a loading spinner with this status
 func (s *Status) Start(status string) {

pkg/internal/util/env/term.go

@@ -1,3 +1,19 @@
+/*
+Copyright 2019 The Kubernetes Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
 package env
 
 import (