event: make all the benchmarks consistent, and clean up time handling
Change-Id: If3ffde20cad174c60a01b5ae4e792e35cd963b7f
Reviewed-on: https://go-review.googlesource.com/c/exp/+/327752
Trust: Ian Cottrell <iancottrell@google.com>
Run-TryBot: Ian Cottrell <iancottrell@google.com>
TryBot-Result: Go Bot <gobot@golang.org>
Reviewed-by: Jonathan Amsterdam <jba@google.com>
diff --git a/event/adapter/eventtest/eventtest.go b/event/adapter/eventtest/eventtest.go
index c3f9137..8c1cdce 100644
--- a/event/adapter/eventtest/eventtest.go
+++ b/event/adapter/eventtest/eventtest.go
@@ -58,7 +58,7 @@
}
var InitialTime = func() time.Time {
- t, _ := time.Parse(time.RFC3339Nano, "2020-03-05T14:27:48Z")
+ t, _ := time.Parse(logfmt.TimeFormat, "2020/03/05 14:27:48")
return t
}()
diff --git a/event/adapter/gokit/bench_test.go b/event/adapter/gokit/bench_test.go
new file mode 100644
index 0000000..7d2fb3e
--- /dev/null
+++ b/event/adapter/gokit/bench_test.go
@@ -0,0 +1,72 @@
+// 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/eventtest"
+ "golang.org/x/exp/event/adapter/logfmt"
+ "golang.org/x/exp/event/bench"
+)
+
+var (
+ gokitLog = bench.Hooks{
+ AStart: func(ctx context.Context, a int) context.Context {
+ gokitCtx(ctx).Log(bench.A.Name, a, "msg", bench.A.Msg)
+ return ctx
+ },
+ AEnd: func(ctx context.Context) {},
+ BStart: func(ctx context.Context, b string) context.Context {
+ gokitCtx(ctx).Log(bench.B.Name, b, "msg", bench.B.Msg)
+ return ctx
+ },
+ BEnd: func(ctx context.Context) {},
+ }
+ gokitLogf = bench.Hooks{
+ AStart: func(ctx context.Context, a int) context.Context {
+ gokitCtx(ctx).Log("msg", fmt.Sprintf(bench.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(bench.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) {
+ bench.RunBenchmark(b, gokitPrint(io.Discard), gokitLog)
+}
+
+func BenchmarkGokitLogfDiscard(b *testing.B) {
+ bench.RunBenchmark(b, gokitPrint(io.Discard), gokitLogf)
+}
+
+func TestGokitLogfDiscard(t *testing.T) {
+ bench.TestBenchmark(t, gokitPrint, gokitLogf, bench.LogfOutput)
+}
+func TestLogGokit(t *testing.T) {
+ bench.TestBenchmark(t, gokitPrint, gokitLog, bench.LogfmtOutput)
+}
diff --git a/event/adapter/logfmt/logfmt.go b/event/adapter/logfmt/logfmt.go
index 71aaa49..83102e4 100644
--- a/event/adapter/logfmt/logfmt.go
+++ b/event/adapter/logfmt/logfmt.go
@@ -9,6 +9,8 @@
"fmt"
"io"
"strconv"
+ "unicode"
+ "unicode/utf8"
"golang.org/x/exp/event"
)
@@ -16,6 +18,8 @@
//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 {
buf [bufCap]byte
needSep bool
@@ -54,10 +58,9 @@
}
func (p *Printer) Event(w io.Writer, ev *event.Event) {
- const timeFormat = "2006-01-02T15:04:05"
p.needSep = false
if !ev.At.IsZero() {
- p.label(w, "time", event.BytesOf(ev.At.AppendFormat(p.buf[:0], timeFormat)))
+ p.label(w, "time", event.BytesOf(ev.At.AppendFormat(p.buf[:0], TimeFormat)))
}
if ev.Parent != 0 {
@@ -101,30 +104,24 @@
}
func (p *Printer) Ident(w io.Writer, s string) {
- //TODO: this should also escape = if it occurs in an ident?
p.Quote(w, s)
}
func (p *Printer) Quote(w io.Writer, s string) {
- if s == "" {
- io.WriteString(w, `""`)
- return
- }
- if !needQuote(s) {
+ if !stringNeedQuote(s) {
io.WriteString(w, s)
return
}
- // string needs quoting
io.WriteString(w, `"`)
written := 0
- for o, r := range s {
+ for offset, r := range s {
q := quoteRune(r)
if len(q) == 0 {
continue
}
// write out any prefix
- io.WriteString(w, s[written:o])
- written = o + 1 // we can plus 1 because all runes we escape are ascii
+ io.WriteString(w, s[written:offset])
+ written = offset + utf8.RuneLen(r)
// and write out the quoted rune
io.WriteString(w, q)
}
@@ -134,8 +131,27 @@
// Bytes writes a byte array in string form to the printer.
func (p *Printer) Bytes(w io.Writer, buf []byte) {
- //TODO: non asci chars need escaping
- w.Write(buf)
+ if !bytesNeedQuote(buf) {
+ w.Write(buf)
+ return
+ }
+ 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, `"`)
}
func (p *Printer) label(w io.Writer, name string, value event.Value) {
@@ -153,21 +169,37 @@
}
}
-func needQuote(s string) bool {
+func stringNeedQuote(s string) bool {
+ if len(s) == 0 {
+ return true
+ }
for _, r := range s {
- if len(quoteRune(r)) > 0 {
+ if runeForcesQuote(r) {
return true
}
}
return false
}
+func bytesNeedQuote(buf []byte) bool {
+ for offset := 0; offset < len(buf); {
+ r, size := utf8.DecodeRune(buf[offset:])
+ offset += size
+ if runeForcesQuote(r) {
+ return true
+ }
+ }
+ return false
+}
+
+func runeForcesQuote(r rune) bool {
+ return !unicode.IsLetter(r) && !unicode.IsNumber(r)
+}
+
func quoteRune(r rune) string {
switch r {
case '"':
return `\"`
- case ' ':
- return ` ` // does not change but forces quoting
case '\n':
return `\n`
case '\\':
diff --git a/event/adapter/logrus/bench_test.go b/event/adapter/logrus/bench_test.go
index 51eb0ee..ce741ff 100644
--- a/event/adapter/logrus/bench_test.go
+++ b/event/adapter/logrus/bench_test.go
@@ -84,22 +84,5 @@
}
func TestLogrusf(t *testing.T) {
- bench.TestBenchmark(t, logrusPrint, logrusLogf, `
-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\""
-`)
+ bench.TestBenchmark(t, logrusPrint, logrusLogf, bench.LogfOutput)
}
diff --git a/event/adapter/zap/bench_test.go b/event/adapter/zap/bench_test.go
index bbad9c8..85b8050 100644
--- a/event/adapter/zap/bench_test.go
+++ b/event/adapter/zap/bench_test.go
@@ -54,7 +54,7 @@
ec := zap.NewProductionEncoderConfig()
ec.EncodeDuration = zapcore.NanosDurationEncoder
timeEncoder := zapcore.TimeEncoderOfLayout(bench.TimeFormat)
- ec.EncodeTime = func(t time.Time, a zapcore.PrimitiveArrayEncoder) {
+ ec.EncodeTime = func(_ time.Time, a zapcore.PrimitiveArrayEncoder) {
timeEncoder(now(), a)
}
enc := zapcore.NewConsoleEncoder(ec)
@@ -83,7 +83,7 @@
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: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
@@ -103,7 +103,7 @@
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: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}
diff --git a/event/adapter/zerolog/bench_test.go b/event/adapter/zerolog/bench_test.go
index 822100f..3c49770 100644
--- a/event/adapter/zerolog/bench_test.go
+++ b/event/adapter/zerolog/bench_test.go
@@ -66,7 +66,7 @@
{"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: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"}
diff --git a/event/bench/bench.go b/event/bench/bench.go
index 8329ed8..b5151d7 100644
--- a/event/bench/bench.go
+++ b/event/bench/bench.go
@@ -11,6 +11,7 @@
"testing"
"github.com/google/go-cmp/cmp"
+ "golang.org/x/exp/event/adapter/logfmt"
)
type Info struct {
@@ -33,7 +34,7 @@
"Some other value",
"A nice longer value but not too long",
"V",
- "",
+ " ",
"ı",
"prime count of values",
}
@@ -52,7 +53,45 @@
)
const (
- TimeFormat = "2006/01/02 15:04:05"
+ 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 {
diff --git a/event/bench/stdlib_test.go b/event/bench/stdlib_test.go
index 1728208..7b99c74 100644
--- a/event/bench/stdlib_test.go
+++ b/event/bench/stdlib_test.go
@@ -87,9 +87,9 @@
now := eventtest.ExporterOptions().Now
return context.WithValue(context.Background(), writerKey{},
func(msg string, args ...interface{}) {
- fmt.Fprint(w, now().Format(bench.TimeFormat), " ")
- fmt.Fprintf(w, msg, args...)
- fmt.Fprintln(w)
+ fmt.Fprintf(w, "time=%q level=info msg=%q\n",
+ now().Format(bench.TimeFormat),
+ fmt.Sprintf(msg, args...))
},
)
}
@@ -111,7 +111,7 @@
a where A=22
b where B="Some other value"
a where A=333
-b where B=""
+b where B=" "
a where A=4444
b where B="prime count of values"
a where A=55555
@@ -124,22 +124,5 @@
}
func TestLogPrintf(t *testing.T) {
- bench.TestBenchmark(t, stdlibWriter, stdlibPrintf, `
-2020/03/05 14:27:48 a where A=0
-2020/03/05 14:27:49 b where B="A value"
-2020/03/05 14:27:50 a where A=1
-2020/03/05 14:27:51 b where B="Some other value"
-2020/03/05 14:27:52 a where A=22
-2020/03/05 14:27:53 b where B="Some other value"
-2020/03/05 14:27:54 a where A=333
-2020/03/05 14:27:55 b where B=""
-2020/03/05 14:27:56 a where A=4444
-2020/03/05 14:27:57 b where B="prime count of values"
-2020/03/05 14:27:58 a where A=55555
-2020/03/05 14:27:59 b where B="V"
-2020/03/05 14:28:00 a where A=666666
-2020/03/05 14:28:01 b where B="A value"
-2020/03/05 14:28:02 a where A=7777777
-2020/03/05 14:28:03 b where B="A value"
-`)
+ bench.TestBenchmark(t, stdlibWriter, stdlibPrintf, bench.LogfOutput)
}
diff --git a/event/bench_test.go b/event/bench_test.go
index 648eeed..5c00395 100644
--- a/event/bench_test.go
+++ b/event/bench_test.go
@@ -14,6 +14,7 @@
"golang.org/x/exp/event/adapter/logfmt"
"golang.org/x/exp/event/bench"
"golang.org/x/exp/event/keys"
+ "golang.org/x/exp/event/severity"
)
var (
@@ -26,12 +27,12 @@
eventLog = bench.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- event.To(ctx).With(aValue.Of(a)).Log(bench.A.Msg)
+ event.To(ctx).With(severity.Info).With(aValue.Of(a)).Log(bench.A.Msg)
return ctx
},
AEnd: func(ctx context.Context) {},
BStart: func(ctx context.Context, b string) context.Context {
- event.To(ctx).With(bValue.Of(b)).Log(bench.B.Msg)
+ event.To(ctx).With(severity.Info).With(bValue.Of(b)).Log(bench.B.Msg)
return ctx
},
BEnd: func(ctx context.Context) {},
@@ -39,12 +40,12 @@
eventLogf = bench.Hooks{
AStart: func(ctx context.Context, a int) context.Context {
- event.To(ctx).Logf(bench.A.Msgf, a)
+ event.To(ctx).With(severity.Info).Logf(bench.A.Msgf, a)
return ctx
},
AEnd: func(ctx context.Context) {},
BStart: func(ctx context.Context, b string) context.Context {
- event.To(ctx).Logf(bench.B.Msgf, b)
+ event.To(ctx).With(severity.Info).Logf(bench.B.Msgf, b)
return ctx
},
BEnd: func(ctx context.Context) {},
diff --git a/event/event_test.go b/event/event_test.go
index ce4bff9..ca1ffb0 100644
--- a/event/event_test.go
+++ b/event/event_test.go
@@ -38,19 +38,19 @@
}{{
name: "simple",
events: func(ctx context.Context) { event.To(ctx).Log("a message") },
- expect: `time=2020-03-05T14:27:48 msg="a message"
+ expect: `time="2020/03/05 14:27:48" msg="a message"
`}, {
name: "log 1",
events: func(ctx context.Context) { event.To(ctx).With(l1).Log("a message") },
- expect: `time=2020-03-05T14:27:48 l1=1 msg="a message"`,
+ expect: `time="2020/03/05 14:27:48" l1=1 msg="a message"`,
}, {
name: "log 2",
events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).Log("a message") },
- expect: `time=2020-03-05T14:27:48 l1=1 l2=2 msg="a message"`,
+ expect: `time="2020/03/05 14:27:48" l1=1 l2=2 msg="a message"`,
}, {
name: "log 3",
events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).With(l3).Log("a message") },
- expect: `time=2020-03-05T14:27:48 l1=1 l2=2 l3=3 msg="a message"`,
+ expect: `time="2020/03/05 14:27:48" l1=1 l2=2 l3=3 msg="a message"`,
}, {
name: "span",
events: func(ctx context.Context) {
@@ -58,8 +58,8 @@
eb.End()
},
expect: `
-time=2020-03-05T14:27:48 trace=1 name=span
-time=2020-03-05T14:27:49 parent=1 end
+time="2020/03/05 14:27:48" trace=1 name=span
+time="2020/03/05 14:27:49" parent=1 end
`}, {
name: "span nested",
events: func(ctx context.Context) {
@@ -70,33 +70,33 @@
event.To(child).Log("message")
},
expect: `
-time=2020-03-05T14:27:48 trace=1 name=parent
-time=2020-03-05T14:27:49 parent=1 trace=2 name=child
-time=2020-03-05T14:27:50 parent=2 msg=message
-time=2020-03-05T14:27:51 parent=2 end
-time=2020-03-05T14:27:52 parent=1 end
+time="2020/03/05 14:27:48" trace=1 name=parent
+time="2020/03/05 14:27:49" parent=1 trace=2 name=child
+time="2020/03/05 14:27:50" parent=2 msg=message
+time="2020/03/05 14:27:51" parent=2 end
+time="2020/03/05 14:27:52" parent=1 end
`}, {
name: "counter",
events: func(ctx context.Context) { event.To(ctx).With(l1).Metric(counter.Record(2)) },
- expect: `time=2020-03-05T14:27:48 l1=1 metricValue=2 metric=Metric("golang.org/x/exp/event_test/hits")`,
+ expect: `time="2020/03/05 14:27:48" l1=1 metricValue=2 metric=Metric("golang.org/x/exp/event_test/hits")`,
}, {
name: "gauge",
events: func(ctx context.Context) { event.To(ctx).With(l1).Metric(gauge.Record(98.6)) },
- expect: `time=2020-03-05T14:27:48 l1=1 metricValue=98.6 metric=Metric("golang.org/x/exp/event_test/temperature")`,
+ expect: `time="2020/03/05 14:27:48" l1=1 metricValue=98.6 metric=Metric("golang.org/x/exp/event_test/temperature")`,
}, {
name: "duration",
events: func(ctx context.Context) {
event.To(ctx).With(l1).With(l2).Metric(latency.Record(3 * time.Second))
},
- expect: `time=2020-03-05T14:27:48 l1=1 l2=2 metricValue=3s metric=Metric("golang.org/x/exp/event_test/latency")`,
+ expect: `time="2020/03/05 14:27:48" l1=1 l2=2 metricValue=3s metric=Metric("golang.org/x/exp/event_test/latency")`,
}, {
name: "annotate",
events: func(ctx context.Context) { event.To(ctx).With(l1).Annotate() },
- expect: `time=2020-03-05T14:27:48 l1=1`,
+ expect: `time="2020/03/05 14:27:48" l1=1`,
}, {
name: "annotate 2",
events: func(ctx context.Context) { event.To(ctx).With(l1).With(l2).Annotate() },
- expect: `time=2020-03-05T14:27:48 l1=1 l2=2`,
+ expect: `time="2020/03/05 14:27:48" l1=1 l2=2`,
}, {
name: "multiple events",
events: func(ctx context.Context) {
@@ -105,8 +105,8 @@
b.With(keys.String("myString").Of("some string value")).Log("string event")
},
expect: `
-time=2020-03-05T14:27:48 myInt=6 msg="my event"
-time=2020-03-05T14:27:49 myString="some string value" msg="string event"
+time="2020/03/05 14:27:48" myInt=6 msg="my event"
+time="2020/03/05 14:27:49" myString="some string value" msg="string event"
`}} {
buf := &strings.Builder{}
ctx := event.WithExporter(ctx, event.NewExporter(logfmt.NewHandler(buf), eventtest.ExporterOptions()))
@@ -124,48 +124,14 @@
event.To(ctx).With(keys.Int("myInt").Of(6)).Log("my event")
event.To(ctx).With(keys.String("myString").Of("some string value")).Log("error event")
// Output:
- // time=2020-03-05T14:27:48 myInt=6 msg="my event"
- // time=2020-03-05T14:27:49 myString="some string value" msg="error event"
+ // 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) {
- bench.TestBenchmark(t, eventPrint, eventLogf, `
-time=2020-03-05T14:27:48 msg="a where A=0"
-time=2020-03-05T14:27:49 msg="b where B=\"A value\""
-time=2020-03-05T14:27:50 msg="a where A=1"
-time=2020-03-05T14:27:51 msg="b where B=\"Some other value\""
-time=2020-03-05T14:27:52 msg="a where A=22"
-time=2020-03-05T14:27:53 msg="b where B=\"Some other value\""
-time=2020-03-05T14:27:54 msg="a where A=333"
-time=2020-03-05T14:27:55 msg="b where B=\"\""
-time=2020-03-05T14:27:56 msg="a where A=4444"
-time=2020-03-05T14:27:57 msg="b where B=\"prime count of values\""
-time=2020-03-05T14:27:58 msg="a where A=55555"
-time=2020-03-05T14:27:59 msg="b where B=\"V\""
-time=2020-03-05T14:28:00 msg="a where A=666666"
-time=2020-03-05T14:28:01 msg="b where B=\"A value\""
-time=2020-03-05T14:28:02 msg="a where A=7777777"
-time=2020-03-05T14:28:03 msg="b where B=\"A value\""
-`)
+ bench.TestBenchmark(t, eventPrint, eventLogf, bench.LogfOutput)
}
func TestLogEvent(t *testing.T) {
- bench.TestBenchmark(t, eventPrint, eventLog, `
-time=2020-03-05T14:27:48 A=0 msg=a
-time=2020-03-05T14:27:49 B="A value" msg=b
-time=2020-03-05T14:27:50 A=1 msg=a
-time=2020-03-05T14:27:51 B="Some other value" msg=b
-time=2020-03-05T14:27:52 A=22 msg=a
-time=2020-03-05T14:27:53 B="Some other value" msg=b
-time=2020-03-05T14:27:54 A=333 msg=a
-time=2020-03-05T14:27:55 B="" msg=b
-time=2020-03-05T14:27:56 A=4444 msg=a
-time=2020-03-05T14:27:57 B="prime count of values" msg=b
-time=2020-03-05T14:27:58 A=55555 msg=a
-time=2020-03-05T14:27:59 B=V msg=b
-time=2020-03-05T14:28:00 A=666666 msg=a
-time=2020-03-05T14:28:01 B="A value" msg=b
-time=2020-03-05T14:28:02 A=7777777 msg=a
-time=2020-03-05T14:28:03 B="A value" msg=b
-`)
+ bench.TestBenchmark(t, eventPrint, eventLog, bench.LogfmtOutput)
}
diff --git a/event/severity/severity_test.go b/event/severity/severity_test.go
index d4e045c..44a94ee 100644
--- a/event/severity/severity_test.go
+++ b/event/severity/severity_test.go
@@ -27,11 +27,11 @@
}{{
name: "debug",
events: func(ctx context.Context) { event.To(ctx).With(severity.Debug).Log("a message") },
- expect: `time=2020-03-05T14:27:48 level=debug msg="a message"`,
+ expect: `time="2020/03/05 14:27:48" level=debug msg="a message"`,
}, {
name: "info",
events: func(ctx context.Context) { event.To(ctx).With(severity.Info).Log("a message") },
- expect: `time=2020-03-05T14:27:48 level=info msg="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()))
