internal/telemetry: a faster logging exporter
Moved printing directly inside the exporter,
which yields a massive reduction in allocations.
name old time/op new time/op delta
/Log-8 41.7µs ± 1% 13.6µs ± 2% -67.48%
name old alloc/op new alloc/op delta
/Log-8 20.9kB ± 0% 3.6kB ± 0% -82.86%
name old allocs/op new allocs/op delta
/Log-8 286 ± 0% 16 ± 0% -94.41%
Change-Id: Ieafd644683d98d24978c8be061e6632dd8ef113e
Reviewed-on: https://go-review.googlesource.com/c/tools/+/227302
Run-TryBot: Ian Cottrell <iancottrell@google.com>
Reviewed-by: Robert Findley <rfindley@google.com>
Reviewed-by: Emmanuel Odeke <emm.odeke@gmail.com>
diff --git a/internal/telemetry/export/log.go b/internal/telemetry/export/log.go
index 2458022..f5278ed 100644
--- a/internal/telemetry/export/log.go
+++ b/internal/telemetry/export/log.go
@@ -8,6 +8,8 @@
"context"
"fmt"
"io"
+ "strconv"
+ "sync"
"golang.org/x/tools/internal/telemetry/event"
)
@@ -22,6 +24,8 @@
}
type logWriter struct {
+ mu sync.Mutex
+ buffer [128]byte
writer io.Writer
onlyErrors bool
}
@@ -32,7 +36,66 @@
if w.onlyErrors && event.Err.Get(tagMap) == nil {
return ctx
}
- fmt.Fprintf(w.writer, "%v\n", ev)
+ w.mu.Lock()
+ defer w.mu.Unlock()
+
+ buf := w.buffer[:0]
+ if !ev.At.IsZero() {
+ w.writer.Write(ev.At.AppendFormat(buf, "2006/01/02 15:04:05 "))
+ }
+ msg := event.Msg.Get(tagMap)
+ io.WriteString(w.writer, msg)
+ if err := event.Err.Get(tagMap); err != nil {
+ io.WriteString(w.writer, ": ")
+ io.WriteString(w.writer, err.Error())
+ }
+ for index := 0; ev.Valid(index); index++ {
+ tag := ev.Tag(index)
+ if !tag.Valid() || tag.Key == event.Msg || tag.Key == event.Err {
+ continue
+ }
+ io.WriteString(w.writer, "\n\t")
+ io.WriteString(w.writer, tag.Key.Name())
+ io.WriteString(w.writer, "=")
+ switch key := tag.Key.(type) {
+ case *event.IntKey:
+ w.writer.Write(strconv.AppendInt(buf, int64(key.From(tag)), 10))
+ case *event.Int8Key:
+ w.writer.Write(strconv.AppendInt(buf, int64(key.From(tag)), 10))
+ case *event.Int16Key:
+ w.writer.Write(strconv.AppendInt(buf, int64(key.From(tag)), 10))
+ case *event.Int32Key:
+ w.writer.Write(strconv.AppendInt(buf, int64(key.From(tag)), 10))
+ case *event.Int64Key:
+ w.writer.Write(strconv.AppendInt(buf, key.From(tag), 10))
+ case *event.UIntKey:
+ w.writer.Write(strconv.AppendUint(buf, uint64(key.From(tag)), 10))
+ case *event.UInt8Key:
+ w.writer.Write(strconv.AppendUint(buf, uint64(key.From(tag)), 10))
+ case *event.UInt16Key:
+ w.writer.Write(strconv.AppendUint(buf, uint64(key.From(tag)), 10))
+ case *event.UInt32Key:
+ w.writer.Write(strconv.AppendUint(buf, uint64(key.From(tag)), 10))
+ case *event.UInt64Key:
+ w.writer.Write(strconv.AppendUint(buf, key.From(tag), 10))
+ case *event.Float32Key:
+ w.writer.Write(strconv.AppendFloat(buf, float64(key.From(tag)), 'E', -1, 32))
+ case *event.Float64Key:
+ w.writer.Write(strconv.AppendFloat(buf, key.From(tag), 'E', -1, 64))
+ case *event.BooleanKey:
+ w.writer.Write(strconv.AppendBool(buf, key.From(tag)))
+ case *event.StringKey:
+ w.writer.Write(strconv.AppendQuote(buf, key.From(tag)))
+ case *event.ErrorKey:
+ io.WriteString(w.writer, key.From(tag).Error())
+ case *event.ValueKey:
+ fmt.Fprint(w.writer, key.From(tag))
+ default:
+ fmt.Fprintf(w.writer, `"invalid key type %T"`, key)
+ }
+ }
+ io.WriteString(w.writer, "\n")
+
case ev.IsStartSpan():
if span := GetSpan(ctx); span != nil {
fmt.Fprintf(w.writer, "start: %v %v", span.Name, span.ID)
