diff options
author | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-16 17:35:35 +0000 |
---|---|---|
committer | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-16 17:35:35 +0000 |
commit | 331441e10889478d5a88eeda5d74057904e5e384 (patch) | |
tree | 0e63feed70b3e3fa3bf3096bb7985d4a80425cb3 /event | |
parent | Initial commit. (diff) | |
download | golang-golang-x-exp-331441e10889478d5a88eeda5d74057904e5e384.tar.xz golang-golang-x-exp-331441e10889478d5a88eeda5d74057904e5e384.zip |
Adding upstream version 0.0~git20231006.7918f67.upstream/0.0_git20231006.7918f67upstream
Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>
Diffstat (limited to 'event')
40 files changed, 4570 insertions, 0 deletions
diff --git a/event/adapter/gokit/bench_test.go b/event/adapter/gokit/bench_test.go new file mode 100644 index 0000000..2313abb --- /dev/null +++ b/event/adapter/gokit/bench_test.go @@ -0,0 +1,71 @@ +// 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. + +package gokit_test + +import ( + "context" + "fmt" + "io" + "testing" + + "github.com/go-kit/kit/log" + "golang.org/x/exp/event/adapter/logfmt" + "golang.org/x/exp/event/eventtest" +) + +var ( + gokitLog = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + gokitCtx(ctx).Log(eventtest.A.Name, a, "msg", eventtest.A.Msg) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + gokitCtx(ctx).Log(eventtest.B.Name, b, "msg", eventtest.B.Msg) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + gokitLogf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + gokitCtx(ctx).Log("msg", fmt.Sprintf(eventtest.A.Msgf, a)) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + gokitCtx(ctx).Log("msg", fmt.Sprintf(eventtest.B.Msgf, b)) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +type gokitKey struct{} + +func gokitCtx(ctx context.Context) log.Logger { + return ctx.Value(gokitKey{}).(log.Logger) +} + +func gokitPrint(w io.Writer) context.Context { + logger := log.NewLogfmtLogger(log.NewSyncWriter(w)) + now := eventtest.ExporterOptions().Now + logger = log.With(logger, "time", log.TimestampFormat(now, logfmt.TimeFormat), "level", "info") + return context.WithValue(context.Background(), gokitKey{}, logger) +} + +func BenchmarkGokitLogDiscard(b *testing.B) { + eventtest.RunBenchmark(b, gokitPrint(io.Discard), gokitLog) +} + +func BenchmarkGokitLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, gokitPrint(io.Discard), gokitLogf) +} + +func TestGokitLogfDiscard(t *testing.T) { + eventtest.TestBenchmark(t, gokitPrint, gokitLogf, eventtest.LogfOutput) +} +func TestLogGokit(t *testing.T) { + eventtest.TestBenchmark(t, gokitPrint, gokitLog, eventtest.LogfmtOutput) +} diff --git a/event/adapter/gokit/gokit.go b/event/adapter/gokit/gokit.go new file mode 100644 index 0000000..e532266 --- /dev/null +++ b/event/adapter/gokit/gokit.go @@ -0,0 +1,53 @@ +// Copyright 2021 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. + +// Package gokit provides a go-kit logger for events. +package gokit + +import ( + "context" + "fmt" + + "github.com/go-kit/kit/log" + "golang.org/x/exp/event" +) + +type logger struct { +} + +// NewLogger returns a logger. +func NewLogger() log.Logger { + return &logger{} +} + +// Log writes a structured log message. +// If the first argument is a context.Context, it is used +// to find the exporter to which to deliver the message. +// Otherwise, the default exporter is used. +func (l *logger) Log(keyvals ...interface{}) error { + ctx := context.Background() + if len(keyvals) > 0 { + if c, ok := keyvals[0].(context.Context); ok { + ctx = c + keyvals = keyvals[1:] + } + } + 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) + value := keyvals[i+1] + if key == "msg" || key == "message" { + msg = fmt.Sprint(value) + } else { + ev.Labels = append(ev.Labels, event.Value(key, value)) + } + } + ev.Labels = append(ev.Labels, event.String("msg", msg)) + ev.Deliver() + return nil +} diff --git a/event/adapter/gokit/gokit_test.go b/event/adapter/gokit/gokit_test.go new file mode 100644 index 0000000..29169f8 --- /dev/null +++ b/event/adapter/gokit/gokit_test.go @@ -0,0 +1,36 @@ +// Copyright 2021 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. + +//go:build !disable_events + +package gokit_test + +import ( + "testing" + + "github.com/google/go-cmp/cmp" + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/gokit" + "golang.org/x/exp/event/eventtest" +) + +func Test(t *testing.T) { + log := gokit.NewLogger() + ctx, h := eventtest.NewCapture() + log.Log(ctx, "msg", "mess", "level", 1, "name", "n/m", "traceID", 17, "resource", "R") + want := []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + event.Value("level", 1), + event.Value("name", "n/m"), + event.Value("traceID", 17), + event.Value("resource", "R"), + event.String("msg", "mess"), + }, + }} + if diff := cmp.Diff(want, h.Got, eventtest.CmpOptions()...); diff != "" { + t.Errorf("mismatch (-want, +got):\n%s", diff) + } +} diff --git a/event/adapter/logfmt/logfmt.go b/event/adapter/logfmt/logfmt.go new file mode 100644 index 0000000..5789e7a --- /dev/null +++ b/event/adapter/logfmt/logfmt.go @@ -0,0 +1,258 @@ +// Copyright 2019 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. + +package logfmt + +import ( + "bytes" + "context" + "fmt" + "io" + "strconv" + "time" + "unicode/utf8" + + "golang.org/x/exp/event" +) + +// TODO: some actual research into what this arbritray optimization number should be +const bufCap = 50 + +const TimeFormat = "2006/01/02 15:04:05" + +type Printer struct { + QuoteValues bool + SuppressNamespace bool + buf [bufCap]byte + needSep bool + w bytes.Buffer +} + +type Handler struct { + to io.Writer + Printer +} + +// NewHandler returns a handler that prints the events to the supplied writer. +// Each event is printed in logfmt format on a single line. +func NewHandler(to io.Writer) *Handler { + return &Handler{to: to} +} + +func (h *Handler) Event(ctx context.Context, ev *event.Event) context.Context { + h.Printer.Event(h.to, ev) + return ctx +} + +func (p *Printer) Event(w io.Writer, ev *event.Event) { + p.needSep = false + if !ev.At.IsZero() { + p.separator(w) + io.WriteString(w, `time="`) + p.time(w, ev.At) + io.WriteString(w, `"`) + } + + if !p.SuppressNamespace && ev.Source.Space != "" { + p.Label(w, event.String("in", ev.Source.Space)) + } + if ev.Source.Owner != "" { + p.Label(w, event.String("owner", ev.Source.Owner)) + } + if ev.Source.Name != "" { + p.Label(w, event.String("name", ev.Source.Name)) + } + + if ev.Parent != 0 { + p.separator(w) + io.WriteString(w, `parent=`) + w.Write(strconv.AppendUint(p.buf[:0], ev.Parent, 10)) + } + for _, l := range ev.Labels { + if l.Name == "" { + continue + } + p.Label(w, l) + } + + if ev.ID != 0 && ev.Kind == event.StartKind { + p.separator(w) + io.WriteString(w, `trace=`) + w.Write(strconv.AppendUint(p.buf[:0], ev.ID, 10)) + } + + if ev.Kind == event.EndKind { + p.separator(w) + io.WriteString(w, `end`) + } + + io.WriteString(w, "\n") +} + +func (p *Printer) separator(w io.Writer) { + if p.needSep { + io.WriteString(w, " ") + } + p.needSep = true +} + +func (p *Printer) Label(w io.Writer, l event.Label) { + if l.Name == "" { + return + } + p.separator(w) + p.Ident(w, l.Name) + if l.HasValue() { + io.WriteString(w, "=") + switch { + case l.IsString(): + p.string(w, l.String()) + case l.IsBytes(): + p.bytes(w, l.Bytes()) + case l.IsInt64(): + w.Write(strconv.AppendInt(p.buf[:0], l.Int64(), 10)) + case l.IsUint64(): + w.Write(strconv.AppendUint(p.buf[:0], l.Uint64(), 10)) + case l.IsFloat64(): + w.Write(strconv.AppendFloat(p.buf[:0], l.Float64(), 'g', -1, 64)) + case l.IsBool(): + if l.Bool() { + io.WriteString(w, "true") + } else { + io.WriteString(w, "false") + } + default: + v := l.Interface() + switch v := v.(type) { + case string: + p.string(w, v) + case fmt.Stringer: + p.string(w, v.String()) + default: + if p.w.Cap() == 0 { + // we rely on the inliner to cause this to not allocate + p.w = *bytes.NewBuffer(p.buf[:0]) + } + fmt.Fprint(&p.w, v) + b := p.w.Bytes() + p.w.Reset() + p.bytes(w, b) + } + } + } +} + +func (p *Printer) Ident(w io.Writer, s string) { + if !stringNeedQuote(s) { + io.WriteString(w, s) + return + } + p.quoteString(w, s) +} + +func (p *Printer) string(w io.Writer, s string) { + if p.QuoteValues || stringNeedQuote(s) { + p.quoteString(w, s) + } else { + io.WriteString(w, s) + } +} + +func (p *Printer) quoteString(w io.Writer, s string) { + io.WriteString(w, `"`) + written := 0 + for offset, r := range s { + q := quoteRune(r) + if len(q) == 0 { + continue + } + // write out any prefix + io.WriteString(w, s[written:offset]) + written = offset + utf8.RuneLen(r) + // and write out the quoted rune + io.WriteString(w, q) + } + io.WriteString(w, s[written:]) + io.WriteString(w, `"`) +} + +func (p *Printer) bytes(w io.Writer, buf []byte) { + if p.QuoteValues || stringNeedQuote(string(buf)) { + p.quoteBytes(w, buf) + } else { + w.Write(buf) + } +} + +// Bytes writes a byte array in string form to the printer. +func (p *Printer) quoteBytes(w io.Writer, buf []byte) { + io.WriteString(w, `"`) + written := 0 + for offset := 0; offset < len(buf); { + r, size := utf8.DecodeRune(buf[offset:]) + offset += size + q := quoteRune(r) + if len(q) == 0 { + continue + } + // write out any prefix + w.Write(buf[written : offset-size]) + written = offset + // and write out the quoted rune + io.WriteString(w, q) + } + w.Write(buf[written:]) + io.WriteString(w, `"`) +} + +// time writes a timstamp in the same format as +func (p *Printer) time(w io.Writer, t time.Time) { + year, month, day := t.Date() + hour, minute, second := t.Clock() + p.padInt(w, int64(year), 4) + io.WriteString(w, `/`) + p.padInt(w, int64(month), 2) + io.WriteString(w, `/`) + p.padInt(w, int64(day), 2) + io.WriteString(w, ` `) + p.padInt(w, int64(hour), 2) + io.WriteString(w, `:`) + p.padInt(w, int64(minute), 2) + io.WriteString(w, `:`) + p.padInt(w, int64(second), 2) +} + +func (p *Printer) padInt(w io.Writer, v int64, width int) { + b := strconv.AppendInt(p.buf[:0], int64(v), 10) + if len(b) < width { + io.WriteString(w, "0000"[:width-len(b)]) + } + w.Write(b) +} + +func stringNeedQuote(s string) bool { + if len(s) == 0 { + return true + } + for i := 0; i < len(s); i++ { + c := s[i] + if c >= utf8.RuneSelf || c == ' ' || c == '"' || c == '\n' || c == '\\' { + return true + } + } + return false +} + +func quoteRune(r rune) string { + switch r { + case '"': + return `\"` + case '\n': + return `\n` + case '\\': + return `\\` + default: + return `` + } +} diff --git a/event/adapter/logfmt/logfmt_test.go b/event/adapter/logfmt/logfmt_test.go new file mode 100644 index 0000000..90b0e6f --- /dev/null +++ b/event/adapter/logfmt/logfmt_test.go @@ -0,0 +1,198 @@ +// Copyright 2019 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. + +package logfmt_test + +import ( + "strings" + "testing" + "time" + + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/logfmt" +) + +func TestPrint(t *testing.T) { + var p logfmt.Printer + buf := &strings.Builder{} + // the exporter is not used, but we need it to build the events + at, _ := time.Parse(logfmt.TimeFormat, "2020/03/05 14:27:48") + for _, test := range []struct { + name string + event event.Event + expect string + }{{ + name: "empty", + event: event.Event{}, + expect: ``, + }, { + name: "span", + event: event.Event{ID: 34, Kind: event.StartKind}, + expect: `trace=34`, + }, { + name: "parent", + event: event.Event{Parent: 14}, + expect: `parent=14`, + }, { + name: "namespace", + event: event.Event{Source: event.Source{Space: "golang.org/x/exp/event"}}, + expect: `in=golang.org/x/exp/event`, + }, { + name: "at", + event: event.Event{At: at}, + expect: `time="2020/03/05 14:27:48"`, + }, { + name: "message", + event: event.Event{Labels: []event.Label{event.String("msg", "a message")}}, + expect: `msg="a message"`, + }, { + name: "end", + event: event.Event{Kind: event.EndKind}, + expect: `end`, + }, { + name: "string", + event: event.Event{ + Labels: []event.Label{ + event.String("v1", "text"), + event.String("v2", "text with quotes"), + event.String("empty", ""), + }, + }, + expect: `v1=text v2="text with quotes" empty=""`, + }, { + name: "int", + event: event.Event{ + Labels: []event.Label{ + event.Int64("value", 67), + }, + }, + expect: `value=67`, + }, { + name: "float", + event: event.Event{ + Labels: []event.Label{ + event.Float64("value", 263.2), + }, + }, + expect: `value=263.2`, + }, { + name: "bool", + event: event.Event{ + Labels: []event.Label{ + event.Bool("v1", true), + event.Bool("v2", false), + }, + }, + expect: `v1=true v2=false`, + }, { + name: "value", + event: event.Event{ + Labels: []event.Label{ + event.Value("v1", notString{"simple"}), + event.Value("v2", notString{"needs quoting"}), + }, + }, + expect: `v1=simple v2="needs quoting"`, + }, { + name: "empty label", + event: event.Event{ + Labels: []event.Label{ + event.Value("before", nil), + event.String("", "text"), + event.Value("after", nil), + }, + }, + expect: `before after`, + }, { + name: "quoted ident", + event: event.Event{ + Labels: []event.Label{ + event.String("name with space", "text"), + }, + }, + expect: `"name with space"=text`, + }, { + name: "quoting quote", + event: event.Event{Labels: []event.Label{event.String("msg", `with"middle`)}}, + expect: `msg="with\"middle"`, + }, { + name: "quoting newline", + event: event.Event{Labels: []event.Label{event.String("msg", "with\nmiddle")}}, + expect: `msg="with\nmiddle"`, + }, { + name: "quoting slash", + event: event.Event{Labels: []event.Label{event.String("msg", `with\middle`)}}, + expect: `msg="with\\middle"`, + }, { + name: "quoting bytes", + event: event.Event{ + Labels: []event.Label{ + event.Bytes("value", ([]byte)(`bytes "need" quote`)), + }, + }, + expect: `value="bytes \"need\" quote"`, + }} { + t.Run(test.name, func(t *testing.T) { + buf.Reset() + p.Event(buf, &test.event) + got := strings.TrimSpace(buf.String()) + if got != test.expect { + t.Errorf("got: \n%q\nexpect:\n%q\n", got, test.expect) + } + }) + } +} + +type notString struct { + value string +} + +func (v notString) String() string { return v.value } + +func TestPrinterFlags(t *testing.T) { + var reference logfmt.Printer + buf := &strings.Builder{} + // the exporter is not used, but we need it to build the events + for _, test := range []struct { + name string + printer logfmt.Printer + event event.Event + before string + after string + }{{ + name: "quote values", + printer: logfmt.Printer{QuoteValues: true}, + event: event.Event{ + Labels: []event.Label{ + event.String("value", "text"), + }, + }, + before: `value=text`, + after: `value="text"`, + }, { + name: "suppress namespace", + printer: logfmt.Printer{SuppressNamespace: true}, + event: event.Event{ + Source: event.Source{Space: "golang.org/x/exp/event"}, + Labels: []event.Label{event.String("msg", "some text")}, + }, + before: `in=golang.org/x/exp/event msg="some text"`, + after: `msg="some text"`, + }} { + t.Run(test.name, func(t *testing.T) { + buf.Reset() + reference.Event(buf, &test.event) + gotBefore := strings.TrimSpace(buf.String()) + buf.Reset() + test.printer.Event(buf, &test.event) + gotAfter := strings.TrimSpace(buf.String()) + if gotBefore != test.before { + t.Errorf("got: \n%q\nexpect:\n%q\n", gotBefore, test.before) + } + if gotAfter != test.after { + t.Errorf("got: \n%q\nexpect:\n%q\n", gotAfter, test.after) + } + }) + } +} diff --git a/event/adapter/logr/logr.go b/event/adapter/logr/logr.go new file mode 100644 index 0000000..0dcfa26 --- /dev/null +++ b/event/adapter/logr/logr.go @@ -0,0 +1,104 @@ +// Copyright 2021 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. + +// Package logr is a logr implementation that uses events. +package logr + +import ( + "context" + + "github.com/go-logr/logr" + "golang.org/x/exp/event" + "golang.org/x/exp/event/severity" +) + +type logSink struct { + ev *event.Event // cloned, never delivered + labels []event.Label + nameSep string + name string + verbosity int +} + +func NewLogger(ctx context.Context, nameSep string) logr.Logger { + return logr.New(&logSink{ + ev: event.New(ctx, event.LogKind), + nameSep: nameSep, + }) +} + +func (*logSink) Init(logr.RuntimeInfo) {} + +// WithName implements logr.LogSink.WithName. +func (l *logSink) WithName(name string) logr.LogSink { + l2 := *l + if l.name == "" { + l2.name = name + } else { + l2.name = l.name + l.nameSep + name + } + return &l2 +} + +// Enabled tests whether this LogSink is enabled at the specified V-level. +// For example, commandline flags might be used to set the logging +// verbosity and disable some info logs. +func (l *logSink) Enabled(level int) bool { + return true +} + +// Info implements logr.LogSink.Info. +func (l *logSink) Info(level int, msg string, keysAndValues ...interface{}) { + if l.ev == nil { + return + } + ev := l.ev.Clone() + ev.Labels = append(ev.Labels, convertVerbosity(level).Label()) + l.log(ev, msg, keysAndValues) +} + +// Error implements logr.LogSink.Error. +func (l *logSink) Error(err error, msg string, keysAndValues ...interface{}) { + if l.ev == nil { + return + } + ev := l.ev.Clone() + ev.Labels = append(ev.Labels, event.Value("error", err)) + l.log(ev, msg, keysAndValues) +} + +func (l *logSink) log(ev *event.Event, msg string, keysAndValues []interface{}) { + ev.Labels = append(ev.Labels) + 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.Labels = append(ev.Labels, + event.String("name", l.name), + event.String("msg", msg), + ) + ev.Deliver() +} + +// WithValues implements logr.LogSink.WithValues. +func (l *logSink) WithValues(keysAndValues ...interface{}) logr.LogSink { + l2 := *l + 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 +} + +func newLabel(key, value interface{}) event.Label { + return event.Value(key.(string), value) +} + +func convertVerbosity(v int) severity.Level { + //TODO: this needs to be more complicated, v decreases with increasing severity + return severity.Level(v) +} diff --git a/event/adapter/logr/logr_test.go b/event/adapter/logr/logr_test.go new file mode 100644 index 0000000..aaa877e --- /dev/null +++ b/event/adapter/logr/logr_test.go @@ -0,0 +1,38 @@ +// Copyright 2021 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. + +//go:build !disable_events + +package logr_test + +import ( + "testing" + + "github.com/google/go-cmp/cmp" + "golang.org/x/exp/event" + elogr "golang.org/x/exp/event/adapter/logr" + "golang.org/x/exp/event/eventtest" + "golang.org/x/exp/event/severity" +) + +func TestInfo(t *testing.T) { + ctx, th := eventtest.NewCapture() + log := elogr.NewLogger(ctx, "/").WithName("n").V(int(severity.Debug)) + log = log.WithName("m") + log.Info("mess", "traceID", 17, "resource", "R") + want := []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + severity.Debug.Label(), + event.Value("traceID", 17), + event.Value("resource", "R"), + event.String("name", "n/m"), + event.String("msg", "mess"), + }, + }} + if diff := cmp.Diff(want, th.Got, eventtest.CmpOptions()...); diff != "" { + t.Errorf("mismatch (-want, +got):\n%s", diff) + } +} diff --git a/event/adapter/logrus/bench_test.go b/event/adapter/logrus/bench_test.go new file mode 100644 index 0000000..da9f5d6 --- /dev/null +++ b/event/adapter/logrus/bench_test.go @@ -0,0 +1,87 @@ +// 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. + +package logrus_test + +import ( + "context" + "io" + "testing" + "time" + + "github.com/sirupsen/logrus" + "golang.org/x/exp/event/eventtest" +) + +var ( + logrusLog = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + logrusCtx(ctx).WithField(eventtest.A.Name, a).Info(eventtest.A.Msg) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + logrusCtx(ctx).WithField(eventtest.B.Name, b).Info(eventtest.B.Msg) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + + logrusLogf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + logrusCtx(ctx).Infof(eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + logrusCtx(ctx).Infof(eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +type logrusKey struct{} +type logrusTimeFormatter struct { + now func() time.Time + wrapped logrus.Formatter +} + +func (f *logrusTimeFormatter) Format(entry *logrus.Entry) ([]byte, error) { + entry.Time = f.now() + return f.wrapped.Format(entry) +} + +func logrusCtx(ctx context.Context) *logrus.Logger { + return ctx.Value(logrusKey{}).(*logrus.Logger) +} + +func logrusPrint(w io.Writer) context.Context { + logger := &logrus.Logger{ + Out: w, + Level: logrus.InfoLevel, + Formatter: &logrusTimeFormatter{ + now: eventtest.ExporterOptions().Now, + wrapped: &logrus.TextFormatter{ + FullTimestamp: true, + TimestampFormat: eventtest.TimeFormat, + DisableSorting: true, + DisableColors: true, + }, + }, + } + return context.WithValue(context.Background(), logrusKey{}, logger) +} + +func BenchmarkLogrusLogDiscard(b *testing.B) { + eventtest.RunBenchmark(b, logrusPrint(io.Discard), logrusLog) +} + +func BenchmarkLogrusLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, logrusPrint(io.Discard), logrusLogf) +} + +func TestLogrusf(t *testing.T) { + eventtest.TestBenchmark(t, logrusPrint, logrusLogf, eventtest.LogfOutput) +} diff --git a/event/adapter/logrus/logrus.go b/event/adapter/logrus/logrus.go new file mode 100644 index 0000000..ed2fa3b --- /dev/null +++ b/event/adapter/logrus/logrus.go @@ -0,0 +1,84 @@ +// Copyright 2021 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. + +//go:build !disable_events + +// Package logrus provides a logrus Formatter for events. +// To use for the global logger: +// +// logrus.SetFormatter(elogrus.NewFormatter(exporter)) +// logrus.SetOutput(io.Discard) +// +// and for a Logger instance: +// +// logger.SetFormatter(elogrus.NewFormatter(exporter)) +// logger.SetOutput(io.Discard) +// +// If you call elogging.SetExporter, then you can pass nil +// for the exporter above and it will use the global one. +package logrus + +import ( + "context" + + "github.com/sirupsen/logrus" + "golang.org/x/exp/event" + "golang.org/x/exp/event/severity" +) + +type formatter struct{} + +func NewFormatter() logrus.Formatter { + return &formatter{} +} + +var _ logrus.Formatter = (*formatter)(nil) + +// Format writes an entry to an event.Exporter. It always returns nil (see below). +// If e.Context is non-nil, Format gets the exporter from the context. Otherwise +// it uses the default exporter. +// +// Logrus first calls the Formatter to get a []byte, then writes that to the +// output. That doesn't work for events, so we subvert it by having the +// Formatter export the event (and thereby write it). That is why the logrus +// Output io.Writer should be set to io.Discard. +func (f *formatter) Format(e *logrus.Entry) ([]byte, error) { + ctx := e.Context + if ctx == nil { + ctx = context.Background() + } + ev := event.New(ctx, event.LogKind) + if ev == nil { + return nil, nil + } + ev.At = e.Time + ev.Labels = append(ev.Labels, convertLevel(e.Level).Label()) + for k, v := range e.Data { + ev.Labels = append(ev.Labels, event.Value(k, v)) + } + ev.Labels = append(ev.Labels, event.String("msg", e.Message)) + ev.Deliver() + return nil, nil +} + +func convertLevel(level logrus.Level) severity.Level { + switch level { + case logrus.PanicLevel: + return severity.Fatal + 1 + case logrus.FatalLevel: + return severity.Fatal + case logrus.ErrorLevel: + return severity.Error + case logrus.WarnLevel: + return severity.Warning + case logrus.InfoLevel: + return severity.Info + case logrus.DebugLevel: + return severity.Debug + case logrus.TraceLevel: + return severity.Trace + default: + return severity.Trace + } +} diff --git a/event/adapter/logrus/logrus_test.go b/event/adapter/logrus/logrus_test.go new file mode 100644 index 0000000..0404940 --- /dev/null +++ b/event/adapter/logrus/logrus_test.go @@ -0,0 +1,44 @@ +// Copyright 2021 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. + +//go:build !disable_events + +package logrus_test + +import ( + "io" + "testing" + + "github.com/google/go-cmp/cmp" + "github.com/sirupsen/logrus" + "golang.org/x/exp/event" + elogrus "golang.org/x/exp/event/adapter/logrus" + "golang.org/x/exp/event/eventtest" + "golang.org/x/exp/event/severity" +) + +func Test(t *testing.T) { + ctx, th := eventtest.NewCapture() + log := logrus.New() + log.SetFormatter(elogrus.NewFormatter()) + log.SetOutput(io.Discard) + // adding WithContext panics, because event.FromContext assumes + log.WithContext(ctx).WithField("traceID", 17).WithField("resource", "R").Info("mess") + + want := []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + severity.Info.Label(), + event.Value("traceID", 17), + event.Value("resource", "R"), + event.String("msg", "mess"), + }, + }} + // logrus fields are stored in a map, so we have to sort to overcome map + // iteration indeterminacy. + if diff := cmp.Diff(want, th.Got, eventtest.CmpOptions()...); diff != "" { + t.Errorf("mismatch (-want, +got):\n%s", diff) + } +} diff --git a/event/adapter/stdlib/bench_test.go b/event/adapter/stdlib/bench_test.go new file mode 100644 index 0000000..da5ddd1 --- /dev/null +++ b/event/adapter/stdlib/bench_test.go @@ -0,0 +1,126 @@ +// 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. + +package stdlib_test + +import ( + "context" + "fmt" + "io" + "log" + "testing" + + "golang.org/x/exp/event/eventtest" +) + +var ( + baseline = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { return ctx }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { return ctx }, + BEnd: func(ctx context.Context) {}, + } + + stdlibLog = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + logCtx(ctx).Printf(eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + logCtx(ctx).Printf(eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + + stdlibPrintf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + ctxPrintf(ctx, eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + ctxPrintf(ctx, eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +func BenchmarkBaseline(b *testing.B) { + eventtest.RunBenchmark(b, context.Background(), eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { return ctx }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { return ctx }, + BEnd: func(ctx context.Context) {}, + }) +} + +type stdlibLogKey struct{} + +func logCtx(ctx context.Context) *log.Logger { + return ctx.Value(stdlibLogKey{}).(*log.Logger) +} + +func stdlibLogger(w io.Writer) context.Context { + logger := log.New(w, "", log.LstdFlags) + return context.WithValue(context.Background(), stdlibLogKey{}, logger) +} + +func stdlibLoggerNoTime(w io.Writer) context.Context { + // there is no way to fixup the time, so we have to suppress it + logger := log.New(w, "", 0) + return context.WithValue(context.Background(), stdlibLogKey{}, logger) +} + +type writerKey struct{} + +func ctxPrintf(ctx context.Context, msg string, args ...interface{}) { + ctx.Value(writerKey{}).(func(string, ...interface{}))(msg, args...) +} + +func stdlibWriter(w io.Writer) context.Context { + now := eventtest.ExporterOptions().Now + return context.WithValue(context.Background(), writerKey{}, + func(msg string, args ...interface{}) { + fmt.Fprintf(w, "time=%q level=info msg=%q\n", + now().Format(eventtest.TimeFormat), + fmt.Sprintf(msg, args...)) + }, + ) +} + +func BenchmarkStdlibLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, stdlibLogger(io.Discard), stdlibLog) +} + +func BenchmarkStdlibPrintfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, stdlibWriter(io.Discard), stdlibPrintf) +} + +func TestLogStdlib(t *testing.T) { + eventtest.TestBenchmark(t, stdlibLoggerNoTime, stdlibLog, ` +a where A=0 +b where B="A value" +a where A=1 +b where B="Some other value" +a where A=22 +b where B="Some other value" +a where A=333 +b where B=" " +a where A=4444 +b where B="prime count of values" +a where A=55555 +b where B="V" +a where A=666666 +b where B="A value" +a where A=7777777 +b where B="A value" +`) +} + +func TestLogPrintf(t *testing.T) { + eventtest.TestBenchmark(t, stdlibWriter, stdlibPrintf, eventtest.LogfOutput) +} diff --git a/event/adapter/zap/bench_test.go b/event/adapter/zap/bench_test.go new file mode 100644 index 0000000..913747f --- /dev/null +++ b/event/adapter/zap/bench_test.go @@ -0,0 +1,115 @@ +// 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. + +package zap_test + +import ( + "context" + "io" + "testing" + "time" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "golang.org/x/exp/event/eventtest" +) + +var ( + zapLog = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + zapCtx(ctx).Info(eventtest.A.Msg, zap.Int(eventtest.A.Name, a)) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + zapCtx(ctx).Info(eventtest.B.Msg, zap.String(eventtest.B.Name, b)) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + zapLogf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + zapCtx(ctx).Sugar().Infof(eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + zapCtx(ctx).Sugar().Infof(eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +type zapKey struct{} + +func zapCtx(ctx context.Context) *zap.Logger { + return ctx.Value(zapKey{}).(*zap.Logger) +} + +func zapPrint(w io.Writer) context.Context { + now := eventtest.ExporterOptions().Now + ec := zap.NewProductionEncoderConfig() + ec.EncodeDuration = zapcore.NanosDurationEncoder + timeEncoder := zapcore.TimeEncoderOfLayout(eventtest.TimeFormat) + ec.EncodeTime = func(_ time.Time, a zapcore.PrimitiveArrayEncoder) { + timeEncoder(now(), a) + } + enc := zapcore.NewConsoleEncoder(ec) + logger := zap.New(zapcore.NewCore( + enc, + zapcore.AddSync(w), + zap.InfoLevel, + )) + return context.WithValue(context.Background(), zapKey{}, logger) +} + +func BenchmarkZapLogDiscard(b *testing.B) { + eventtest.RunBenchmark(b, zapPrint(io.Discard), zapLog) +} + +func BenchmarkZapLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, zapPrint(io.Discard), zapLogf) +} + +func TestZapLogfDiscard(t *testing.T) { + eventtest.TestBenchmark(t, zapPrint, zapLogf, ` +2020/03/05 14:27:48 info a where A=0 +2020/03/05 14:27:49 info b where B="A value" +2020/03/05 14:27:50 info a where A=1 +2020/03/05 14:27:51 info b where B="Some other value" +2020/03/05 14:27:52 info a where A=22 +2020/03/05 14:27:53 info b where B="Some other value" +2020/03/05 14:27:54 info a where A=333 +2020/03/05 14:27:55 info b where B=" " +2020/03/05 14:27:56 info a where A=4444 +2020/03/05 14:27:57 info b where B="prime count of values" +2020/03/05 14:27:58 info a where A=55555 +2020/03/05 14:27:59 info b where B="V" +2020/03/05 14:28:00 info a where A=666666 +2020/03/05 14:28:01 info b where B="A value" +2020/03/05 14:28:02 info a where A=7777777 +2020/03/05 14:28:03 info b where B="A value" +`) +} +func TestLogZap(t *testing.T) { + eventtest.TestBenchmark(t, zapPrint, zapLog, ` +2020/03/05 14:27:48 info a {"A": 0} +2020/03/05 14:27:49 info b {"B": "A value"} +2020/03/05 14:27:50 info a {"A": 1} +2020/03/05 14:27:51 info b {"B": "Some other value"} +2020/03/05 14:27:52 info a {"A": 22} +2020/03/05 14:27:53 info b {"B": "Some other value"} +2020/03/05 14:27:54 info a {"A": 333} +2020/03/05 14:27:55 info b {"B": " "} +2020/03/05 14:27:56 info a {"A": 4444} +2020/03/05 14:27:57 info b {"B": "prime count of values"} +2020/03/05 14:27:58 info a {"A": 55555} +2020/03/05 14:27:59 info b {"B": "V"} +2020/03/05 14:28:00 info a {"A": 666666} +2020/03/05 14:28:01 info b {"B": "A value"} +2020/03/05 14:28:02 info a {"A": 7777777} +2020/03/05 14:28:03 info b {"B": "A value"} +`) +} diff --git a/event/adapter/zap/zap.go b/event/adapter/zap/zap.go new file mode 100644 index 0000000..6fe8a27 --- /dev/null +++ b/event/adapter/zap/zap.go @@ -0,0 +1,176 @@ +// Copyright 2021 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. + +//go:build !disable_events + +// zap provides an implementation of zapcore.Core for events. +// To use globally: +// +// zap.ReplaceGlobals(zap.New(NewCore(exporter))) +// +// If you call elogging.SetExporter, then you can pass nil +// for the exporter above and it will use the global one. +package zap + +import ( + "context" + "fmt" + "math" + "reflect" + "time" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "golang.org/x/exp/event" + "golang.org/x/exp/event/severity" +) + +type core struct { + ev *event.Event // cloned but never delivered + labels []event.Label +} + +var _ zapcore.Core = (*core)(nil) + +func NewCore(ctx context.Context) zapcore.Core { + return &core{ev: event.New(ctx, event.LogKind)} +} + +func (c *core) Enabled(level zapcore.Level) bool { + return true +} + +func (c *core) With(fields []zapcore.Field) zapcore.Core { + c2 := *c + 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 { + if c.ev == nil { + return nil + } + ev := c.ev.Clone() + if ev == nil { + return nil + } + ev.At = e.Time + // TODO: Add labels more efficiently: compare cap(ev.Labels) to the total number to add, + // and allocate a []Label once. + ev.Labels = append(ev.Labels, c.labels...) + ev.Labels = append(ev.Labels, convertLevel(e.Level).Label()) + ev.Labels = append(ev.Labels, event.String("name", e.LoggerName)) + if e.Stack != "" { + ev.Labels = append(ev.Labels, event.String("stack", e.Stack)) + } + if e.Caller.Defined { + ev.Labels = append(ev.Labels, event.String("caller", e.Caller.String())) + } + for _, f := range fs { + ev.Labels = append(ev.Labels, newLabel(f)) + } + ev.Labels = append(ev.Labels, event.String("msg", e.Message)) + ev.Deliver() + return nil +} + +func (c *core) Check(e zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry { + return ce.AddCore(e, c) +} + +func (c *core) Sync() error { return nil } + +func newLabel(f zap.Field) event.Label { + switch f.Type { + case zapcore.ArrayMarshalerType, zapcore.ObjectMarshalerType, zapcore.BinaryType, zapcore.ByteStringType, + zapcore.Complex128Type, zapcore.Complex64Type, zapcore.TimeFullType, zapcore.ReflectType, + zapcore.ErrorType: + return event.Value(f.Key, f.Interface) + case zapcore.DurationType: + return event.Duration(f.Key, time.Duration(f.Integer)) + case zapcore.Float64Type: + return event.Float64(f.Key, math.Float64frombits(uint64(f.Integer))) + case zapcore.Float32Type: + return event.Float64(f.Key, float64(math.Float32frombits(uint32(f.Integer)))) + case zapcore.BoolType: + b := false + if f.Integer != 0 { + b = true + } + return event.Bool(f.Key, b) + case zapcore.Int64Type: + return event.Int64(f.Key, f.Integer) + case zapcore.Int32Type: + return event.Int64(f.Key, f.Integer) + + //, zapcore.Int16Type, zapcore.Int8Type, + // zapcore.Uint64Type, zapcore.Uint32Type, zapcore.Uint16Type, zapcore.Uint8Type, zapcore.UintptrType: + // return (f.Key,uint64(f.Integer)) + case zapcore.StringType: + return event.String(f.Key, f.String) + case zapcore.TimeType: + t := time.Unix(0, f.Integer) + if f.Interface != nil { + t = t.In(f.Interface.(*time.Location)) + } + return event.Value(f.Key, t) + case zapcore.StringerType: + return event.String(f.Key, stringerToString(f.Interface)) + case zapcore.NamespaceType: + // TODO: ??? + return event.Label{} + case zapcore.SkipType: + // TODO: avoid creating a label at all in this case. + return event.Label{} + default: + panic(fmt.Sprintf("unknown field type: %v", f)) + } +} + +// Adapter from encodeStringer in go.uber.org/zap/zapcore/field.go. +func stringerToString(stringer interface{}) (s string) { + // Try to capture panics (from nil references or otherwise) when calling + // the String() method, similar to https://golang.org/src/fmt/print.go#L540 + defer func() { + if err := recover(); err != nil { + // If it's a nil pointer, just say "<nil>". The likeliest causes are a + // Stringer that fails to guard against nil or a nil pointer for a + // value receiver, and in either case, "<nil>" is a nice result. + if v := reflect.ValueOf(stringer); v.Kind() == reflect.Ptr && v.IsNil() { + s = "<nil>" + return + } + s = fmt.Sprintf("PANIC=%v", err) + } + }() + + return stringer.(fmt.Stringer).String() +} + +func convertLevel(level zapcore.Level) severity.Level { + switch level { + case zapcore.DebugLevel: + return severity.Debug + case zapcore.InfoLevel: + return severity.Info + case zapcore.WarnLevel: + return severity.Warning + case zapcore.ErrorLevel: + return severity.Error + case zapcore.DPanicLevel: + return severity.Fatal - 1 + case zapcore.PanicLevel: + return severity.Fatal + 1 + case zapcore.FatalLevel: + return severity.Fatal + default: + return severity.Trace + } +} diff --git a/event/adapter/zap/zap_test.go b/event/adapter/zap/zap_test.go new file mode 100644 index 0000000..ed2e03c --- /dev/null +++ b/event/adapter/zap/zap_test.go @@ -0,0 +1,40 @@ +// Copyright 2021 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. + +//go:build !disable_events + +package zap_test + +import ( + "testing" + + "github.com/google/go-cmp/cmp" + "go.uber.org/zap" + "golang.org/x/exp/event" + ezap "golang.org/x/exp/event/adapter/zap" + "golang.org/x/exp/event/eventtest" + "golang.org/x/exp/event/severity" +) + +func Test(t *testing.T) { + ctx, h := eventtest.NewCapture() + log := zap.New(ezap.NewCore(ctx), zap.Fields(zap.Int("traceID", 17), zap.String("resource", "R"))) + log = log.Named("n/m") + log.Info("mess", zap.Float64("pi", 3.14)) + want := []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + event.Int64("traceID", 17), + event.String("resource", "R"), + severity.Info.Label(), + event.String("name", "n/m"), + event.Float64("pi", 3.14), + event.String("msg", "mess"), + }, + }} + if diff := cmp.Diff(want, h.Got, eventtest.CmpOptions()...); diff != "" { + t.Errorf("mismatch (-want, +got):\n%s", diff) + } +} diff --git a/event/adapter/zerolog/bench_test.go b/event/adapter/zerolog/bench_test.go new file mode 100644 index 0000000..480754d --- /dev/null +++ b/event/adapter/zerolog/bench_test.go @@ -0,0 +1,78 @@ +// 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. + +package zerolog_test + +import ( + "context" + "io" + "testing" + + "github.com/rs/zerolog" + "golang.org/x/exp/event/eventtest" +) + +var ( + zerologMsg = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + zerolog.Ctx(ctx).Info().Int(eventtest.A.Name, a).Msg(eventtest.A.Msg) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + zerolog.Ctx(ctx).Info().Str(eventtest.B.Name, b).Msg(eventtest.B.Msg) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + + zerologMsgf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + zerolog.Ctx(ctx).Info().Msgf(eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + zerolog.Ctx(ctx).Info().Msgf(eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +func zerologPrint(w io.Writer) context.Context { + zerolog.TimeFieldFormat = eventtest.TimeFormat + zerolog.TimestampFunc = eventtest.ExporterOptions().Now + logger := zerolog.New(zerolog.SyncWriter(w)).With().Timestamp().Logger() + return logger.WithContext(context.Background()) +} + +func BenchmarkZerologLogDiscard(b *testing.B) { + eventtest.RunBenchmark(b, zerologPrint(io.Discard), zerologMsg) +} + +func BenchmarkZerologLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, zerologPrint(io.Discard), zerologMsgf) +} + +func TestLogZerologf(t *testing.T) { + eventtest.TestBenchmark(t, zerologPrint, zerologMsgf, ` +{"level":"info","time":"2020/03/05 14:27:48","message":"a where A=0"} +{"level":"info","time":"2020/03/05 14:27:49","message":"b where B=\"A value\""} +{"level":"info","time":"2020/03/05 14:27:50","message":"a where A=1"} +{"level":"info","time":"2020/03/05 14:27:51","message":"b where B=\"Some other value\""} +{"level":"info","time":"2020/03/05 14:27:52","message":"a where A=22"} +{"level":"info","time":"2020/03/05 14:27:53","message":"b where B=\"Some other value\""} +{"level":"info","time":"2020/03/05 14:27:54","message":"a where A=333"} +{"level":"info","time":"2020/03/05 14:27:55","message":"b where B=\" \""} +{"level":"info","time":"2020/03/05 14:27:56","message":"a where A=4444"} +{"level":"info","time":"2020/03/05 14:27:57","message":"b where B=\"prime count of values\""} +{"level":"info","time":"2020/03/05 14:27:58","message":"a where A=55555"} +{"level":"info","time":"2020/03/05 14:27:59","message":"b where B=\"V\""} +{"level":"info","time":"2020/03/05 14:28:00","message":"a where A=666666"} +{"level":"info","time":"2020/03/05 14:28:01","message":"b where B=\"A value\""} +{"level":"info","time":"2020/03/05 14:28:02","message":"a where A=7777777"} +{"level":"info","time":"2020/03/05 14:28:03","message":"b where B=\"A value\""} +`) +} diff --git a/event/alloc_test.go b/event/alloc_test.go new file mode 100644 index 0000000..1cf7e75 --- /dev/null +++ b/event/alloc_test.go @@ -0,0 +1,35 @@ +// 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. + +//go:build !race + +package event_test + +import ( + "context" + "io" + "testing" + + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/logfmt" + "golang.org/x/exp/event/eventtest" +) + +func TestAllocs(t *testing.T) { + anInt := event.Int64("int", 4) + aString := event.String("string", "value") + + e := event.NewExporter(logfmt.NewHandler(io.Discard), &event.ExporterOptions{EnableNamespaces: true}) + ctx := event.WithExporter(context.Background(), e) + allocs := int(testing.AllocsPerRun(5, func() { + event.Log(ctx, "message", aString, anInt) + })) + if allocs != 0 { + t.Errorf("Got %d allocs, expect 0", allocs) + } +} + +func TestBenchAllocs(t *testing.T) { + eventtest.TestAllocs(t, eventPrint, eventLog, 0) +} diff --git a/event/bench_test.go b/event/bench_test.go new file mode 100644 index 0000000..b3bd0ea --- /dev/null +++ b/event/bench_test.go @@ -0,0 +1,134 @@ +// 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. + +package event_test + +import ( + "context" + "io" + "testing" + + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/logfmt" + "golang.org/x/exp/event/eventtest" + "golang.org/x/exp/event/severity" +) + +var ( + eventLog = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + severity.Info.Log(ctx, eventtest.A.Msg, event.Int64(eventtest.A.Name, int64(a))) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + severity.Info.Log(ctx, eventtest.B.Msg, event.String(eventtest.B.Name, b)) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + + eventLogf = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + severity.Info.Logf(ctx, eventtest.A.Msgf, a) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + severity.Info.Logf(ctx, eventtest.B.Msgf, b) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } + + eventTrace = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + ctx = event.Start(ctx, eventtest.A.Msg, event.Int64(eventtest.A.Name, int64(a))) + return ctx + }, + AEnd: func(ctx context.Context) { + event.End(ctx) + }, + BStart: func(ctx context.Context, b string) context.Context { + ctx = event.Start(ctx, eventtest.B.Msg, event.String(eventtest.B.Name, b)) + return ctx + }, + BEnd: func(ctx context.Context) { + event.End(ctx) + }, + } + + eventMetric = eventtest.Hooks{ + AStart: func(ctx context.Context, a int) context.Context { + gauge.Record(ctx, 1, event.Int64("aValue", int64(a))) + gauge.Record(ctx, 1, event.Int64("aCount", 1)) + return ctx + }, + AEnd: func(ctx context.Context) {}, + BStart: func(ctx context.Context, b string) context.Context { + gauge.Record(ctx, 1, event.Int64("BLen", int64(len(b)))) + gauge.Record(ctx, 1, event.Int64("B", 1)) + return ctx + }, + BEnd: func(ctx context.Context) {}, + } +) + +func eventNoExporter() context.Context { + return event.WithExporter(context.Background(), nil) +} + +func eventNoop() context.Context { + return event.WithExporter(context.Background(), event.NewExporter(nopHandler{}, eventtest.ExporterOptions())) +} + +func eventPrint(w io.Writer) context.Context { + return event.WithExporter(context.Background(), event.NewExporter(logfmt.NewHandler(w), eventtest.ExporterOptions())) +} + +func eventPrintSource(w io.Writer) context.Context { + opts := eventtest.ExporterOptions() + opts.EnableNamespaces = true + 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) +} + +func BenchmarkEventLogNoop(b *testing.B) { + eventtest.RunBenchmark(b, eventNoop(), eventLog) +} + +func BenchmarkEventLogDiscard(b *testing.B) { + eventtest.RunBenchmark(b, eventPrint(io.Discard), eventLog) +} + +func BenchmarkEventLogSourceDiscard(b *testing.B) { + eventtest.RunBenchmark(b, eventPrintSource(io.Discard), eventLog) +} + +func BenchmarkEventLogfDiscard(b *testing.B) { + eventtest.RunBenchmark(b, eventPrint(io.Discard), eventLogf) +} + +func BenchmarkEventTraceNoop(b *testing.B) { + eventtest.RunBenchmark(b, eventNoop(), eventTrace) +} + +func BenchmarkEventTraceDiscard(b *testing.B) { + eventtest.RunBenchmark(b, eventPrint(io.Discard), eventTrace) +} + +func BenchmarkEventMetricNoop(b *testing.B) { + eventtest.RunBenchmark(b, eventNoop(), eventMetric) +} + +func BenchmarkEventMetricDiscard(b *testing.B) { + eventtest.RunBenchmark(b, eventPrint(io.Discard), eventMetric) +} diff --git a/event/common.go b/event/common.go new file mode 100644 index 0000000..f12b84a --- /dev/null +++ b/event/common.go @@ -0,0 +1,159 @@ +// Copyright 2019 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. + +package event + +import ( + "context" + "fmt" + "sync" +) + +const ( + MetricKey = interfaceKey("metric") + MetricVal = "metricValue" + DurationMetric = interfaceKey("durationMetric") +) + +type Kind int + +const ( + unknownKind = Kind(iota) + + LogKind + MetricKind + StartKind + EndKind + + dynamicKindStart +) + +type ( + valueKey string + interfaceKey string +) + +var ( + dynamicKindMu sync.Mutex + nextDynamicKind = dynamicKindStart + dynamicKindNames map[Kind]string +) + +func NewKind(name string) Kind { + dynamicKindMu.Lock() + defer dynamicKindMu.Unlock() + for _, n := range dynamicKindNames { + if n == name { + panic(fmt.Errorf("kind %s is already registered", name)) + } + } + k := nextDynamicKind + nextDynamicKind++ + dynamicKindNames[k] = name + return k +} + +func (k Kind) String() string { + switch k { + case unknownKind: + return "unknown" + case LogKind: + return "log" + case MetricKind: + return "metric" + case StartKind: + return "start" + case EndKind: + return "end" + default: + dynamicKindMu.Lock() + defer dynamicKindMu.Unlock() + name, ok := dynamicKindNames[k] + if !ok { + return fmt.Sprintf("?unknownKind:%d?", k) + } + return name + } +} + +func Log(ctx context.Context, msg string, labels ...Label) { + ev := New(ctx, LogKind) + if ev != nil { + ev.Labels = append(ev.Labels, labels...) + ev.Labels = append(ev.Labels, String("msg", msg)) + ev.Deliver() + } +} + +func Logf(ctx context.Context, msg string, args ...interface{}) { + ev := New(ctx, LogKind) + if ev != nil { + ev.Labels = append(ev.Labels, String("msg", fmt.Sprintf(msg, args...))) + ev.Deliver() + } +} + +func Error(ctx context.Context, msg string, err error, labels ...Label) { + ev := New(ctx, LogKind) + if ev != nil { + ev.Labels = append(ev.Labels, labels...) + ev.Labels = append(ev.Labels, String("msg", msg), Value("error", err)) + 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, String("name", name)) + ev.Labels = append(ev.Labels, labels...) + ev.Trace() + 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.prepare() + // 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.(*DurationDistribution).Record(ctx, ev.At.Sub(ev.target.startTime)) + } + ev.Deliver() + } +} + +func (k interfaceKey) Of(v interface{}) Label { + return Value(string(k), v) +} + +func (k interfaceKey) Find(ev *Event) (interface{}, bool) { + v, ok := lookupValue(string(k), ev.Labels) + if !ok { + return nil, false + } + return v.Interface(), true + +} + +func lookupValue(name string, labels []Label) (Label, bool) { + for i := len(labels) - 1; i >= 0; i-- { + if labels[i].Name == name { + return labels[i], true + } + } + return Label{}, false +} diff --git a/event/disabled.go b/event/disabled.go new file mode 100644 index 0000000..7aee0bd --- /dev/null +++ b/event/disabled.go @@ -0,0 +1,40 @@ +// Copyright 2019 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. + +//go:build disable_events + +package event + +import ( + "context" + "time" +) + +type Builder struct{ ctx context.Context } +type Exporter struct { + Now func() time.Time +} + +func NewExporter(h interface{}) *Exporter { return &Exporter{} } + +func To(ctx context.Context) Builder { return Builder{} } +func (b Builder) Clone() 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() {} +func (b Builder) Annotate() {} +func (b Builder) End() {} +func (b Builder) Event() *Event { return &Event{} } +func (b Builder) Start(name string) (context.Context, func()) { + return b.ctx, func() {} +} + +func newContext(ctx context.Context, exporter *Exporter, parent uint64) context.Context { + return ctx +} +func FromContext(ctx context.Context) *Target { return nil } + +func setDefaultExporter(e *Exporter) {} diff --git a/event/doc.go b/event/doc.go new file mode 100644 index 0000000..bb11122 --- /dev/null +++ b/event/doc.go @@ -0,0 +1,18 @@ +// Copyright 2019 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. + +// Package event provides low-cost tracing, metrics and structured logging. +// These are often grouped under the term "observability". +// +// This package is highly experimental and in a state of flux; it is public only +// to allow for collaboration on the design and implementation, and may be +// changed or removed at any time. +// +// It uses a common event system to provide a way for libraries to produce +// observability information in a way that does not tie the libraries to a +// specific API or applications to a specific export format. +// +// It is designed for minimal overhead when no exporter is used so that it is +// safe to leave calls in libraries. +package event diff --git a/event/event.go b/event/event.go new file mode 100644 index 0000000..e5746b0 --- /dev/null +++ b/event/event.go @@ -0,0 +1,138 @@ +// Copyright 2019 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. + +package event + +import ( + "context" + "sync" + "time" +) + +// Event holds the information about an event that occurred. +// It combines the event metadata with the user supplied labels. +type Event struct { + ID uint64 + Parent uint64 // id of the parent event for this event + Source Source // source of event; if empty, set by exporter to import path + At time.Time // time at which the event is delivered to the exporter. + Kind Kind + 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 { + // Event is called with each event. + Event(context.Context, *Event) context.Context +} + +// 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 +// return quickly so as not to hold up user code. +func WithExporter(ctx context.Context, e *Exporter) context.Context { + return newContext(ctx, e, 0, time.Time{}) +} + +// SetDefaultExporter sets an exporter that is used if no exporter can be +// found on the context. +func SetDefaultExporter(e *Exporter) { + setDefaultExporter(e) +} + +// 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 +} + +// Clone makes a deep copy of the Event. +// Deliver can be called on both Events independently. +func (ev *Event) Clone() *Event { + ev2 := eventPool.Get().(*Event) + *ev2 = *ev + ev2.Labels = append(ev2.labels[:0], ev.Labels...) + return ev2 +} + +func (ev *Event) Trace() { + ev.prepare() + ev.ctx = newContext(ev.ctx, ev.target.exporter, ev.ID, ev.At) +} + +// 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.prepare() + ctx := ev.deliver() + eventPool.Put(ev) + return ctx +} + +func (ev *Event) deliver() context.Context { + // hold the lock while we deliver the event + e := ev.target.exporter + e.mu.Lock() + defer e.mu.Unlock() + return e.handler.Event(ev.ctx, ev) +} + +func (ev *Event) Find(name string) Label { + for _, l := range ev.Labels { + if l.Name == name { + return l + } + } + return Label{} +} diff --git a/event/event_test.go b/event/event_test.go new file mode 100644 index 0000000..5899988 --- /dev/null +++ b/event/event_test.go @@ -0,0 +1,347 @@ +// 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. + +//go:build !disable_events + +package event_test + +import ( + "context" + "errors" + "fmt" + "os" + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/logfmt" + "golang.org/x/exp/event/eventtest" +) + +var ( + l1 = event.Int64("l1", 1) + l2 = event.Int64("l2", 2) + l3 = event.Int64("l3", 3) + counter = event.NewCounter("hits", nil) + gauge = event.NewFloatGauge("temperature", nil) + latency = event.NewDuration("latency", nil) + err = errors.New("an error") +) + +func TestCommon(t *testing.T) { + for _, test := range []struct { + method string + events func(context.Context) + expect []event.Event + }{{ + method: "simple", + events: func(ctx context.Context) { event.Log(ctx, "a message") }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "a message")}, + }}, + }, { + method: "log 1", + events: func(ctx context.Context) { event.Log(ctx, "a message", l1) }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "a message"), l1}, + }}, + }, { + method: "log 2", + events: func(ctx context.Context) { event.Log(ctx, "a message", l1, l2) }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "a message"), l1, l2}, + }}, + }, { + method: "log 3", + events: func(ctx context.Context) { event.Log(ctx, "a message", l1, l2, l3) }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "a message"), l1, l2, l3}, + }}, + }, { + method: "logf", + events: func(ctx context.Context) { event.Logf(ctx, "logf %s message", "to") }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "logf to message")}, + }}, + }, { + method: "error", + events: func(ctx context.Context) { event.Error(ctx, "failed", err, l1) }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + event.String("msg", "failed"), + event.Value("error", err), + l1, + }, + }}, + }, { + method: "span", + events: func(ctx context.Context) { + ctx = event.Start(ctx, `span`) + event.End(ctx) + }, + expect: []event.Event{{ + ID: 1, + Kind: event.StartKind, + Labels: []event.Label{event.String("name", "span")}, + }, { + ID: 2, + Parent: 1, + Kind: event.EndKind, + Labels: []event.Label{}, + }}, + }, { + method: "span nested", + events: func(ctx context.Context) { + ctx = event.Start(ctx, "parent") + defer event.End(ctx) + child := event.Start(ctx, "child") + defer event.End(child) + event.Log(child, "message") + }, + expect: []event.Event{{ + ID: 1, + Kind: event.StartKind, + Labels: []event.Label{event.String("name", "parent")}, + }, { + ID: 2, + Parent: 1, + Kind: event.StartKind, + Labels: []event.Label{event.String("name", "child")}, + }, { + ID: 3, + Parent: 2, + Kind: event.LogKind, + Labels: []event.Label{event.String("msg", "message")}, + }, { + ID: 4, + Parent: 2, + Kind: event.EndKind, + Labels: []event.Label{}, + }, { + ID: 5, + Parent: 1, + Kind: event.EndKind, + Labels: []event.Label{}, + }}, + }, { + method: "counter", + events: func(ctx context.Context) { counter.Record(ctx, 2, l1) }, + expect: []event.Event{{ + ID: 1, + Kind: event.MetricKind, + Labels: []event.Label{ + event.Int64("metricValue", 2), + event.Value("metric", counter), + l1, + }, + }}, + }, { + method: "gauge", + events: func(ctx context.Context) { gauge.Record(ctx, 98.6, l1) }, + expect: []event.Event{{ + ID: 1, + Kind: event.MetricKind, + Labels: []event.Label{ + event.Float64("metricValue", 98.6), + event.Value("metric", gauge), + l1, + }, + }}, + }, { + method: "duration", + events: func(ctx context.Context) { latency.Record(ctx, 3*time.Second, l1, l2) }, + expect: []event.Event{{ + ID: 1, + Kind: event.MetricKind, + Labels: []event.Label{ + event.Duration("metricValue", 3*time.Second), + event.Value("metric", latency), + l1, l2, + }, + }}, + }, { + method: "annotate", + events: func(ctx context.Context) { event.Annotate(ctx, l1) }, + expect: []event.Event{{ + ID: 1, + Labels: []event.Label{l1}, + }}, + }, { + method: "annotate 2", + events: func(ctx context.Context) { event.Annotate(ctx, l1, l2) }, + expect: []event.Event{{ + ID: 1, + Labels: []event.Label{l1, l2}, + }}, + }, { + method: "multiple events", + events: func(ctx context.Context) { + /*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", event.Int64("myInt", 6)) + event.Log(ctx, "string event", event.String("myString", "some string value")) + }, + expect: []event.Event{{ + ID: 1, + Kind: event.LogKind, + Labels: []event.Label{ + event.String("msg", "my event"), + event.Int64("myInt", 6), + }, + }, { + ID: 2, + Kind: event.LogKind, + Labels: []event.Label{ + event.String("msg", "string event"), + event.String("myString", "some string value"), + }, + }}, + }} { + t.Run(test.method, func(t *testing.T) { + ctx, h := eventtest.NewCapture() + test.events(ctx) + if diff := cmp.Diff(test.expect, h.Got, eventtest.CmpOptions()...); diff != "" { + t.Errorf("mismatch (-want, +got):\n%s", diff) + } + }) + } +} + +func ExampleLog() { + ctx := event.WithExporter(context.Background(), event.NewExporter(logfmt.NewHandler(os.Stdout), eventtest.ExporterOptions())) + event.Log(ctx, "my event", event.Int64("myInt", 6)) + event.Log(ctx, "error event", event.String("myString", "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" +} + +func TestLogEventf(t *testing.T) { + eventtest.TestBenchmark(t, eventPrint, eventLogf, eventtest.LogfOutput) +} + +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", nil) + 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.Label +} + +func (t *testTraceDurationHandler) Event(ctx context.Context, ev *event.Event) context.Context { + for _, l := range ev.Labels { + if l.Name == string(event.MetricVal) { + t.got = l + } + } + return ctx +} + +func BenchmarkBuildContext(b *testing.B) { + // How long does it take to deliver an event from a nested context? + c := event.NewCounter("c", nil) + 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/bench.go b/event/eventtest/bench.go new file mode 100644 index 0000000..0fb7189 --- /dev/null +++ b/event/eventtest/bench.go @@ -0,0 +1,151 @@ +// 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. + +package eventtest + +import ( + "context" + "io" + "strings" + "testing" + + "github.com/google/go-cmp/cmp" + "golang.org/x/exp/event/adapter/logfmt" +) + +type Info struct { + Name string + Msg string + Msgf string +} + +type Hooks struct { + AStart func(ctx context.Context, a int) context.Context + AEnd func(ctx context.Context) + BStart func(ctx context.Context, b string) context.Context + BEnd func(ctx context.Context) +} + +var ( + initialList = []int{0, 1, 22, 333, 4444, 55555, 666666, 7777777} + stringList = []string{ + "A value", + "Some other value", + "A nice longer value but not too long", + "V", + " ", + "ı", + "prime count of values", + } + + A = Info{ + Name: "A", + Msg: "a", + Msgf: "a where A=%d", + } + + B = Info{ + Name: "B", + Msg: "b", + Msgf: "b where B=%q", + } +) + +const ( + TimeFormat = logfmt.TimeFormat + + LogfmtOutput = ` +time="2020/03/05 14:27:48" level=info A=0 msg=a +time="2020/03/05 14:27:49" level=info B="A value" msg=b +time="2020/03/05 14:27:50" level=info A=1 msg=a +time="2020/03/05 14:27:51" level=info B="Some other value" msg=b +time="2020/03/05 14:27:52" level=info A=22 msg=a +time="2020/03/05 14:27:53" level=info B="Some other value" msg=b +time="2020/03/05 14:27:54" level=info A=333 msg=a +time="2020/03/05 14:27:55" level=info B=" " msg=b +time="2020/03/05 14:27:56" level=info A=4444 msg=a +time="2020/03/05 14:27:57" level=info B="prime count of values" msg=b +time="2020/03/05 14:27:58" level=info A=55555 msg=a +time="2020/03/05 14:27:59" level=info B=V msg=b +time="2020/03/05 14:28:00" level=info A=666666 msg=a +time="2020/03/05 14:28:01" level=info B="A value" msg=b +time="2020/03/05 14:28:02" level=info A=7777777 msg=a +time="2020/03/05 14:28:03" level=info B="A value" msg=b +` + + LogfOutput = ` +time="2020/03/05 14:27:48" level=info msg="a where A=0" +time="2020/03/05 14:27:49" level=info msg="b where B=\"A value\"" +time="2020/03/05 14:27:50" level=info msg="a where A=1" +time="2020/03/05 14:27:51" level=info msg="b where B=\"Some other value\"" +time="2020/03/05 14:27:52" level=info msg="a where A=22" +time="2020/03/05 14:27:53" level=info msg="b where B=\"Some other value\"" +time="2020/03/05 14:27:54" level=info msg="a where A=333" +time="2020/03/05 14:27:55" level=info msg="b where B=\" \"" +time="2020/03/05 14:27:56" level=info msg="a where A=4444" +time="2020/03/05 14:27:57" level=info msg="b where B=\"prime count of values\"" +time="2020/03/05 14:27:58" level=info msg="a where A=55555" +time="2020/03/05 14:27:59" level=info msg="b where B=\"V\"" +time="2020/03/05 14:28:00" level=info msg="a where A=666666" +time="2020/03/05 14:28:01" level=info msg="b where B=\"A value\"" +time="2020/03/05 14:28:02" level=info msg="a where A=7777777" +time="2020/03/05 14:28:03" level=info msg="b where B=\"A value\"" +` +) + +type namedBenchmark struct { + name string + test func(ctx context.Context) func(*testing.B) +} + +func benchA(ctx context.Context, hooks Hooks, a int) int { + ctx = hooks.AStart(ctx, a) + defer hooks.AEnd(ctx) + return benchB(ctx, hooks, a, stringList[a%len(stringList)]) +} + +func benchB(ctx context.Context, hooks Hooks, a int, b string) int { + ctx = hooks.BStart(ctx, b) + defer hooks.BEnd(ctx) + return a + len(b) +} + +func runOnce(ctx context.Context, hooks Hooks) { + var acc int + for _, value := range initialList { + acc += benchA(ctx, hooks, value) + } +} + +func RunBenchmark(b *testing.B, ctx context.Context, hooks Hooks) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + runOnce(ctx, hooks) + } +} + +func TestBenchmark(t *testing.T, f func(io.Writer) context.Context, hooks Hooks, expect string) { + buf := strings.Builder{} + ctx := f(&buf) + runOnce(ctx, hooks) + got := strings.TrimSpace(buf.String()) + expect = strings.TrimSpace(expect) + if diff := cmp.Diff(got, expect); diff != "" { + t.Error(diff) + } +} + +func TestAllocs(t *testing.T, f func(io.Writer) context.Context, hooks Hooks, expect int) { + t.Helper() + var acc int + ctx := f(io.Discard) + got := int(testing.AllocsPerRun(5, func() { + for _, value := range initialList { + acc += benchA(ctx, hooks, value) + } + })) + if got != expect { + t.Errorf("Got %d allocs, expect %d", got, expect) + } +} diff --git a/event/eventtest/capture.go b/event/eventtest/capture.go new file mode 100644 index 0000000..9510b3e --- /dev/null +++ b/event/eventtest/capture.go @@ -0,0 +1,31 @@ +package eventtest + +import ( + "context" + + "golang.org/x/exp/event" +) + +type CaptureHandler struct { + Got []event.Event +} + +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) Reset() { + if len(h.Got) > 0 { + h.Got = h.Got[:0] + } +} + +func NewCapture() (context.Context, *CaptureHandler) { + h := &CaptureHandler{} + ctx := event.WithExporter(context.Background(), event.NewExporter(h, ExporterOptions())) + return ctx, h +} diff --git a/event/eventtest/eventtest.go b/event/eventtest/eventtest.go new file mode 100644 index 0000000..8081159 --- /dev/null +++ b/event/eventtest/eventtest.go @@ -0,0 +1,65 @@ +// 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. + +// Package eventtest supports logging events to a test. +// You can use NewContext to create a context that knows how to deliver +// telemetry events back to the test. +// You must use this context or a derived one anywhere you want telemetry to be +// correctly routed back to the test it was constructed with. +package eventtest + +import ( + "context" + "os" + "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" +) + +// NewContext returns a context you should use for the active test. +func NewContext(ctx context.Context, tb testing.TB) context.Context { + h := &testHandler{tb: tb} + return event.WithExporter(ctx, event.NewExporter(h, nil)) +} + +type testHandler struct { + tb testing.TB + printer logfmt.Printer +} + +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 { + t, _ := time.Parse(logfmt.TimeFormat, "2020/03/05 14:27:48") + return t +}() + +func ExporterOptions() *event.ExporterOptions { + nextTime := InitialTime + return &event.ExporterOptions{ + Now: func() time.Time { + thisTime := nextTime + nextTime = nextTime.Add(time.Second) + return thisTime + }, + } +} + +func CmpOptions() []cmp.Option { + return []cmp.Option{ + cmpopts.SortSlices(func(x, y event.Label) bool { + return x.Name < y.Name + }), + cmpopts.IgnoreFields(event.Event{}, "At", "ctx", "target", "labels"), + } +} diff --git a/event/export.go b/event/export.go new file mode 100644 index 0000000..5dc7f02 --- /dev/null +++ b/event/export.go @@ -0,0 +1,116 @@ +// Copyright 2019 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. + +//go:build !disable_events + +package event + +import ( + "context" + "sync" + "sync/atomic" + "time" + "unsafe" +) + +// Exporter synchronizes the delivery of events to handlers. +type Exporter struct { + lastEvent uint64 // accessed using atomic, must be 64 bit aligned + opts ExporterOptions + + 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 { + // If non-nil, sets zero Event.At on delivery. + Now func() time.Time + + // Disable some event types, for better performance. + DisableLogging bool + DisableTracing bool + DisableAnnotations bool + DisableMetrics bool + + // Enable automatically setting the event Namespace to the calling package's + // import path. + EnableNamespaces bool +} + +// contextKeyType is used as the key for storing a contextValue on the context. +type contextKeyType struct{} + +var contextKey interface{} = contextKeyType{} + +var ( + defaultTarget unsafe.Pointer +) + +// NewExporter creates an Exporter using the supplied handler and options. +// Event delivery is serialized to enable safe atomic handling. +func NewExporter(handler Handler, opts *ExporterOptions) *Exporter { + if handler == nil { + panic("handler must not be nil") + } + e := &Exporter{ + handler: handler, + sources: newCallers(), + } + if opts != nil { + e.opts = *opts + } + if e.opts.Now == nil { + e.opts.Now = time.Now + } + return e +} + +func setDefaultExporter(e *Exporter) { + atomic.StorePointer(&defaultTarget, unsafe.Pointer(&target{exporter: e})) +} + +func getDefaultTarget() *target { + return (*target)(atomic.LoadPointer(&defaultTarget)) +} + +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 context.WithValue(ctx, contextKey, t) +} + +// prepare events before delivering to the underlying handler. +// 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. +func (ev *Event) prepare() { + e := ev.target.exporter + if ev.ID == 0 { + ev.ID = atomic.AddUint64(&e.lastEvent, 1) + } + if e.opts.Now != nil && ev.At.IsZero() { + ev.At = e.opts.Now() + } + if e.opts.EnableNamespaces && ev.Source.Space == "" { + ev.Source = e.sources.scanStack() + } +} + +func (e *Exporter) loggingEnabled() bool { return !e.opts.DisableLogging } +func (e *Exporter) annotationsEnabled() bool { return !e.opts.DisableAnnotations } +func (e *Exporter) tracingEnabled() bool { return !e.opts.DisableTracing } +func (e *Exporter) metricsEnabled() bool { return !e.opts.DisableMetrics } diff --git a/event/go.mod b/event/go.mod new file mode 100644 index 0000000..c96b707 --- /dev/null +++ b/event/go.mod @@ -0,0 +1,27 @@ +module golang.org/x/exp/event + +go 1.18 + +require ( + github.com/go-kit/kit v0.12.0 + github.com/go-logr/logr v1.2.2 + github.com/google/go-cmp v0.5.7 + github.com/rs/zerolog v1.26.1 + github.com/sirupsen/logrus v1.8.1 + go.opentelemetry.io/otel v1.4.0 + go.opentelemetry.io/otel/metric v0.27.0 + go.opentelemetry.io/otel/sdk v1.4.0 + go.opentelemetry.io/otel/trace v1.4.0 + go.uber.org/zap v1.21.0 +) + +require ( + github.com/go-kit/log v0.2.0 // indirect + github.com/go-logfmt/logfmt v0.5.1 // indirect + github.com/go-logr/stdr v1.2.2 // indirect + go.opentelemetry.io/otel/internal/metric v0.27.0 // indirect + go.uber.org/atomic v1.9.0 // indirect + go.uber.org/multierr v1.7.0 // indirect + golang.org/x/sys v0.11.0 // indirect + golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect +) diff --git a/event/go.sum b/event/go.sum new file mode 100644 index 0000000..77dda10 --- /dev/null +++ b/event/go.sum @@ -0,0 +1,104 @@ +github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8= +github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= +github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/go-kit/kit v0.12.0 h1:e4o3o3IsBfAKQh5Qbbiqyfu97Ku7jrO/JbohvztANh4= +github.com/go-kit/kit v0.12.0/go.mod h1:lHd+EkCZPIwYItmGDDRdhinkzX2A1sj+M9biaEaizzs= +github.com/go-kit/log v0.2.0 h1:7i2K3eKTos3Vc0enKCfnVcgHh2olr/MyfboYq7cAcFw= +github.com/go-kit/log v0.2.0/go.mod h1:NwTd00d/i8cPZ3xOwwiv2PO5MOcx78fFErGNcVmBjv0= +github.com/go-logfmt/logfmt v0.5.1 h1:otpy5pqBCBZ1ng9RQ0dPu4PN7ba75Y/aA+UpowDyNVA= +github.com/go-logfmt/logfmt v0.5.1/go.mod h1:WYhtIu8zTZfxdn5+rREduYbwxfcBr/Vr6KEVveWlfTs= +github.com/go-logr/logr v1.2.2 h1:ahHml/yUpnlb96Rp8HCvtYVPY8ZYpxq3g7UYchIYwbs= +github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= +github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= +github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o= +github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rs/xid v1.3.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.26.1 h1:/ihwxqH+4z8UxyI70wM1z9yCvkWcfz/a3mj48k/Zngc= +github.com/rs/zerolog v1.26.1/go.mod h1:/wSSJWX7lVrsOwlbyTRSOJvqRlc+WjWlfes+CiJ+tmc= +github.com/sirupsen/logrus v1.8.1 h1:dJKuHgqk1NNQlqoA6BTlM1Wf9DOH3NBjQyu0h9+AZZE= +github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= +github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= +github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= +github.com/yuin/goldmark v1.4.0/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= +go.opentelemetry.io/otel v1.4.0 h1:7ESuKPq6zpjRaY5nvVDGiuwK7VAJ8MwkKnmNJ9whNZ4= +go.opentelemetry.io/otel v1.4.0/go.mod h1:jeAqMFKy2uLIxCtKxoFj0FAL5zAPKQagc3+GtBWakzk= +go.opentelemetry.io/otel/internal/metric v0.27.0 h1:9dAVGAfFiiEq5NVB9FUJ5et+btbDQAUIJehJ+ikyryk= +go.opentelemetry.io/otel/internal/metric v0.27.0/go.mod h1:n1CVxRqKqYZtqyTh9U/onvKapPGv7y/rpyOTI+LFNzw= +go.opentelemetry.io/otel/metric v0.27.0 h1:HhJPsGhJoKRSegPQILFbODU56NS/L1UE4fS1sC5kIwQ= +go.opentelemetry.io/otel/metric v0.27.0/go.mod h1:raXDJ7uP2/Jc0nVZWQjJtzoyssOYWu/+pjZqRzfvZ7g= +go.opentelemetry.io/otel/sdk v1.4.0 h1:LJE4SW3jd4lQTESnlpQZcBhQ3oci0U2MLR5uhicfTHQ= +go.opentelemetry.io/otel/sdk v1.4.0/go.mod h1:71GJPNJh4Qju6zJuYl1CrYtXbrgfau/M9UAggqiy1UE= +go.opentelemetry.io/otel/trace v1.4.0 h1:4OOUrPZdVFQkbzl/JSdvGCWIdw5ONXXxzHlaLlWppmo= +go.opentelemetry.io/otel/trace v1.4.0/go.mod h1:uc3eRsqDfWs9R7b92xbQbU42/eTNz4N+gLP8qJCi4aE= +go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE= +go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI= +go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ= +go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= +go.uber.org/multierr v1.7.0 h1:zaiO/rmgFjbmCXdSYJWQcdvOCsthmdaHfr3Gm2Kx4Ec= +go.uber.org/multierr v1.7.0/go.mod h1:7EAYxJLBy9rStEaz58O2t4Uvip6FSURkq8/ppBp95ak= +go.uber.org/zap v1.21.0 h1:WefMeulhovoZ2sYXz7st6K0sLj7bBhpiFaud4r4zST8= +go.uber.org/zap v1.21.0/go.mod h1:wjWOCqI0f2ZZrJF/UufIOkiC8ii6tm1iqIsLo76RfJw= +golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= +golang.org/x/crypto v0.0.0-20211215165025-cf75a172585e/go.mod h1:P+XmwS30IXTQdn5tA2iutPOUgjI07+tq3H3K9MVA1s8= +golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc= +golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= +golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= +golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg= +golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM= +golang.org/x/net v0.0.0-20210805182204-aaa1db679c0d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= +golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.11.0 h1:eG7RXZHdqOJ1i+0lgLgCpSXAp6M3LYlAo6osgSi0xOM= +golang.org/x/sys v0.11.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= +golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= +golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= +golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs= +golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= +golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk= +golang.org/x/tools v0.1.7/go.mod h1:LGqMHiF4EqQNHR1JncWGqT5BVaXmza+X+BDGol+dOxo= +golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE= +golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v2 v2.2.8 h1:obN1ZagJSUGI0Ek/LBmuj4SNLPfIny3KsKFopxRdj10= +gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b h1:h8qDotaEPuJATrMmW04NCwg7v22aHH28wwpauUhK9Oo= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/event/keys/keys.go b/event/keys/keys.go new file mode 100644 index 0000000..b9b7a44 --- /dev/null +++ b/event/keys/keys.go @@ -0,0 +1,198 @@ +// Copyright 2019 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. + +package keys + +import ( + "golang.org/x/exp/event" +) + +// Value represents a key for untyped values. +type Value string + +// From can be used to get a value from a Label. +func (k Value) From(l event.Label) interface{} { return l.Interface() } + +// Of creates a new Label with this key and the supplied value. +func (k Value) Of(v interface{}) event.Label { + return event.Value(string(k), v) +} + +// Tag represents a key for tagging labels that have no value. +// These are used when the existence of the label is the entire information it +// carries, such as marking events to be of a specific kind, or from a specific +// package. +type Tag string + +// New creates a new Label with this key. +func (k Tag) New() event.Label { + return event.Label{Name: string(k)} +} + +// Int represents a key +type Int string + +// Of creates a new Label with this key and the supplied value. +func (k Int) Of(v int) event.Label { + return event.Int64(string(k), int64(v)) +} + +// From can be used to get a value from a Label. +func (k Int) From(l event.Label) int { return int(l.Int64()) } + +// Int8 represents a key +type Int8 string + +// Of creates a new Label with this key and the supplied value. +func (k Int8) Of(v int8) event.Label { + return event.Int64(string(k), int64(v)) +} + +// From can be used to get a value from a Label. +func (k Int8) From(l event.Label) int8 { return int8(l.Int64()) } + +// Int16 represents a key +type Int16 string + +// Of creates a new Label with this key and the supplied value. +func (k Int16) Of(v int16) event.Label { + return event.Int64(string(k), int64(v)) +} + +// From can be used to get a value from a Label. +func (k Int16) From(l event.Label) int16 { return int16(l.Int64()) } + +// Int32 represents a key +type Int32 string + +// Of creates a new Label with this key and the supplied value. +func (k Int32) Of(v int32) event.Label { + return event.Int64(string(k), int64(v)) +} + +// From can be used to get a value from a Label. +func (k Int32) From(l event.Label) int32 { return int32(l.Int64()) } + +// Int64 represents a key +type Int64 string + +// Of creates a new Label with this key and the supplied value. +func (k Int64) Of(v int64) event.Label { + return event.Int64(string(k), v) +} + +// From can be used to get a value from a Label. +func (k Int64) From(l event.Label) int64 { return l.Int64() } + +// UInt represents a key +type UInt string + +// Of creates a new Label with this key and the supplied value. +func (k UInt) Of(v uint) event.Label { + return event.Uint64(string(k), uint64(v)) +} + +// From can be used to get a value from a Label. +func (k UInt) From(l event.Label) uint { return uint(l.Uint64()) } + +// UInt8 represents a key +type UInt8 string + +// Of creates a new Label with this key and the supplied value. +func (k UInt8) Of(v uint8) event.Label { + return event.Uint64(string(k), uint64(v)) +} + +// From can be used to get a value from a Label. +func (k UInt8) From(l event.Label) uint8 { return uint8(l.Uint64()) } + +// UInt16 represents a key +type UInt16 string + +// Of creates a new Label with this key and the supplied value. +func (k UInt16) Of(v uint16) event.Label { + return event.Uint64(string(k), uint64(v)) +} + +// From can be used to get a value from a Label. +func (k UInt16) From(l event.Label) uint16 { return uint16(l.Uint64()) } + +// UInt32 represents a key +type UInt32 string + +// Of creates a new Label with this key and the supplied value. +func (k UInt32) Of(v uint32) event.Label { + return event.Uint64(string(k), uint64(v)) +} + +// From can be used to get a value from a Label. +func (k UInt32) From(l event.Label) uint32 { return uint32(l.Uint64()) } + +// UInt64 represents a key +type UInt64 string + +// Of creates a new Label with this key and the supplied value. +func (k UInt64) Of(v uint64) event.Label { + return event.Uint64(string(k), v) +} + +// From can be used to get a value from a Label. +func (k UInt64) From(l event.Label) uint64 { return l.Uint64() } + +// Float32 represents a key +type Float32 string + +// Of creates a new Label with this key and the supplied value. +func (k Float32) Of(v float32) event.Label { + return event.Float64(string(k), float64(v)) +} + +// From can be used to get a value from a Label. +func (k Float32) From(l event.Label) float32 { return float32(l.Float64()) } + +// Float64 represents a key +type Float64 string + +// Of creates a new Label with this key and the supplied value. +func (k Float64) Of(v float64) event.Label { + return event.Float64(string(k), v) +} + +// From can be used to get a value from a Label. +func (k Float64) From(l event.Label) float64 { + return l.Float64() +} + +// String represents a key +type String string + +// Of creates a new Label with this key and the supplied value. +func (k String) Of(v string) event.Label { + return event.String(string(k), v) +} + +// From can be used to get a value from a Label. +func (k String) From(l event.Label) string { return l.String() } + +// Bool represents a key +type Bool string + +// Of creates a new Label with this key and the supplied value. +func (k Bool) Of(v bool) event.Label { + return event.Bool(string(k), v) +} + +// From can be used to get a value from a Label. +func (k Bool) From(l event.Label) bool { return l.Bool() } + +// Error represents a key +type Error string + +// Of creates a new Label with this key and the supplied value. +func (k Error) Of(v error) event.Label { + return event.Value(string(k), v) +} + +// From can be used to get a value from a Label. +func (k Error) From(l event.Label) error { return l.Interface().(error) } diff --git a/event/label.go b/event/label.go new file mode 100644 index 0000000..57307cc --- /dev/null +++ b/event/label.go @@ -0,0 +1,272 @@ +// Copyright 2019 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. + +package event + +import ( + "fmt" + "math" + "reflect" + "strconv" + "time" + "unsafe" +) + +// Label is a named value. +type Label struct { + Name string + + packed uint64 + untyped interface{} +} + +// stringptr is used in untyped when the Value is a string +type stringptr unsafe.Pointer + +// bytesptr is used in untyped when the Value is a byte slice +type bytesptr unsafe.Pointer + +// int64Kind is used in untyped when the Value is a signed integer +type int64Kind struct{} + +// uint64Kind is used in untyped when the Value is an unsigned integer +type uint64Kind struct{} + +// float64Kind is used in untyped when the Value is a floating point number +type float64Kind struct{} + +// boolKind is used in untyped when the Value is a boolean +type boolKind struct{} + +// durationKind is used in untyped when the Value is a time.Duration +type durationKind struct{} + +// HasValue returns true if the value is set to any type. +func (l Label) HasValue() bool { return l.untyped != nil } + +// Equal reports whether two labels are equal. +func (l Label) Equal(l2 Label) bool { + if l.Name != l2.Name { + return false + } + if !l.HasValue() { + return !l2.HasValue() + } + if !l2.HasValue() { + return false + } + switch { + case l.IsString(): + return l2.IsString() && l.String() == l2.String() + case l.IsInt64(): + return l2.IsInt64() && l.packed == l2.packed + case l.IsUint64(): + return l2.IsUint64() && l.packed == l2.packed + case l.IsFloat64(): + return l2.IsFloat64() && l.Float64() == l2.Float64() + case l.IsBool(): + return l2.IsBool() && l.packed == l2.packed + case l.IsDuration(): + return l2.IsDuration() && l.packed == l2.packed + default: + return l.untyped == l2.untyped + } +} + +// Value returns a Label for the supplied value. +func Value(name string, value interface{}) Label { + return Label{Name: name, untyped: value} +} + +// Interface returns the value. +// This will never panic, things that were not set using SetInterface will be +// unpacked and returned anyway. +func (v Label) Interface() interface{} { + switch { + case v.IsString(): + return v.String() + case v.IsInt64(): + return v.Int64() + case v.IsUint64(): + return v.Uint64() + case v.IsFloat64(): + return v.Float64() + case v.IsBool(): + return v.Bool() + case v.IsDuration(): + return v.Duration() + default: + return v.untyped + } +} + +// String returns a new Value for a string. +func String(name string, s string) Label { + hdr := (*reflect.StringHeader)(unsafe.Pointer(&s)) + return Label{Name: name, packed: uint64(hdr.Len), untyped: stringptr(hdr.Data)} +} + +// String returns the value as a string. +// This does not panic if v's Kind is not String, instead, it returns a string +// representation of the value in all cases. +func (v Label) String() string { + if sp, ok := v.untyped.(stringptr); ok { + var s string + hdr := (*reflect.StringHeader)(unsafe.Pointer(&s)) + hdr.Data = uintptr(sp) + hdr.Len = int(v.packed) + return s + } + // not a string, convert to one + switch { + case v.IsInt64(): + return strconv.FormatInt(v.Int64(), 10) + case v.IsUint64(): + return strconv.FormatUint(v.Uint64(), 10) + case v.IsFloat64(): + return strconv.FormatFloat(v.Float64(), 'g', -1, 64) + case v.IsBool(): + if v.Bool() { + return "true" + } else { + return "false" + } + default: + return fmt.Sprint(v.Interface()) + } +} + +// IsString returns true if the value was built with StringOf. +func (v Label) IsString() bool { + _, ok := v.untyped.(stringptr) + return ok +} + +// Bytes returns a new Value for a string. +func Bytes(name string, data []byte) Label { + hdr := (*reflect.SliceHeader)(unsafe.Pointer(&data)) + return Label{Name: name, packed: uint64(hdr.Len), untyped: bytesptr(hdr.Data)} +} + +// Bytes returns the value as a bytes array. +func (v Label) Bytes() []byte { + bp, ok := v.untyped.(bytesptr) + if !ok { + panic("Bytes called on non []byte value") + } + var buf []byte + hdr := (*reflect.SliceHeader)(unsafe.Pointer(&buf)) + hdr.Data = uintptr(bp) + hdr.Len = int(v.packed) + hdr.Cap = hdr.Len + return buf +} + +// IsBytes returns true if the value was built with BytesOf. +func (v Label) IsBytes() bool { + _, ok := v.untyped.(bytesptr) + return ok +} + +// Int64 returns a new Value for a signed integer. +func Int64(name string, u int64) Label { + return Label{Name: name, packed: uint64(u), untyped: int64Kind{}} +} + +// Int64 returns the int64 from a value that was set with SetInt64. +// It will panic for any value for which IsInt64 is not true. +func (v Label) Int64() int64 { + if !v.IsInt64() { + panic("Int64 called on non int64 value") + } + return int64(v.packed) +} + +// IsInt64 returns true if the value was built with SetInt64. +func (v Label) IsInt64() bool { + _, ok := v.untyped.(int64Kind) + return ok +} + +// Uint64 returns a new Value for an unsigned integer. +func Uint64(name string, u uint64) Label { + return Label{Name: name, packed: u, untyped: uint64Kind{}} +} + +// Uint64 returns the uint64 from a value that was set with SetUint64. +// It will panic for any value for which IsUint64 is not true. +func (v Label) Uint64() uint64 { + if !v.IsUint64() { + panic("Uint64 called on non uint64 value") + } + return v.packed +} + +// IsUint64 returns true if the value was built with SetUint64. +func (v Label) IsUint64() bool { + _, ok := v.untyped.(uint64Kind) + return ok +} + +// Float64 returns a new Value for a floating point number. +func Float64(name string, f float64) Label { + return Label{Name: name, packed: math.Float64bits(f), untyped: float64Kind{}} +} + +// Float64 returns the float64 from a value that was set with SetFloat64. +// It will panic for any value for which IsFloat64 is not true. +func (v Label) Float64() float64 { + if !v.IsFloat64() { + panic("Float64 called on non float64 value") + } + return math.Float64frombits(v.packed) +} + +// IsFloat64 returns true if the value was built with SetFloat64. +func (v Label) IsFloat64() bool { + _, ok := v.untyped.(float64Kind) + return ok +} + +// Bool returns a new Value for a bool. +func Bool(name string, b bool) Label { + if b { + return Label{Name: name, packed: 1, untyped: boolKind{}} + } + return Label{Name: name, packed: 0, untyped: boolKind{}} +} + +// Bool returns the bool from a value that was set with SetBool. +// It will panic for any value for which IsBool is not true. +func (v Label) Bool() bool { + if !v.IsBool() { + panic("Bool called on non bool value") + } + if v.packed != 0 { + return true + } + return false +} + +// IsBool returns true if the value was built with SetBool. +func (v Label) IsBool() bool { + _, ok := v.untyped.(boolKind) + return ok +} + +func Duration(name string, d time.Duration) Label { + return Label{Name: name, packed: uint64(d), untyped: durationKind{}} +} + +func (v Label) Duration() time.Duration { + if !v.IsDuration() { + panic("Duration called on non-Duration value") + } + return time.Duration(v.packed) +} + +func (v Label) IsDuration() bool { + _, ok := v.untyped.(durationKind) + return ok +} diff --git a/event/label_test.go b/event/label_test.go new file mode 100644 index 0000000..0bf3ae1 --- /dev/null +++ b/event/label_test.go @@ -0,0 +1,152 @@ +// Copyright 2021 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. + +package event_test + +import ( + "testing" + "time" + + "golang.org/x/exp/event" +) + +func TestOfAs(t *testing.T) { + const i = 3 + var v event.Label + v = event.Int64("key", i) + if got := v.Int64(); got != i { + t.Errorf("got %v, want %v", got, i) + } + v = event.Uint64("key", i) + if got := v.Uint64(); got != i { + t.Errorf("got %v, want %v", got, i) + } + v = event.Float64("key", i) + if got := v.Float64(); got != i { + t.Errorf("got %v, want %v", got, i) + } + v = event.Bool("key", true) + if got := v.Bool(); got != true { + t.Errorf("got %v, want %v", got, true) + } + const s = "foo" + v = event.String("key", s) + if got := v.String(); got != s { + t.Errorf("got %v, want %v", got, s) + } + v = event.Bytes("key", []byte(s)) + if got := v.Bytes(); string(got) != s { + t.Errorf("got %v, want %v", got, s) + } + tm := time.Now() + v = event.Value("key", tm) + if got := v.Interface(); got != tm { + t.Errorf("got %v, want %v", got, tm) + } + var vnil event.Label + if got := vnil.Interface(); got != nil { + t.Errorf("got %v, want nil", got) + } +} + +func TestEqual(t *testing.T) { + var x, y int + vals := []event.Label{ + {}, + event.Int64("key", 1), + event.Int64("key", 2), + event.Uint64("key", 3), + event.Uint64("key", 4), + event.Float64("key", 3.5), + event.Float64("key", 3.7), + event.Bool("key", true), + event.Bool("key", false), + event.Value("key", &x), + event.Value("key", &y), + } + for i, v1 := range vals { + for j, v2 := range vals { + got := v1.Equal(v2) + want := i == j + if got != want { + t.Errorf("%v.Equal(%v): got %t, want %t", v1, v2, got, want) + } + } + } +} + +func panics(f func()) (b bool) { + defer func() { + if x := recover(); x != nil { + b = true + } + }() + f() + return false +} + +func TestPanics(t *testing.T) { + for _, test := range []struct { + name string + f func() + }{ + {"int64", func() { event.Float64("key", 3).Int64() }}, + {"uint64", func() { event.Int64("key", 3).Uint64() }}, + {"float64", func() { event.Uint64("key", 3).Float64() }}, + {"bool", func() { event.Int64("key", 3).Bool() }}, + {"duration", func() { event.Value("key", "value").Duration() }}, + {"bytes", func() { event.String("key", "value").Bytes() }}, + } { + if !panics(test.f) { + t.Errorf("%s: got no panic, want panic", test.name) + } + } +} + +func TestString(t *testing.T) { + for _, test := range []struct { + v event.Label + want string + }{ + {event.Int64("key", -3), "-3"}, + {event.Uint64("key", 3), "3"}, + {event.Float64("key", .15), "0.15"}, + {event.Bool("key", true), "true"}, + {event.String("key", "foo"), "foo"}, + {event.Value("key", time.Duration(3*time.Second)), "3s"}, + } { + if got := test.v.String(); got != test.want { + t.Errorf("%#v: got %q, want %q", test.v, got, test.want) + } + } +} + +func TestNoAlloc(t *testing.T) { + // Assign values just to make sure the compiler doesn't optimize away the statements. + var ( + i int64 + u uint64 + f float64 + b bool + s string + x interface{} + p = &i + ) + a := int(testing.AllocsPerRun(5, func() { + i = event.Int64("key", 1).Int64() + u = event.Uint64("key", 1).Uint64() + f = event.Float64("key", 1).Float64() + b = event.Bool("key", true).Bool() + s = event.String("key", "foo").String() + x = event.Value("key", p).Interface() + })) + if a != 0 { + t.Errorf("got %d allocs, want zero", a) + } + _ = u + _ = f + _ = b + _ = s + _ = x +} diff --git a/event/metric.go b/event/metric.go new file mode 100644 index 0000000..e74689e --- /dev/null +++ b/event/metric.go @@ -0,0 +1,158 @@ +// Copyright 2021 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. + +package event + +import ( + "context" + "time" +) + +// A Unit is a unit of measurement for a metric. +type Unit string + +const ( + UnitDimensionless Unit = "1" + UnitBytes Unit = "By" + UnitMilliseconds Unit = "ms" +) + +// A Metric represents a kind of recorded measurement. +type Metric interface { + Name() string + Options() MetricOptions +} + +type MetricOptions struct { + // A string that should be common for all metrics of an application or + // service. Defaults to the import path of the package calling + // the metric construction function (NewCounter, etc.). + Namespace string + + // Optional description of the metric. + Description string + + // Optional unit for the metric. Defaults to UnitDimensionless. + Unit Unit +} + +// A Counter is a metric that counts something cumulatively. +type Counter struct { + name string + opts MetricOptions +} + +func initOpts(popts *MetricOptions) MetricOptions { + var opts MetricOptions + if popts != nil { + opts = *popts + } + if opts.Namespace == "" { + opts.Namespace = scanStack().Space + } + if opts.Unit == "" { + opts.Unit = UnitDimensionless + } + return opts +} + +// NewCounter creates a counter with the given name. +func NewCounter(name string, opts *MetricOptions) *Counter { + return &Counter{name, initOpts(opts)} +} + +func (c *Counter) Name() string { return c.name } +func (c *Counter) Options() MetricOptions { return c.opts } + +// Record delivers a metric event with the given metric, value and labels to the +// exporter in the context. +func (c *Counter) Record(ctx context.Context, v int64, labels ...Label) { + ev := New(ctx, MetricKind) + if ev != nil { + record(ev, c, Int64(string(MetricVal), v)) + ev.Labels = append(ev.Labels, labels...) + ev.Deliver() + } +} + +// A FloatGauge records a single floating-point value that may go up or down. +// TODO(generics): Gauge[T] +type FloatGauge struct { + name string + opts MetricOptions +} + +// NewFloatGauge creates a new FloatGauge with the given name. +func NewFloatGauge(name string, opts *MetricOptions) *FloatGauge { + return &FloatGauge{name, initOpts(opts)} +} + +func (g *FloatGauge) Name() string { return g.name } +func (g *FloatGauge) Options() MetricOptions { return g.opts } + +// Record converts its argument into a Value and returns a MetricValue with the +// receiver and the value. +func (g *FloatGauge) Record(ctx context.Context, v float64, labels ...Label) { + ev := New(ctx, MetricKind) + if ev != nil { + record(ev, g, Float64(string(MetricVal), v)) + ev.Labels = append(ev.Labels, labels...) + ev.Deliver() + } +} + +// A DurationDistribution records a distribution of durations. +// TODO(generics): Distribution[T] +type DurationDistribution struct { + name string + opts MetricOptions +} + +// NewDuration creates a new Duration with the given name. +func NewDuration(name string, opts *MetricOptions) *DurationDistribution { + return &DurationDistribution{name, initOpts(opts)} +} + +func (d *DurationDistribution) Name() string { return d.name } +func (d *DurationDistribution) Options() MetricOptions { return d.opts } + +// Record converts its argument into a Value and returns a MetricValue with the +// receiver and the value. +func (d *DurationDistribution) Record(ctx context.Context, v time.Duration, labels ...Label) { + ev := New(ctx, MetricKind) + if ev != nil { + record(ev, d, Duration(string(MetricVal), v)) + ev.Labels = append(ev.Labels, labels...) + ev.Deliver() + } +} + +// An IntDistribution records a distribution of int64s. +type IntDistribution struct { + name string + opts MetricOptions +} + +func (d *IntDistribution) Name() string { return d.name } +func (d *IntDistribution) Options() MetricOptions { return d.opts } + +// NewIntDistribution creates a new IntDistribution with the given name. +func NewIntDistribution(name string, opts *MetricOptions) *IntDistribution { + return &IntDistribution{name, initOpts(opts)} +} + +// Record converts its argument into a Value and returns a MetricValue with the +// receiver and the value. +func (d *IntDistribution) Record(ctx context.Context, v int64, labels ...Label) { + ev := New(ctx, MetricKind) + if ev != nil { + record(ev, d, Int64(string(MetricVal), v)) + ev.Labels = append(ev.Labels, labels...) + ev.Deliver() + } +} + +func record(ev *Event, m Metric, l Label) { + ev.Labels = append(ev.Labels, l, MetricKey.Of(m)) +} diff --git a/event/otel/metric.go b/event/otel/metric.go new file mode 100644 index 0000000..910cc94 --- /dev/null +++ b/event/otel/metric.go @@ -0,0 +1,131 @@ +// Copyright 2022 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. + +package otel + +import ( + "context" + "errors" + "fmt" + "sync" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/metric" + otelunit "go.opentelemetry.io/otel/metric/unit" + "golang.org/x/exp/event" +) + +// MetricHandler is an event.Handler for OpenTelemetry metrics. +// Its Event method handles Metric events and ignores all others. +type MetricHandler struct { + meter metric.MeterMust + mu sync.Mutex + // A map from event.Metrics to, effectively, otel Meters. + // But since the only thing we need from the Meter is recording a value, we + // use a function for that that closes over the Meter itself. + recordFuncs map[event.Metric]recordFunc +} + +type recordFunc func(context.Context, event.Label, []attribute.KeyValue) + +var _ event.Handler = (*MetricHandler)(nil) + +// NewMetricHandler creates a new MetricHandler. +func NewMetricHandler(m metric.Meter) *MetricHandler { + return &MetricHandler{ + meter: metric.Must(m), + recordFuncs: map[event.Metric]recordFunc{}, + } +} + +func (m *MetricHandler) Event(ctx context.Context, e *event.Event) context.Context { + if e.Kind != event.MetricKind { + return ctx + } + // Get the otel instrument corresponding to the event's MetricDescriptor, + // or create a new one. + mi, ok := event.MetricKey.Find(e) + if !ok { + panic(errors.New("no metric key for metric event")) + } + em := mi.(event.Metric) + lval := e.Find(event.MetricVal) + if !lval.HasValue() { + panic(errors.New("no metric value for metric event")) + } + rf := m.getRecordFunc(em) + if rf == nil { + panic(fmt.Errorf("unable to record for metric %v", em)) + } + rf(ctx, lval, labelsToAttributes(e.Labels)) + return ctx +} + +func (m *MetricHandler) getRecordFunc(em event.Metric) recordFunc { + m.mu.Lock() + defer m.mu.Unlock() + if f, ok := m.recordFuncs[em]; ok { + return f + } + f := m.newRecordFunc(em) + m.recordFuncs[em] = f + return f +} + +func (m *MetricHandler) newRecordFunc(em event.Metric) recordFunc { + opts := em.Options() + name := opts.Namespace + "/" + em.Name() + otelOpts := []metric.InstrumentOption{ + metric.WithDescription(opts.Description), + metric.WithUnit(otelunit.Unit(opts.Unit)), // cast OK: same strings + } + switch em.(type) { + case *event.Counter: + c := m.meter.NewInt64Counter(name, otelOpts...) + return func(ctx context.Context, l event.Label, attrs []attribute.KeyValue) { + c.Add(ctx, l.Int64(), attrs...) + } + + case *event.FloatGauge: + g := m.meter.NewFloat64UpDownCounter(name, otelOpts...) + return func(ctx context.Context, l event.Label, attrs []attribute.KeyValue) { + g.Add(ctx, l.Float64(), attrs...) + } + + case *event.DurationDistribution: + r := m.meter.NewInt64Histogram(name, otelOpts...) + return func(ctx context.Context, l event.Label, attrs []attribute.KeyValue) { + r.Record(ctx, l.Duration().Nanoseconds(), attrs...) + } + + default: + return nil + } +} + +func labelsToAttributes(ls []event.Label) []attribute.KeyValue { + var attrs []attribute.KeyValue + for _, l := range ls { + if l.Name == string(event.MetricKey) || l.Name == string(event.MetricVal) { + continue + } + attrs = append(attrs, labelToAttribute(l)) + } + return attrs +} + +func labelToAttribute(l event.Label) attribute.KeyValue { + switch { + case l.IsString(): + return attribute.String(l.Name, l.String()) + case l.IsInt64(): + return attribute.Int64(l.Name, l.Int64()) + case l.IsFloat64(): + return attribute.Float64(l.Name, l.Float64()) + case l.IsBool(): + return attribute.Bool(l.Name, l.Bool()) + default: // including uint64 + panic(fmt.Errorf("cannot convert label value of type %T to attribute.KeyValue", l.Interface())) + } +} diff --git a/event/otel/metric_test.go b/event/otel/metric_test.go new file mode 100644 index 0000000..300f4a7 --- /dev/null +++ b/event/otel/metric_test.go @@ -0,0 +1,75 @@ +// Copyright 2021 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. + +package otel_test + +import ( + "context" + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/metric/metrictest" + "go.opentelemetry.io/otel/metric/number" + "golang.org/x/exp/event" + "golang.org/x/exp/event/otel" +) + +func TestMeter(t *testing.T) { + ctx := context.Background() + mp := metrictest.NewMeterProvider() + mh := otel.NewMetricHandler(mp.Meter("test")) + ctx = event.WithExporter(ctx, event.NewExporter(mh, nil)) + recordMetrics(ctx) + + lib := metrictest.Library{InstrumentationName: "test"} + emptyLabels := map[attribute.Key]attribute.Value{} + got := metrictest.AsStructs(mp.MeasurementBatches) + want := []metrictest.Measured{ + { + Name: "golang.org/x/exp/event/otel_test/hits", + Number: number.NewInt64Number(8), + Labels: emptyLabels, + Library: lib, + }, + { + Name: "golang.org/x/exp/event/otel_test/temp", + Number: number.NewFloat64Number(-100), + Labels: map[attribute.Key]attribute.Value{"location": attribute.StringValue("Mare Imbrium")}, + Library: lib, + }, + { + Name: "golang.org/x/exp/event/otel_test/latency", + Number: number.NewInt64Number(int64(1248 * time.Millisecond)), + Labels: emptyLabels, + Library: lib, + }, + { + Name: "golang.org/x/exp/event/otel_test/latency", + Number: number.NewInt64Number(int64(1255 * time.Millisecond)), + Labels: emptyLabels, + Library: lib, + }, + } + + if diff := cmp.Diff(want, got, cmp.Comparer(valuesEqual)); diff != "" { + t.Errorf("mismatch (-want, got):\n%s", diff) + } +} + +func valuesEqual(v1, v2 attribute.Value) bool { + return v1.AsInterface() == v2.AsInterface() +} + +func recordMetrics(ctx context.Context) { + c := event.NewCounter("hits", &event.MetricOptions{Description: "Earth meteorite hits"}) + g := event.NewFloatGauge("temp", &event.MetricOptions{Description: "moon surface temperature in Kelvin"}) + d := event.NewDuration("latency", &event.MetricOptions{Description: "Earth-moon comms lag, milliseconds"}) + + c.Record(ctx, 8) + g.Record(ctx, -100, event.String("location", "Mare Imbrium")) + d.Record(ctx, 1248*time.Millisecond) + d.Record(ctx, 1255*time.Millisecond) +} diff --git a/event/otel/trace.go b/event/otel/trace.go new file mode 100644 index 0000000..67fbe29 --- /dev/null +++ b/event/otel/trace.go @@ -0,0 +1,58 @@ +// Copyright 2021 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. + +package otel + +import ( + "context" + + "go.opentelemetry.io/otel/trace" + "golang.org/x/exp/event" +) + +type TraceHandler struct { + tracer trace.Tracer +} + +func NewTraceHandler(t trace.Tracer) *TraceHandler { + return &TraceHandler{tracer: t} +} + +type spanKey struct{} + +func (t *TraceHandler) Event(ctx context.Context, ev *event.Event) context.Context { + switch ev.Kind { + case event.StartKind: + name, opts := labelsToSpanStartOptions(ev.Labels) + octx, span := t.tracer.Start(ctx, 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 + } +} + +func labelsToSpanStartOptions(ls []event.Label) (string, []trace.SpanStartOption) { + var opts []trace.SpanStartOption + var name string + for _, l := range ls { + switch l.Name { + case "link": + opts = append(opts, trace.WithLinks(l.Interface().(trace.Link))) + case "newRoot": + opts = append(opts, trace.WithNewRoot()) + case "spanKind": + opts = append(opts, trace.WithSpanKind(l.Interface().(trace.SpanKind))) + case "name": + name = l.String() + } + } + return name, opts +} diff --git a/event/otel/trace_test.go b/event/otel/trace_test.go new file mode 100644 index 0000000..81d369f --- /dev/null +++ b/event/otel/trace_test.go @@ -0,0 +1,159 @@ +// Copyright 2021 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. + +//go:build !disable_events + +package otel_test + +import ( + "bytes" + "context" + "fmt" + "io" + "testing" + + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/trace" + "golang.org/x/exp/event" + "golang.org/x/exp/event/otel" +) + +func TestTrace(t *testing.T) { + // Verify that otel and event traces work well together. + // This test uses a single, fixed span tree (see makeTraceSpec). + // Each test case varies which of the individual spans are + // created directly from an otel tracer, and which are created + // using the event package. + + want := "root (f (g h) p (q r))" + + for i, tfunc := range []func(int) bool{ + func(int) bool { return true }, + func(int) bool { return false }, + func(i int) bool { return i%2 == 0 }, + func(i int) bool { return i%2 == 1 }, + func(i int) bool { return i%3 == 0 }, + func(i int) bool { return i%3 == 1 }, + } { + ctx, tr, shutdown := setupOtel() + // There are 7 spans, so we create a 7-element slice. + // tfunc determines, for each index, whether it holds + // an otel tracer or nil. + tracers := make([]trace.Tracer, 7) + for i := 0; i < len(tracers); i++ { + if tfunc(i) { + tracers[i] = tr + } + } + s := makeTraceSpec(tracers) + s.apply(ctx) + got := shutdown() + if got != want { + t.Errorf("#%d: got %v, want %v", i, got, want) + } + } +} + +func makeTraceSpec(tracers []trace.Tracer) *traceSpec { + return &traceSpec{ + name: "root", + tracer: tracers[0], + children: []*traceSpec{ + { + name: "f", + tracer: tracers[1], + children: []*traceSpec{ + {name: "g", tracer: tracers[2]}, + {name: "h", tracer: tracers[3]}, + }, + }, + { + name: "p", + tracer: tracers[4], + children: []*traceSpec{ + {name: "q", tracer: tracers[5]}, + {name: "r", tracer: tracers[6]}, + }, + }, + }, + } +} + +type traceSpec struct { + name string + tracer trace.Tracer // nil for event + children []*traceSpec +} + +// apply builds spans for the traceSpec and all its children, +// If the traceSpec has a non-nil tracer, it is used to create the span. +// Otherwise, event.Trace.Start is used. +func (s *traceSpec) apply(ctx context.Context) { + if s.tracer != nil { + var span trace.Span + ctx, span = s.tracer.Start(ctx, s.name) + defer span.End() + } else { + ctx = event.Start(ctx, s.name) + defer event.End(ctx) + } + for _, c := range s.children { + c.apply(ctx) + } +} + +func setupOtel() (context.Context, trace.Tracer, func() string) { + ctx := context.Background() + e := newTestExporter() + bsp := sdktrace.NewSimpleSpanProcessor(e) + stp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(bsp)) + tracer := stp.Tracer("") + + ee := event.NewExporter(otel.NewTraceHandler(tracer), nil) + ctx = event.WithExporter(ctx, ee) + return ctx, tracer, func() string { stp.Shutdown(ctx); return e.got } +} + +// testExporter is an otel exporter for traces +type testExporter struct { + m map[trace.SpanID][]sdktrace.ReadOnlySpan // key is parent SpanID + got string +} + +var _ sdktrace.SpanExporter = (*testExporter)(nil) + +func newTestExporter() *testExporter { + return &testExporter{m: map[trace.SpanID][]sdktrace.ReadOnlySpan{}} +} + +func (e *testExporter) ExportSpans(ctx context.Context, ss []sdktrace.ReadOnlySpan) error { + for _, s := range ss { + sid := s.Parent().SpanID() + e.m[sid] = append(e.m[sid], s) + } + return nil +} + +func (e *testExporter) Shutdown(ctx context.Context) error { + root := e.m[trace.SpanID{}][0] + var buf bytes.Buffer + e.print(&buf, root) + e.got = buf.String() + return nil +} + +func (e *testExporter) print(w io.Writer, ss sdktrace.ReadOnlySpan) { + fmt.Fprintf(w, "%s", ss.Name()) + children := e.m[ss.SpanContext().SpanID()] + if len(children) > 0 { + fmt.Fprint(w, " (") + for i, ss := range children { + if i != 0 { + fmt.Fprint(w, " ") + } + e.print(w, ss) + } + fmt.Fprint(w, ")") + } +} diff --git a/event/severity/severity.go b/event/severity/severity.go new file mode 100644 index 0000000..aeae88d --- /dev/null +++ b/event/severity/severity.go @@ -0,0 +1,154 @@ +// 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. + +package severity + +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. +// Smaller numerical values correspond to less severe events (such as debug events), +// larger numerical values correspond to more severe events (such as errors and critical events). +// +// The following table defines the meaning severity levels: +// 1-4 TRACE A fine-grained debugging event. Typically disabled in default configurations. +// 5-8 DEBUG A debugging event. +// 9-12 INFO An informational event. Indicates that an event happened. +// 13-16 WARN A warning event. Not an error but is likely more important than an informational event. +// 17-20 ERROR An error event. Something went wrong. +// 21-24 FATAL A fatal error such as application or system crash. +// +// See https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/logs/data-model.md#severity-fields +// for more details +type Level uint64 + +const ( + Trace = Level(1) + Debug = Level(5) + Info = Level(9) + Warning = Level(13) + Error = Level(17) + Fatal = Level(21) + Max = Level(24) +) + +const Key = "level" + +// Of creates a label for the level. +func (l Level) Label() event.Label { + return event.Value(Key, l) +} + +// From can be used to get a value from a Label. +func From(t event.Label) Level { + return t.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.Labels = append(ev.Labels, event.String("msg", 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.Labels = append(ev.Labels, event.String("msg", fmt.Sprintf(msg, args...))) + ev.Deliver() + } +} + +func (l Level) Class() Level { + switch { + 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 + } +} + +func (l Level) String() string { + switch l { + case 0: + return "invalid" + + case Trace: + return "trace" + case Trace + 1: + return "trace2" + case Trace + 2: + return "trace3" + case Trace + 3: + return "trace4" + + case Debug: + return "debug" + case Debug + 1: + return "debug2" + case Debug + 2: + return "debug3" + case Debug + 3: + return "debug4" + + case Info: + return "info" + case Info + 1: + return "info2" + case Info + 2: + return "info3" + case Info + 3: + return "info4" + + case Warning: + return "warning" + case Warning + 1: + return "warning2" + case Warning + 2: + return "warning3" + case Warning + 3: + return "warning4" + + case Error: + return "error" + case Error + 1: + return "error2" + case Error + 2: + return "error3" + case Error + 3: + return "error4" + + case Fatal: + return "fatal" + case Fatal + 1: + return "fatal2" + case Fatal + 2: + return "fatal3" + case Fatal + 3: + return "fatal4" + default: + return "invalid" + } +} diff --git a/event/severity/severity_test.go b/event/severity/severity_test.go new file mode 100644 index 0000000..b5ca973 --- /dev/null +++ b/event/severity/severity_test.go @@ -0,0 +1,44 @@ +// 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. + +//go:build !disable_events + +package severity_test + +import ( + "context" + "strings" + "testing" + + "golang.org/x/exp/event" + "golang.org/x/exp/event/adapter/logfmt" + "golang.org/x/exp/event/eventtest" + "golang.org/x/exp/event/severity" +) + +func TestPrint(t *testing.T) { + ctx := context.Background() + for _, test := range []struct { + name string + events func(context.Context) + expect string + }{{ + name: "debug", + 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) { severity.Info.Log(ctx, "a message") }, + expect: `time="2020/03/05 14:27:48" level=info msg="a message"`}, + } { + buf := &strings.Builder{} + ctx := event.WithExporter(ctx, event.NewExporter(logfmt.NewHandler(buf), eventtest.ExporterOptions())) + test.events(ctx) + got := strings.TrimSpace(buf.String()) + expect := strings.TrimSpace(test.expect) + if got != expect { + t.Errorf("%s failed\ngot : %q\nexpect: %q", test.name, got, expect) + } + } +} diff --git a/event/source.go b/event/source.go new file mode 100644 index 0000000..3af0bd4 --- /dev/null +++ b/event/source.go @@ -0,0 +1,210 @@ +// Copyright 2019 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. + +//go:build !disable_events + +package event + +import ( + "reflect" + "runtime" + "sort" + "strings" +) + +const ( + // this is the maximum amount of helpers we scan past to find a non helper + helperDepthLimit = 5 +) + +type sources struct { + entries []caller +} + +type Source struct { + Space string + Owner string + Name string +} + +type caller struct { + helper bool + pc uintptr + source Source +} + +var globalCallers chan *sources + +// RegisterHelper records a function as being an event helper that should not +// be used when capturing the source information on events. +// v should be either a string or a function pointer. +// If v is a string it is of the form +// +// Space.Owner.Name +// +// where Owner and Name cannot contain '/' and Name also cannot contain '.' +func RegisterHelper(v interface{}) { + g := <-globalCallers + defer func() { globalCallers <- g }() + switch v := v.(type) { + case string: + g.entries = append(g.entries, caller{source: splitName(v), helper: true}) + default: + g.helperFunction(v) + } +} + +func init() { + g := &sources{} + // make all entries in the event package helpers + globalCallers = make(chan *sources, 1) + globalCallers <- g + RegisterHelper("golang.org/x/exp/event") +} + +func newCallers() sources { + g := <-globalCallers + defer func() { globalCallers <- g }() + c := sources{} + c.entries = make([]caller, len(g.entries)) + copy(c.entries, g.entries) + return c +} + +func (c *sources) addCaller(entry caller) { + i := sort.Search(len(c.entries), func(i int) bool { + return c.entries[i].pc >= entry.pc + }) + if i >= len(c.entries) { + // add to end + c.entries = append(c.entries, entry) + return + } + if c.entries[i].pc == entry.pc { + // already present + return + } + //expand the array + c.entries = append(c.entries, caller{}) + //make a space + copy(c.entries[i+1:], c.entries[i:]) + // insert the entry + c.entries[i] = entry +} + +func (c *sources) getCaller(pc uintptr) (caller, bool) { + i := sort.Search(len(c.entries), func(i int) bool { + return c.entries[i].pc >= pc + }) + if i == len(c.entries) || c.entries[i].pc != pc { + return caller{}, false + } + return c.entries[i], true +} + +func scanStack() Source { + g := <-globalCallers + defer func() { globalCallers <- g }() + return g.scanStack() +} + +func (c *sources) scanStack() Source { + // first capture the caller stack + var stack [helperDepthLimit]uintptr + // we can skip the first three entries + // runtime.Callers + // event.(*sources).scanStack (this function) + // another function in this package (because scanStack is private) + depth := runtime.Callers(3, stack[:]) // start at 2 to skip Callers and this function + // do a cheap first pass to see if we have an entry for this stack + for i := 0; i < depth; i++ { + pc := stack[i] + e, found := c.getCaller(pc) + if found { + if !e.helper { + // exact non helper match match found, return it + return e.source + } + // helper found, keep scanning + continue + } + // stack entry not found, we need to fill one in + f := runtime.FuncForPC(stack[i]) + if f == nil { + // symtab lookup failed, pretend it does not exist + continue + } + e = caller{ + source: splitName(f.Name()), + pc: pc, + } + e.helper = c.isHelper(e) + c.addCaller(e) + if !e.helper { + // found a non helper entry, add it and return it + return e.source + } + } + // ran out of stack, was all helpers + return Source{} +} + +// we do helper matching by name, if the pc matched we would have already found +// that, but helper registration does not know the call stack pcs +func (c *sources) isHelper(entry caller) bool { + // scan to see if it matches any of the helpers + // we match by name in case of inlining + for _, e := range c.entries { + if !e.helper { + // ignore all the non helper entries + continue + } + if isMatch(entry.source.Space, e.source.Space) && + isMatch(entry.source.Owner, e.source.Owner) && + isMatch(entry.source.Name, e.source.Name) { + return true + } + } + return false +} + +func isMatch(value, against string) bool { + return len(against) == 0 || value == against +} + +func (c *sources) helperFunction(v interface{}) { + r := reflect.ValueOf(v) + pc := r.Pointer() + f := runtime.FuncForPC(pc) + entry := caller{ + source: splitName(f.Name()), + pc: f.Entry(), + helper: true, + } + c.addCaller(entry) + if entry.pc != pc { + entry.pc = pc + c.addCaller(entry) + } +} + +func splitName(full string) Source { + // Function is the fully-qualified function name. The name itself may + // have dots (for a closure, for instance), but it can't have slashes. + // So the package path ends at the first dot after the last slash. + entry := Source{Space: full} + slash := strings.LastIndexByte(full, '/') + if slash < 0 { + slash = 0 + } + if dot := strings.IndexByte(full[slash:], '.'); dot >= 0 { + entry.Space = full[:slash+dot] + entry.Name = full[slash+dot+1:] + if dot = strings.LastIndexByte(entry.Name, '.'); dot >= 0 { + entry.Owner = entry.Name[:dot] + entry.Name = entry.Name[dot+1:] + } + } + return entry +} diff --git a/event/source_test.go b/event/source_test.go new file mode 100644 index 0000000..603f23c --- /dev/null +++ b/event/source_test.go @@ -0,0 +1,86 @@ +// Copyright 2021 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. + +package event_test + +import ( + "context" + "testing" + + "golang.org/x/exp/event" + "golang.org/x/exp/event/eventtest" +) + +const thisImportPath = "golang.org/x/exp/event_test" + +func TestNamespace(t *testing.T) { + event.RegisterHelper(testHelperB) + event.RegisterHelper(thisImportPath + ".testHelperC") + h := &eventtest.CaptureHandler{} + opt := eventtest.ExporterOptions() + opt.EnableNamespaces = true + ctx := event.WithExporter(context.Background(), event.NewExporter(h, opt)) + for _, test := range []struct { + name string + do func(context.Context) + expect event.Source + }{{ + name: "simple", + do: testA, + expect: event.Source{Space: thisImportPath, Name: "testA"}, + }, { + name: "pointer helper", + do: testB, + expect: event.Source{Space: thisImportPath, Name: "testB"}, + }, { + name: "named helper", + do: testC, + expect: event.Source{Space: thisImportPath, Name: "testC"}, + }, { + name: "method", + do: testD, + expect: event.Source{Space: thisImportPath, Owner: "tester", Name: "D"}, + }} { + t.Run(test.name, func(t *testing.T) { + h.Got = h.Got[:0] + test.do(ctx) + if len(h.Got) != 1 { + t.Fatalf("Expected 1 event, got %v", len(h.Got)) + } + got := h.Got[0].Source + if got.Space != test.expect.Space { + t.Errorf("got namespace %q, want, %q", got.Space, test.expect.Space) + } + if got.Owner != test.expect.Owner { + t.Errorf("got owner %q, want, %q", got.Owner, test.expect.Owner) + } + if got.Name != test.expect.Name { + t.Errorf("got name %q, want, %q", got.Name, test.expect.Name) + } + }) + } +} + +type tester struct{} + +//go:noinline +func testA(ctx context.Context) { event.Log(ctx, "test A") } + +//go:noinline +func testB(ctx context.Context) { testHelperB(ctx) } + +//go:noinline +func testHelperB(ctx context.Context) { event.Log(ctx, "test B") } + +//go:noinline +func testC(ctx context.Context) { testHelperC(ctx) } + +//go:noinline +func testHelperC(ctx context.Context) { event.Log(ctx, "test C") } + +//go:noinline +func testD(ctx context.Context) { tester{}.D(ctx) } + +//go:noinline +func (tester) D(ctx context.Context) { event.Log(ctx, "test D") } |