Support Structured Tags

Adds `STags` to `Entry` and delegates marshalling those structures to
the emitters in whatever format is most appropriate.

Structured tags are added via the alog.AddStructuredTags(ctx, sTag1,
sTag2...) function.

context.go

@@ -2,28 +2,57 @@ package alog
 
 import "context"
 
-type key struct{}
+type stringKey struct{}
+type structuredKey struct{}
 
-var ctxkey = &key{}
+var stringCtxKey = stringKey{}
+var structuredCtxKey = structuredKey{}
+
+// STag is a structured tag.
+type STag struct {
+	// A unique key for the structure being logged.
+	Key string
+	// The structure you would like logged.  This will be marshalled into an
+	// appropriate form based on the chosen emitter.
+	Val interface{}
+}
 
 // AddTags adds paired strings to the set of tags in the Context.
 //
 // Any unpaired strings are ignored.
 func AddTags(ctx context.Context, pairs ...string) context.Context {
-	old := fromContext(ctx)
+	old := tagsFromContext(ctx)
 	new := make([][2]string, len(old)+(len(pairs)/2))
 	copy(new, old)
 	for o := range new[len(old):] {
 		new[len(old)+o][0] = pairs[o*2]
 		new[len(old)+o][1] = pairs[o*2+1]
 	}
-	return context.WithValue(ctx, ctxkey, new)
+	return context.WithValue(ctx, stringCtxKey, new)
 }
 
-// fromContext wraps the type assertion coming out of a Context.
-func fromContext(ctx context.Context) [][2]string {
-	if t, ok := ctx.Value(ctxkey).([][2]string); ok {
+// tagsFromContext wraps the type assertion coming out of a Context.
+func tagsFromContext(ctx context.Context) [][2]string {
+	if t, ok := ctx.Value(stringCtxKey).([][2]string); ok {
 		return t
 	}
 	return nil
 }
+
+// AddStructuredTags adds tag structures to the Context.
+func AddStructuredTags(ctx context.Context, tags ...STag) context.Context {
+	oldTags := sTagsFromContext(ctx)
+
+	newTags := append(oldTags[:len(oldTags):len(oldTags)], tags...)
+
+	return context.WithValue(ctx, structuredCtxKey, newTags)
+}
+
+// sTagsFromContext wraps the type assertion for structured tags coming out
+// of the context.
+func sTagsFromContext(ctx context.Context) []STag {
+	if tags, ok := ctx.Value(structuredCtxKey).([]STag); ok {
+		return tags
+	}
+	return ([]STag)(nil)
+}

emitter/gkelog/emitter.go

@@ -357,19 +357,44 @@ func Emitter(opt ...Option) alog.Emitter {
 
 		jsonTrace(ctx, o, b)
 
-		tagClean := make(map[string]int, len(e.Tags))
-		for i, tag := range e.Tags {
-			tagClean[tag[0]] = i
+		// Get all the tags and take their positions in the list.  If there are
+		// tags with the same key (first element of the string tuple) the latest
+		// tag will take precedence.
+		tagPositions := make(map[string]int, len(e.Tags))
+		for i, t := range e.Tags {
+			tagPositions[t[0]] = i
 		}
 		for i, tag := range e.Tags {
-			if tagClean[tag[0]] != i || reservedKeys[tag[0]] {
+			if tagPositions[tag[0]] != i || reservedKeys[tag[0]] {
 				continue
 			}
 			jsonKey(b, tag[0])
 			jsonString(b, tag[1])
 			b.WriteString(", ")
 		}
 
+		sTagPositions := make(map[string]int, len(e.STags))
+		for i, t := range e.STags {
+			sTagPositions[t.Key] = i
+		}
+		for i, sTag := range e.STags {
+			_, asStringTag := tagPositions[sTag.Key] // has this already been used as a string tag?
+			if tagPositions[sTag.Key] != i || asStringTag || reservedKeys[sTag.Key] {
+				continue
+			}
+
+			jsonKey(b, sTag.Key)
+
+			marshalled, marshalErr := json.Marshal(sTag.Val)
+			if marshalErr == nil {
+				b.Write(marshalled)
+			} else {
+				jsonString(b, "json marshal err: "+marshalErr.Error())
+			}
+
+			b.WriteString(", ")
+		}
+
 		if e.File != "" {
 			jsonKey(b, "logging.googleapis.com/sourceLocation")
 			b.WriteByte('{')

emitter/gkelog/emitter_test.go

@@ -49,10 +49,19 @@ func TestLabels(t *testing.T) {
 	ctx := context.Background()
 	l := alog.New(alog.WithEmitter(Emitter(WithWriter(b))), zeroTimeOpt)
 
+	structured := alog.STag{
+		Key: "structured",
+		Val: struct {
+			X int `json:"x"`
+		}{
+			X: 1,
+		},
+	}
 	ctx = alog.AddTags(ctx, "allthese", "tags", "andanother", "tag")
+	ctx = alog.AddStructuredTags(ctx, structured)
 	l.Print(ctx, "test")
 
-	want := `{"time":"0001-01-01T00:00:00Z", "allthese":"tags", "andanother":"tag", "message":"test"}` + "\n"
+	want := `{"time":"0001-01-01T00:00:00Z", "allthese":"tags", "andanother":"tag", "structured":{"x":1}, "message":"test"}` + "\n"
 	got := b.String()
 	if got != want {
 		t.Errorf("got:\n%s\nwant:\n%s", got, want)

emitter/jsonlog/emitter.go

@@ -106,14 +106,15 @@ func Emitter(w io.Writer, opt ...Option) alog.Emitter {
 			b.WriteString(", ")
 		}
 
+		tagPositions := make(map[string]int, len(e.Tags))
+		for i, tag := range e.Tags {
+			tagPositions[tag[0]] = i
+		}
+
 		if len(e.Tags) > 0 {
 			b.WriteString(`"tags":{`)
-			tagClean := make(map[string]int, len(e.Tags))
 			for i, tag := range e.Tags {
-				tagClean[tag[0]] = i
-			}
-			for i, tag := range e.Tags {
-				if tagClean[tag[0]] != i {
+				if tagPositions[tag[0]] != i {
 					continue
 				}
 				jsonString(b, tag[0])
@@ -126,6 +127,34 @@ func Emitter(w io.Writer, opt ...Option) alog.Emitter {
 			b.WriteString("}, ")
 		}
 
+		if len(e.STags) > 0 {
+			sTagPositions := make(map[string]int, len(e.STags))
+			for i, tag := range e.STags {
+				sTagPositions[tag.Key] = i
+			}
+			b.WriteString(`"sTags":{`)
+			for i, tag := range e.STags {
+				_, asStringTag := tagPositions[tag.Key]
+				if sTagPositions[tag.Key] != i || asStringTag {
+					continue
+				}
+
+				jsonString(b, tag.Key)
+				b.WriteByte(':')
+
+				marshalled, marshalErr := json.Marshal(tag.Val)
+				if marshalErr == nil {
+					b.Write(marshalled)
+				} else {
+					jsonString(b, "json marshal err: "+marshalErr.Error())
+				}
+				if i < len(e.Tags)-1 {
+					b.WriteString(", ")
+				}
+			}
+			b.WriteString("}, ")
+		}
+
 		b.WriteString(messageField)
 		b.WriteByte(':')
 		jsonString(b, e.Msg)

emitter/jsonlog/emitter_test.go

@@ -17,14 +17,26 @@ func TestEmitter(t *testing.T) {
 	ctx := context.Background()
 	l := alog.New(alog.WithCaller(), alog.WithEmitter(Emitter(b, WithShortFile())), zeroTimeOpt)
 
+	structuredVal := struct {
+		X int `json:"x"`
+		Y int `json:"why"`
+	}{
+		X: 1,
+		Y: 42,
+	}
+
 	ctx = alog.AddTags(ctx, "allthese", "tags", "andanother", "tag")
+	ctx = alog.AddStructuredTags(ctx, alog.STag{Key: "structured", Val: structuredVal}, alog.STag{Key: "other-struct", Val: structuredVal})
 	l.Print(ctx, "test")
 
-	want := `{"timestamp":"0001-01-01T00:00:00.000000000Z", "caller":"emitter_test.go:21", "tags":{"allthese":"tags", "andanother":"tag"}, "message":"test"}` + "\n"
+	want := `{"timestamp":"0001-01-01T00:00:00.000000000Z", "caller":"emitter_test.go:30", "tags":{"allthese":"tags", "andanother":"tag"}, "sTags":{"structured":{"x":1,"why":42}, "other-struct":{"x":1,"why":42}}, "message":"test"}` + "\n"
 	got := b.String()
 	if got != want {
 		t.Errorf("got:\n%s\nwant:\n%s", got, want)
 	}
+	if !json.Valid([]byte(got)) {
+		t.Errorf("invalid json: %s", got)
+	}
 }
 
 func TestMessageOnly(t *testing.T) {
@@ -53,7 +65,7 @@ func TestCustomFieldNames(t *testing.T) {
 
 	l.Print(ctx, "test")
 
-	want := `{"ts":"0001-01-01T00:00:00.000000000Z", "called_at":"emitter_test.go:54", "msg":"test"}` + "\n"
+	want := `{"ts":"0001-01-01T00:00:00.000000000Z", "called_at":"emitter_test.go:66", "msg":"test"}` + "\n"
 	got := b.String()
 	if got != want {
 		t.Errorf("got:\n%s\nwant:\n%s", got, want)

emitter/testlog/emitter.go

@@ -29,6 +29,6 @@ func Emitter(t testing.TB, opt ...Option) alog.Emitter {
 		if o.shortfile {
 			e.File = path.Base(e.File)
 		}
-		t.Logf("%s %s %v", e.File, e.Msg, e.Tags)
+		t.Logf("%s %s %v %+v", e.File, e.Msg, e.Tags, e.STags)
 	})
 }

emitter/testlog/emitter_test.go

@@ -12,9 +12,16 @@ func TestEmitter(t *testing.T) {
 	ctx := context.Background()
 	l := DefaultLogger(t, WithShortFile())
 
+	structured := struct {
+		X int
+	}{
+		X: 1,
+	}
+
 	ctx = alog.AddTags(ctx, "test", "tags")
+	ctx = alog.AddStructuredTags(ctx, alog.STag{Key: "structured", Val: structured})
 	l.Print(ctx, "testMessage")
 
 	// Output
-	// logger.go:40: emitter_test.go testMessage [[test tags]]
+	// logger.go:40: emitter_test.go testMessage [[test tags]] [{Key:structured Val:{X:1}}]
 }

emitter/textlog/emitter.go

@@ -2,6 +2,7 @@ package textlog
 
 import (
 	"context"
+	"fmt"
 	"io"
 	"os"
 	"time"
@@ -64,6 +65,18 @@ func Emitter(w io.Writer, opt ...Option) alog.Emitter {
 			}
 			m.WriteString("] ")
 		}
+		if t := e.STags; len(t) != 0 {
+			m.WriteByte('[')
+			for i, p := range t {
+				if i != 0 {
+					m.WriteByte(' ')
+				}
+				m.WriteString(p.Key)
+				m.WriteByte('=')
+				fmt.Fprintf(m, "%+v", p.Val)
+			}
+			m.WriteString("] ")
+		}
 		m.WriteString(e.Msg)
 		if m.Bytes()[m.Len()-1] != '\n' {
 			m.WriteByte('\n')

emitter/textlog/emitter_test.go

@@ -14,8 +14,15 @@ func ExampleEmitter() {
 		alog.WithEmitter(Emitter(os.Stdout, WithShortFile(), WithDateFormat(time.RFC3339))),
 		alog.OverrideTimestamp(func() time.Time { return time.Time{} }))
 
+	structuredVal := struct {
+		X int
+	}{
+		X: 1,
+	}
+
 	ctx = alog.AddTags(ctx, "allthese", "tags")
+	ctx = alog.AddStructuredTags(ctx, alog.STag{Key: "structured", Val: structuredVal})
 	l.Print(ctx, "test")
 	// Output:
-	// 0001-01-01T00:00:00Z emitter_test.go:18: [allthese=tags] test
+	// 0001-01-01T00:00:00Z emitter_test.go:25: [allthese=tags] [structured={X:1}] test
 }

entry.go

@@ -4,9 +4,10 @@ import "time"
 
 // Entry is the struct passed to user-supplied formatters.
 type Entry struct {
-	Time time.Time
-	Tags [][2]string
-	File string
-	Line int
-	Msg  string
+	Time  time.Time
+	Tags  [][2]string
+	STags []STag
+	File  string
+	Line  int
+	Msg   string
 }

logger.go

@@ -67,9 +67,10 @@ func (l *Logger) Output(ctx context.Context, calldepth int, msg string) {
 		l.now = time.Now
 	}
 	e := Entry{
-		Time: l.now(),
-		Tags: fromContext(ctx),
-		Msg:  msg,
+		Time:  l.now(),
+		Tags:  tagsFromContext(ctx),
+		STags: sTagsFromContext(ctx),
+		Msg:   msg,
 	}
 
 	if l.caller {