TUN-6030: Add ttfb span for origin http request

Author: DevinCarr

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)
 }
 

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)

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...)

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)
 }

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,26 +25,41 @@ 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")
 )
 
 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))

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)