From 6dc554b7c5af0849885114bab7a0e691d1cf0dc5 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Sun, 7 May 2017 22:40:20 +0200 Subject: [PATCH 1/3] Add ErrorCount to span --- json_span.go | 1 + recorder.go | 1 + span.go | 14 ++++++++++++++ 3 files changed, 16 insertions(+) diff --git a/json_span.go b/json_span.go index d57a913af..f3efa2dcb 100644 --- a/json_span.go +++ b/json_span.go @@ -12,6 +12,7 @@ type jsonSpan struct { Duration uint64 `json:"d"` Name string `json:"n"` From *fromS `json:"f"` + Ec int `json:"ec,omitempty"` Data *jsonData `json:"data"` } diff --git a/recorder.go b/recorder.go index f7aa25e75..8cb3c8daf 100644 --- a/recorder.go +++ b/recorder.go @@ -121,6 +121,7 @@ func (r *Recorder) RecordSpan(span *spanS) { Timestamp: uint64(span.Start.UnixNano()) / uint64(time.Millisecond), Duration: uint64(span.Duration) / uint64(time.Millisecond), Name: "sdk", + Ec: span.Ec, From: sensor.agent.from, Data: data}) diff --git a/span.go b/span.go index f24595ac8..418ab1a53 100644 --- a/span.go +++ b/span.go @@ -22,6 +22,7 @@ type spanS struct { Duration time.Duration Tags ot.Tags Logs []ot.LogRecord + Ec int } func (r *spanS) BaggageItem(key string) string { @@ -109,6 +110,14 @@ func (r *spanS) LogEventWithPayload(event string, payload interface{}) { } func (r *spanS) LogFields(fields ...otlog.Field) { + + for _, v := range fields { + // If this tag indicates an error, increase the error count + if v.Key() == "error" { + r.Ec++ + } + } + lr := ot.LogRecord{ Fields: fields, } @@ -156,6 +165,11 @@ func (r *spanS) SetTag(key string, value interface{}) ot.Span { r.Tags = ot.Tags{} } + // If this tag indicates an error, increase the error count + if key == "error" { + r.Ec++ + } + r.Tags[key] = value return r From 225b54e8edaabec9b5da71fc4ac02149d4dc9fd1 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Sun, 7 May 2017 22:41:06 +0200 Subject: [PATCH 2/3] Add tests to validate error reporting/logging --- span_test.go | 143 +++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 143 insertions(+) diff --git a/span_test.go b/span_test.go index e3b61ad56..eb7f423b3 100644 --- a/span_test.go +++ b/span_test.go @@ -1,6 +1,8 @@ package instana_test import ( + "errors" + "fmt" "testing" "time" @@ -8,6 +10,8 @@ import ( "github.com/instana/golang-sensor" ot "github.com/opentracing/opentracing-go" + ext "github.com/opentracing/opentracing-go/ext" + "github.com/opentracing/opentracing-go/log" ) func TestBasicSpan(t *testing.T) { @@ -101,3 +105,142 @@ func TestSpanTags(t *testing.T) { assert.NotNil(t, span.Data.SDK.Custom.Tags, "Missing Tags") } + +func TestSpanLogFields(t *testing.T) { + const op = "test" + opts := instana.Options{LogLevel: instana.Debug} + recorder := instana.NewTestRecorder() + tracer := instana.NewTracerWithEverything(&opts, recorder) + + span := tracer.StartSpan(op) + span.LogFields( + log.String("event", "soft error"), + log.String("type", "cache timeout"), + log.Int("waited.millis", 1500)) + span.Finish() + + spans := recorder.GetSpans() + assert.Equal(t, len(spans), 1) + firstSpan := spans[0] + + // j, _ := json.MarshalIndent(spans, "", " ") + // fmt.Printf("spans:", bytes.NewBuffer(j)) + + logData := firstSpan.Data.SDK.Custom.Logs + assert.NotNil(t, logData, "Missing logged fields") + assert.Equal(t, 1, len(logData), "Unexpected log count") + + for _, v := range logData { + assert.Equal(t, "soft error", v["event"], "Wrong or missing log") + assert.Equal(t, "cache timeout", v["type"], "Wrong or missing log") + assert.Equal(t, 1500, v["waited.millis"], "Wrong or missing log") + } +} + +func TestSpanLogKVs(t *testing.T) { + const op = "test" + opts := instana.Options{LogLevel: instana.Debug} + recorder := instana.NewTestRecorder() + tracer := instana.NewTracerWithEverything(&opts, recorder) + + span := tracer.StartSpan(op) + span.LogKV( + "event", "soft error", + "type", "cache timeout", + "waited.millis", 1500) + span.Finish() + + spans := recorder.GetSpans() + assert.Equal(t, len(spans), 1) + firstSpan := spans[0] + + // j, _ := json.MarshalIndent(spans, "", " ") + // fmt.Printf("spans:", bytes.NewBuffer(j)) + + logData := firstSpan.Data.SDK.Custom.Logs + assert.NotNil(t, logData, "Missing logged fields") + assert.Equal(t, 1, len(logData), "Unexpected log count") + + for _, v := range logData { + assert.Equal(t, "soft error", v["event"], "Wrong or missing log") + assert.Equal(t, "cache timeout", v["type"], "Wrong or missing log") + assert.Equal(t, 1500, v["waited.millis"], "Wrong or missing log") + } +} + +func TestOTLogError(t *testing.T) { + const op = "test" + opts := instana.Options{LogLevel: instana.Debug} + recorder := instana.NewTestRecorder() + tracer := instana.NewTracerWithEverything(&opts, recorder) + + span := tracer.StartSpan(op) + ext.Error.Set(span, true) + span.Finish() + + spans := recorder.GetSpans() + assert.Equal(t, len(spans), 1) + firstSpan := spans[0] + + logData := firstSpan.Data.SDK.Custom.Logs + tagData := firstSpan.Data.SDK.Custom.Tags + assert.Equal(t, 1, len(tagData), "Unexpected log count") + assert.Equal(t, 1, firstSpan.Ec, "Error count should be 1") + + for _, v := range logData { + for sk, sv := range v { + fmt.Print(v) + assert.Equal(t, "error", sk, "Wrong or missing log") + assert.Equal(t, "simulated error", sv, "Wrong or missing log") + } + } +} + +func TestSpanErrorLogKV(t *testing.T) { + const op = "test" + opts := instana.Options{LogLevel: instana.Debug} + recorder := instana.NewTestRecorder() + tracer := instana.NewTracerWithEverything(&opts, recorder) + + span := tracer.StartSpan(op) + span.LogKV("error", "simulated error") + span.Finish() + + spans := recorder.GetSpans() + assert.Equal(t, len(spans), 1) + firstSpan := spans[0] + + logData := firstSpan.Data.SDK.Custom.Logs + assert.NotNil(t, logData, "Missing logged fields") + assert.Equal(t, 1, len(logData), "Unexpected log count") + assert.Equal(t, 1, firstSpan.Ec, "Error count should be 1") + + for _, v := range logData { + for sk, sv := range v { + assert.Equal(t, "error", sk, "Wrong or missing log") + assert.Equal(t, "simulated error", sv, "Wrong or missing log") + } + } +} + +func TestSpanErrorLogFields(t *testing.T) { + const op = "test" + opts := instana.Options{LogLevel: instana.Debug} + recorder := instana.NewTestRecorder() + tracer := instana.NewTracerWithEverything(&opts, recorder) + + span := tracer.StartSpan(op) + + err := errors.New("simulated error") + span.LogFields(log.Error(err), log.String("function", "TestspanErrorLogFields")) + span.LogFields(log.Error(err), log.String("function", "TestspanErrorLogFields")) + span.Finish() + + spans := recorder.GetSpans() + assert.Equal(t, len(spans), 1) + firstSpan := spans[0] + + logData := firstSpan.Data.SDK.Custom.Logs + assert.Equal(t, 1, len(logData), "Unexpected tag count") + assert.Equal(t, 2, firstSpan.Ec, "Error count should be 2") +} From 56f9fed5b6b9139813e670dd38d7b28681777e09 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Mon, 8 May 2017 11:03:27 +0200 Subject: [PATCH 3/3] Report ta field with span; add test to validate --- json_span.go | 1 + recorder.go | 1 + span_test.go | 1 + 3 files changed, 3 insertions(+) diff --git a/json_span.go b/json_span.go index f3efa2dcb..f99057d4e 100644 --- a/json_span.go +++ b/json_span.go @@ -13,6 +13,7 @@ type jsonSpan struct { Name string `json:"n"` From *fromS `json:"f"` Ec int `json:"ec,omitempty"` + Lang string `json:"ta,omitempty"` Data *jsonData `json:"data"` } diff --git a/recorder.go b/recorder.go index 8cb3c8daf..5566abdf3 100644 --- a/recorder.go +++ b/recorder.go @@ -122,6 +122,7 @@ func (r *Recorder) RecordSpan(span *spanS) { Duration: uint64(span.Duration) / uint64(time.Millisecond), Name: "sdk", Ec: span.Ec, + Lang: "go", From: sensor.agent.from, Data: data}) diff --git a/span_test.go b/span_test.go index eb7f423b3..87cb5c649 100644 --- a/span_test.go +++ b/span_test.go @@ -35,6 +35,7 @@ func TestBasicSpan(t *testing.T) { assert.Equal(t, "test", span.Data.SDK.Name, "Missing span name") assert.Nil(t, span.Data.SDK.Custom.Tags, "Tags has an unexpected value") assert.Nil(t, span.Data.SDK.Custom.Baggage, "Baggage has an unexpected value") + assert.Equal(t, "go", span.Lang, "Missing or wrong ta/lang") } func TestSpanHeritage(t *testing.T) {