TUN-6576: Consume cf-trace-id from incoming TCP requests to create root span

(cherry picked from commit f48a7cd)

Author: DevinCarr

connection/connection.go

@@ -123,23 +123,24 @@ func (t Type) String() string {
 
 // OriginProxy is how data flows from cloudflared to the origin services running behind it.
 type OriginProxy interface {
-	ProxyHTTP(w ResponseWriter, tr *tracing.TracedRequest, isWebsocket bool) error
+	ProxyHTTP(w ResponseWriter, tr *tracing.TracedHTTPRequest, isWebsocket bool) error
 	ProxyTCP(ctx context.Context, rwa ReadWriteAcker, req *TCPRequest) error
 }
 
 // TCPRequest defines the input format needed to perform a TCP proxy.
 type TCPRequest struct {
-	Dest    string
-	CFRay   string
-	LBProbe bool
-	FlowID  string
+	Dest      string
+	CFRay     string
+	LBProbe   bool
+	FlowID    string
+	CfTraceID string
 }
 
 // ReadWriteAcker is a readwriter with the ability to Acknowledge to the downstream (edge) that the origin has
 // accepted the connection.
 type ReadWriteAcker interface {
 	io.ReadWriter
-	AckConnection() error
+	AckConnection(tracePropagation string) error
 }
 
 // HTTPResponseReadWriteAcker is an HTTP implementation of ReadWriteAcker.
@@ -168,7 +169,7 @@ func (h *HTTPResponseReadWriteAcker) Write(p []byte) (int, error) {
 
 // AckConnection acks an HTTP connection by sending a switch protocols status code that enables the caller to
 // upgrade to streams.
-func (h *HTTPResponseReadWriteAcker) AckConnection() error {
+func (h *HTTPResponseReadWriteAcker) AckConnection(tracePropagation string) error {
 	resp := &http.Response{
 		Status:        switchingProtocolText,
 		StatusCode:    http.StatusSwitchingProtocols,
@@ -179,6 +180,10 @@ func (h *HTTPResponseReadWriteAcker) AckConnection() error {
 		resp.Header = websocket.NewResponseHeader(h.req)
 	}
 
+	if tracePropagation != "" {
+		resp.Header.Add(tracing.CanonicalCloudflaredTracingHeader, tracePropagation)
+	}
+
 	return h.w.WriteRespHeaders(resp.StatusCode, resp.Header)
 }
 

connection/connection_test.go

@@ -30,6 +30,8 @@ var (
 	testLargeResp = make([]byte, largeFileSize)
 )
 
+var _ ReadWriteAcker = (*HTTPResponseReadWriteAcker)(nil)
+
 type testRequest struct {
 	name           string
 	endpoint       string
@@ -60,7 +62,7 @@ type mockOriginProxy struct{}
 
 func (moc *mockOriginProxy) ProxyHTTP(
 	w ResponseWriter,
-	tr *tracing.TracedRequest,
+	tr *tracing.TracedHTTPRequest,
 	isWebsocket bool,
 ) error {
 	req := tr.Request

connection/h2mux.go

@@ -69,6 +69,7 @@ func NewH2muxConnection(
 	connIndex uint8,
 	observer *Observer,
 	gracefulShutdownC <-chan struct{},
+	log *zerolog.Logger,
 ) (*h2muxConnection, error, bool) {
 	h := &h2muxConnection{
 		orchestrator:      orchestrator,
@@ -79,6 +80,7 @@ func NewH2muxConnection(
 		observer:          observer,
 		gracefulShutdownC: gracefulShutdownC,
 		newRPCClientFunc:  newRegistrationRPCClient,
+		log:               log,
 	}
 
 	// Establish a muxed connection with the edge
@@ -234,7 +236,7 @@ func (h *h2muxConnection) ServeStream(stream *h2mux.MuxedStream) error {
 		return err
 	}
 
-	err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedRequest(req), sourceConnectionType == TypeWebsocket)
+	err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, h.log), sourceConnectionType == TypeWebsocket)
 	if err != nil {
 		respWriter.WriteErrorResponse()
 	}

connection/h2mux_test.go

@@ -48,7 +48,7 @@ func newH2MuxConnection(t require.TestingT) (*h2muxConnection, *h2mux.Muxer) {
 	}()
 	var connIndex = uint8(0)
 	testObserver := NewObserver(&log, &log)
-	h2muxConn, err, _ := NewH2muxConnection(testOrchestrator, testGracePeriod, testMuxerConfig, originConn, connIndex, testObserver, nil)
+	h2muxConn, err, _ := NewH2muxConnection(testOrchestrator, testGracePeriod, testMuxerConfig, originConn, connIndex, testObserver, nil, &log)
 	require.NoError(t, err)
 	return h2muxConn, <-edgeMuxChan
 }

connection/http2.go

@@ -132,7 +132,7 @@ func (c *HTTP2Connection) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	case TypeWebsocket, TypeHTTP:
 		stripWebsocketUpgradeHeader(r)
 		// Check for tracing on request
-		tr := tracing.NewTracedRequest(r)
+		tr := tracing.NewTracedHTTPRequest(r, c.log)
 		if err := originProxy.ProxyHTTP(respWriter, tr, connType == TypeWebsocket); err != nil {
 			err := fmt.Errorf("Failed to proxy HTTP: %w", err)
 			c.log.Error().Err(err)

connection/quic.go

@@ -197,7 +197,7 @@ func (q *QUICConnection) dispatchRequest(ctx context.Context, stream *quicpogs.R
 
 	switch request.Type {
 	case quicpogs.ConnectionTypeHTTP, quicpogs.ConnectionTypeWebsocket:
-		tracedReq, err := buildHTTPRequest(ctx, request, stream)
+		tracedReq, err := buildHTTPRequest(ctx, request, stream, q.logger)
 		if err != nil {
 			return err
 		}
@@ -208,8 +208,9 @@ func (q *QUICConnection) dispatchRequest(ctx context.Context, stream *quicpogs.R
 		rwa := &streamReadWriteAcker{stream}
 		metadata := request.MetadataMap()
 		return originProxy.ProxyTCP(ctx, rwa, &TCPRequest{
-			Dest:   request.Dest,
-			FlowID: metadata[QUICMetadataFlowID],
+			Dest:      request.Dest,
+			FlowID:    metadata[QUICMetadataFlowID],
+			CfTraceID: metadata[tracing.TracerContextName],
 		})
 	}
 	return nil
@@ -296,8 +297,12 @@ type streamReadWriteAcker struct {
 }
 
 // AckConnection acks response back to the proxy.
-func (s *streamReadWriteAcker) AckConnection() error {
-	return s.WriteConnectResponseData(nil)
+func (s *streamReadWriteAcker) AckConnection(tracePropagation string) error {
+	metadata := quicpogs.Metadata{
+		Key: tracing.CanonicalCloudflaredTracingHeader,
+		Val: tracePropagation,
+	}
+	return s.WriteConnectResponseData(nil, metadata)
 }
 
 // httpResponseAdapter translates responses written by the HTTP Proxy into ones that can be used in QUIC.
@@ -325,7 +330,12 @@ func (hrw httpResponseAdapter) WriteErrorResponse(err error) {
 	hrw.WriteConnectResponseData(err, quicpogs.Metadata{Key: "HttpStatus", Val: strconv.Itoa(http.StatusBadGateway)})
 }
 
-func buildHTTPRequest(ctx context.Context, connectRequest *quicpogs.ConnectRequest, body io.ReadCloser) (*tracing.TracedRequest, error) {
+func buildHTTPRequest(
+	ctx context.Context,
+	connectRequest *quicpogs.ConnectRequest,
+	body io.ReadCloser,
+	log *zerolog.Logger,
+) (*tracing.TracedHTTPRequest, error) {
 	metadata := connectRequest.MetadataMap()
 	dest := connectRequest.Dest
 	method := metadata[HTTPMethodKey]
@@ -367,7 +377,7 @@ func buildHTTPRequest(ctx context.Context, connectRequest *quicpogs.ConnectReque
 	stripWebsocketUpgradeHeader(req)
 
 	// Check for tracing on request
-	tracedReq := tracing.NewTracedRequest(req)
+	tracedReq := tracing.NewTracedHTTPRequest(req, log)
 	return tracedReq, err
 }
 

connection/quic_test.go

@@ -36,6 +36,8 @@ var (
 	}
 )
 
+var _ ReadWriteAcker = (*streamReadWriteAcker)(nil)
+
 // TestQUICServer tests if a quic server accepts and responds to a quic client with the acceptance protocol.
 // It also serves as a demonstration for communication with the QUIC connection started by a cloudflared.
 func TestQUICServer(t *testing.T) {
@@ -220,7 +222,7 @@ func quicServer(
 
 type mockOriginProxyWithRequest struct{}
 
-func (moc *mockOriginProxyWithRequest) ProxyHTTP(w ResponseWriter, tr *tracing.TracedRequest, isWebsocket bool) error {
+func (moc *mockOriginProxyWithRequest) ProxyHTTP(w ResponseWriter, tr *tracing.TracedHTTPRequest, isWebsocket bool) error {
 	// These are a series of crude tests to ensure the headers and http related data is transferred from
 	// metadata.
 	r := tr.Request
@@ -475,9 +477,10 @@ func TestBuildHTTPRequest(t *testing.T) {
 		},
 	}
 
+	log := zerolog.Nop()
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			req, err := buildHTTPRequest(context.Background(), test.connectRequest, test.body)
+			req, err := buildHTTPRequest(context.Background(), test.connectRequest, test.body, &log)
 			assert.NoError(t, err)
 			test.req = test.req.WithContext(req.Context())
 			assert.Equal(t, test.req, req.Request)
@@ -486,7 +489,7 @@ func TestBuildHTTPRequest(t *testing.T) {
 }
 
 func (moc *mockOriginProxyWithRequest) ProxyTCP(ctx context.Context, rwa ReadWriteAcker, tcpRequest *TCPRequest) error {
-	rwa.AckConnection()
+	rwa.AckConnection("")
 	io.Copy(rwa, rwa)
 	return nil
 }

orchestration/orchestrator_test.go

@@ -355,7 +355,7 @@ func proxyHTTP(originProxy connection.OriginProxy, hostname string) (*http.Respo
 		return nil, err
 	}
 
-	err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedRequest(req), false)
+	err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), false)
 	if err != nil {
 		return nil, err
 	}
@@ -604,7 +604,7 @@ func TestPersistentConnection(t *testing.T) {
 		respWriter, err := connection.NewHTTP2RespWriter(req, wsRespReadWriter, connection.TypeWebsocket, &log)
 		require.NoError(t, err)
 
-		err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedRequest(req), true)
+		err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), true)
 		require.NoError(t, err)
 	}()
 

proxy/proxy.go

@@ -63,7 +63,7 @@ func NewOriginProxy(
 // a simple roundtrip or a tcp/websocket dial depending on ingres rule setup.
 func (p *Proxy) ProxyHTTP(
 	w connection.ResponseWriter,
-	tr *tracing.TracedRequest,
+	tr *tracing.TracedHTTPRequest,
 	isWebsocket bool,
 ) error {
 	incrementRequests()
@@ -108,7 +108,7 @@ func (p *Proxy) ProxyHTTP(
 		}
 
 		rws := connection.NewHTTPResponseReadWriterAcker(w, req)
-		if err := p.proxyStream(req.Context(), rws, dest, originProxy); err != nil {
+		if err := p.proxyStream(tr.ToTracedContext(), rws, dest, originProxy); err != nil {
 			rule, srv := ruleField(p.ingressRules, ruleNum)
 			p.logRequestError(err, cfRay, "", rule, srv)
 			return err
@@ -137,9 +137,11 @@ func (p *Proxy) ProxyTCP(
 	serveCtx, cancel := context.WithCancel(ctx)
 	defer cancel()
 
+	tracedCtx := tracing.NewTracedContext(serveCtx, req.CfTraceID, p.log)
+
 	p.log.Debug().Str(LogFieldFlowID, req.FlowID).Msg("tcp proxy stream started")
 
-	if err := p.proxyStream(serveCtx, rwa, req.Dest, p.warpRouting.Proxy); err != nil {
+	if err := p.proxyStream(tracedCtx, rwa, req.Dest, p.warpRouting.Proxy); err != nil {
 		p.logRequestError(err, req.CFRay, req.FlowID, "", ingress.ServiceWarpRouting)
 		return err
 	}
@@ -160,7 +162,7 @@ func ruleField(ing ingress.Ingress, ruleNum int) (ruleID string, srv string) {
 // ProxyHTTPRequest proxies requests of underlying type http and websocket to the origin service.
 func (p *Proxy) proxyHTTPRequest(
 	w connection.ResponseWriter,
-	tr *tracing.TracedRequest,
+	tr *tracing.TracedHTTPRequest,
 	httpService ingress.HTTPOriginProxy,
 	isWebsocket bool,
 	disableChunkedEncoding bool,
@@ -211,7 +213,7 @@ func (p *Proxy) proxyHTTPRequest(
 	}
 
 	// Add spans to response header (if available)
-	tr.AddSpans(resp.Header, p.log)
+	tr.AddSpans(resp.Header)
 
 	err = w.WriteRespHeaders(resp.StatusCode, resp.Header)
 	if err != nil {
@@ -248,17 +250,23 @@ func (p *Proxy) proxyHTTPRequest(
 // proxyStream proxies type TCP and other underlying types if the connection is defined as a stream oriented
 // ingress rule.
 func (p *Proxy) proxyStream(
-	ctx context.Context,
+	tr *tracing.TracedContext,
 	rwa connection.ReadWriteAcker,
 	dest string,
 	connectionProxy ingress.StreamBasedOriginProxy,
 ) error {
+	ctx := tr.Context
+	_, connectSpan := tr.Tracer().Start(ctx, "stream_connect")
 	originConn, err := connectionProxy.EstablishConnection(ctx, dest)
 	if err != nil {
+		tracing.EndWithErrorStatus(connectSpan, err)
 		return err
 	}
+	connectSpan.End()
+
+	encodedSpans := tr.GetSpans()
 
-	if err := rwa.AckConnection(); err != nil {
+	if err := rwa.AckConnection(encodedSpans); err != nil {
 		return err
 	}
 

proxy/proxy_test.go

@@ -157,7 +157,8 @@ func testProxyHTTP(proxy connection.OriginProxy) func(t *testing.T) {
 		req, err := http.NewRequest(http.MethodGet, "http://localhost:8080", nil)
 		require.NoError(t, err)
 
-		err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedRequest(req), false)
+		log := zerolog.Nop()
+		err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
 		require.NoError(t, err)
 		for _, tag := range testTags {
 			assert.Equal(t, tag.Value, req.Header.Get(TagHeaderNamePrefix+tag.Name))
@@ -184,7 +185,8 @@ func testProxyWebsocket(proxy connection.OriginProxy) func(t *testing.T) {
 
 		errGroup, ctx := errgroup.WithContext(ctx)
 		errGroup.Go(func() error {
-			err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedRequest(req), true)
+			log := zerolog.Nop()
+			err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), true)
 			require.NoError(t, err)
 
 			require.Equal(t, http.StatusSwitchingProtocols, responseWriter.Code)
@@ -245,7 +247,8 @@ func testProxySSE(proxy connection.OriginProxy) func(t *testing.T) {
 		wg.Add(1)
 		go func() {
 			defer wg.Done()
-			err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedRequest(req), false)
+			log := zerolog.Nop()
+			err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
 			require.NoError(t, err)
 
 			require.Equal(t, http.StatusOK, responseWriter.Code)
@@ -357,7 +360,7 @@ func runIngressTestScenarios(t *testing.T, unvalidatedIngress []config.Unvalidat
 		req, err := http.NewRequest(http.MethodGet, test.url, nil)
 		require.NoError(t, err)
 
-		err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedRequest(req), false)
+		err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
 		require.NoError(t, err)
 
 		assert.Equal(t, test.expectedStatus, responseWriter.Code)
@@ -404,7 +407,7 @@ func TestProxyError(t *testing.T) {
 	req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1", nil)
 	assert.NoError(t, err)
 
-	assert.Error(t, proxy.ProxyHTTP(responseWriter, tracing.NewTracedRequest(req), false))
+	assert.Error(t, proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false))
 }
 
 type replayer struct {
@@ -682,7 +685,8 @@ func TestConnections(t *testing.T) {
 				rwa := connection.NewHTTPResponseReadWriterAcker(respWriter, req)
 				err = proxy.ProxyTCP(ctx, rwa, &connection.TCPRequest{Dest: dest})
 			} else {
-				err = proxy.ProxyHTTP(respWriter, tracing.NewTracedRequest(req), test.args.connectionType == connection.TypeWebsocket)
+				log := zerolog.Nop()
+				err = proxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), test.args.connectionType == connection.TypeWebsocket)
 			}
 
 			cancel()