From a97233bb3e3abb695e76935037403f7559012e21 Mon Sep 17 00:00:00 2001 From: Devin Carr Date: Mon, 11 Apr 2022 16:02:13 -0700 Subject: [PATCH] TUN-6030: Add ttfb span for origin http request --- cmd/cloudflared/main.go | 2 ++ proxy/proxy.go | 10 ++++++-- tracing/client.go | 4 ++-- tracing/client_test.go | 4 ++-- tracing/tracing.go | 52 ++++++++++++++++++++++++++++++----------- tracing/tracing_test.go | 10 ++++---- 6 files changed, 57 insertions(+), 25 deletions(-) diff --git a/cmd/cloudflared/main.go b/cmd/cloudflared/main.go index 889e1f64..07271eb4 100644 --- a/cmd/cloudflared/main.go +++ b/cmd/cloudflared/main.go @@ -21,6 +21,7 @@ import ( "github.com/cloudflare/cloudflared/logger" "github.com/cloudflare/cloudflared/metrics" "github.com/cloudflare/cloudflared/overwatch" + "github.com/cloudflare/cloudflared/tracing" "github.com/cloudflare/cloudflared/watcher" ) @@ -86,6 +87,7 @@ func main() { tunnel.Init(bInfo, graceShutdownC) // we need this to support the tunnel sub command... access.Init(graceShutdownC) updater.Init(Version) + tracing.Init(Version) runApp(app, graceShutdownC) } diff --git a/proxy/proxy.go b/proxy/proxy.go index f24f0290..bcdab8de 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -11,6 +11,8 @@ import ( "github.com/pkg/errors" "github.com/rs/zerolog" "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" "github.com/cloudflare/cloudflared/carrier" "github.com/cloudflare/cloudflared/cfio" @@ -72,7 +74,8 @@ func (p *Proxy) ProxyHTTP( lbProbe := connection.IsLBProbeRequest(req) p.appendTagHeaders(req) - _, ruleSpan := tr.Tracer().Start(req.Context(), "ingress_match") + _, ruleSpan := tr.Tracer().Start(req.Context(), "ingress_match", + trace.WithAttributes(attribute.String("req-host", req.Host))) rule, ruleNum := p.ingressRules.FindMatchingRule(req.Host, req.URL.Path) logFields := logFields{ cfRay: cfRay, @@ -167,7 +170,7 @@ func (p *Proxy) proxyHTTPRequest( ) error { roundTripReq := tr.Request if isWebsocket { - roundTripReq = tr.Request.Clone(tr.Request.Context()) + roundTripReq = tr.Clone(tr.Request.Context()) roundTripReq.Header.Set("Connection", "Upgrade") roundTripReq.Header.Set("Upgrade", "websocket") roundTripReq.Header.Set("Sec-Websocket-Version", "13") @@ -191,10 +194,13 @@ func (p *Proxy) proxyHTTPRequest( roundTripReq.Header.Set("User-Agent", "") } + _, ttfbSpan := tr.Tracer().Start(tr.Context(), "ttfb_origin") resp, err := httpService.RoundTrip(roundTripReq) if err != nil { + tracing.EndWithStatus(ttfbSpan, codes.Error, "") return errors.Wrap(err, "Unable to reach the origin service. The service may be down or it may not be responding to traffic from cloudflared") } + tracing.EndWithStatus(ttfbSpan, codes.Ok, resp.Status) defer resp.Body.Close() // Add spans to response header (if available) diff --git a/tracing/client.go b/tracing/client.go index 5ed4efb3..ffc477e1 100644 --- a/tracing/client.go +++ b/tracing/client.go @@ -12,7 +12,7 @@ import ( ) const ( - maxTraceAmount = 20 + MaxTraceAmount = 20 ) var ( @@ -46,7 +46,7 @@ func (mc *InMemoryOtlpClient) UploadTraces(_ context.Context, protoSpans []*trac defer mc.mu.Unlock() // Catch to make sure too many traces aren't being added to response header. // Returning nil makes sure we don't fail to send the traces we already recorded. - if len(mc.spans)+len(protoSpans) > maxTraceAmount { + if len(mc.spans)+len(protoSpans) > MaxTraceAmount { return nil } mc.spans = append(mc.spans, protoSpans...) diff --git a/tracing/client_test.go b/tracing/client_test.go index 946ee7f5..175c9112 100644 --- a/tracing/client_test.go +++ b/tracing/client_test.go @@ -108,12 +108,12 @@ func TestSpansNil(t *testing.T) { func TestSpansTooManySpans(t *testing.T) { client := &InMemoryOtlpClient{} - for i := 0; i < maxTraceAmount+1; i++ { + for i := 0; i < MaxTraceAmount+1; i++ { spans := createResourceSpans([]*tracepb.Span{createOtlpSpan(traceId)}) err := client.UploadTraces(context.Background(), spans) assert.NoError(t, err) } - assert.Len(t, client.spans, maxTraceAmount) + assert.Len(t, client.spans, MaxTraceAmount) _, err := client.Spans() assert.NoError(t, err) } diff --git a/tracing/tracing.go b/tracing/tracing.go index f124e367..d3786603 100644 --- a/tracing/tracing.go +++ b/tracing/tracing.go @@ -3,7 +3,10 @@ package tracing import ( "context" "errors" + "fmt" "net/http" + "os" + "runtime" "github.com/rs/zerolog" otelContrib "go.opentelemetry.io/contrib/propagators/Jaeger" @@ -22,19 +25,26 @@ const ( service = "cloudflared" tracerInstrumentName = "origin" - tracerContextName = "cf-trace-id" - tracerContextNameOverride = "uber-trace-id" + TracerContextName = "cf-trace-id" + TracerContextNameOverride = "uber-trace-id" IntCloudflaredTracingHeader = "cf-int-cloudflared-tracing" ) var ( CanonicalCloudflaredTracingHeader = http.CanonicalHeaderKey(IntCloudflaredTracingHeader) - Http2TransportAttribute = trace.WithAttributes(TransportAttributeKey.String("http2")) - QuicTransportAttribute = trace.WithAttributes(TransportAttributeKey.String("quic")) + Http2TransportAttribute = trace.WithAttributes(transportAttributeKey.String("http2")) + QuicTransportAttribute = trace.WithAttributes(transportAttributeKey.String("quic")) + HostOSAttribute = semconv.HostTypeKey.String(runtime.GOOS) + HostArchAttribute = semconv.HostArchKey.String(runtime.GOARCH) - TransportAttributeKey = attribute.Key("transport") - TrafficAttributeKey = attribute.Key("traffic") + otelVersionAttribute attribute.KeyValue + hostnameAttribute attribute.KeyValue + cloudflaredVersionAttribute attribute.KeyValue + serviceAttribute = semconv.ServiceNameKey.String(service) + + transportAttributeKey = attribute.Key("transport") + otelVersionAttributeKey = attribute.Key("jaeger.version") errNoopTracerProvider = errors.New("noop tracer provider records no spans") ) @@ -42,6 +52,14 @@ var ( func init() { // Register the jaeger propagator globally. otel.SetTextMapPropagator(otelContrib.Jaeger{}) + otelVersionAttribute = otelVersionAttributeKey.String(fmt.Sprintf("go-otel-%s", otel.Version())) + if hostname, err := os.Hostname(); err == nil { + hostnameAttribute = attribute.String("hostname", hostname) + } +} + +func Init(version string) { + cloudflaredVersionAttribute = semconv.ProcessRuntimeVersionKey.String(version) } type TracedRequest struct { @@ -67,7 +85,12 @@ func NewTracedRequest(req *http.Request) *TracedRequest { // Record information about this application in a Resource. tracesdk.WithResource(resource.NewWithAttributes( semconv.SchemaURL, - semconv.ServiceNameKey.String(service), + serviceAttribute, + otelVersionAttribute, + hostnameAttribute, + cloudflaredVersionAttribute, + HostOSAttribute, + HostArchAttribute, )), ) @@ -110,27 +133,28 @@ func EndWithStatus(span trace.Span, code codes.Code, status string) { span.End() } -// extractTrace attempts to check for a cf-trace-id from a request header. +// extractTrace attempts to check for a cf-trace-id from a request and return the +// trace context with the provided http.Request. func extractTrace(req *http.Request) (context.Context, bool) { // Only add tracing for requests with appropriately tagged headers - remoteTraces := req.Header.Values(tracerContextName) + remoteTraces := req.Header.Values(TracerContextName) if len(remoteTraces) <= 0 { // Strip the cf-trace-id header - req.Header.Del(tracerContextName) + req.Header.Del(TracerContextName) return nil, false } - traceHeader := make(map[string]string, 1) + traceHeader := map[string]string{} for _, t := range remoteTraces { // Override the 'cf-trace-id' as 'uber-trace-id' so the jaeger propagator can extract it. // Last entry wins if multiple provided - traceHeader[tracerContextNameOverride] = t + traceHeader[TracerContextNameOverride] = t } // Strip the cf-trace-id header - req.Header.Del(tracerContextName) + req.Header.Del(TracerContextName) - if traceHeader[tracerContextNameOverride] == "" { + if traceHeader[TracerContextNameOverride] == "" { return nil, false } remoteCtx := otel.GetTextMapPropagator().Extract(req.Context(), propagation.MapCarrier(traceHeader)) diff --git a/tracing/tracing_test.go b/tracing/tracing_test.go index 50dcb3ff..1bd23e89 100644 --- a/tracing/tracing_test.go +++ b/tracing/tracing_test.go @@ -12,7 +12,7 @@ import ( func TestNewCfTracer(t *testing.T) { req := httptest.NewRequest("GET", "http://localhost", nil) - req.Header.Add(tracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1") + req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1") tr := NewTracedRequest(req) assert.NotNil(t, tr) assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider) @@ -21,8 +21,8 @@ func TestNewCfTracer(t *testing.T) { func TestNewCfTracerMultiple(t *testing.T) { req := httptest.NewRequest("GET", "http://localhost", nil) - req.Header.Add(tracerContextName, "1241ce3ecdefc68854e8514e69ba42ca:b38f1bf5eae406f3:0:1") - req.Header.Add(tracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1") + req.Header.Add(TracerContextName, "1241ce3ecdefc68854e8514e69ba42ca:b38f1bf5eae406f3:0:1") + req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1") tr := NewTracedRequest(req) assert.NotNil(t, tr) assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider) @@ -31,7 +31,7 @@ func TestNewCfTracerMultiple(t *testing.T) { func TestNewCfTracerNilHeader(t *testing.T) { req := httptest.NewRequest("GET", "http://localhost", nil) - req.Header[http.CanonicalHeaderKey(tracerContextName)] = nil + req.Header[http.CanonicalHeaderKey(TracerContextName)] = nil tr := NewTracedRequest(req) assert.NotNil(t, tr) assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider) @@ -41,7 +41,7 @@ func TestNewCfTracerNilHeader(t *testing.T) { func TestNewCfTracerInvalidHeaders(t *testing.T) { req := httptest.NewRequest("GET", "http://localhost", nil) for _, test := range [][]string{nil, {""}} { - req.Header[http.CanonicalHeaderKey(tracerContextName)] = test + req.Header[http.CanonicalHeaderKey(TracerContextName)] = test tr := NewTracedRequest(req) assert.NotNil(t, tr) assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider)