blob: d918bcda545324552bdf1818ffadbd1b6921a5bd [file] [log] [blame]
// Copyright 2020 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
// +build !disable_events
package event_test
import (
"context"
"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", "cache hits")
gauge = event.NewFloatGauge("temperature", "CPU board temperature in Celsius")
latency = event.NewDuration("latency", "how long it took")
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", "")
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 == 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", "")
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()
}
})
*/
})
}
}