TUN-6030: Add ttfb span for origin http request

This commit is contained in:
Devin Carr 2022-04-11 16:02:13 -07:00
parent 775c2bc93e
commit a97233bb3e
6 changed files with 57 additions and 25 deletions

View File

@ -21,6 +21,7 @@ import (
"github.com/cloudflare/cloudflared/logger" "github.com/cloudflare/cloudflared/logger"
"github.com/cloudflare/cloudflared/metrics" "github.com/cloudflare/cloudflared/metrics"
"github.com/cloudflare/cloudflared/overwatch" "github.com/cloudflare/cloudflared/overwatch"
"github.com/cloudflare/cloudflared/tracing"
"github.com/cloudflare/cloudflared/watcher" "github.com/cloudflare/cloudflared/watcher"
) )
@ -86,6 +87,7 @@ func main() {
tunnel.Init(bInfo, graceShutdownC) // we need this to support the tunnel sub command... tunnel.Init(bInfo, graceShutdownC) // we need this to support the tunnel sub command...
access.Init(graceShutdownC) access.Init(graceShutdownC)
updater.Init(Version) updater.Init(Version)
tracing.Init(Version)
runApp(app, graceShutdownC) runApp(app, graceShutdownC)
} }

View File

@ -11,6 +11,8 @@ import (
"github.com/pkg/errors" "github.com/pkg/errors"
"github.com/rs/zerolog" "github.com/rs/zerolog"
"go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/codes"
"go.opentelemetry.io/otel/trace"
"github.com/cloudflare/cloudflared/carrier" "github.com/cloudflare/cloudflared/carrier"
"github.com/cloudflare/cloudflared/cfio" "github.com/cloudflare/cloudflared/cfio"
@ -72,7 +74,8 @@ func (p *Proxy) ProxyHTTP(
lbProbe := connection.IsLBProbeRequest(req) lbProbe := connection.IsLBProbeRequest(req)
p.appendTagHeaders(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) rule, ruleNum := p.ingressRules.FindMatchingRule(req.Host, req.URL.Path)
logFields := logFields{ logFields := logFields{
cfRay: cfRay, cfRay: cfRay,
@ -167,7 +170,7 @@ func (p *Proxy) proxyHTTPRequest(
) error { ) error {
roundTripReq := tr.Request roundTripReq := tr.Request
if isWebsocket { if isWebsocket {
roundTripReq = tr.Request.Clone(tr.Request.Context()) roundTripReq = tr.Clone(tr.Request.Context())
roundTripReq.Header.Set("Connection", "Upgrade") roundTripReq.Header.Set("Connection", "Upgrade")
roundTripReq.Header.Set("Upgrade", "websocket") roundTripReq.Header.Set("Upgrade", "websocket")
roundTripReq.Header.Set("Sec-Websocket-Version", "13") roundTripReq.Header.Set("Sec-Websocket-Version", "13")
@ -191,10 +194,13 @@ func (p *Proxy) proxyHTTPRequest(
roundTripReq.Header.Set("User-Agent", "") roundTripReq.Header.Set("User-Agent", "")
} }
_, ttfbSpan := tr.Tracer().Start(tr.Context(), "ttfb_origin")
resp, err := httpService.RoundTrip(roundTripReq) resp, err := httpService.RoundTrip(roundTripReq)
if err != nil { 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") 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() defer resp.Body.Close()
// Add spans to response header (if available) // Add spans to response header (if available)

View File

@ -12,7 +12,7 @@ import (
) )
const ( const (
maxTraceAmount = 20 MaxTraceAmount = 20
) )
var ( var (
@ -46,7 +46,7 @@ func (mc *InMemoryOtlpClient) UploadTraces(_ context.Context, protoSpans []*trac
defer mc.mu.Unlock() defer mc.mu.Unlock()
// Catch to make sure too many traces aren't being added to response header. // 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. // 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 return nil
} }
mc.spans = append(mc.spans, protoSpans...) mc.spans = append(mc.spans, protoSpans...)

View File

@ -108,12 +108,12 @@ func TestSpansNil(t *testing.T) {
func TestSpansTooManySpans(t *testing.T) { func TestSpansTooManySpans(t *testing.T) {
client := &InMemoryOtlpClient{} client := &InMemoryOtlpClient{}
for i := 0; i < maxTraceAmount+1; i++ { for i := 0; i < MaxTraceAmount+1; i++ {
spans := createResourceSpans([]*tracepb.Span{createOtlpSpan(traceId)}) spans := createResourceSpans([]*tracepb.Span{createOtlpSpan(traceId)})
err := client.UploadTraces(context.Background(), spans) err := client.UploadTraces(context.Background(), spans)
assert.NoError(t, err) assert.NoError(t, err)
} }
assert.Len(t, client.spans, maxTraceAmount) assert.Len(t, client.spans, MaxTraceAmount)
_, err := client.Spans() _, err := client.Spans()
assert.NoError(t, err) assert.NoError(t, err)
} }

View File

@ -3,7 +3,10 @@ package tracing
import ( import (
"context" "context"
"errors" "errors"
"fmt"
"net/http" "net/http"
"os"
"runtime"
"github.com/rs/zerolog" "github.com/rs/zerolog"
otelContrib "go.opentelemetry.io/contrib/propagators/Jaeger" otelContrib "go.opentelemetry.io/contrib/propagators/Jaeger"
@ -22,19 +25,26 @@ const (
service = "cloudflared" service = "cloudflared"
tracerInstrumentName = "origin" tracerInstrumentName = "origin"
tracerContextName = "cf-trace-id" TracerContextName = "cf-trace-id"
tracerContextNameOverride = "uber-trace-id" TracerContextNameOverride = "uber-trace-id"
IntCloudflaredTracingHeader = "cf-int-cloudflared-tracing" IntCloudflaredTracingHeader = "cf-int-cloudflared-tracing"
) )
var ( var (
CanonicalCloudflaredTracingHeader = http.CanonicalHeaderKey(IntCloudflaredTracingHeader) CanonicalCloudflaredTracingHeader = http.CanonicalHeaderKey(IntCloudflaredTracingHeader)
Http2TransportAttribute = trace.WithAttributes(TransportAttributeKey.String("http2")) Http2TransportAttribute = trace.WithAttributes(transportAttributeKey.String("http2"))
QuicTransportAttribute = trace.WithAttributes(TransportAttributeKey.String("quic")) QuicTransportAttribute = trace.WithAttributes(transportAttributeKey.String("quic"))
HostOSAttribute = semconv.HostTypeKey.String(runtime.GOOS)
HostArchAttribute = semconv.HostArchKey.String(runtime.GOARCH)
TransportAttributeKey = attribute.Key("transport") otelVersionAttribute attribute.KeyValue
TrafficAttributeKey = attribute.Key("traffic") 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") errNoopTracerProvider = errors.New("noop tracer provider records no spans")
) )
@ -42,6 +52,14 @@ var (
func init() { func init() {
// Register the jaeger propagator globally. // Register the jaeger propagator globally.
otel.SetTextMapPropagator(otelContrib.Jaeger{}) 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 { type TracedRequest struct {
@ -67,7 +85,12 @@ func NewTracedRequest(req *http.Request) *TracedRequest {
// Record information about this application in a Resource. // Record information about this application in a Resource.
tracesdk.WithResource(resource.NewWithAttributes( tracesdk.WithResource(resource.NewWithAttributes(
semconv.SchemaURL, 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() 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) { func extractTrace(req *http.Request) (context.Context, bool) {
// Only add tracing for requests with appropriately tagged headers // Only add tracing for requests with appropriately tagged headers
remoteTraces := req.Header.Values(tracerContextName) remoteTraces := req.Header.Values(TracerContextName)
if len(remoteTraces) <= 0 { if len(remoteTraces) <= 0 {
// Strip the cf-trace-id header // Strip the cf-trace-id header
req.Header.Del(tracerContextName) req.Header.Del(TracerContextName)
return nil, false return nil, false
} }
traceHeader := make(map[string]string, 1) traceHeader := map[string]string{}
for _, t := range remoteTraces { for _, t := range remoteTraces {
// Override the 'cf-trace-id' as 'uber-trace-id' so the jaeger propagator can extract it. // Override the 'cf-trace-id' as 'uber-trace-id' so the jaeger propagator can extract it.
// Last entry wins if multiple provided // Last entry wins if multiple provided
traceHeader[tracerContextNameOverride] = t traceHeader[TracerContextNameOverride] = t
} }
// Strip the cf-trace-id header // Strip the cf-trace-id header
req.Header.Del(tracerContextName) req.Header.Del(TracerContextName)
if traceHeader[tracerContextNameOverride] == "" { if traceHeader[TracerContextNameOverride] == "" {
return nil, false return nil, false
} }
remoteCtx := otel.GetTextMapPropagator().Extract(req.Context(), propagation.MapCarrier(traceHeader)) remoteCtx := otel.GetTextMapPropagator().Extract(req.Context(), propagation.MapCarrier(traceHeader))

View File

@ -12,7 +12,7 @@ import (
func TestNewCfTracer(t *testing.T) { func TestNewCfTracer(t *testing.T) {
req := httptest.NewRequest("GET", "http://localhost", nil) 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) tr := NewTracedRequest(req)
assert.NotNil(t, tr) assert.NotNil(t, tr)
assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider) assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider)
@ -21,8 +21,8 @@ func TestNewCfTracer(t *testing.T) {
func TestNewCfTracerMultiple(t *testing.T) { func TestNewCfTracerMultiple(t *testing.T) {
req := httptest.NewRequest("GET", "http://localhost", nil) req := httptest.NewRequest("GET", "http://localhost", nil)
req.Header.Add(tracerContextName, "1241ce3ecdefc68854e8514e69ba42ca:b38f1bf5eae406f3:0:1") req.Header.Add(TracerContextName, "1241ce3ecdefc68854e8514e69ba42ca:b38f1bf5eae406f3:0:1")
req.Header.Add(tracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1") req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1")
tr := NewTracedRequest(req) tr := NewTracedRequest(req)
assert.NotNil(t, tr) assert.NotNil(t, tr)
assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider) assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider)
@ -31,7 +31,7 @@ func TestNewCfTracerMultiple(t *testing.T) {
func TestNewCfTracerNilHeader(t *testing.T) { func TestNewCfTracerNilHeader(t *testing.T) {
req := httptest.NewRequest("GET", "http://localhost", nil) req := httptest.NewRequest("GET", "http://localhost", nil)
req.Header[http.CanonicalHeaderKey(tracerContextName)] = nil req.Header[http.CanonicalHeaderKey(TracerContextName)] = nil
tr := NewTracedRequest(req) tr := NewTracedRequest(req)
assert.NotNil(t, tr) assert.NotNil(t, tr)
assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider) assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider)
@ -41,7 +41,7 @@ func TestNewCfTracerNilHeader(t *testing.T) {
func TestNewCfTracerInvalidHeaders(t *testing.T) { func TestNewCfTracerInvalidHeaders(t *testing.T) {
req := httptest.NewRequest("GET", "http://localhost", nil) req := httptest.NewRequest("GET", "http://localhost", nil)
for _, test := range [][]string{nil, {""}} { for _, test := range [][]string{nil, {""}} {
req.Header[http.CanonicalHeaderKey(tracerContextName)] = test req.Header[http.CanonicalHeaderKey(TracerContextName)] = test
tr := NewTracedRequest(req) tr := NewTracedRequest(req)
assert.NotNil(t, tr) assert.NotNil(t, tr)
assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider) assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider)