From 8f4f7a55ae6ae75a0a479f520929303bcec24139 Mon Sep 17 00:00:00 2001 From: ForrestWeston Date: Wed, 6 Dec 2017 18:31:27 -0800 Subject: [PATCH 1/2] Add Opentracing Spans to event logging Create a span from the provided context for each event. For traces to be created use with [PR 39](https://github.com/ipfs/go-ipfs-cmds/pull/39) in go-ipfs-cmds. Wrap log event in context Needed when event logging on async methods e.g. the method returns a channel or returns before event is complete License: MIT Signed-off-by: ForrestWeston --- log.go | 78 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 77 insertions(+), 1 deletion(-) diff --git a/log.go b/log.go index 740450ca750d..8f56f3763c60 100644 --- a/log.go +++ b/log.go @@ -8,6 +8,10 @@ import ( "encoding/json" "fmt" "time" + + opentrace "github.com/opentracing/opentracing-go" + otExt "github.com/opentracing/opentracing-go/ext" + otl "github.com/opentracing/opentracing-go/log" ) // StandardLogger provides API compatibility with standard printf loggers @@ -48,6 +52,8 @@ type EventLogger interface { Event(ctx context.Context, event string, m ...Loggable) EventBegin(ctx context.Context, event string, m ...Loggable) *EventInProgress + + EventBeginInContext(ctx context.Context, event string, m ...Loggable) context.Context } // Logger retrieves an event logger by name @@ -78,19 +84,52 @@ func (el *eventLogger) EventBegin(ctx context.Context, event string, metadata .. start := time.Now() el.Event(ctx, fmt.Sprintf("%sBegin", event), metadata...) + span, ctx := opentrace.StartSpanFromContext(ctx, event) + eip := &EventInProgress{} eip.doneFunc = func(additional []Loggable) { - metadata = append(metadata, additional...) // anything added during the operation metadata = append(metadata, LoggableMap(map[string]interface{}{ // finally, duration of event "duration": time.Now().Sub(start), })) el.Event(ctx, event, metadata...) + if traceingDisabled() { + return + } + otExt.Component.Set(span, el.system) + for _, m := range metadata { + for l, v := range m.Loggable() { + if l == "error" { + otExt.Error.Set(span, true) + } + f := getOpentracingField(l, v) + span.LogFields(f) + } + } + span.Finish() } return eip } +type activeEventKeyType struct{} + +var activeEventKey = activeEventKeyType{} + +// Stores an event in a context to be finished at a later point +func (el *eventLogger) EventBeginInContext(ctx context.Context, event string, metadata ...Loggable) context.Context { + eip := el.EventBegin(ctx, event, metadata...) + return context.WithValue(ctx, activeEventKey, eip) +} + +// Will complete an event if there is one in ctx +func MaybeFinishEvent(ctx context.Context) { + val := ctx.Value(activeEventKey) + if eip, ok := val.(*EventInProgress); ok { + eip.Done() + } +} + func (el *eventLogger) Event(ctx context.Context, event string, metadata ...Loggable) { // short circuit if theres nothing to write to @@ -172,3 +211,40 @@ func (eip *EventInProgress) Close() error { func FormatRFC3339(t time.Time) string { return t.UTC().Format(time.RFC3339Nano) } + +func getOpentracingField(l string, v interface{}) otl.Field { + var f otl.Field + switch v.(type) { + case bool: + f = otl.Bool(l, v.(bool)) + case string: + f = otl.String(l, v.(string)) + case float32: + f = otl.Float32(l, v.(float32)) + case float64: + f = otl.Float64(l, v.(float64)) + case int: + f = otl.Int(l, v.(int)) + case int32: + f = otl.Int32(l, v.(int32)) + case int64: + f = otl.Int64(l, v.(int64)) + case uint32: + f = otl.Uint32(l, v.(uint32)) + case uint64: + f = otl.Uint64(l, v.(uint64)) + default: + f = otl.Object(l, v) + } + return f +} + +func traceingDisabled() bool { + maybeTracer := opentrace.GlobalTracer() + switch maybeTracer.(type) { + case opentrace.NoopTracer: + return true + default: + return false + } +} From c4ea31a0acafb2a0b2ee04c09901dcda86938acf Mon Sep 17 00:00:00 2001 From: ForrestWeston Date: Tue, 19 Dec 2017 14:38:37 -0800 Subject: [PATCH 2/2] gx publish 1.3.0 License: MIT Signed-off-by: ForrestWeston --- .gx/lastpubver | 2 +- package.json | 8 +++++++- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/.gx/lastpubver b/.gx/lastpubver index c0a35616b589..3603be488c3a 100644 --- a/.gx/lastpubver +++ b/.gx/lastpubver @@ -1 +1 @@ -1.2.0: QmSpJByNKFX1sCsHBEp3R73FL4NF6FnQTEGyNAXHm2GS52 +1.3.0: QmVtpU2ufDFa8VU4eNXRi3YAVMcSpc4ZujHix3m8ZRCP6T diff --git a/package.json b/package.json index ceff11753df1..a01c8fe9b5bf 100644 --- a/package.json +++ b/package.json @@ -9,6 +9,12 @@ "hash": "QmQvJiADDe7JR4m968MwXobTCCzUqQkP87aRHe29MEBGHV", "name": "go-logging", "version": "0.0.0" + }, + { + "author": "forrestweston", + "hash": "QmYdApJEk7WcDz8mhbYrosKKbHxcP5thozoVe6fxaLwoXg", + "name": "opentracing-go", + "version": "0.0.0" } ], "gxVersion": "0.7.0", @@ -16,5 +22,5 @@ "language": "go", "license": "", "name": "go-log", - "version": "1.2.0" + "version": "1.3.0" }