Add JSON logger

Closes #10

Author: nhooyr

examples_test.go

@@ -1,12 +1,15 @@
 package slog_test
 
 import (
+	"context"
 	"io"
+	"os"
 	"testing"
 
 	"golang.org/x/xerrors"
 
 	"go.coder.com/slog"
+	"go.coder.com/slog/sloggers/slogjson"
 	"go.coder.com/slog/sloggers/slogtest"
 )
 
@@ -56,3 +59,19 @@ func TestExample(t *testing.T) {
 		slog.Component("test"),
 	)
 }
+
+func TestJSON(t *testing.T) {
+	l := slogjson.Make(os.Stderr)
+	l.Info(context.Background(), "my message here",
+		slog.F("field_name", "something or the other"),
+		slog.F("some_map", slog.Map(
+			slog.F("nested_fields", "wowow"),
+		)),
+		slog.Error(
+			xerrors.Errorf("wrap1: %w",
+				xerrors.Errorf("wrap2: %w",
+					io.EOF),
+			)),
+		slog.Component("test"),
+	)
+}

go.mod

@@ -6,7 +6,7 @@ require (
 	github.com/fatih/camelcase v1.0.0
 	github.com/fatih/color v1.7.0
 	github.com/golang/protobuf v1.3.2
-	github.com/google/go-cmp v0.3.0
+	github.com/google/go-cmp v0.3.2-0.20190829225427-b1c9c4891a65
 	github.com/konsorten/go-windows-terminal-sequences v1.0.2 // indirect
 	github.com/kr/pretty v0.1.0 // indirect
 	github.com/mattn/go-colorable v0.1.2 // indirect

go.sum

@@ -24,6 +24,8 @@ github.com/golang/protobuf v1.3.2/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5y
 github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M=
 github.com/google/go-cmp v0.3.0 h1:crn/baboCvb5fXaQ0IJ1SGTsTVrWpDsCWC8EGETZijY=
 github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU=
+github.com/google/go-cmp v0.3.2-0.20190829225427-b1c9c4891a65 h1:B3yqxlLHBEoav+FDQM8ph7IIRA6AhQ70w119k3hoT2Y=
+github.com/google/go-cmp v0.3.2-0.20190829225427-b1c9c4891a65/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU=
 github.com/hpcloud/tail v1.0.0 h1:nfCOvKYfkgYP8hkirhJocXT2+zOD8yUNjXaWfTlyFKI=
 github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU=
 github.com/jonboulle/clockwork v0.1.0 h1:VKV+ZcuP6l3yW9doeqz6ziZGgcynBVQO+obU0+0hcPo=

internal/diff/diff.go renamed to internal/assert/equalf.go

@@ -1,18 +1,27 @@
-// Package diff is a helper package around go-cmp for generating
-// diffs between arbitrary interfaces.
-// See https://github.com/google/go-cmp/issues/40#issuecomment-328615283
-// Copied from https://github.com/nhooyr/websocket/blob/1b874731eab56c69c8bb3ebf8a029020c7863fc9/cmp_test.go
-package diff
+// Package assert is a helper package for asserting equality and
+// generating diffs in tests.
+package assert
 
 import (
 	"reflect"
+	"testing"
 
 	"github.com/google/go-cmp/cmp"
 )
 
-// Diff returns a diff between exp and act.
+// Equalf compares exp to act. If they are not equal, it will fatal the test
+// with the passed msg, args and also a diff of the differences.
+func Equalf(t *testing.T, exp, act interface{}, msg string, v ...interface{}) {
+	if diff := diff(exp, act); diff != "" {
+		t.Fatalf(msg+": %v", append(v, diff)...)
+	}
+}
+
+// diff returns a diff between exp and act.
 // The empty string is returned if they are identical.
-func Diff(exp, act interface{}) string {
+// See https://github.com/google/go-cmp/issues/40#issuecomment-328615283
+// Copied from https://github.com/nhooyr/websocket/blob/1b874731eab56c69c8bb3ebf8a029020c7863fc9/cmp_test.go
+func diff(exp, act interface{}) string {
 	return cmp.Diff(exp, act, deepAllowUnexported(exp, act))
 }
 

internal/humanfmt/marshal_test.go

@@ -4,7 +4,7 @@ import (
 	"testing"
 
 	"go.coder.com/slog"
-	"go.coder.com/slog/internal/diff"
+	"go.coder.com/slog/internal/assert"
 	"go.coder.com/slog/slogval"
 )
 
@@ -107,6 +107,17 @@ c:`,
 dsamkld`),
 			),
 			out: `"nhooyr_\tsoftware™️": hi
+"\rxeow\r": mdsla
+  dsamkld`,
+		},
+		{
+			name: "specialCharacterKey",
+			in: slog.Map(
+				slog.F("nhooyr \tsoftware™️", "hi"),
+				slog.F("\rxeow\r", `mdsla
+dsamkld`),
+			),
+			out: `"nhooyr_\tsoftware™️": hi
 "\rxeow\r": mdsla
   dsamkld`,
 		},
@@ -120,9 +131,7 @@ dsamkld`),
 			v := slogval.Encode(tc.in).(slogval.Map)
 			actOut := humanFields(v)
 			t.Logf("yaml:\n%v", actOut)
-			if diff := diff.Diff(tc.out, actOut); diff != "" {
-				t.Fatalf("unexpected output: %v", diff)
-			}
+			assert.Equalf(t, tc.out, actOut, "unexpected output")
 		})
 	}
 }

internal/syncwriter/syncwriter.go

@@ -0,0 +1,27 @@
+// Package syncwriter implements a concurrency safe io.Writer wrapper.
+package syncwriter
+
+import (
+	"io"
+	"sync"
+)
+
+// Writer implements a concurrency safe io.Writer wrapper.
+type Writer struct {
+	mu sync.Mutex
+	w  io.Writer
+}
+
+// New returns a new Writer that writes to w.
+func New(w io.Writer) *Writer {
+	return &Writer{
+		w: w,
+	}
+}
+
+// Write implements io.Writer.
+func (w *Writer) Write(p []byte) (int, error) {
+	w.mu.Lock()
+	defer w.mu.Unlock()
+	return w.w.Write(p)
+}

sloggers/sloghuman/sloghuman.go

@@ -6,49 +6,42 @@ import (
 	"context"
 	"io"
 	"strings"
-	"sync"
 
 	"go.coder.com/slog"
 	"go.coder.com/slog/internal/humanfmt"
+	"go.coder.com/slog/internal/syncwriter"
 )
 
 type humanSink struct {
-	mu    sync.Mutex
-	w     io.Writer
+	w     *syncwriter.Writer
 	color bool
 }
 
-var _ slog.Sink = &humanSink{}
-
-func (s *humanSink) LogEntry(ctx context.Context, ent slog.Entry) {
+func (s humanSink) LogEntry(ctx context.Context, ent slog.Entry) {
 	str := humanfmt.Entry(ent, s.color)
 	lines := strings.Split(str, "\n")
 
+	// We need to add 4 spaces before every field line for readability.
+	// humanfmt doesn't do it for us because the testSink doesn't want
+	// it as *testing.T automatically does it.
 	fieldsLines := lines[1:]
 	for i, line := range fieldsLines {
 		if line == "" {
 			continue
 		}
-		fieldsLines[i] = "\t" + line
+		fieldsLines[i] = strings.Repeat("    ", 4) + line
 	}
 
 	str = strings.Join(lines, "\n")
 
-	s.writeString(str + "\n")
-}
-
-func (s *humanSink) writeString(str string) {
-	s.mu.Lock()
-	defer s.mu.Unlock()
-
-	io.WriteString(s.w, str)
+	io.WriteString(s.w, str+"\n")
 }
 
 // Make creates a logger that writes logs in a human
 // readable YAML like format to the given writer.
 func Make(w io.Writer) slog.Logger {
 	return slog.Make(&humanSink{
-		w:     w,
+		w:     syncwriter.New(w),
 		color: humanfmt.IsTTY(w),
 	})
 }

sloggers/slogjson/slogjson.go

@@ -1,15 +1,82 @@
-// Package slogjson contains the slogger
-// that writes logs in a JSON format.
+// Package slogjson contains the slogger that writes logs in a JSON format.
+//
+// Format
+//
+//  {
+//    "level": "INFO",
+//    "msg": "hi",
+//    "ts": "",
+//    "caller": "slog/examples_test.go:62",
+//    "func": "go.coder.com/slog/sloggers/slogtest_test.TestExampleTest",
+//    "component": "comp.subcomp",
+//    "trace": "<traceid>",
+//    "span": "<spanid>",
+//    "fields": {
+//      "myField": "fieldValue"
+//    }
+//  }
 package slogjson // import "go.coder.com/slog/sloggers/slogjson"
 
 import (
+	"context"
+	"encoding/json"
+	"fmt"
 	"io"
+	"time"
+
+	"go.opencensus.io/trace"
+	"golang.org/x/xerrors"
 
 	"go.coder.com/slog"
+	"go.coder.com/slog/internal/syncwriter"
+	"go.coder.com/slog/slogval"
 )
 
 // Make creates a logger that writes JSON logs
-// to the given writer. The format is as follows:
+// to the given writer. See package level docs
+// for the format.
 func Make(w io.Writer) slog.Logger {
-	panic("TODO")
+	return slog.Make(jsonSink{
+		w: syncwriter.New(w),
+	})
+}
+
+type jsonSink struct {
+	w *syncwriter.Writer
+}
+
+func (s jsonSink) LogEntry(ctx context.Context, ent slog.Entry) {
+	m := slog.Map(
+		slog.F("level", ent.Level),
+		slog.F("msg", ent.Message),
+		slog.F("ts", jsonTimestamp(ent.Time)),
+		slog.F("caller", fmt.Sprintf("%v:%v", ent.File, ent.Line)),
+		slog.F("func", ent.Func),
+		slog.F("component", ent.Component),
+	)
+
+	if ent.SpanContext != (trace.SpanContext{}) {
+		m = append(m,
+			slog.F("trace", ent.SpanContext.TraceID),
+			slog.F("span", ent.SpanContext.SpanID),
+		)
+	}
+
+	m = append(m,
+		slog.F("fields", ent.Fields),
+	)
+
+	v := slogval.Reflect(m)
+	// We use NewEncoder because it reuses buffers behind the scenes which we cannot
+	// do with json.Marshal.
+	e := json.NewEncoder(s.w)
+	e.Encode(v)
+}
+
+func jsonTimestamp(t time.Time) interface{} {
+	ts, err := t.MarshalText()
+	if err != nil {
+		return xerrors.Errorf("failed to marshal timestamp to text: %w", err)
+	}
+	return string(ts)
 }

slogval/encode.go

@@ -54,7 +54,7 @@ func encode(rv reflect.Value) Value {
 		lv := m.Call(nil)
 		return encode(lv[0])
 	case implements(typ, (*xerrors.Formatter)(nil)):
-		return extractErrorChain(rv)
+		return extractXErrorChain(rv)
 	case implements(typ, (*error)(nil)):
 		m := rv.MethodByName("Error")
 		s := m.Call(nil)
@@ -231,7 +231,7 @@ func (p *xerrorPrinter) fields() Value {
 }
 
 // The value passed in must implement xerrors.Formatter.
-func extractErrorChain(rv reflect.Value) List {
+func extractXErrorChain(rv reflect.Value) List {
 	errs := List{}
 
 	formatError := func(p xerrors.Printer) error {

slogval/encode_test.go

@@ -8,7 +8,7 @@ import (
 
 	"golang.org/x/xerrors"
 
-	"go.coder.com/slog/internal/diff"
+	"go.coder.com/slog/internal/assert"
 )
 
 func TestEncode(t *testing.T) {
@@ -75,9 +75,7 @@ go.coder.com/slog/slogval.TestEncode
 			t.Parallel()
 
 			actOut := Encode(tc.in)
-			if diff := diff.Diff(tc.out, actOut); diff != "" {
-				t.Fatalf("unexpected output: %v", diff)
-			}
+			assert.Equalf(t, tc.out, actOut, "unexpected output")
 		})
 	}
 }

slogval/slogval.go

@@ -3,7 +3,11 @@
 package slogval // import "go.coder.com/slog/slogval"
 
 import (
+	"bytes"
+	"encoding/json"
 	"sort"
+
+	"golang.org/x/xerrors"
 )
 
 // Value represents a primitive value for structured logging.
@@ -87,3 +91,34 @@ func (m Map) sort() {
 		return m[i].Name < m[j].Name
 	})
 }
+
+var _ json.Marshaler = Map(nil)
+
+// MarshalJSON implements json.Marshaler.
+func (m Map) MarshalJSON() ([]byte, error) {
+	b := &bytes.Buffer{}
+	b.WriteString("{")
+	for i, f := range m {
+		fieldName, err := json.Marshal(f.Name)
+		if err != nil {
+			return nil, xerrors.Errorf("failed to marshal field name: %w", err)
+		}
+
+		fieldValue, err := json.Marshal(f.Value)
+		if err != nil {
+			return nil, xerrors.Errorf("failed to marshal field value: %w", err)
+		}
+
+		b.WriteString("\n")
+		b.Write(fieldName)
+		b.WriteString(":")
+		b.Write(fieldValue)
+
+		if i < len(m)-1 {
+			b.WriteString(",")
+		}
+	}
+	b.WriteString(`}`)
+
+	return b.Bytes(), nil
+}