From 50d041cbc0820a1940413ab72a002f6bd49f5286 Mon Sep 17 00:00:00 2001 From: Kevin Zheng Date: Tue, 23 Apr 2024 20:46:38 +0000 Subject: [PATCH 1/3] feat(logging): OpenTelemetry trace/span ID integration for Go logging library --- logging/go.mod | 2 +- logging/logging.go | 9 +++ logging/logging_test.go | 166 ++++++++++++++++++++++++++++++++++++++++ 3 files changed, 176 insertions(+), 1 deletion(-) diff --git a/logging/go.mod b/logging/go.mod index 7cd12e377117..0c918f4019e0 100644 --- a/logging/go.mod +++ b/logging/go.mod @@ -11,6 +11,7 @@ require ( github.com/google/go-cmp v0.6.0 github.com/googleapis/gax-go/v2 v2.12.3 go.opencensus.io v0.24.0 + go.opentelemetry.io/otel/trace v1.24.0 golang.org/x/oauth2 v0.18.0 google.golang.org/api v0.172.0 google.golang.org/genproto v0.0.0-20240213162025-012b6fc9bca9 @@ -35,7 +36,6 @@ require ( go.opentelemetry.io/otel v1.24.0 // indirect go.opentelemetry.io/otel/metric v1.24.0 // indirect go.opentelemetry.io/otel/sdk v1.22.0 // indirect - go.opentelemetry.io/otel/trace v1.24.0 // indirect golang.org/x/crypto v0.21.0 // indirect golang.org/x/net v0.22.0 // indirect golang.org/x/sync v0.6.0 // indirect diff --git a/logging/logging.go b/logging/logging.go index 8d79ed54a285..cdf94131356a 100644 --- a/logging/logging.go +++ b/logging/logging.go @@ -41,6 +41,8 @@ import ( "time" "unicode/utf8" + "go.opentelemetry.io/otel/trace" + vkit "cloud.google.com/go/logging/apiv2" logpb "cloud.google.com/go/logging/apiv2/loggingpb" "cloud.google.com/go/logging/internal" @@ -813,6 +815,13 @@ func populateTraceInfo(e *Entry, req *http.Request) bool { return false } } + otelSpanContext := trace.SpanContextFromContext(req.Context()) + if otelSpanContext.IsValid() { + e.Trace = otelSpanContext.TraceID().String() + e.SpanID = otelSpanContext.SpanID().String() + e.TraceSampled = otelSpanContext.IsSampled() + return true + } header := req.Header.Get("Traceparent") if header != "" { // do not use traceSampled flag defined by traceparent because diff --git a/logging/logging_test.go b/logging/logging_test.go index aaa4d2ac62da..fc117a1cc20d 100644 --- a/logging/logging_test.go +++ b/logging/logging_test.go @@ -48,6 +48,8 @@ import ( "github.com/google/go-cmp/cmp" "github.com/google/go-cmp/cmp/cmpopts" gax "github.com/googleapis/gax-go/v2" + "go.opentelemetry.io/otel/trace" + "go.opentelemetry.io/otel/trace/noop" "golang.org/x/oauth2" "google.golang.org/api/iterator" "google.golang.org/api/option" @@ -609,6 +611,170 @@ func TestToLogEntry(t *testing.T) { } } +func TestToLogEntryOTelIntegration(t *testing.T) { + // Some slight modifications need to be done for testing ToLogEntry + // for the OpenTelemetry integration, so they are in a separate function. + u := &url.URL{Scheme: "http"} + otelTraceID, _ := trace.TraceIDFromHex(strings.Repeat("a", 32)) + otelSpanID, _ := trace.SpanIDFromHex(strings.Repeat("f", 16)) + otelTraceFlags := trace.FlagsSampled // tracesampled = true + tests := []struct { + name string + in logging.Entry + spanContextConfig trace.SpanContextConfig // default = noop span context + want *logpb.LogEntry + }{ + { + name: "Using OpenTelemetry with a valid span", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + }, + }, + }, + spanContextConfig: trace.SpanContextConfig{ + TraceID: otelTraceID, + SpanID: otelSpanID, + TraceFlags: otelTraceFlags, + }, + want: &logpb.LogEntry{ + Trace: "projects/P/traces/" + otelTraceID.String(), + SpanId: otelSpanID.String(), + TraceSampled: otelTraceFlags.IsSampled(), + }, + }, + { + name: "OpenTelemetry only with a noop span", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + }, + }, + }, + want: &logpb.LogEntry{}, + }, + { + name: "Using OpenTelemetry only with a valid span + valid traceparent headers (precedence test)", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + Header: http.Header{ + "Traceparent": {"00-105445aa7843bc8bf206b12000100012-000000000000004a-01"}, + }, + }, + }, + }, + spanContextConfig: trace.SpanContextConfig{ + TraceID: otelTraceID, + SpanID: otelSpanID, + TraceFlags: otelTraceFlags, + }, + want: &logpb.LogEntry{ + Trace: "projects/P/traces/" + otelTraceID.String(), + SpanId: otelSpanID.String(), + TraceSampled: otelTraceFlags.IsSampled(), + }, + }, + { + name: "Using OpenTelemetry only with a valid span + valid XCTC headers (precedence test)", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + Header: http.Header{ + "X-Cloud-Trace-Context": {"105445aa7843bc8bf206b120000000/0000000000000bbb;o=1"}, + }, + }, + }, + }, + spanContextConfig: trace.SpanContextConfig{ + TraceID: otelTraceID, + SpanID: otelSpanID, + TraceFlags: otelTraceFlags, + }, + want: &logpb.LogEntry{ + Trace: "projects/P/traces/" + otelTraceID.String(), + SpanId: otelSpanID.String(), + TraceSampled: otelTraceFlags.IsSampled(), + }, + }, + { + name: "Using OpenTelemetry only with a noop span + valid traceparent headers (edge case)", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + Header: http.Header{ + "Traceparent": {"00-105445aa7843bc8bf206b12000100012-000000000000004a-01"}, + }, + }, + }, + }, + want: &logpb.LogEntry{ + Trace: "projects/P/traces/105445aa7843bc8bf206b12000100012", + SpanId: "000000000000004a", + TraceSampled: false, + }, + }, + { + name: "Using OpenTelemetry with a valid span + trace info set in Entry object", + in: logging.Entry{ + HTTPRequest: &logging.HTTPRequest{ + Request: &http.Request{ + URL: u, + }, + }, + Trace: "abc", + SpanID: "def", + TraceSampled: false, + }, + spanContextConfig: trace.SpanContextConfig{ + TraceID: otelTraceID, + SpanID: otelSpanID, + TraceFlags: otelTraceFlags, + }, + want: &logpb.LogEntry{ + Trace: "abc", + SpanId: "def", + TraceSampled: false, + }, + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + ctx := context.Background() + + // Need to set a span context for the context so it's not a noop + spanContext := trace.NewSpanContext(test.spanContextConfig) + ctx = trace.ContextWithSpanContext(ctx, spanContext) + ctx, span := noop.NewTracerProvider().Tracer("test tracer").Start(ctx, "test span") + defer span.End() + + if test.in.HTTPRequest != nil && test.in.HTTPRequest.Request != nil { + test.in.HTTPRequest.Request = test.in.HTTPRequest.Request.WithContext(ctx) + } + + e, err := logging.ToLogEntry(test.in, "projects/P") + if err != nil { + t.Fatalf("Unexpected error: %+v: %v", test.in, err) + } + if got := e.Trace; got != test.want.Trace { + t.Errorf("TraceId: %+v: SpanContext: %+v: got %q, want %q", test.in, spanContext, got, test.want.Trace) + } + if got := e.SpanId; got != test.want.SpanId { + t.Errorf("SpanId: %+v: SpanContext: %+v: got %q, want %q", test.in, spanContext, got, test.want.SpanId) + } + if got := e.TraceSampled; got != test.want.TraceSampled { + t.Errorf("TraceSampled: %+v: SpanContext: %+v: got %t, want %t", test.in, spanContext, got, test.want.TraceSampled) + } + + }) + } +} + // compareEntries compares most fields list of Entries against expected. compareEntries does not compare: // - HTTPRequest // - Operation From 6715d8416b9645fbac5dfdf8b2e0ff2d71fc10b6 Mon Sep 17 00:00:00 2001 From: Kevin Zheng Date: Thu, 2 May 2024 19:23:31 +0000 Subject: [PATCH 2/3] Added system/integration tests --- logging/go.mod | 3 +- logging/logging_test.go | 117 ++++++++++++++-------------------------- 2 files changed, 41 insertions(+), 79 deletions(-) diff --git a/logging/go.mod b/logging/go.mod index 1aae3ea406b3..58e485caa087 100644 --- a/logging/go.mod +++ b/logging/go.mod @@ -11,6 +11,7 @@ require ( github.com/google/go-cmp v0.6.0 github.com/googleapis/gax-go/v2 v2.12.3 go.opencensus.io v0.24.0 + go.opentelemetry.io/otel/sdk v1.24.0 go.opentelemetry.io/otel/trace v1.24.0 golang.org/x/oauth2 v0.19.0 google.golang.org/api v0.175.0 @@ -33,12 +34,10 @@ require ( github.com/google/s2a-go v0.1.7 // indirect github.com/google/uuid v1.6.0 // indirect github.com/googleapis/enterprise-certificate-proxy v0.3.2 // indirect - github.com/stretchr/testify v1.9.0 // indirect go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc v0.49.0 // indirect go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.49.0 // indirect go.opentelemetry.io/otel v1.24.0 // indirect go.opentelemetry.io/otel/metric v1.24.0 // indirect - go.opentelemetry.io/otel/sdk v1.24.0 // indirect golang.org/x/crypto v0.22.0 // indirect golang.org/x/net v0.24.0 // indirect golang.org/x/sync v0.7.0 // indirect diff --git a/logging/logging_test.go b/logging/logging_test.go index fc117a1cc20d..a767a7eb2f9e 100644 --- a/logging/logging_test.go +++ b/logging/logging_test.go @@ -48,6 +48,7 @@ import ( "github.com/google/go-cmp/cmp" "github.com/google/go-cmp/cmp/cmpopts" gax "github.com/googleapis/gax-go/v2" + sdktrace "go.opentelemetry.io/otel/sdk/trace" "go.opentelemetry.io/otel/trace" "go.opentelemetry.io/otel/trace/noop" "golang.org/x/oauth2" @@ -615,14 +616,10 @@ func TestToLogEntryOTelIntegration(t *testing.T) { // Some slight modifications need to be done for testing ToLogEntry // for the OpenTelemetry integration, so they are in a separate function. u := &url.URL{Scheme: "http"} - otelTraceID, _ := trace.TraceIDFromHex(strings.Repeat("a", 32)) - otelSpanID, _ := trace.SpanIDFromHex(strings.Repeat("f", 16)) - otelTraceFlags := trace.FlagsSampled // tracesampled = true tests := []struct { - name string - in logging.Entry - spanContextConfig trace.SpanContextConfig // default = noop span context - want *logpb.LogEntry + name string + in logging.Entry + want *logpb.LogEntry // if want is nil, pull wants from spanContext }{ { name: "Using OpenTelemetry with a valid span", @@ -633,27 +630,6 @@ func TestToLogEntryOTelIntegration(t *testing.T) { }, }, }, - spanContextConfig: trace.SpanContextConfig{ - TraceID: otelTraceID, - SpanID: otelSpanID, - TraceFlags: otelTraceFlags, - }, - want: &logpb.LogEntry{ - Trace: "projects/P/traces/" + otelTraceID.String(), - SpanId: otelSpanID.String(), - TraceSampled: otelTraceFlags.IsSampled(), - }, - }, - { - name: "OpenTelemetry only with a noop span", - in: logging.Entry{ - HTTPRequest: &logging.HTTPRequest{ - Request: &http.Request{ - URL: u, - }, - }, - }, - want: &logpb.LogEntry{}, }, { name: "Using OpenTelemetry only with a valid span + valid traceparent headers (precedence test)", @@ -667,16 +643,6 @@ func TestToLogEntryOTelIntegration(t *testing.T) { }, }, }, - spanContextConfig: trace.SpanContextConfig{ - TraceID: otelTraceID, - SpanID: otelSpanID, - TraceFlags: otelTraceFlags, - }, - want: &logpb.LogEntry{ - Trace: "projects/P/traces/" + otelTraceID.String(), - SpanId: otelSpanID.String(), - TraceSampled: otelTraceFlags.IsSampled(), - }, }, { name: "Using OpenTelemetry only with a valid span + valid XCTC headers (precedence test)", @@ -690,34 +656,6 @@ func TestToLogEntryOTelIntegration(t *testing.T) { }, }, }, - spanContextConfig: trace.SpanContextConfig{ - TraceID: otelTraceID, - SpanID: otelSpanID, - TraceFlags: otelTraceFlags, - }, - want: &logpb.LogEntry{ - Trace: "projects/P/traces/" + otelTraceID.String(), - SpanId: otelSpanID.String(), - TraceSampled: otelTraceFlags.IsSampled(), - }, - }, - { - name: "Using OpenTelemetry only with a noop span + valid traceparent headers (edge case)", - in: logging.Entry{ - HTTPRequest: &logging.HTTPRequest{ - Request: &http.Request{ - URL: u, - Header: http.Header{ - "Traceparent": {"00-105445aa7843bc8bf206b12000100012-000000000000004a-01"}, - }, - }, - }, - }, - want: &logpb.LogEntry{ - Trace: "projects/P/traces/105445aa7843bc8bf206b12000100012", - SpanId: "000000000000004a", - TraceSampled: false, - }, }, { name: "Using OpenTelemetry with a valid span + trace info set in Entry object", @@ -731,31 +669,57 @@ func TestToLogEntryOTelIntegration(t *testing.T) { SpanID: "def", TraceSampled: false, }, - spanContextConfig: trace.SpanContextConfig{ - TraceID: otelTraceID, - SpanID: otelSpanID, - TraceFlags: otelTraceFlags, - }, want: &logpb.LogEntry{ Trace: "abc", SpanId: "def", TraceSampled: false, }, }, + { + name: "Using OpenTelemetry without a request", + in: logging.Entry{}, + want: &logpb.LogEntry{}, + }, } for _, test := range tests { t.Run(test.name, func(t *testing.T) { + var span trace.Span ctx := context.Background() - // Need to set a span context for the context so it's not a noop - spanContext := trace.NewSpanContext(test.spanContextConfig) - ctx = trace.ContextWithSpanContext(ctx, spanContext) - ctx, span := noop.NewTracerProvider().Tracer("test tracer").Start(ctx, "test span") - defer span.End() + // Set up an OTel SDK tracer if integration test, mock noop tracer if not. + if integrationTest { + tracerProvider := sdktrace.NewTracerProvider() + defer tracerProvider.Shutdown(ctx) + + ctx, span = tracerProvider.Tracer("integration-test-tracer").Start(ctx, "test span") + defer span.End() + } else { + otelTraceID, _ := trace.TraceIDFromHex(strings.Repeat("a", 32)) + otelSpanID, _ := trace.SpanIDFromHex(strings.Repeat("f", 16)) + otelTraceFlags := trace.FlagsSampled // tracesampled = true + mockSpanContext := trace.NewSpanContext(trace.SpanContextConfig{ + TraceID: otelTraceID, + SpanID: otelSpanID, + TraceFlags: otelTraceFlags, + }) + ctx = trace.ContextWithSpanContext(ctx, mockSpanContext) + ctx, span = noop.NewTracerProvider().Tracer("test tracer").Start(ctx, "test span") + defer span.End() + } if test.in.HTTPRequest != nil && test.in.HTTPRequest.Request != nil { test.in.HTTPRequest.Request = test.in.HTTPRequest.Request.WithContext(ctx) } + spanContext := trace.SpanContextFromContext(ctx) + + // if want is nil, pull wants from spanContext + if test.want == nil { + test.want = &logpb.LogEntry{ + Trace: "projects/P/traces/" + spanContext.TraceID().String(), + SpanId: spanContext.SpanID().String(), + TraceSampled: spanContext.TraceFlags().IsSampled(), + } + } e, err := logging.ToLogEntry(test.in, "projects/P") if err != nil { @@ -770,7 +734,6 @@ func TestToLogEntryOTelIntegration(t *testing.T) { if got := e.TraceSampled; got != test.want.TraceSampled { t.Errorf("TraceSampled: %+v: SpanContext: %+v: got %t, want %t", test.in, spanContext, got, test.want.TraceSampled) } - }) } } From ccdd65482a71287553e0bbf47bbbc16109d8ecb8 Mon Sep 17 00:00:00 2001 From: Kevin Zheng Date: Thu, 2 May 2024 19:34:51 +0000 Subject: [PATCH 3/3] added go.sum --- logging/go.sum | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/logging/go.sum b/logging/go.sum index 25ae8fd75027..b26abca2178b 100644 --- a/logging/go.sum +++ b/logging/go.sum @@ -75,8 +75,7 @@ github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpE github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg= -github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk= go.opencensus.io v0.24.0 h1:y73uSU6J157QMP2kn2r30vwW1A2W2WFwSCGnAVxeaD0= go.opencensus.io v0.24.0/go.mod h1:vNK8G9p7aAivkbmorf4v+7Hgx+Zs0yY+0fOtgBfjQKo= go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc v0.49.0 h1:4Pp6oUg3+e/6M4C0A/3kJ2VYa++dsWVTtGgLVj5xtHg=