event: Remove the builder concept
We no longer need it, the optimizer now manages to a avoid allocations on ... functions.
Change-Id: If6ac86cba8cabfc855b347fd597192d093c69663
Reviewed-on: https://go-review.googlesource.com/c/exp/+/329629
Trust: Ian Cottrell <iancottrell@google.com>
Run-TryBot: Ian Cottrell <iancottrell@google.com>
TryBot-Result: Go Bot <gobot@golang.org>
Reviewed-by: Jonathan Amsterdam <jba@google.com>
diff --git a/event/adapter/gokit/gokit.go b/event/adapter/gokit/gokit.go
index b51fab4..c442ed6 100644
--- a/event/adapter/gokit/gokit.go
+++ b/event/adapter/gokit/gokit.go
@@ -34,7 +34,10 @@
keyvals = keyvals[1:]
}
}
- b := event.To(ctx)
+ ev := event.New(ctx, event.LogKind)
+ if ev == nil {
+ return nil
+ }
var msg string
for i := 0; i < len(keyvals); i += 2 {
key := keyvals[i].(string)
@@ -42,9 +45,10 @@
if key == "msg" || key == "message" {
msg = fmt.Sprint(value)
} else {
- b.With(keys.Value(key).Of(value))
+ ev.Labels = append(ev.Labels, keys.Value(key).Of(value))
}
}
- b.Log(msg)
+ ev.Message = msg
+ ev.Deliver()
return nil
}
diff --git a/event/adapter/gokit/gokit_test.go b/event/adapter/gokit/gokit_test.go
index f8d6cad..9c84590 100644
--- a/event/adapter/gokit/gokit_test.go
+++ b/event/adapter/gokit/gokit_test.go
@@ -31,7 +31,7 @@
keys.Value("resource").Of("R"),
},
}}
- if diff := cmp.Diff(want, h.Got); diff != "" {
+ if diff := cmp.Diff(want, h.Got, eventtest.CmpOption()); diff != "" {
t.Errorf("mismatch (-want, +got):\n%s", diff)
}
}
diff --git a/event/adapter/logfmt/logfmt.go b/event/adapter/logfmt/logfmt.go
index 9735b38..cc8b297 100644
--- a/event/adapter/logfmt/logfmt.go
+++ b/event/adapter/logfmt/logfmt.go
@@ -40,27 +40,11 @@
return &Handler{to: to}
}
-func (h *Handler) Log(ctx context.Context, ev *event.Event) {
- h.Printer.Event(h.to, ev)
-}
-
-func (h *Handler) Metric(ctx context.Context, ev *event.Event) {
- h.Printer.Event(h.to, ev)
-}
-
-func (h *Handler) Annotate(ctx context.Context, ev *event.Event) {
- h.Printer.Event(h.to, ev)
-}
-
-func (h *Handler) Start(ctx context.Context, ev *event.Event) context.Context {
+func (h *Handler) Event(ctx context.Context, ev *event.Event) context.Context {
h.Printer.Event(h.to, ev)
return ctx
}
-func (h *Handler) End(ctx context.Context, ev *event.Event) {
- h.Printer.Event(h.to, ev)
-}
-
func (p *Printer) Event(w io.Writer, ev *event.Event) {
p.needSep = false
if !ev.At.IsZero() {
@@ -94,7 +78,7 @@
p.label(w, "name", event.StringOf(ev.Name))
}
- if ev.Kind == event.TraceKind && ev.TraceID == 0 {
+ if ev.Kind == event.EndKind {
p.label(w, "end", event.Value{})
}
diff --git a/event/adapter/logfmt/logfmt_test.go b/event/adapter/logfmt/logfmt_test.go
index ca764e3..be80ade 100644
--- a/event/adapter/logfmt/logfmt_test.go
+++ b/event/adapter/logfmt/logfmt_test.go
@@ -57,7 +57,7 @@
expect: `err="an error"`,
}, {
name: "end",
- event: event.Event{Kind: event.TraceKind},
+ event: event.Event{Kind: event.EndKind},
expect: `end`,
}, {
name: "string",
diff --git a/event/adapter/logr/logr.go b/event/adapter/logr/logr.go
index 2dfb62a..23bf172 100644
--- a/event/adapter/logr/logr.go
+++ b/event/adapter/logr/logr.go
@@ -15,8 +15,8 @@
)
type logger struct {
- exporter *event.Exporter
- builder event.Builder // never delivered, only cloned
+ ctx context.Context
+ labels []event.Label
nameSep string
name string
verbosity int
@@ -26,7 +26,7 @@
func NewLogger(ctx context.Context, nameSep string) logr.Logger {
return &logger{
- builder: event.To(ctx),
+ ctx: ctx,
nameSep: nameSep,
}
}
@@ -63,13 +63,6 @@
return true
}
-// addLabels adds labels for keysAndValues to b.
-func addLabels(b event.Builder, keysAndValues []interface{}) {
- for i := 0; i < len(keysAndValues); i += 2 {
- b.With(newLabel(keysAndValues[i], keysAndValues[i+1]))
- }
-}
-
// Info logs a non-error message with the given key/value pairs as context.
//
// The msg argument should be used to add some constant description to
@@ -77,7 +70,10 @@
// variable information. The key/value pairs should alternate string
// keys and arbitrary values.
func (l *logger) Info(msg string, keysAndValues ...interface{}) {
- l.log(msg, l.builder.Clone(), keysAndValues)
+ ev := event.New(l.ctx, event.LogKind)
+ if ev != nil {
+ l.log(ev, msg, keysAndValues)
+ }
}
// Error logs an error, with the given message and key/value pairs as context.
@@ -89,22 +85,35 @@
// while the err field should be used to attach the actual error that
// triggered this log line, if present.
func (l *logger) Error(err error, msg string, keysAndValues ...interface{}) {
- l.log(msg, l.builder.Clone().Error(err), keysAndValues)
+ ev := event.New(l.ctx, event.LogKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, keys.Value("error").Of(err))
+ l.log(ev, msg, keysAndValues)
+ }
}
-func (l *logger) log(msg string, b event.Builder, keysAndValues []interface{}) {
- b.With(convertVerbosity(l.verbosity))
- b.Name(l.name)
- addLabels(b, keysAndValues)
- b.Log(msg)
+func (l *logger) log(ev *event.Event, msg string, keysAndValues []interface{}) {
+ ev.Labels = append(ev.Labels, convertVerbosity(l.verbosity).Label())
+ ev.Labels = append(ev.Labels, l.labels...)
+ for i := 0; i < len(keysAndValues); i += 2 {
+ ev.Labels = append(ev.Labels, newLabel(keysAndValues[i], keysAndValues[i+1]))
+ }
+ ev.Name = l.name
+ ev.Message = msg
+ ev.Deliver()
}
// WithValues adds some key-value pairs of context to a logger.
// See Info for documentation on how key/value pairs work.
func (l *logger) WithValues(keysAndValues ...interface{}) logr.Logger {
l2 := *l
- l2.builder = l2.builder.Clone()
- addLabels(l2.builder, keysAndValues)
+ if len(keysAndValues) > 0 {
+ l2.labels = make([]event.Label, len(l.labels), len(l.labels)+(len(keysAndValues)/2))
+ copy(l2.labels, l.labels)
+ for i := 0; i < len(keysAndValues); i += 2 {
+ l2.labels = append(l2.labels, newLabel(keysAndValues[i], keysAndValues[i+1]))
+ }
+ }
return &l2
}
@@ -112,7 +121,7 @@
return keys.Value(key.(string)).Of(value)
}
-func convertVerbosity(v int) event.Label {
+func convertVerbosity(v int) severity.Level {
//TODO: this needs to be more complicated, v decreases with increasing severity
- return severity.Of(severity.Level(v))
+ return severity.Level(v)
}
diff --git a/event/adapter/logr/logr_test.go b/event/adapter/logr/logr_test.go
index 8b897e4..6417755 100644
--- a/event/adapter/logr/logr_test.go
+++ b/event/adapter/logr/logr_test.go
@@ -19,7 +19,7 @@
func TestInfo(t *testing.T) {
ctx, th := eventtest.NewCapture()
- log := elogr.NewLogger(ctx, "/").WithName("n").V(int(severity.DebugLevel))
+ log := elogr.NewLogger(ctx, "/").WithName("n").V(int(severity.Debug))
log = log.WithName("m")
log.Info("mess", "traceID", 17, "resource", "R")
want := []event.Event{{
@@ -28,12 +28,12 @@
Message: "mess",
Name: "n/m",
Labels: []event.Label{
- severity.Debug,
+ severity.Debug.Label(),
keys.Value("traceID").Of(17),
keys.Value("resource").Of("R"),
},
}}
- if diff := cmp.Diff(want, th.Got); diff != "" {
+ if diff := cmp.Diff(want, th.Got, eventtest.CmpOption()); diff != "" {
t.Errorf("mismatch (-want, +got):\n%s", diff)
}
}
diff --git a/event/adapter/logrus/logrus.go b/event/adapter/logrus/logrus.go
index fe21fee..af41ce4 100644
--- a/event/adapter/logrus/logrus.go
+++ b/event/adapter/logrus/logrus.go
@@ -46,19 +46,24 @@
if ctx == nil {
ctx = context.Background()
}
- b := event.To(ctx).At(e.Time)
- b.With(convertLevel(e.Level))
- for k, v := range e.Data {
- b.With(keys.Value(k).Of(v))
+ ev := event.New(ctx, event.LogKind)
+ if ev == nil {
+ return nil, nil
}
- b.Log(e.Message)
+ ev.At = e.Time
+ ev.Labels = append(ev.Labels, convertLevel(e.Level).Label())
+ for k, v := range e.Data {
+ ev.Labels = append(ev.Labels, keys.Value(k).Of(v))
+ }
+ ev.Message = e.Message
+ ev.Deliver()
return nil, nil
}
-func convertLevel(level logrus.Level) event.Label {
+func convertLevel(level logrus.Level) severity.Level {
switch level {
case logrus.PanicLevel:
- return severity.Of(severity.FatalLevel + 1)
+ return severity.Fatal + 1
case logrus.FatalLevel:
return severity.Fatal
case logrus.ErrorLevel:
diff --git a/event/adapter/logrus/logrus_test.go b/event/adapter/logrus/logrus_test.go
index babc686..8b1f98a 100644
--- a/event/adapter/logrus/logrus_test.go
+++ b/event/adapter/logrus/logrus_test.go
@@ -32,7 +32,7 @@
Kind: event.LogKind,
Message: "mess",
Labels: []event.Label{
- severity.Info,
+ severity.Info.Label(),
keys.Value("traceID").Of(17),
keys.Value("resource").Of("R"),
},
@@ -40,7 +40,7 @@
// logrus fields are stored in a map, so we have to sort to overcome map
// iteration indeterminacy.
less := func(a, b event.Label) bool { return a.Name < b.Name }
- if diff := cmp.Diff(want, th.Got, cmpopts.SortSlices(less), cmpopts.IgnoreFields(event.Event{}, "At")); diff != "" {
+ if diff := cmp.Diff(want, th.Got, cmpopts.SortSlices(less), eventtest.CmpOption()); diff != "" {
t.Errorf("mismatch (-want, +got):\n%s", diff)
}
}
diff --git a/event/adapter/zap/zap.go b/event/adapter/zap/zap.go
index 22304dd..e73e45d 100644
--- a/event/adapter/zap/zap.go
+++ b/event/adapter/zap/zap.go
@@ -27,15 +27,14 @@
)
type core struct {
- builder event.Builder // never delivered, only cloned
+ ctx context.Context
+ labels []event.Label
}
var _ zapcore.Core = (*core)(nil)
func NewCore(ctx context.Context) zapcore.Core {
- return &core{
- builder: event.To(ctx),
- }
+ return &core{ctx: ctx}
}
func (c *core) Enabled(level zapcore.Level) bool {
@@ -44,25 +43,37 @@
func (c *core) With(fields []zapcore.Field) zapcore.Core {
c2 := *c
- c2.builder = c2.builder.Clone()
- addLabels(c2.builder, fields)
+ if len(fields) > 0 {
+ c2.labels = make([]event.Label, len(c.labels), len(c.labels)+len(fields))
+ copy(c2.labels, c.labels)
+ for _, f := range fields {
+ c2.labels = append(c2.labels, newLabel(f))
+ }
+ }
return &c2
}
func (c *core) Write(e zapcore.Entry, fs []zapcore.Field) error {
- b := c.builder.Clone().
- At(e.Time).
- With(convertLevel(e.Level)).
- Name(e.LoggerName)
+ ev := event.New(c.ctx, event.LogKind)
+ if ev == nil {
+ return nil
+ }
+ ev.At = e.Time
+ ev.Labels = append(ev.Labels, c.labels...)
+ ev.Labels = append(ev.Labels, convertLevel(e.Level).Label())
+ ev.Name = e.LoggerName
// TODO: add these additional labels more efficiently.
if e.Stack != "" {
- b.With(keys.String("stack").Of(e.Stack))
+ ev.Labels = append(ev.Labels, keys.String("stack").Of(e.Stack))
}
if e.Caller.Defined {
- b.With(keys.String("caller").Of(e.Caller.String()))
+ ev.Labels = append(ev.Labels, keys.String("caller").Of(e.Caller.String()))
}
- addLabels(b, fs)
- b.Log(e.Message)
+ for _, f := range fs {
+ ev.Labels = append(ev.Labels, newLabel(f))
+ }
+ ev.Message = e.Message
+ ev.Deliver()
return nil
}
@@ -72,14 +83,6 @@
func (c *core) Sync() error { return nil }
-// addLabels creates a new []event.Label with the given labels followed by the
-// labels constructed from fields.
-func addLabels(b event.Builder, fields []zap.Field) {
- for i := 0; i < len(fields); i++ {
- b.With(newLabel(fields[i]))
- }
-}
-
func newLabel(f zap.Field) event.Label {
switch f.Type {
case zapcore.ArrayMarshalerType, zapcore.ObjectMarshalerType, zapcore.BinaryType, zapcore.ByteStringType,
@@ -149,7 +152,7 @@
return stringer.(fmt.Stringer).String()
}
-func convertLevel(level zapcore.Level) event.Label {
+func convertLevel(level zapcore.Level) severity.Level {
switch level {
case zapcore.DebugLevel:
return severity.Debug
@@ -160,9 +163,9 @@
case zapcore.ErrorLevel:
return severity.Error
case zapcore.DPanicLevel:
- return severity.Of(severity.FatalLevel - 1)
+ return severity.Fatal - 1
case zapcore.PanicLevel:
- return severity.Of(severity.FatalLevel + 1)
+ return severity.Fatal + 1
case zapcore.FatalLevel:
return severity.Fatal
default:
diff --git a/event/adapter/zap/zap_test.go b/event/adapter/zap/zap_test.go
index 4ae028a..870fc56 100644
--- a/event/adapter/zap/zap_test.go
+++ b/event/adapter/zap/zap_test.go
@@ -10,7 +10,6 @@
"testing"
"github.com/google/go-cmp/cmp"
- "github.com/google/go-cmp/cmp/cmpopts"
"go.uber.org/zap"
"golang.org/x/exp/event"
ezap "golang.org/x/exp/event/adapter/zap"
@@ -31,11 +30,11 @@
Labels: []event.Label{
keys.Int64("traceID").Of(17),
keys.String("resource").Of("R"),
- severity.Info,
+ severity.Info.Label(),
keys.Float64("pi").Of(3.14),
},
}}
- if diff := cmp.Diff(want, h.Got, cmpopts.IgnoreFields(event.Event{}, "At")); diff != "" {
+ if diff := cmp.Diff(want, h.Got, eventtest.CmpOption()); diff != "" {
t.Errorf("mismatch (-want, +got):\n%s", diff)
}
}
diff --git a/event/alloc_test.go b/event/alloc_test.go
index 070dfdf..80ce051 100644
--- a/event/alloc_test.go
+++ b/event/alloc_test.go
@@ -23,8 +23,7 @@
e := event.NewExporter(logfmt.NewHandler(ioutil.Discard), &event.ExporterOptions{EnableNamespaces: true})
ctx := event.WithExporter(context.Background(), e)
allocs := int(testing.AllocsPerRun(5, func() {
- event.To(ctx).With(aString).With(anInt).Log("message1")
- event.To(ctx).With(aString, anInt).Log("message2")
+ event.Log(ctx, "message", aString, anInt)
}))
if allocs != 0 {
t.Errorf("Got %d allocs, expect 0", allocs)
diff --git a/event/bench_test.go b/event/bench_test.go
index 0a07dea..8cc1206 100644
--- a/event/bench_test.go
+++ b/event/bench_test.go
@@ -26,12 +26,12 @@
eventLog = eventtest.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- event.To(ctx).With(severity.Info).With(aValue.Of(a)).Log(eventtest.A.Msg)
+ severity.Info.Log(ctx, eventtest.A.Msg, aValue.Of(a))
return ctx
},
AEnd: func(ctx context.Context) {},
BStart: func(ctx context.Context, b string) context.Context {
- event.To(ctx).With(severity.Info).With(bValue.Of(b)).Log(eventtest.B.Msg)
+ severity.Info.Log(ctx, eventtest.B.Msg, bValue.Of(b))
return ctx
},
BEnd: func(ctx context.Context) {},
@@ -39,12 +39,12 @@
eventLogf = eventtest.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- event.To(ctx).With(severity.Info).Logf(eventtest.A.Msgf, a)
+ severity.Info.Logf(ctx, eventtest.A.Msgf, a)
return ctx
},
AEnd: func(ctx context.Context) {},
BStart: func(ctx context.Context, b string) context.Context {
- event.To(ctx).With(severity.Info).Logf(eventtest.B.Msgf, b)
+ severity.Info.Logf(ctx, eventtest.B.Msgf, b)
return ctx
},
BEnd: func(ctx context.Context) {},
@@ -52,33 +52,31 @@
eventTrace = eventtest.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- ctx, _ = event.To(ctx).Start(eventtest.A.Msg)
- event.To(ctx).With(aValue.Of(a)).Annotate()
+ ctx = event.Start(ctx, eventtest.A.Msg, aValue.Of(a))
return ctx
},
AEnd: func(ctx context.Context) {
- event.To(ctx).End()
+ event.End(ctx)
},
BStart: func(ctx context.Context, b string) context.Context {
- ctx, _ = event.To(ctx).Start(eventtest.B.Msg)
- event.To(ctx).With(bValue.Of(b)).Annotate()
+ ctx = event.Start(ctx, eventtest.B.Msg, bValue.Of(b))
return ctx
},
BEnd: func(ctx context.Context) {
- event.To(ctx).End()
+ event.End(ctx)
},
}
eventMetric = eventtest.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- event.To(ctx).With(aStat.Of(a)).Metric(gauge.Record(1))
- event.To(ctx).With(aCount.Of(1)).Metric(gauge.Record(1))
+ gauge.Record(ctx, 1, aStat.Of(a))
+ gauge.Record(ctx, 1, aCount.Of(1))
return ctx
},
AEnd: func(ctx context.Context) {},
BStart: func(ctx context.Context, b string) context.Context {
- event.To(ctx).With(bLength.Of(len(b))).Metric(gauge.Record(1))
- event.To(ctx).With(bCount.Of(1)).Metric(gauge.Record(1))
+ gauge.Record(ctx, 1, bLength.Of(len(b)))
+ gauge.Record(ctx, 1, bCount.Of(1))
return ctx
},
BEnd: func(ctx context.Context) {},
@@ -90,7 +88,7 @@
}
func eventNoop() context.Context {
- return event.WithExporter(context.Background(), event.NewExporter(event.NopHandler{}, eventtest.ExporterOptions()))
+ return event.WithExporter(context.Background(), event.NewExporter(nopHandler{}, eventtest.ExporterOptions()))
}
func eventPrint(w io.Writer) context.Context {
@@ -103,6 +101,10 @@
return event.WithExporter(context.Background(), event.NewExporter(logfmt.NewHandler(w), opts))
}
+type nopHandler struct{}
+
+func (nopHandler) Event(ctx context.Context, _ *event.Event) context.Context { return ctx }
+
func BenchmarkEventLogNoExporter(b *testing.B) {
eventtest.RunBenchmark(b, eventNoExporter(), eventLog)
}
diff --git a/event/builder.go b/event/builder.go
deleted file mode 100644
index 1452dcf..0000000
--- a/event/builder.go
+++ /dev/null
@@ -1,303 +0,0 @@
-// Copyright 2020 The Go Authors. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
-
-// +build !disable_events
-
-package event
-
-import (
- "context"
- "fmt"
- "sync"
- "sync/atomic"
- "time"
-)
-
-// Builder is a fluent builder for construction of new events.
-type Builder struct {
- builderCommon
-}
-
-type builderCommon struct {
- ctx context.Context
- data *builder
- builderID uint64 // equals data.id if all is well
-}
-
-// preallocateLabels controls the space reserved for labels in a builder.
-// Storing the first few labels directly in builders can avoid an allocation at
-// all for the very common cases of simple events. The length needs to be large
-// enough to cope with the majority of events but no so large as to cause undue
-// stack pressure.
-const preallocateLabels = 6
-
-type builder struct {
- exporter *Exporter
- Event Event
- labels [preallocateLabels]Label
- id uint64
- parentStart time.Time
-}
-
-var builderPool = sync.Pool{New: func() interface{} { return &builder{} }}
-
-// To initializes a builder from the values stored in a context.
-func To(ctx context.Context) Builder {
- b := Builder{builderCommon{ctx: ctx}}
- b.data = newBuilder(ctx)
- if b.data != nil {
- b.builderID = b.data.id
- }
- return b
-}
-
-var builderID uint64 // atomic
-
-func newBuilder(ctx context.Context) *builder {
- exporter, parent, parentStart := FromContext(ctx)
- if exporter == nil {
- return nil
- }
- b := allocBuilder()
- b.exporter = exporter
- b.parentStart = parentStart
- b.Event.Labels = b.labels[:0]
- b.Event.Parent = parent
- return b
-}
-
-func allocBuilder() *builder {
- b := builderPool.Get().(*builder)
- b.id = atomic.AddUint64(&builderID, 1)
- return b
-}
-
-// Clone returns a copy of this builder.
-// The two copies can be independently delivered.
-func (b Builder) Clone() Builder {
- return Builder{b.clone()}
-}
-
-func (b builderCommon) clone() builderCommon {
- if b.data == nil {
- return b
- }
- bb := allocBuilder()
- bbid := bb.id
- clone := builderCommon{ctx: b.ctx, data: bb, builderID: bb.id}
- *clone.data = *b.data
- clone.data.id = bbid
- if len(b.data.Event.Labels) == 0 || &b.data.labels[0] == &b.data.Event.Labels[0] {
- clone.data.Event.Labels = clone.data.labels[:len(b.data.Event.Labels)]
- } else {
- clone.data.Event.Labels = make([]Label, len(b.data.Event.Labels))
- copy(clone.data.Event.Labels, b.data.Event.Labels)
- }
- return clone
-}
-
-func (b Builder) Name(name string) Builder {
- if b.data != nil {
- b.data.Event.Name = name
- }
- return b
-}
-
-func (b Builder) Error(err error) Builder {
- if b.data != nil {
- b.data.Event.Error = err
- }
- return b
-}
-
-func (b builderCommon) addLabel(label Label) {
- if b.data != nil {
- checkValid(b.data, b.builderID)
- }
-}
-
-// With adds all the supplied labels to the event being constructed.
-func (b Builder) With(labels ...Label) Builder {
- if b.data == nil || len(labels) == 0 {
- return b
- }
- checkValid(b.data, b.builderID)
- b.data.Event.Labels = append(b.data.Event.Labels, labels...)
- return b
-}
-
-func (b Builder) At(t time.Time) Builder {
- b.setAt(t)
- return b
-}
-
-func (b builderCommon) setAt(t time.Time) {
- if b.data != nil {
- checkValid(b.data, b.builderID)
- b.data.Event.At = t
- }
-}
-
-func (b Builder) Namespace(ns string) Builder {
- b.setNamespace(ns)
- return b
-}
-
-func (b builderCommon) setNamespace(ns string) {
- if b.data != nil {
- checkValid(b.data, b.builderID)
- b.data.Event.Namespace = ns
- }
-}
-
-// Log is a helper that calls Deliver with LogKind.
-func (b Builder) Log(message string) {
- if b.data == nil {
- return
- }
- checkValid(b.data, b.builderID)
- if b.data.exporter.loggingEnabled() {
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- b.data.Event.Kind = LogKind
- b.data.Event.Message = message
- b.data.exporter.prepare(&b.data.Event)
- b.data.exporter.handler.Log(b.ctx, &b.data.Event)
- }
- b.done()
-}
-
-// Logf is a helper that uses fmt.Sprint to build the message and then
-// calls Deliver with LogKind.
-func (b Builder) Logf(template string, args ...interface{}) {
- if b.data == nil {
- return
- }
- checkValid(b.data, b.builderID)
- if b.data.exporter.loggingEnabled() {
- message := fmt.Sprintf(template, args...)
- // Duplicate code from Log so Exporter.deliver's invocation of runtime.Callers is correct.
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- b.data.Event.Kind = LogKind
- b.data.Event.Message = message
- b.data.exporter.prepare(&b.data.Event)
- b.data.exporter.handler.Log(b.ctx, &b.data.Event)
- }
- b.done()
-}
-
-func (b Builder) Metric(mv MetricValue) {
- if b.data == nil {
- return
- }
- checkValid(b.data, b.builderID)
- if b.data.exporter.metricsEnabled() {
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- if b.data.Event.Namespace == "" {
- b.data.Event.Namespace = mv.m.Descriptor().Namespace()
- }
- b.data.Event.Labels = append(b.data.Event.Labels, MetricVal.Of(mv.v), MetricKey.Of(mv.m))
- b.data.Event.Kind = MetricKind
- b.data.exporter.prepare(&b.data.Event)
- b.data.exporter.handler.Metric(b.ctx, &b.data.Event)
- }
- b.done()
-}
-
-// Annotate is a helper that calls Deliver with AnnotateKind.
-func (b Builder) Annotate() {
- if b.data == nil {
- return
- }
- checkValid(b.data, b.builderID)
- if b.data.exporter.annotationsEnabled() {
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- b.data.exporter.prepare(&b.data.Event)
- b.data.exporter.handler.Annotate(b.ctx, &b.data.Event)
- }
- b.done()
-}
-
-// End is a helper that calls Deliver with EndKind.
-func (b Builder) End() {
- if b.data == nil {
- return
- }
- checkValid(b.data, b.builderID)
- if b.data.exporter.tracingEnabled() {
- // If there is a DurationMetric label, emit a Metric event
- // with the time since Start was called.
- if v, ok := DurationMetric.Find(&b.data.Event); ok {
- m := v.(*Duration)
- b.Clone().Metric(m.Record(time.Since(b.data.parentStart)))
- }
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- b.data.Event.Kind = TraceKind
- b.data.exporter.prepare(&b.data.Event)
- b.data.exporter.handler.End(b.ctx, &b.data.Event)
- }
- b.done()
-}
-
-// Event returns a copy of the event currently being built.
-func (b Builder) Event() *Event {
- checkValid(b.data, b.builderID)
- clone := b.data.Event
- if len(b.data.Event.Labels) > 0 {
- clone.Labels = make([]Label, len(b.data.Event.Labels))
- copy(clone.Labels, b.data.Event.Labels)
- }
- return &clone
-}
-
-func (b builderCommon) done() {
- *b.data = builder{}
- builderPool.Put(b.data)
-}
-
-// Start delivers a start event with the given name and labels.
-// Its second return value is a Builder whose End method can be
-// called to deliver the matching End event.
-// (It is also fine to ignore the Builder.)
-// All events created from the returned context will have this start event
-// as their parent.
-func (b Builder) Start(name string) (context.Context, Builder) {
- if b.data == nil {
- return b.ctx, Builder{}
- }
- checkValid(b.data, b.builderID)
- ctx := b.ctx
- var endBuilder Builder
- if b.data.exporter.tracingEnabled() {
- b.data.exporter.mu.Lock()
- defer b.data.exporter.mu.Unlock()
- b.data.exporter.lastEvent++
- traceID := b.data.exporter.lastEvent
- // create the end builder
- endBuilder = b.Clone()
- endBuilder.data.Event.Parent = traceID
- b.data.Event.Kind = TraceKind
- b.data.Event.TraceID = traceID
- b.data.exporter.prepare(&b.data.Event)
- // and now deliver the start event
- b.data.Event.Name = name
- now := time.Now()
- ctx = newContext(ctx, b.data.exporter, traceID, now)
- ctx = b.data.exporter.handler.Start(ctx, &b.data.Event)
- endBuilder.data.parentStart = now
- endBuilder.ctx = ctx
- }
- b.done()
- return ctx, endBuilder
-}
-
-func checkValid(b *builder, wantID uint64) {
- if b.exporter == nil || b.id != wantID {
- panic("Builder already delivered an event; missing call to Clone")
- }
-}
diff --git a/event/builder_test.go b/event/builder_test.go
deleted file mode 100644
index c467adb..0000000
--- a/event/builder_test.go
+++ /dev/null
@@ -1,194 +0,0 @@
-// Copyright 2020 The Go Authors. All rights reserved.
-// Use of this source code is governed by a BSD-style
-// license that can be found in the LICENSE file.
-
-// +build !disable_events
-
-package event_test
-
-import (
- "context"
- "fmt"
- "strings"
- "testing"
- "time"
-
- "github.com/google/go-cmp/cmp"
- "golang.org/x/exp/event"
- "golang.org/x/exp/event/keys"
-)
-
-func TestClone(t *testing.T) {
- var labels []event.Label
- for i := 0; i < 5; i++ { // one greater than len(Builder.labels)
- labels = append(labels, keys.Int(fmt.Sprintf("l%d", i)).Of(i))
- }
-
- ctx := event.WithExporter(context.Background(), event.NewExporter(event.NopHandler{}, nil))
- b1 := event.To(ctx)
- b1.With(labels[0]).With(labels[1])
- check(t, b1, labels[:2])
- b2 := b1.Clone()
- check(t, b1, labels[:2])
- check(t, b2, labels[:2])
-
- b2.With(labels[2])
- check(t, b1, labels[:2])
- check(t, b2, labels[:3])
-
- // Force a new backing array for b.Event.Labels.
- for i := 3; i < len(labels); i++ {
- b2.With(labels[i])
- }
- check(t, b1, labels[:2])
- check(t, b2, labels)
-
- b2.Log("") // put b2 back in the pool.
- b2 = event.To(ctx)
- check(t, b1, labels[:2])
- check(t, b2, []event.Label{})
-
- b2.With(labels[3]).With(labels[4])
- check(t, b1, labels[:2])
- check(t, b2, labels[3:5])
-}
-
-func check(t *testing.T, b event.Builder, want []event.Label) {
- t.Helper()
- if got := b.Event().Labels; !cmp.Equal(got, want, cmp.Comparer(valueEqual)) {
- t.Fatalf("got %v, want %v", got, want)
- }
-}
-
-func valueEqual(l1, l2 event.Value) bool {
- return fmt.Sprint(l1) == fmt.Sprint(l2)
-}
-
-func TestTraceBuilder(t *testing.T) {
- // Verify that the context returned from the handler is also returned from Start,
- // and is the context passed to End.
- ctx := event.WithExporter(context.Background(), event.NewExporter(&testTraceHandler{t: t}, nil))
- ctx, eb := event.To(ctx).Start("s")
- val := ctx.Value("x")
- if val != 1 {
- t.Fatal("context not returned from Start")
- }
- eb.End()
-}
-
-type testTraceHandler struct {
- event.NopHandler
- t *testing.T
-}
-
-func (*testTraceHandler) Start(ctx context.Context, _ *event.Event) context.Context {
- return context.WithValue(ctx, "x", 1)
-}
-
-func (t *testTraceHandler) End(ctx context.Context, _ *event.Event) {
- val := ctx.Value("x")
- if val != 1 {
- t.t.Fatal("Start context not passed to End")
- }
-}
-
-func TestFailToClone(t *testing.T) {
- ctx := event.WithExporter(context.Background(), event.NewExporter(event.NopHandler{}, nil))
-
- catch := func(f func()) {
- defer func() {
- r := recover()
- if r == nil {
- t.Error("expected panic, did not get one")
- return
- }
- got, ok := r.(string)
- if !ok || !strings.Contains(got, "Clone") {
- t.Errorf("got panic(%v), want string with 'Clone'", r)
- }
- }()
-
- f()
- }
-
- catch(func() {
- b1 := event.To(ctx)
- b1.Log("msg1")
- // Reuse of Builder without Clone; b1.data has been cleared.
- b1.Log("msg2")
- })
-
- catch(func() {
- b1 := event.To(ctx)
- b1.Log("msg1")
- _ = event.To(ctx) // re-allocate the builder
- // b1.data is populated, but with the wrong information.
- b1.Log("msg2")
- })
-}
-
-func TestTraceDuration(t *testing.T) {
- // Verify that a trace can can emit a latency metric.
- dur := event.NewDuration("test", "")
- want := 200 * time.Millisecond
-
- check := func(t *testing.T, h *testTraceDurationHandler) {
- if !h.got.HasValue() {
- t.Fatal("no metric value")
- }
- got := h.got.Duration().Round(50 * time.Millisecond)
- if got != want {
- t.Fatalf("got %s, want %s", got, want)
- }
- }
-
- t.Run("returned builder", func(t *testing.T) {
- h := &testTraceDurationHandler{}
- ctx := event.WithExporter(context.Background(), event.NewExporter(h, nil))
- ctx, eb := event.To(ctx).With(event.DurationMetric.Of(dur)).Start("s")
- time.Sleep(want)
- eb.End()
- check(t, h)
- })
- t.Run("separate builder", func(t *testing.T) {
- h := &testTraceDurationHandler{}
- ctx := event.WithExporter(context.Background(), event.NewExporter(h, nil))
- ctx, _ = event.To(ctx).Start("s")
- time.Sleep(want)
- event.To(ctx).With(event.DurationMetric.Of(dur)).End()
- check(t, h)
- })
-}
-
-type testTraceDurationHandler struct {
- event.NopHandler
- got event.Value
-}
-
-func (t *testTraceDurationHandler) Metric(ctx context.Context, e *event.Event) {
- t.got, _ = event.MetricVal.Find(e)
-}
-
-func BenchmarkBuildContext(b *testing.B) {
- // How long does it take to deliver an event from a nested context?
- c := event.NewCounter("c", "")
- for _, depth := range []int{1, 5, 7, 10} {
- b.Run(fmt.Sprintf("depth %d", depth), func(b *testing.B) {
- ctx := event.WithExporter(context.Background(), event.NewExporter(event.NopHandler{}, nil))
- for i := 0; i < depth; i++ {
- ctx = context.WithValue(ctx, i, i)
- }
- b.Run("direct", func(b *testing.B) {
- for i := 0; i < b.N; i++ {
- event.To(ctx).Name("foo").Metric(c.Record(1))
- }
- })
- b.Run("cloned", func(b *testing.B) {
- bu := event.To(ctx)
- for i := 0; i < b.N; i++ {
- bu.Clone().Name("foo").Metric(c.Record(1))
- }
- })
- })
- }
-}
diff --git a/event/common.go b/event/common.go
index 4eb9ea0..b6876e3 100644
--- a/event/common.go
+++ b/event/common.go
@@ -4,6 +4,12 @@
package event
+import (
+ "context"
+ "fmt"
+ "sync/atomic"
+)
+
const (
MetricKey = interfaceKey("metric")
MetricVal = valueKey("metricValue")
@@ -17,7 +23,8 @@
LogKind
MetricKind
- TraceKind
+ StartKind
+ EndKind
)
type (
@@ -25,13 +32,60 @@
interfaceKey string
)
-func (k valueKey) Of(v Value) Label {
- return Label{Name: string(k), Value: v}
+func Log(ctx context.Context, msg string, labels ...Label) {
+ ev := New(ctx, LogKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Message = msg
+ ev.Deliver()
+ }
}
-func (k valueKey) Matches(ev *Event) bool {
- _, found := k.Find(ev)
- return found
+func Logf(ctx context.Context, msg string, args ...interface{}) {
+ ev := New(ctx, LogKind)
+ if ev != nil {
+ ev.Message = fmt.Sprintf(msg, args...)
+ ev.Deliver()
+ }
+}
+
+func Annotate(ctx context.Context, labels ...Label) {
+ ev := New(ctx, 0)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Deliver()
+ }
+}
+
+func Start(ctx context.Context, name string, labels ...Label) context.Context {
+ ev := New(ctx, StartKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Name = name
+ ev.TraceID = atomic.AddUint64(&ev.target.exporter.lastEvent, 1)
+ ev.target.exporter.prepare(ev)
+ ev.ctx = newContext(ev.ctx, ev.target.exporter, ev.TraceID, ev.At)
+ ctx = ev.Deliver()
+ }
+ return ctx
+}
+
+func End(ctx context.Context, labels ...Label) {
+ ev := New(ctx, EndKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, labels...)
+ ev.target.exporter.prepare(ev)
+ // this was an end event, do we need to send a duration?
+ if v, ok := DurationMetric.Find(ev); ok {
+ //TODO: do we want the rest of the values from the end event?
+ v.(*Duration).Record(ctx, ev.At.Sub(ev.target.startTime))
+ }
+ ev.Deliver()
+ }
+}
+
+func (k valueKey) Of(v Value) Label {
+ return Label{Name: string(k), Value: v}
}
func (k valueKey) Find(ev *Event) (Value, bool) {
@@ -42,11 +96,6 @@
return Label{Name: string(k), Value: ValueOf(v)}
}
-func (k interfaceKey) Matches(ev *Event) bool {
- _, found := k.Find(ev)
- return found
-}
-
func (k interfaceKey) Find(ev *Event) (interface{}, bool) {
v, ok := lookupValue(string(k), ev.Labels)
if !ok {
diff --git a/event/common_test.go b/event/common_test.go
index d104024..852da43 100644
--- a/event/common_test.go
+++ b/event/common_test.go
@@ -11,6 +11,7 @@
"golang.org/x/exp/event"
"golang.org/x/exp/event/eventtest"
+ "golang.org/x/exp/event/keys"
)
func TestCommon(t *testing.T) {
@@ -20,27 +21,32 @@
const simple = "simple message"
const trace = "a trace"
- event.To(ctx).Log(simple)
+ event.Log(ctx, simple)
checkMessage(t, h, "Log", simple)
checkName(t, h, "Log", "")
h.Reset()
- event.To(ctx).Metric(m.Record(3))
+ event.Logf(ctx, "logf %s message", "to")
+ checkMessage(t, h, "Logf", "logf to message")
+ checkName(t, h, "Logf", "")
+ h.Reset()
+
+ m.Record(ctx, 3)
checkMessage(t, h, "Metric", "")
checkName(t, h, "Metric", "")
h.Reset()
- event.To(ctx).Annotate()
+ event.Annotate(ctx, keys.String("").Of(""))
checkMessage(t, h, "Annotate", "")
checkName(t, h, "Annotate", "")
h.Reset()
- _, eb := event.To(ctx).Start(trace)
+ ctx = event.Start(ctx, trace)
checkMessage(t, h, "Start", "")
checkName(t, h, "Start", trace)
h.Reset()
- eb.End()
+ event.End(ctx)
checkMessage(t, h, "End", "")
checkName(t, h, "End", "")
}
diff --git a/event/disabled.go b/event/disabled.go
index 77cbe75..20019ca 100644
--- a/event/disabled.go
+++ b/event/disabled.go
@@ -20,8 +20,8 @@
func To(ctx context.Context) Builder { return Builder{} }
func (b Builder) Clone() Builder { return b }
-func (b Builder) With(label Label) Builder { return b }
-func (b Builder) WithAll(labels ...Label) Builder { return b }
+func (b Builder) Label(label Label) Builder { return b }
+func (b Builder) Labels(labels ...Label) Builder { return b }
func (b Builder) Log(message string) {}
func (b Builder) Logf(template string, args ...interface{}) {}
func (b Builder) Metric() {}
@@ -35,6 +35,6 @@
func newContext(ctx context.Context, exporter *Exporter, parent uint64) context.Context {
return ctx
}
-func FromContext(ctx context.Context) (*Exporter, uint64) { return nil, 0 }
+func FromContext(ctx context.Context) *Target { return nil }
func setDefaultExporter(e *Exporter) {}
diff --git a/event/event.go b/event/event.go
index 369bcc5..b0718ee 100644
--- a/event/event.go
+++ b/event/event.go
@@ -6,6 +6,7 @@
import (
"context"
+ "sync"
"time"
)
@@ -21,27 +22,26 @@
Name string
Error error
Labels []Label
+
+ ctx context.Context
+ target *target
+ labels [preallocateLabels]Label
}
// Handler is a the type for something that handles events as they occur.
type Handler interface {
- // Log indicates a logging event.
- Log(context.Context, *Event)
- // Metric indicates a metric record event.
- Metric(context.Context, *Event)
- // Annotate reports label values at a point in time.
- Annotate(context.Context, *Event)
- // Start indicates a trace start event.
- Start(context.Context, *Event) context.Context
- // End indicates a trace end event.
- End(context.Context, *Event)
+ // Event is called with each event.
+ Event(context.Context, *Event) context.Context
}
-// Matcher is the interface to something that can check if an event matches
-// a condition.
-type Matcher interface {
- Matches(ev *Event) bool
-}
+// preallocateLabels controls the space reserved for labels in a builder.
+// Storing the first few labels directly in builders can avoid an allocation at
+// all for the very common cases of simple events. The length needs to be large
+// enough to cope with the majority of events but no so large as to cause undue
+// stack pressure.
+const preallocateLabels = 6
+
+var eventPool = sync.Pool{New: func() interface{} { return &Event{} }}
// WithExporter returns a context with the exporter attached.
// The exporter is called synchronously from the event call site, so it should
@@ -56,23 +56,58 @@
setDefaultExporter(e)
}
-// Is uses the matcher to check if the event is a match.
-// This is a simple helper to convert code like
-// event.End.Matches(ev)
-// to the more readable
-// ev.Is(event.End)
-func (ev *Event) Is(m Matcher) bool {
- return m.Matches(ev)
+// New prepares a new event.
+// This is intended to avoid allocations in the steady state case, to do this
+// it uses a pool of events.
+// Events are returned to the pool when Deliver is called. Failure to call
+// Deliver will exhaust the pool and cause allocations.
+// It returns nil if there is no active exporter for this kind of event.
+func New(ctx context.Context, kind Kind) *Event {
+ var t *target
+ if v, ok := ctx.Value(contextKey).(*target); ok {
+ t = v
+ } else {
+ t = getDefaultTarget()
+ }
+ if t == nil {
+ return nil
+ }
+ //TODO: we can change this to a much faster test
+ switch kind {
+ case LogKind:
+ if !t.exporter.loggingEnabled() {
+ return nil
+ }
+ case MetricKind:
+ if !t.exporter.metricsEnabled() {
+ return nil
+ }
+ case StartKind, EndKind:
+ if !t.exporter.tracingEnabled() {
+ return nil
+ }
+ }
+ ev := eventPool.Get().(*Event)
+ *ev = Event{
+ ctx: ctx,
+ target: t,
+ Kind: kind,
+ Parent: t.parent,
+ }
+ ev.Labels = ev.labels[:0]
+ return ev
}
-// NopHandler is a handler that does nothing. It can be used for tests, or
-// embedded in a struct to avoid having to implement all the Handler methods.
-type NopHandler struct{}
-
-func (NopHandler) Log(context.Context, *Event) {}
-func (NopHandler) Metric(context.Context, *Event) {}
-func (NopHandler) Annotate(context.Context, *Event) {}
-func (NopHandler) End(context.Context, *Event) {}
-func (NopHandler) Start(ctx context.Context, _ *Event) context.Context {
+// Deliver the event to the exporter that was found in New.
+// This also returns the event to the pool, it is an error to do anything
+// with the event after it is delivered.
+func (ev *Event) Deliver() context.Context {
+ // get the event ready to send
+ ev.target.exporter.prepare(ev)
+ // now hold the lock while we deliver the event
+ ev.target.exporter.mu.Lock()
+ defer ev.target.exporter.mu.Unlock()
+ ctx := ev.target.exporter.handler.Event(ev.ctx, ev)
+ eventPool.Put(ev)
return ctx
}
diff --git a/event/event_test.go b/event/event_test.go
index fe4501a..857c6c3 100644
--- a/event/event_test.go
+++ b/event/event_test.go
@@ -8,6 +8,7 @@
import (
"context"
+ "fmt"
"os"
"strings"
"testing"
@@ -36,25 +37,25 @@
expect string
}{{
name: "simple",
- events: func(ctx context.Context) { event.To(ctx).Log("a message") },
+ events: func(ctx context.Context) { event.Log(ctx, "a message") },
expect: `time="2020/03/05 14:27:48" msg="a message"
`}, {
name: "log 1",
- events: func(ctx context.Context) { event.To(ctx).With(l1).Log("a message") },
+ events: func(ctx context.Context) { event.Log(ctx, "a message", l1) },
expect: `time="2020/03/05 14:27:48" l1=1 msg="a message"`,
}, {
name: "log 2",
- events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).Log("a message") },
+ events: func(ctx context.Context) { event.Log(ctx, "a message", l1, l2) },
expect: `time="2020/03/05 14:27:48" l1=1 l2=2 msg="a message"`,
}, {
name: "log 3",
- events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).With(l3).Log("a message") },
+ events: func(ctx context.Context) { event.Log(ctx, "a message", l1, l2, l3) },
expect: `time="2020/03/05 14:27:48" l1=1 l2=2 l3=3 msg="a message"`,
}, {
name: "span",
events: func(ctx context.Context) {
- ctx, eb := event.To(ctx).Start("span")
- eb.End()
+ ctx = event.Start(ctx, "span")
+ event.End(ctx)
},
expect: `
time="2020/03/05 14:27:48" trace=1 name=span
@@ -62,11 +63,11 @@
`}, {
name: "span nested",
events: func(ctx context.Context) {
- ctx, eb := event.To(ctx).Start("parent")
- defer eb.End()
- child, eb2 := event.To(ctx).Start("child")
- defer eb2.End()
- event.To(child).Log("message")
+ ctx = event.Start(ctx, "parent")
+ defer event.End(ctx)
+ child := event.Start(ctx, "child")
+ defer event.End(child)
+ event.Log(child, "message")
},
expect: `
time="2020/03/05 14:27:48" trace=1 name=parent
@@ -76,32 +77,37 @@
time="2020/03/05 14:27:52" parent=1 end
`}, {
name: "counter",
- events: func(ctx context.Context) { event.To(ctx).With(l1).Metric(counter.Record(2)) },
- expect: `time="2020/03/05 14:27:48" in="golang.org/x/exp/event_test" l1=1 metricValue=2 metric="Metric(\"golang.org/x/exp/event_test/hits\")"`,
+ events: func(ctx context.Context) { counter.Record(ctx, 2, l1) },
+ expect: `time="2020/03/05 14:27:48" metricValue=2 metric="Metric(\"golang.org/x/exp/event_test/hits\")" l1=1`,
}, {
name: "gauge",
- events: func(ctx context.Context) { event.To(ctx).With(l1).Metric(gauge.Record(98.6)) },
- expect: `time="2020/03/05 14:27:48" in="golang.org/x/exp/event_test" l1=1 metricValue=98.6 metric="Metric(\"golang.org/x/exp/event_test/temperature\")"`,
+ events: func(ctx context.Context) { gauge.Record(ctx, 98.6, l1) },
+ expect: `time="2020/03/05 14:27:48" metricValue=98.6 metric="Metric(\"golang.org/x/exp/event_test/temperature\")" l1=1`,
}, {
name: "duration",
events: func(ctx context.Context) {
- event.To(ctx).With(l1).With(l2).Metric(latency.Record(3 * time.Second))
+ latency.Record(ctx, 3*time.Second, l1, l2)
},
- expect: `time="2020/03/05 14:27:48" in="golang.org/x/exp/event_test" l1=1 l2=2 metricValue=3s metric="Metric(\"golang.org/x/exp/event_test/latency\")"`,
+ expect: `time="2020/03/05 14:27:48" metricValue=3s metric="Metric(\"golang.org/x/exp/event_test/latency\")" l1=1 l2=2`,
}, {
name: "annotate",
- events: func(ctx context.Context) { event.To(ctx).With(l1).Annotate() },
+ events: func(ctx context.Context) { event.Annotate(ctx, l1) },
expect: `time="2020/03/05 14:27:48" l1=1`,
}, {
name: "annotate 2",
- events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).Annotate() },
+ events: func(ctx context.Context) { event.Annotate(ctx, l1, l2) },
expect: `time="2020/03/05 14:27:48" l1=1 l2=2`,
}, {
name: "multiple events",
events: func(ctx context.Context) {
- b := event.To(ctx)
- b.Clone().With(keys.Int("myInt").Of(6)).Log("my event")
- b.With(keys.String("myString").Of("some string value")).Log("string event")
+ /*TODO: this is supposed to be using a cached target
+ t := event.To(ctx)
+ p := event.Prototype{}.As(event.LogKind)
+ t.With(p).Int("myInt", 6).Message("my event").Send()
+ t.With(p).String("myString", "some string value").Message("string event").Send()
+ */
+ event.Log(ctx, "my event", keys.Int("myInt").Of(6))
+ event.Log(ctx, "string event", keys.String("myString").Of("some string value"))
},
expect: `
time="2020/03/05 14:27:48" myInt=6 msg="my event"
@@ -120,8 +126,8 @@
func ExampleLog() {
ctx := event.WithExporter(context.Background(), event.NewExporter(logfmt.NewHandler(os.Stdout), eventtest.ExporterOptions()))
- event.To(ctx).With(keys.Int("myInt").Of(6)).Log("my event")
- event.To(ctx).With(keys.String("myString").Of("some string value")).Log("error event")
+ event.Log(ctx, "my event", keys.Int("myInt").Of(6))
+ event.Log(ctx, "error event", keys.String("myString").Of("some string value"))
// Output:
// time="2020/03/05 14:27:48" myInt=6 msg="my event"
// time="2020/03/05 14:27:49" myString="some string value" msg="error event"
@@ -134,3 +140,105 @@
func TestLogEvent(t *testing.T) {
eventtest.TestBenchmark(t, eventPrint, eventLog, eventtest.LogfmtOutput)
}
+
+func TestTraceBuilder(t *testing.T) {
+ // Verify that the context returned from the handler is also returned from Start,
+ // and is the context passed to End.
+ ctx := event.WithExporter(context.Background(), event.NewExporter(&testTraceHandler{t: t}, eventtest.ExporterOptions()))
+ ctx = event.Start(ctx, "s")
+ val := ctx.Value("x")
+ if val != 1 {
+ t.Fatal("context not returned from Start")
+ }
+ event.End(ctx)
+}
+
+type testTraceHandler struct {
+ t *testing.T
+}
+
+func (t *testTraceHandler) Event(ctx context.Context, ev *event.Event) context.Context {
+ switch ev.Kind {
+ case event.StartKind:
+ return context.WithValue(ctx, "x", 1)
+ case event.EndKind:
+ val := ctx.Value("x")
+ if val != 1 {
+ t.t.Fatal("Start context not passed to End")
+ }
+ return ctx
+ default:
+ return ctx
+ }
+}
+
+func TestTraceDuration(t *testing.T) {
+ // Verify that a trace can can emit a latency metric.
+ dur := event.NewDuration("test", "")
+ want := time.Second
+
+ check := func(t *testing.T, h *testTraceDurationHandler) {
+ if !h.got.HasValue() {
+ t.Fatal("no metric value")
+ }
+ got := h.got.Duration()
+ if got != want {
+ t.Fatalf("got %s, want %s", got, want)
+ }
+ }
+
+ t.Run("returned builder", func(t *testing.T) {
+ h := &testTraceDurationHandler{}
+ ctx := event.WithExporter(context.Background(), event.NewExporter(h, eventtest.ExporterOptions()))
+ ctx = event.Start(ctx, "s")
+ time.Sleep(want)
+ event.End(ctx, event.DurationMetric.Of(dur))
+ check(t, h)
+ })
+ //TODO: come back and fix this
+ t.Run("separate builder", func(t *testing.T) {
+ h := &testTraceDurationHandler{}
+ ctx := event.WithExporter(context.Background(), event.NewExporter(h, eventtest.ExporterOptions()))
+ ctx = event.Start(ctx, "s")
+ time.Sleep(want)
+ event.End(ctx, event.DurationMetric.Of(dur))
+ check(t, h)
+ })
+}
+
+type testTraceDurationHandler struct {
+ got event.Value
+}
+
+func (t *testTraceDurationHandler) Event(ctx context.Context, ev *event.Event) context.Context {
+ if ev.Kind == event.MetricKind {
+ t.got, _ = event.MetricVal.Find(ev)
+ }
+ return ctx
+}
+
+func BenchmarkBuildContext(b *testing.B) {
+ // How long does it take to deliver an event from a nested context?
+ c := event.NewCounter("c", "")
+ for _, depth := range []int{1, 5, 7, 10} {
+ b.Run(fmt.Sprintf("depth %d", depth), func(b *testing.B) {
+ ctx := event.WithExporter(context.Background(), event.NewExporter(nopHandler{}, eventtest.ExporterOptions()))
+ for i := 0; i < depth; i++ {
+ ctx = context.WithValue(ctx, i, i)
+ }
+ b.Run("direct", func(b *testing.B) {
+ for i := 0; i < b.N; i++ {
+ c.Record(ctx, 1)
+ }
+ })
+ /*TODO: work out how we do cached labels
+ b.Run("cloned", func(b *testing.B) {
+ bu := event.To(ctx)
+ for i := 0; i < b.N; i++ {
+ c.RecordTB(bu, 1).Name("foo").Send()
+ }
+ })
+ */
+ })
+ }
+}
diff --git a/event/eventtest/capture.go b/event/eventtest/capture.go
index 12a4615..9510b3e 100644
--- a/event/eventtest/capture.go
+++ b/event/eventtest/capture.go
@@ -10,40 +10,20 @@
Got []event.Event
}
-func (h *CaptureHandler) Log(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *CaptureHandler) Metric(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *CaptureHandler) Annotate(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *CaptureHandler) Start(ctx context.Context, ev *event.Event) context.Context {
- h.event(ctx, ev)
+func (h *CaptureHandler) Event(ctx context.Context, ev *event.Event) context.Context {
+ h.Got = append(h.Got, *ev)
+ got := &h.Got[len(h.Got)-1]
+ got.Labels = make([]event.Label, len(ev.Labels))
+ copy(got.Labels, ev.Labels)
return ctx
}
-func (h *CaptureHandler) End(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
func (h *CaptureHandler) Reset() {
if len(h.Got) > 0 {
h.Got = h.Got[:0]
}
}
-func (h *CaptureHandler) event(ctx context.Context, ev *event.Event) {
- h.Got = append(h.Got, *ev)
- got := &h.Got[len(h.Got)-1]
- got.Labels = make([]event.Label, len(ev.Labels))
- copy(got.Labels, ev.Labels)
-}
-
func NewCapture() (context.Context, *CaptureHandler) {
h := &CaptureHandler{}
ctx := event.WithExporter(context.Background(), event.NewExporter(h, ExporterOptions()))
diff --git a/event/eventtest/eventtest.go b/event/eventtest/eventtest.go
index 8c1cdce..dd55a43 100644
--- a/event/eventtest/eventtest.go
+++ b/event/eventtest/eventtest.go
@@ -15,6 +15,8 @@
"testing"
"time"
+ "github.com/google/go-cmp/cmp"
+ "github.com/google/go-cmp/cmp/cmpopts"
"golang.org/x/exp/event"
"golang.org/x/exp/event/adapter/logfmt"
)
@@ -30,31 +32,11 @@
printer logfmt.Printer
}
-func (h *testHandler) Log(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *testHandler) Metric(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *testHandler) Annotate(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *testHandler) Start(ctx context.Context, ev *event.Event) context.Context {
- h.event(ctx, ev)
- return ctx
-}
-
-func (h *testHandler) End(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *testHandler) event(ctx context.Context, ev *event.Event) {
+func (h *testHandler) Event(ctx context.Context, ev *event.Event) context.Context {
//TODO: choose between stdout and stderr based on the event
//TODO: decide if we should be calling h.tb.Fail()
h.printer.Event(os.Stdout, ev)
+ return ctx
}
var InitialTime = func() time.Time {
@@ -72,3 +54,7 @@
},
}
}
+
+func CmpOption() cmp.Option {
+ return cmpopts.IgnoreFields(event.Event{}, "At", "ctx", "target", "labels")
+}
diff --git a/event/export.go b/event/export.go
index eee6a92..abfe673 100644
--- a/event/export.go
+++ b/event/export.go
@@ -16,12 +16,20 @@
// Exporter synchronizes the delivery of events to handlers.
type Exporter struct {
- opts ExporterOptions
+ lastEvent uint64 // accessed using atomic, must be 64 bit aligned
+ opts ExporterOptions
- mu sync.Mutex
- handler Handler
- lastEvent uint64
- sources sources
+ mu sync.Mutex
+ handler Handler
+ sources sources
+}
+
+// target is a bound exporter.
+// Normally you get a target by looking in the context using To.
+type target struct {
+ exporter *Exporter
+ parent uint64
+ startTime time.Time // for trace latency
}
type ExporterOptions struct {
@@ -44,16 +52,8 @@
var contextKey interface{} = contextKeyType{}
-// contextValue is stored by value in the context to track the exporter and
-// current parent event.
-type contextValue struct {
- exporter *Exporter
- parent uint64
- startTime time.Time // for trace latency
-}
-
var (
- defaultExporter unsafe.Pointer
+ defaultTarget unsafe.Pointer
)
// NewExporter creates an Exporter using the supplied handler and options.
@@ -76,32 +76,27 @@
}
func setDefaultExporter(e *Exporter) {
- atomic.StorePointer(&defaultExporter, unsafe.Pointer(e))
+ atomic.StorePointer(&defaultTarget, unsafe.Pointer(&target{exporter: e}))
}
-func getDefaultExporter() *Exporter {
- return (*Exporter)(atomic.LoadPointer(&defaultExporter))
+func getDefaultTarget() *target {
+ return (*target)(atomic.LoadPointer(&defaultTarget))
}
-func newContext(ctx context.Context, exporter *Exporter, parent uint64, t time.Time) context.Context {
- return context.WithValue(ctx, contextKey, contextValue{exporter: exporter, parent: parent, startTime: t})
-}
-
-// FromContext returns the exporter, parentID and parent start time for the supplied context.
-func FromContext(ctx context.Context) (*Exporter, uint64, time.Time) {
- if v, ok := ctx.Value(contextKey).(contextValue); ok {
- return v.exporter, v.parent, v.startTime
+func newContext(ctx context.Context, exporter *Exporter, parent uint64, start time.Time) context.Context {
+ var t *target
+ if exporter != nil {
+ t = &target{exporter: exporter, parent: parent, startTime: start}
}
- return getDefaultExporter(), 0, time.Time{}
+ return context.WithValue(ctx, contextKey, t)
}
// prepare events before delivering to the underlying handler.
-// The event will be assigned a new ID.
+// it is safe to call this more than once (trace events have to call it early)
// If the event does not have a timestamp, and the exporter has a Now function
// then the timestamp will be updated.
// If automatic namespaces are enabled and the event doesn't have a namespace,
// one based on the caller's import path will be provided.
-// prepare must be called with the export mutex held.
func (e *Exporter) prepare(ev *Event) {
if e.opts.Now != nil && ev.At.IsZero() {
ev.At = e.opts.Now()
diff --git a/event/label.go b/event/label.go
index 71c65fa..1593cf5 100644
--- a/event/label.go
+++ b/event/label.go
@@ -166,7 +166,7 @@
hdr := (*reflect.SliceHeader)(unsafe.Pointer(&buf))
hdr.Data = uintptr(bp)
hdr.Len = int(v.packed)
- hdr.Cap = hdr.Len // TODO: is this safe?
+ hdr.Cap = hdr.Len
return buf
}
diff --git a/event/metric.go b/event/metric.go
index a2611ac..143a5a3 100644
--- a/event/metric.go
+++ b/event/metric.go
@@ -5,6 +5,7 @@
package event
import (
+ "context"
"fmt"
"time"
)
@@ -37,8 +38,7 @@
panic("name cannot be empty")
}
return &MetricDescriptor{
- name: name,
- // TODO: use the global callers, will also need a lock
+ name: name,
namespace: scanStack().Space,
description: description,
}
@@ -84,8 +84,13 @@
// Record converts its argument into a Value and returns a MetricValue with the
// receiver and the value. It is intended to be used as an argument to
// Builder.Metric.
-func (c *Counter) Record(v uint64) MetricValue {
- return MetricValue{c, Uint64Of(v)}
+func (c *Counter) Record(ctx context.Context, v uint64, labels ...Label) {
+ ev := New(ctx, MetricKind)
+ if ev != nil {
+ record(ev, c, Uint64Of(v))
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Deliver()
+ }
}
// A FloatGauge records a single floating-point value that may go up or down.
@@ -107,8 +112,13 @@
// Record converts its argument into a Value and returns a MetricValue with the
// receiver and the value. It is intended to be used as an argument to
// Builder.Metric.
-func (g *FloatGauge) Record(v float64) MetricValue {
- return MetricValue{g, Float64Of(v)}
+func (g *FloatGauge) Record(ctx context.Context, v float64, labels ...Label) {
+ ev := New(ctx, MetricKind)
+ if ev != nil {
+ record(ev, g, Float64Of(v))
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Deliver()
+ }
}
// A Duration records a distribution of durations.
@@ -130,8 +140,13 @@
// Record converts its argument into a Value and returns a MetricValue with the
// receiver and the value. It is intended to be used as an argument to
// Builder.Metric.
-func (d *Duration) Record(v time.Duration) MetricValue {
- return MetricValue{d, DurationOf(v)}
+func (d *Duration) Record(ctx context.Context, v time.Duration, labels ...Label) {
+ ev := New(ctx, MetricKind)
+ if ev != nil {
+ record(ev, d, DurationOf(v))
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Deliver()
+ }
}
// An IntDistribution records a distribution of int64s.
@@ -152,6 +167,15 @@
// Record converts its argument into a Value and returns a MetricValue with the
// receiver and the value. It is intended to be used as an argument to
// Builder.Metric.
-func (d *IntDistribution) Record(v int64) MetricValue {
- return MetricValue{d, Int64Of(v)}
+func (d *IntDistribution) Record(ctx context.Context, v int64, labels ...Label) {
+ ev := New(ctx, MetricKind)
+ if ev != nil {
+ record(ev, d, Int64Of(v))
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Deliver()
+ }
+}
+
+func record(ev *Event, m Metric, v Value) {
+ ev.Labels = append(ev.Labels, MetricVal.Of(v), MetricKey.Of(ValueOf(m)))
}
diff --git a/event/namespace_test.go b/event/namespace_test.go
index d3789c9..abab523 100644
--- a/event/namespace_test.go
+++ b/event/namespace_test.go
@@ -17,7 +17,7 @@
func TestNamespace(t *testing.T) {
var h nsHandler
ctx := event.WithExporter(context.Background(), event.NewExporter(&h, &event.ExporterOptions{EnableNamespaces: true}))
- event.To(ctx).Log("msg")
+ event.Log(ctx, "msg")
if got, want := h.ns, thisImportPath; got != want {
t.Errorf("got namespace %q, want, %q", got, want)
}
@@ -27,31 +27,11 @@
ns string
}
-func (h *nsHandler) Log(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *nsHandler) Metric(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *nsHandler) Annotate(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *nsHandler) Start(ctx context.Context, ev *event.Event) context.Context {
- h.event(ctx, ev)
+func (h *nsHandler) Event(ctx context.Context, ev *event.Event) context.Context {
+ h.ns = ev.Namespace
return ctx
}
-func (h *nsHandler) End(ctx context.Context, ev *event.Event) {
- h.event(ctx, ev)
-}
-
-func (h *nsHandler) event(event context.Context, e *event.Event) {
- h.ns = e.Namespace
-}
-
func BenchmarkRuntimeCallers(b *testing.B) {
for i := 0; i < b.N; i++ {
var pcs [1]uintptr
diff --git a/event/otel/trace.go b/event/otel/trace.go
index 14f8533..2c43edf 100644
--- a/event/otel/trace.go
+++ b/event/otel/trace.go
@@ -21,21 +21,22 @@
type spanKey struct{}
-func (t *TraceHandler) Log(ctx context.Context, ev *event.Event) {}
-func (t *TraceHandler) Annotate(ctx context.Context, ev *event.Event) {}
-func (t *TraceHandler) Metric(ctx context.Context, ev *event.Event) {}
-func (t *TraceHandler) Start(ctx context.Context, ev *event.Event) context.Context {
- opts := labelsToSpanOptions(ev.Labels)
- octx, span := t.tracer.Start(ctx, ev.Name, opts...)
- return context.WithValue(octx, spanKey{}, span)
-}
-
-func (t *TraceHandler) End(ctx context.Context, e *event.Event) {
- span, ok := ctx.Value(spanKey{}).(trace.Span)
- if !ok {
- panic("End called on context with no span")
+func (t *TraceHandler) Event(ctx context.Context, ev *event.Event) context.Context {
+ switch ev.Kind {
+ case event.StartKind:
+ opts := labelsToSpanOptions(ev.Labels)
+ octx, span := t.tracer.Start(ctx, ev.Name, opts...)
+ return context.WithValue(octx, spanKey{}, span)
+ case event.EndKind:
+ span, ok := ctx.Value(spanKey{}).(trace.Span)
+ if !ok {
+ panic("End called on context with no span")
+ }
+ span.End()
+ return ctx
+ default:
+ return ctx
}
- span.End()
}
func labelsToSpanOptions(ls []event.Label) []trace.SpanOption {
diff --git a/event/otel/trace_test.go b/event/otel/trace_test.go
index c29f392..787b1ed 100644
--- a/event/otel/trace_test.go
+++ b/event/otel/trace_test.go
@@ -95,9 +95,8 @@
ctx, span = s.tracer.Start(ctx, s.name)
defer span.End()
} else {
- var eb event.Builder
- ctx, eb = event.To(ctx).Start(s.name)
- defer eb.End()
+ ctx = event.Start(ctx, s.name)
+ defer event.End(ctx)
}
for _, c := range s.children {
c.apply(ctx)
diff --git a/event/severity/severity.go b/event/severity/severity.go
index 66892b5..64e1441 100644
--- a/event/severity/severity.go
+++ b/event/severity/severity.go
@@ -4,7 +4,12 @@
package severity
-import "golang.org/x/exp/event"
+import (
+ "context"
+ "fmt"
+
+ "golang.org/x/exp/event"
+)
// Level represents a severity level of an event.
// The basic severity levels are designed to match the levels used in open telemetry.
@@ -24,35 +29,20 @@
type Level uint64
const (
- TraceLevel = Level(1)
- DebugLevel = Level(5)
- InfoLevel = Level(9)
- WarningLevel = Level(13)
- ErrorLevel = Level(17)
- FatalLevel = Level(21)
- MaxLevel = Level(24)
+ Trace = Level(1)
+ Debug = Level(5)
+ Info = Level(9)
+ Warning = Level(13)
+ Error = Level(17)
+ Fatal = Level(21)
+ Max = Level(24)
)
const Key = "level"
-var (
- // Trace is an event.Label for trace level events.
- Trace = Of(TraceLevel)
- // Debug is an event.Label for debug level events.
- Debug = Of(DebugLevel)
- // Info is an event.Label for info level events.
- Info = Of(InfoLevel)
- // Warning is an event.Label for warning level events.
- Warning = Of(WarningLevel)
- // Error is an event.Label for error level events.
- Error = Of(ErrorLevel)
- // Fatal is an event.Label for fatal level events.
- Fatal = Of(FatalLevel)
-)
-
-// Of creates a new Label with this key and the supplied value.
-func Of(v Level) event.Label {
- return event.Label{Name: Key, Value: event.ValueOf(v)}
+// Of creates a label for the level.
+func (l Level) Label() event.Label {
+ return event.Label{Name: Key, Value: event.ValueOf(l)}
}
// From can be used to get a value from a Label.
@@ -60,22 +50,41 @@
return t.Value.Interface().(Level)
}
+func (l Level) Log(ctx context.Context, msg string, labels ...event.Label) {
+ ev := event.New(ctx, event.LogKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, l.Label())
+ ev.Labels = append(ev.Labels, labels...)
+ ev.Message = msg
+ ev.Deliver()
+ }
+}
+
+func (l Level) Logf(ctx context.Context, msg string, args ...interface{}) {
+ ev := event.New(ctx, event.LogKind)
+ if ev != nil {
+ ev.Labels = append(ev.Labels, l.Label())
+ ev.Message = fmt.Sprintf(msg, args...)
+ ev.Deliver()
+ }
+}
+
func (l Level) Class() Level {
switch {
- case l > MaxLevel:
- return MaxLevel
- case l > FatalLevel:
- return FatalLevel
- case l > ErrorLevel:
- return ErrorLevel
- case l > WarningLevel:
- return WarningLevel
- case l > DebugLevel:
- return DebugLevel
- case l > InfoLevel:
- return InfoLevel
- case l > TraceLevel:
- return TraceLevel
+ case l > Max:
+ return Max
+ case l > Fatal:
+ return Fatal
+ case l > Error:
+ return Error
+ case l > Warning:
+ return Warning
+ case l > Debug:
+ return Debug
+ case l > Info:
+ return Info
+ case l > Trace:
+ return Trace
default:
return 0
}
@@ -86,58 +95,58 @@
case 0:
return "invalid"
- case TraceLevel:
+ case Trace:
return "trace"
- case TraceLevel + 1:
+ case Trace + 1:
return "trace2"
- case TraceLevel + 2:
+ case Trace + 2:
return "trace3"
- case TraceLevel + 3:
+ case Trace + 3:
return "trace4"
- case DebugLevel:
+ case Debug:
return "debug"
- case DebugLevel + 1:
+ case Debug + 1:
return "debug2"
- case DebugLevel + 2:
+ case Debug + 2:
return "debug3"
- case DebugLevel + 3:
+ case Debug + 3:
return "debug4"
- case InfoLevel:
+ case Info:
return "info"
- case InfoLevel + 1:
+ case Info + 1:
return "info2"
- case InfoLevel + 2:
+ case Info + 2:
return "info3"
- case InfoLevel + 3:
+ case Info + 3:
return "info4"
- case WarningLevel:
+ case Warning:
return "warning"
- case WarningLevel + 1:
+ case Warning + 1:
return "warning2"
- case WarningLevel + 2:
+ case Warning + 2:
return "warning3"
- case WarningLevel + 3:
+ case Warning + 3:
return "warning4"
- case ErrorLevel:
+ case Error:
return "error"
- case ErrorLevel + 1:
+ case Error + 1:
return "error2"
- case ErrorLevel + 2:
+ case Error + 2:
return "error3"
- case ErrorLevel + 3:
+ case Error + 3:
return "error4"
- case FatalLevel:
+ case Fatal:
return "fatal"
- case FatalLevel + 1:
+ case Fatal + 1:
return "fatal2"
- case FatalLevel + 2:
+ case Fatal + 2:
return "fatal3"
- case FatalLevel + 3:
+ case Fatal + 3:
return "fatal4"
default:
return "invalid"
diff --git a/event/severity/severity_test.go b/event/severity/severity_test.go
index f115052..8825f23 100644
--- a/event/severity/severity_test.go
+++ b/event/severity/severity_test.go
@@ -18,7 +18,6 @@
)
func TestPrint(t *testing.T) {
- //TODO: print the textual form of severity
ctx := context.Background()
for _, test := range []struct {
name string
@@ -26,11 +25,11 @@
expect string
}{{
name: "debug",
- events: func(ctx context.Context) { event.To(ctx).With(severity.Debug).Log("a message") },
+ events: func(ctx context.Context) { severity.Debug.Log(ctx, "a message") },
expect: `time="2020/03/05 14:27:48" level=debug msg="a message"`,
}, {
name: "info",
- events: func(ctx context.Context) { event.To(ctx).With(severity.Info).Log("a message") },
+ events: func(ctx context.Context) { severity.Info.Log(ctx, "a message") },
expect: `time="2020/03/05 14:27:48" level=info msg="a message"`},
} {
buf := &strings.Builder{}
diff --git a/jsonrpc2/conn.go b/jsonrpc2/conn.go
index cbc1558..1b26d3a 100644
--- a/jsonrpc2/conn.go
+++ b/jsonrpc2/conn.go
@@ -12,6 +12,7 @@
"sync/atomic"
"golang.org/x/exp/event"
+ "golang.org/x/exp/event/keys"
errors "golang.org/x/xerrors"
)
@@ -52,10 +53,10 @@
}
type AsyncCall struct {
- id ID
- response chan *Response // the channel a response will be delivered on
- resultBox chan asyncResult
- endBuilder event.Builder // close the tracing span when all processing for the message is complete
+ id ID
+ response chan *Response // the channel a response will be delivered on
+ resultBox chan asyncResult
+ ctx context.Context
}
type asyncResult struct {
@@ -65,11 +66,10 @@
// incoming is used to track an incoming request as it is being handled
type incoming struct {
- request *Request // the request being processed
- baseCtx context.Context // a base context for the message processing
- endBuilder event.Builder // builder's End method called when all processing for the message is complete
- handleCtx context.Context // the context for handling the message, child of baseCtx
- cancel func() // a function that cancels the handling context
+ request *Request // the request being processed
+ baseCtx context.Context // a base context for the message processing
+ handleCtx context.Context // the context for handling the message, child of baseCtx
+ cancel func() // a function that cancels the handling context
}
// Bind returns the options unmodified.
@@ -124,12 +124,14 @@
if err != nil {
return errors.Errorf("marshaling notify parameters: %v", err)
}
- b := event.To(ctx).With(Method.Of(method))
- b.Clone().Metric(Started.Record(1))
- ctx, endBuilder := b.With(RPCDirection.Of(Outbound)).Start(method)
- err = c.write(ctx, notify)
- event.To(ctx).With(Error.Of(err)).Metric(Finished.Record(1))
- endBuilder.End()
+ ctx = event.Start(ctx, method, RPCDirection.Of(Outbound))
+ Started.Record(ctx, 1, Method.Of(method))
+ var errLabel event.Label
+ if err = c.write(ctx, notify); err != nil {
+ errLabel = keys.Value("error").Of(err)
+ }
+ Finished.Record(ctx, 1, errLabel)
+ event.End(ctx)
return err
}
@@ -150,10 +152,11 @@
result.resultBox <- asyncResult{err: errors.Errorf("marshaling call parameters: %w", err)}
return result
}
- b := event.To(ctx).With(Method.Of(method))
- b.Clone().Metric(Started.Record(1))
- ctx, endBuilder := b.Clone().With(RPCDirection.Of(Outbound)).With(RPCID.Of(fmt.Sprintf("%q", result.id))).Start(method)
- result.endBuilder = endBuilder
+ //TODO: rewrite this using the new target/prototype stuff
+ ctx = event.Start(ctx, method,
+ Method.Of(method), RPCDirection.Of(Outbound), RPCID.Of(fmt.Sprintf("%q", result.id)))
+ Started.Record(ctx, 1, Method.Of(method))
+ result.ctx = ctx
// We have to add ourselves to the pending map before we send, otherwise we
// are racing the response.
// rchan is buffered in case the response arrives without a listener.
@@ -191,7 +194,7 @@
// The response will be unmarshaled from JSON into the result.
func (a *AsyncCall) Await(ctx context.Context, result interface{}) error {
status := "NONE"
- defer a.endBuilder.With(StatusCode.Of(status)).End()
+ defer event.End(a.ctx, StatusCode.Of(status))
var r asyncResult
select {
case response := <-a.response:
@@ -292,14 +295,14 @@
request: msg,
}
// add a span to the context for this request
- b := event.To(ctx).With(Method.Of(msg.Method)).With(RPCDirection.Of(Inbound))
+ var idLabel event.Label
if msg.IsCall() {
- b = b.With(RPCID.Of(fmt.Sprintf("%q", msg.ID)))
+ idLabel = RPCID.Of(fmt.Sprintf("%q", msg.ID))
}
- entry.baseCtx, entry.endBuilder = b.Start(msg.Method)
- b = event.To(entry.baseCtx).With(Method.Of(msg.Method))
- b.Clone().Metric(Started.Record(1))
- b.Metric(ReceivedBytes.Record(n))
+ entry.baseCtx = event.Start(ctx, msg.Method,
+ Method.Of(msg.Method), RPCDirection.Of(Inbound), idLabel)
+ Started.Record(entry.baseCtx, 1, Method.Of(msg.Method))
+ ReceivedBytes.Record(entry.baseCtx, n, Method.Of(msg.Method))
// in theory notifications cannot be cancelled, but we build them a cancel context anyway
entry.handleCtx, entry.cancel = context.WithCancel(entry.baseCtx)
// if the request is a call, add it to the incoming map so it can be
@@ -412,7 +415,7 @@
if err := c.respond(entry, result, rerr); err != nil {
// no way to propagate this error
//TODO: should we do more than just log it?
- event.To(entry.baseCtx).With(Error.Of(err)).Log("jsonrpc2 message delivery failed")
+ event.Log(entry.baseCtx, "jsonrpc2 message delivery failed", keys.Value("error").Of(err))
}
}
@@ -458,7 +461,7 @@
entry.cancel = nil
}
// mark the entire request processing as done
- entry.endBuilder.With(StatusCode.Of(status)).End()
+ event.End(entry.baseCtx, StatusCode.Of(status))
return err
}
@@ -469,6 +472,6 @@
defer func() { c.writerBox <- writer }()
n, err := writer.Write(ctx, msg)
// TODO: get a method label in here somehow.
- event.To(ctx).Metric(SentBytes.Record(n))
+ SentBytes.Record(ctx, n)
return err
}
diff --git a/jsonrpc2/defs.go b/jsonrpc2/defs.go
index f40800d..802a205 100644
--- a/jsonrpc2/defs.go
+++ b/jsonrpc2/defs.go
@@ -13,7 +13,6 @@
Method = keys.String("method")
RPCID = keys.String("id")
RPCDirection = keys.String("direction")
- Error = keys.Value("error")
StatusCode = keys.String("status.code")
)
