Merge pull request #53 from hashicorp/f-no-panic

Fixup how odd numbers of args and non-string keys are handled to avoid runtime panics

go.sum

@@ -1,5 +1,6 @@
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/fatih/color v1.7.0 h1:DkWD4oS2D8LGGgTQ6IvwJJXSL5Vp2ffcQg58nFV38Ys=
 github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4=
 github.com/mattn/go-colorable v0.1.4 h1:snbPLB8fVfU9iwbbo30TPtbLRzwWu6aJS6Xh4eaaviA=
 github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
@@ -13,4 +14,5 @@ github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223 h1:DH4skfRX4EBpamg7iV4ZlCpblAHI6s6TDM39bFZumv8=
 golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20191008105621-543471e840be h1:QAcqgptGM8IQBC9K/RC4o+O9YmqEm0diQn9QmZw/0mU=
 golang.org/x/sys v0.0.0-20191008105621-543471e840be/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=

intlogger.go

@@ -222,7 +222,8 @@ func (l *intLogger) log(t time.Time, name string, level Level, msg string, args
 				args = args[:len(args)-1]
 				stacktrace = cs
 			} else {
-				args = append(args, "<unknown>")
+				extra := args[len(args)-1]
+				args = append(args[:len(args)-1], MissingKey, extra)
 			}
 		}
 
@@ -274,7 +275,12 @@ func (l *intLogger) log(t time.Time, name string, level Level, msg string, args
 			}
 
 			l.writer.WriteByte(' ')
-			l.writer.WriteString(args[i].(string))
+			switch st := args[i].(type) {
+			case string:
+				l.writer.WriteString(st)
+			default:
+				l.writer.WriteString(fmt.Sprintf("%s", st))
+			}
 			l.writer.WriteByte('=')
 
 			if !raw && strings.ContainsAny(val, " \t\n\r") {
@@ -345,16 +351,12 @@ func (l *intLogger) logJSON(t time.Time, name string, level Level, msg string, a
 				args = args[:len(args)-1]
 				vals["stacktrace"] = cs
 			} else {
-				args = append(args, "<unknown>")
+				extra := args[len(args)-1]
+				args = append(args[:len(args)-1], MissingKey, extra)
 			}
 		}
 
 		for i := 0; i < len(args); i = i + 2 {
-			if _, ok := args[i].(string); !ok {
-				// As this is the logging function not much we can do here
-				// without injecting into logs...
-				continue
-			}
 			val := args[i+1]
 			switch sv := val.(type) {
 			case error:
@@ -370,7 +372,15 @@ func (l *intLogger) logJSON(t time.Time, name string, level Level, msg string, a
 				val = fmt.Sprintf(sv[0].(string), sv[1:]...)
 			}
 
-			vals[args[i].(string)] = val
+			var key string
+
+			switch st := args[i].(type) {
+			case string:
+				key = st
+			default:
+				key = fmt.Sprintf("%s", st)
+			}
+			vals[key] = val
 		}
 	}
 
@@ -471,12 +481,17 @@ func (l *intLogger) IsError() bool {
 	return Level(atomic.LoadInt32(l.level)) <= Error
 }
 
+const MissingKey = "EXTRA_VALUE_AT_END"
+
 // Return a sub-Logger for which every emitted log message will contain
 // the given key/value pairs. This is used to create a context specific
 // Logger.
 func (l *intLogger) With(args ...interface{}) Logger {
+	var extra interface{}
+
 	if len(args)%2 != 0 {
-		panic("With() call requires paired arguments")
+		extra = args[len(args)-1]
+		args = args[:len(args)-1]
 	}
 
 	sl := *l
@@ -509,6 +524,10 @@ func (l *intLogger) With(args ...interface{}) Logger {
 		sl.implied = append(sl.implied, result[k])
 	}
 
+	if extra != nil {
+		sl.implied = append(sl.implied, MissingKey, extra)
+	}
+
 	return &sl
 }
 

logger_test.go

@@ -208,20 +208,18 @@ func TestLogger(t *testing.T) {
 	})
 
 	t.Run("unpaired with", func(t *testing.T) {
-		defer func() {
-			if r := recover(); r == nil {
-				t.Fatal("expected panic")
-			}
-		}()
-
 		var buf bytes.Buffer
 
 		rootLogger := New(&LoggerOptions{
 			Name:   "with_test",
 			Output: &buf,
 		})
 
-		rootLogger = rootLogger.With("a")
+		derived1 := rootLogger.With("a")
+		derived1.Info("test1")
+		output := buf.String()
+		dataIdx := strings.IndexByte(output, ' ')
+		assert.Equal(t, "[INFO]  with_test: test1: EXTRA_VALUE_AT_END=a\n", output[dataIdx+1:])
 	})
 
 	t.Run("use with and log", func(t *testing.T) {