Format console encoder fields as key=value

config_test.go

@@ -49,9 +49,9 @@ func TestConfig(t *testing.T) {
 			desc:    "development",
 			cfg:     NewDevelopmentConfig(),
 			expectN: 3 + 200, // 3 initial logs, all 200 subsequent logs
-			expectRe: "DEBUG\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\tdebug\t" + `{"k": "v", "z": "zz"}` + "\n" +
-				"INFO\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\tinfo\t" + `{"k": "v", "z": "zz"}` + "\n" +
-				"WARN\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\twarn\t" + `{"k": "v", "z": "zz"}` + "\n" +
+			expectRe: "DEBUG\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\tdebug\t" + `k="v"` + "\t" + `z="zz"` + "\n" +
+				"INFO\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\tinfo\t" + `k="v"` + "\t" + `z="zz"` + "\n" +
+				"WARN\t[a-z0-9_-]+/config_test.go:" + `\d+` + "\twarn\t" + `k="v"` + "\t" + `z="zz"` + "\n" +
 				`go.uber.org/zap.TestConfig.\w+`,
 		},
 	}

zapcore/console_encoder.go

@@ -21,11 +21,15 @@
 package zapcore
 
 import (
+	"encoding/json"
 	"fmt"
-	"sync"
-
 	"go.uber.org/zap/buffer"
 	"go.uber.org/zap/internal/bufferpool"
+	"reflect"
+	"sort"
+	"strings"
+	"sync"
+	"time"
 )
 
 var _sliceEncoderPool = sync.Pool{
@@ -44,13 +48,14 @@
 }
 
 type consoleEncoder struct {
-	*jsonEncoder
+	*EncoderConfig
+	*MapObjectEncoder
 }
 
 // NewConsoleEncoder creates an encoder whose output is designed for human -
 // rather than machine - consumption. It serializes the core log entry data
 // (message, level, timestamp, etc.) in a plain-text format and leaves the
-// structured context as JSON.
+// structured context as key value pairs.
 //
 // Note that although the console encoder doesn't use the keys specified in the
 // encoder configuration, it will omit any element whose key is set to the empty
@@ -60,11 +65,18 @@
 		// Use a default delimiter of '\t' for backwards compatibility
 		cfg.ConsoleSeparator = "\t"
 	}
-	return consoleEncoder{newJSONEncoder(cfg, true)}
+
+	if cfg.SkipLineEnding {
+		cfg.LineEnding = ""
+	} else if cfg.LineEnding == "" {
+		cfg.LineEnding = DefaultLineEnding
+	}
+
+	return consoleEncoder{EncoderConfig: &cfg, MapObjectEncoder: NewMapObjectEncoder()}
 }
 
 func (c consoleEncoder) Clone() Encoder {
-	return consoleEncoder{c.jsonEncoder.Clone().(*jsonEncoder)}
+	return consoleEncoder{EncoderConfig: c.EncoderConfig, MapObjectEncoder: c.MapObjectEncoder.clone()}
 }
 
 func (c consoleEncoder) EncodeEntry(ent Entry, fields []Field) (*buffer.Buffer, error) {
@@ -130,24 +142,76 @@
 }
 
 func (c consoleEncoder) writeContext(line *buffer.Buffer, extra []Field) {
-	context := c.jsonEncoder.Clone().(*jsonEncoder)
-	defer func() {
-		// putJSONEncoder assumes the buffer is still used, but we write out the buffer so
-		// we can free it.
-		context.buf.Free()
-		putJSONEncoder(context)
-	}()
-
+	context := c.MapObjectEncoder.clone()
 	addFields(context, extra)
-	context.closeOpenNamespaces()
-	if context.buf.Len() == 0 {
+
+	if len(context.Fields) == 0 {
 		return
 	}
 
+	var pairs []string
+	for key, value := range context.Fields {
+		pairs = append(pairs, fmt.Sprintf("%s=%v", key, c.formatValue(value)))
+	}
+
+	sort.Slice(pairs, func(i, j int) bool {
+		return pairs[i] < pairs[j]
+	})
+
 	c.addSeparatorIfNecessary(line)
-	line.AppendByte('{')
-	line.Write(context.buf.Bytes())
-	line.AppendByte('}')
+	line.WriteString(strings.Join(pairs, c.ConsoleSeparator))
+}
+
+func (c consoleEncoder) formatValue(v interface{}) interface{} {
+	switch t := v.(type) {
+	case time.Time:
+		if enc := c.EncodeTime; enc != nil {
+			arr := getSliceEncoder()
+			defer putSliceEncoder(arr)
+
+			enc(t, arr)
+			if len(arr.elems) == 0 {
+				return t.UnixNano()
+			}
+			return fmt.Sprintf("%q", arr.elems[0])
+		}
+		return t.String()
+	case time.Duration:
+		if enc := c.EncodeDuration; enc != nil {
+			arr := getSliceEncoder()
+			defer putSliceEncoder(arr)
+
+			enc(t, arr)
+			if len(arr.elems) == 0 {
+				return int64(t)
+			}
+			return fmt.Sprintf("%q", arr.elems[0])
+		}
+		return t.String()
+	case string:
+		return fmt.Sprintf("%q", t)
+	case fmt.Stringer:
+		return fmt.Sprintf("%q", t.String())
+	}
+
+	switch rt := reflect.TypeOf(v); rt.Kind() {
+	case reflect.Slice:
+		asSlice, ok := v.([]interface{})
+		if !ok {
+			break
+		}
+
+		var out []interface{}
+		for i := 0; i < len(asSlice); i++ {
+			out = append(out, c.formatValue(asSlice[i]))
+		}
+		return out
+	case reflect.Map:
+		encoded, _ := json.Marshal(v)
+		return string(encoded)
+	}
+
+	return v
 }
 
 func (c consoleEncoder) addSeparatorIfNecessary(line *buffer.Buffer) {

zapcore/encoder_test.go

@@ -85,6 +85,7 @@ func TestEncoderConfiguration(t *testing.T) {
 		expectedJSON    string
 		expectedConsole string
 	}{
+
 		{
 			desc: "messages to be escaped",
 			cfg:  base,
@@ -292,7 +293,7 @@ func TestEncoderConfiguration(t *testing.T) {
 			},
 			expectedJSON: `{"L":"info","T":"1970-01-01 00:00:00 +0000 UTC","N":"main","C":"foo.go:42","F":"foo.Foo","M":"hello","extra":"1970-01-01 00:00:00 +0000 UTC","extras":["1970-01-01 00:00:00 +0000 UTC"],"S":"fake-stack"}` + "\n",
 			expectedConsole: "1970-01-01 00:00:00 +0000 UTC\tinfo\tmain\tfoo.go:42\tfoo.Foo\thello\t" + // plain-text preamble
-				`{"extra": "1970-01-01 00:00:00 +0000 UTC", "extras": ["1970-01-01 00:00:00 +0000 UTC"]}` + // JSON context
+				`extra="1970-01-01 00:00:00 +0000 UTC"	extras=["1970-01-01 00:00:00 +0000 UTC"]` + // JSON context
 				"\nfake-stack\n", // stacktrace after newline
 		},
 		{
@@ -320,7 +321,7 @@ func TestEncoderConfiguration(t *testing.T) {
 			},
 			expectedJSON: `{"L":"info","T":0,"N":"main","C":"foo.go:42","F":"foo.Foo","M":"hello","extra":"1s","extras":["1m0s"],"S":"fake-stack"}` + "\n",
 			expectedConsole: "0\tinfo\tmain\tfoo.go:42\tfoo.Foo\thello\t" + // preamble
-				`{"extra": "1s", "extras": ["1m0s"]}` + // context
+				`extra="1s"	extras=["1m0s"]` + // context
 				"\nfake-stack\n", // stacktrace
 		},
 		{
@@ -386,7 +387,7 @@ func TestEncoderConfiguration(t *testing.T) {
 			},
 			expectedJSON: `{"L":"info","T":0,"N":"main","C":"foo.go:42","F":"foo.Foo","M":"hello","outer":{"inner":{"foo":"bar","innermost":{}}},"S":"fake-stack"}` + "\n",
 			expectedConsole: "0\tinfo\tmain\tfoo.go:42\tfoo.Foo\thello\t" +
-				`{"outer": {"inner": {"foo": "bar", "innermost": {}}}}` +
+				`outer={"inner":{"foo":"bar","innermost":{}}}` +
 				"\nfake-stack\n",
 		},
 		{
@@ -407,7 +408,7 @@ func TestEncoderConfiguration(t *testing.T) {
 			},
 			extra:           func(enc Encoder) { enc.AddTime("sometime", time.Unix(0, 100)) },
 			expectedJSON:    `{"L":"info","T":0,"N":"main","C":"foo.go:42","F":"foo.Foo","M":"hello","sometime":100,"S":"fake-stack"}` + "\n",
-			expectedConsole: "info\tmain\tfoo.go:42\tfoo.Foo\thello\t" + `{"sometime": 100}` + "\nfake-stack\n",
+			expectedConsole: "info\tmain\tfoo.go:42\tfoo.Foo\thello\t" + `sometime=100` + "\nfake-stack\n",
 		},
 		{
 			desc: "handle no-op EncodeDuration",
@@ -427,7 +428,7 @@ func TestEncoderConfiguration(t *testing.T) {
 			},
 			extra:           func(enc Encoder) { enc.AddDuration("someduration", time.Microsecond) },
 			expectedJSON:    `{"L":"info","T":0,"N":"main","C":"foo.go:42","F":"foo.Foo","M":"hello","someduration":1000,"S":"fake-stack"}` + "\n",
-			expectedConsole: "0\tinfo\tmain\tfoo.go:42\tfoo.Foo\thello\t" + `{"someduration": 1000}` + "\nfake-stack\n",
+			expectedConsole: "0\tinfo\tmain\tfoo.go:42\tfoo.Foo\thello\t" + `someduration=1000` + "\nfake-stack\n",
 		},
 		{
 			desc: "handle no-op EncodeLevel",

zapcore/memory_encoder.go

@@ -20,7 +20,9 @@
 
 package zapcore
 
-import "time"
+import (
+	"time"
+)
 
 // MapObjectEncoder is an ObjectEncoder backed by a simple
 // map[string]interface{}. It's not fast enough for production use, but it's
@@ -132,6 +134,17 @@ func (m *MapObjectEncoder) OpenNamespace(k string) {
 	m.cur = ns
 }
 
+func (m *MapObjectEncoder) clone() *MapObjectEncoder {
+	clone := NewMapObjectEncoder()
+	for key, value := range m.Fields {
+		clone.Fields[key] = value
+	}
+	for key, value := range m.cur {
+		clone.cur[key] = value
+	}
+	return clone
+}
+
 // sliceArrayEncoder is an ArrayEncoder backed by a simple []interface{}. Like
 // the MapObjectEncoder, it's not designed for production use.
 type sliceArrayEncoder struct {

zaptest/logger_test.go

@@ -53,7 +53,7 @@ func TestTestLogger(t *testing.T) {
 		"INFO	received work order",
 		"DEBUG	starting work",
 		"WARN	work may fail",
-		`ERROR	work failed	{"error": "great sadness"}`,
+		`ERROR	work failed	error="great sadness"`,
 		"PANIC	failed to do work",
 	)
 }
@@ -75,7 +75,7 @@ func TestTestLoggerSupportsLevels(t *testing.T) {
 
 	ts.AssertMessages(
 		"WARN	work may fail",
-		`ERROR	work failed	{"error": "great sadness"}`,
+		`ERROR	work failed	error="great sadness"`,
 		"PANIC	failed to do work",
 	)
 }
@@ -96,11 +96,11 @@ func TestTestLoggerSupportsWrappedZapOptions(t *testing.T) {
 	}, "log.Panic should panic")
 
 	ts.AssertMessages(
-		`INFO	zaptest/logger_test.go:89	received work order	{"k1": "v1"}`,
-		`DEBUG	zaptest/logger_test.go:90	starting work	{"k1": "v1"}`,
-		`WARN	zaptest/logger_test.go:91	work may fail	{"k1": "v1"}`,
-		`ERROR	zaptest/logger_test.go:92	work failed	{"k1": "v1", "error": "great sadness"}`,
-		`PANIC	zaptest/logger_test.go:95	failed to do work	{"k1": "v1"}`,
+		`INFO	zaptest/logger_test.go:89	received work order	k1="v1"`,
+		`DEBUG	zaptest/logger_test.go:90	starting work	k1="v1"`,
+		`WARN	zaptest/logger_test.go:91	work may fail	k1="v1"`,
+		`ERROR	zaptest/logger_test.go:92	work failed	error="great sadness"	k1="v1"`,
+		`PANIC	zaptest/logger_test.go:95	failed to do work	k1="v1"`,
 	)
 }