Adjust to the new key-value logging regime

event.go

@@ -19,7 +19,12 @@ type EventBaggage struct {
 	Key, Value string
 }
 
+// EventLogFields is received when LogFields or LogKV is called.
+type EventLogFields opentracing.LogRecord
+
 // EventLog is received when Log (or one of its derivatives) is called.
+//
+// DEPRECATED
 type EventLog opentracing.LogData
 
 // EventFinish is received when Finish is called.
@@ -40,6 +45,11 @@ func (s *spanImpl) onLog(ld opentracing.LogData) {
 		s.event(EventLog(ld))
 	}
 }
+func (s *spanImpl) onLogFields(lr opentracing.LogRecord) {
+	if s.event != nil {
+		s.event(EventLogFields(lr))
+	}
+}
 func (s *spanImpl) onBaggage(key, value string) {
 	if s.event != nil {
 		s.event(EventBaggage{Key: key, Value: value})

examples/dapperish.go

@@ -5,7 +5,7 @@ import (
 	"bytes"
 	"fmt"
 	"io/ioutil"
-	"log"
+	golog "log"
 	"net/http"
 	"os"
 	"runtime"
@@ -16,6 +16,7 @@ import (
 	"github.com/opentracing/basictracer-go/examples/dapperish"
 	opentracing "github.com/opentracing/opentracing-go"
 	"github.com/opentracing/opentracing-go/ext"
+	"github.com/opentracing/opentracing-go/log"
 )
 
 func client() {
@@ -25,7 +26,7 @@ func client() {
 		ctx := opentracing.ContextWithSpan(context.Background(), span)
 		// Make sure that global baggage propagation works.
 		span.SetBaggageItem("User", os.Getenv("USER"))
-		span.LogEventWithPayload("ctx", ctx)
+		span.LogFields(log.Object("ctx", ctx))
 		fmt.Print("\n\nEnter text (empty string to exit): ")
 		text, _ := reader.ReadString('\n')
 		text = strings.TrimSpace(text)
@@ -34,7 +35,7 @@ func client() {
 			os.Exit(0)
 		}
 
-		span.LogEvent(text)
+		span.LogFields(log.String("user text", text))
 
 		httpClient := &http.Client{}
 		httpReq, _ := http.NewRequest("POST", "http://localhost:8080/", bytes.NewReader([]byte(text)))
@@ -45,9 +46,9 @@ func client() {
 		}
 		resp, err := httpClient.Do(httpReq)
 		if err != nil {
-			span.LogEventWithPayload("error", err)
+			span.LogFields(log.Error(err))
 		} else {
-			span.LogEventWithPayload("got response", resp)
+			span.LogFields(log.Object("response", resp))
 		}
 
 		span.Finish()
@@ -70,12 +71,12 @@ func server() {
 
 		fullBody, err := ioutil.ReadAll(req.Body)
 		if err != nil {
-			serverSpan.LogEventWithPayload("body read error", err)
+			serverSpan.LogFields(log.Error(err))
 		}
-		serverSpan.LogEventWithPayload("got request with body", string(fullBody))
+		serverSpan.LogFields(log.String("request body", string(fullBody)))
 	})
 
-	log.Fatal(http.ListenAndServe(":8080", nil))
+	golog.Fatal(http.ListenAndServe(":8080", nil))
 }
 
 func main() {

examples/dapperish/trivialrecorder.go

@@ -2,7 +2,6 @@ package dapperish
 
 import (
 	"fmt"
-	"reflect"
 
 	"github.com/opentracing/basictracer-go"
 )
@@ -38,6 +37,6 @@ func (t *TrivialRecorder) RecordSpan(span basictracer.RawSpan) {
 		span.Context, span.Context.Baggage)
 	for i, l := range span.Logs {
 		fmt.Printf(
-			"    log %v @ %v: %v --> %v\n", i, l.Timestamp, l.Event, reflect.TypeOf(l.Payload))
+			"    log %v @ %v: %v\n", i, l.Timestamp, l.Fields)
 	}
 }

raw.go

@@ -30,5 +30,5 @@ type RawSpan struct {
 	Tags opentracing.Tags
 
 	// The span's "microlog".
-	Logs []opentracing.LogData
+	Logs []opentracing.LogRecord
 }

span.go

@@ -1,11 +1,13 @@
 package basictracer
 
 import (
+	"fmt"
 	"sync"
 	"time"
 
 	opentracing "github.com/opentracing/opentracing-go"
 	"github.com/opentracing/opentracing-go/ext"
+	"github.com/opentracing/opentracing-go/log"
 )
 
 // Span provides access to the essential details of the span, for use
@@ -88,6 +90,35 @@ func (s *spanImpl) SetTag(key string, value interface{}) opentracing.Span {
 	return s
 }
 
+func (s *spanImpl) LogKV(keyValues ...interface{}) {
+	if len(keyValues)%2 != 0 {
+		s.LogFields(log.Error(fmt.Errorf("Non-even keyValues len: %v", len(keyValues))))
+		return
+	}
+	fields, err := log.InterleavedKVToFields(keyValues...)
+	if err != nil {
+		s.LogFields(log.Error(err), log.String("function", "LogKV"))
+		return
+	}
+	s.LogFields(fields...)
+}
+
+func (s *spanImpl) LogFields(fields ...log.Field) {
+	lr := opentracing.LogRecord{
+		Fields: fields,
+	}
+	defer s.onLogFields(lr)
+	s.Lock()
+	defer s.Unlock()
+	if s.trim() || s.tracer.options.DropAllLogs {
+		return
+	}
+	if lr.Timestamp.IsZero() {
+		lr.Timestamp = time.Now()
+	}
+	s.raw.Logs = append(s.raw.Logs, lr)
+}
+
 func (s *spanImpl) LogEvent(event string) {
 	s.Log(opentracing.LogData{
 		Event: event,
@@ -113,7 +144,7 @@ func (s *spanImpl) Log(ld opentracing.LogData) {
 		ld.Timestamp = time.Now()
 	}
 
-	s.raw.Logs = append(s.raw.Logs, ld)
+	s.raw.Logs = append(s.raw.Logs, ld.ToLogRecord())
 }
 
 func (s *spanImpl) Finish() {
@@ -129,8 +160,11 @@ func (s *spanImpl) FinishWithOptions(opts opentracing.FinishOptions) {
 
 	s.Lock()
 	defer s.Unlock()
-	if opts.BulkLogData != nil {
-		s.raw.Logs = append(s.raw.Logs, opts.BulkLogData...)
+	if opts.LogRecords != nil {
+		s.raw.Logs = append(s.raw.Logs, opts.LogRecords...)
+	}
+	for _, ld := range opts.BulkLogData {
+		s.raw.Logs = append(s.raw.Logs, ld.ToLogRecord())
 	}
 	s.raw.Duration = duration
 

span_test.go

@@ -1,10 +1,12 @@
 package basictracer
 
 import (
+	"reflect"
 	"testing"
 
 	opentracing "github.com/opentracing/opentracing-go"
 	"github.com/opentracing/opentracing-go/ext"
+	"github.com/opentracing/opentracing-go/log"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -86,15 +88,22 @@ func TestSpan_SingleLoggedTaggedSpan(t *testing.T) {
 	})
 	span := tracer.StartSpan("x")
 	span.LogEventWithPayload("event", "payload")
+	span.LogFields(log.String("key_str", "value"), log.Uint32("32bit", 4294967295))
 	span.SetTag("tag", "value")
 	span.Finish()
 	spans := recorder.GetSpans()
 	assert.Equal(t, 1, len(spans))
 	assert.Equal(t, "x", spans[0].Operation)
-	assert.Equal(t, 1, len(spans[0].Logs))
-	assert.Equal(t, "event", spans[0].Logs[0].Event)
-	assert.Equal(t, "payload", spans[0].Logs[0].Payload)
+	assert.Equal(t, 2, len(spans[0].Logs))
 	assert.Equal(t, opentracing.Tags{"tag": "value"}, spans[0].Tags)
+	lfv := log.NewLogFieldValidator(t, spans[0].Logs[0].Fields)
+	lfv.
+		ExpectNextFieldEquals("event", reflect.String, "event").
+		ExpectNextFieldEquals("payload", reflect.Interface, "payload")
+	lfv = log.NewLogFieldValidator(t, spans[0].Logs[1].Fields)
+	lfv.
+		ExpectNextFieldEquals("key_str", reflect.String, "value").
+		ExpectNextFieldEquals("32bit", reflect.Uint32, "4294967295")
 }
 
 func TestSpan_TrimUnsampledSpans(t *testing.T) {
@@ -107,15 +116,17 @@ func TestSpan_TrimUnsampledSpans(t *testing.T) {
 	})
 
 	span := tracer.StartSpan("x")
-	span.LogEventWithPayload("event", "payload")
+	span.LogFields(log.String("key_str", "value"), log.Uint32("32bit", 4294967295))
 	span.SetTag("tag", "value")
 	span.Finish()
 	spans := recorder.GetSpans()
 	assert.Equal(t, 1, len(spans))
 	assert.Equal(t, 1, len(spans[0].Logs))
-	assert.Equal(t, "event", spans[0].Logs[0].Event)
-	assert.Equal(t, "payload", spans[0].Logs[0].Payload)
 	assert.Equal(t, opentracing.Tags{"tag": "value"}, spans[0].Tags)
+	lfv := log.NewLogFieldValidator(t, spans[0].Logs[0].Fields)
+	lfv.
+		ExpectNextFieldEquals("key_str", reflect.String, "value").
+		ExpectNextFieldEquals("32bit", reflect.Uint32, "4294967295")
 
 	recorder.Reset()
 	// Tracer that trims only unsampled and never samples
@@ -126,7 +137,7 @@ func TestSpan_TrimUnsampledSpans(t *testing.T) {
 	})
 
 	span = tracer.StartSpan("x")
-	span.LogEventWithPayload("event", "payload")
+	span.LogFields(log.String("key_str", "value"), log.Uint32("32bit", 4294967295))
 	span.SetTag("tag", "value")
 	span.Finish()
 	spans = recorder.GetSpans()
@@ -145,7 +156,7 @@ func TestSpan_DropAllLogs(t *testing.T) {
 	})
 
 	span := tracer.StartSpan("x")
-	span.LogEventWithPayload("event", "payload")
+	span.LogFields(log.String("key_str", "value"), log.Uint32("32bit", 4294967295))
 	span.SetTag("tag", "value")
 	span.Finish()
 	spans := recorder.GetSpans()