feat: tracing improvements (#4988)

coderd/coderd.go

@@ -204,8 +204,10 @@ func New(options *Options) *API {
 	})
 
 	r.Use(
-		httpmw.AttachRequestID,
 		httpmw.Recover(api.Logger),
+		tracing.StatusWriterMiddleware,
+		tracing.Middleware(api.TracerProvider),
+		httpmw.AttachRequestID,
 		httpmw.ExtractRealIP(api.RealIPConfig),
 		httpmw.Logger(api.Logger),
 		httpmw.Prometheus(options.PrometheusRegistry),
@@ -239,7 +241,6 @@ func New(options *Options) *API {
 
 	apps := func(r chi.Router) {
 		r.Use(
-			tracing.Middleware(api.TracerProvider),
 			httpmw.RateLimit(options.APIRateLimit, time.Minute),
 			httpmw.ExtractAPIKey(httpmw.ExtractAPIKeyConfig{
 				DB:            options.Database,
@@ -287,7 +288,6 @@ func New(options *Options) *API {
 
 		r.NotFound(func(rw http.ResponseWriter, r *http.Request) { httpapi.RouteNotFound(rw) })
 		r.Use(
-			tracing.Middleware(api.TracerProvider),
 			// Specific routes can specify smaller limits.
 			httpmw.RateLimit(options.APIRateLimit, time.Minute),
 		)
@@ -508,14 +508,6 @@ func New(options *Options) *API {
 				r.Get("/listening-ports", api.workspaceAgentListeningPorts)
 				r.Get("/connection", api.workspaceAgentConnection)
 				r.Get("/coordinate", api.workspaceAgentClientCoordinate)
-				// TODO: This can be removed in October. It allows for a friendly
-				// error message when transitioning from WebRTC to Tailscale. See:
-				// https://github.com/coder/coder/issues/4126
-				r.Get("/dial", func(w http.ResponseWriter, r *http.Request) {
-					httpapi.Write(r.Context(), w, http.StatusGone, codersdk.Response{
-						Message: "Your Coder CLI is out of date, and requires v0.8.15+ to connect!",
-					})
-				})
 			})
 		})
 		r.Route("/workspaces", func(r chi.Router) {

coderd/coderdtest/authorize.go

@@ -55,8 +55,6 @@ func AGPLRoutes(a *AuthTester) (map[string]string, map[string]RouteCheck) {
 		"POST:/api/v2/csp/reports":      {NoAuthorize: true},
 		"POST:/api/v2/authcheck":        {NoAuthorize: true},
 		"GET:/api/v2/applications/host": {NoAuthorize: true},
-		// This is a dummy endpoint for compatibility with older CLI versions.
-		"GET:/api/v2/workspaceagents/{workspaceagent}/dial": {NoAuthorize: true},
 
 		// Has it's own auth
 		"GET:/api/v2/users/oauth2/github/callback": {NoAuthorize: true},

coderd/httpmw/logger.go

@@ -1,6 +1,8 @@
 package httpmw
 
 import (
+	"context"
+	"fmt"
 	"net/http"
 	"time"
 
@@ -11,9 +13,13 @@ import (
 
 func Logger(log slog.Logger) func(next http.Handler) http.Handler {
 	return func(next http.Handler) http.Handler {
-		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
 			start := time.Now()
-			sw := &tracing.StatusWriter{ResponseWriter: w}
+
+			sw, ok := rw.(*tracing.StatusWriter)
+			if !ok {
+				panic(fmt.Sprintf("ResponseWriter not a *tracing.StatusWriter; got %T", rw))
+			}
 
 			httplog := log.With(
 				slog.F("host", httpapi.RequestHost(r)),
@@ -51,7 +57,11 @@ func Logger(log slog.Logger) func(next http.Handler) http.Handler {
 				logLevelFn = httplog.Warn
 			}
 
-			logLevelFn(r.Context(), r.Method)
+			// We already capture most of this information in the span (minus
+			// the response body which we don't want to capture anyways).
+			tracing.RunWithoutSpan(r.Context(), func(ctx context.Context) {
+				logLevelFn(ctx, r.Method)
+			})
 		})
 	}
 }

coderd/httpmw/patternmatcher/routepatterns.go

@@ -0,0 +1,50 @@
+package patternmatcher
+
+import (
+	"fmt"
+	"regexp"
+	"strings"
+
+	"golang.org/x/xerrors"
+)
+
+// RoutePatterns provides a method to generate a regex which will match a URL
+// path against a collection of patterns. If any of the patterns match the path,
+// the regex will return a successful match.
+//
+// Multiple patterns can be provided and they are matched in order. Example:
+// - /api/* matches /api/1 but not /api or /api/1/2
+// - /api/*/2 matches /api/1/2 but not /api/2 /api/1
+// - /api/** matches /api/1, /api/1/2, /api/1/2/3 but not /api
+// - /api/**/3 matches /api/1/2, /api/1/2/3 but not /api, /api/1 or /api/1/2
+//
+// All patterns support an optional trailing slash.
+type RoutePatterns []string
+
+func (rp RoutePatterns) MustCompile() *regexp.Regexp {
+	re, err := rp.Compile()
+	if err != nil {
+		panic(err)
+	}
+	return re
+}
+
+func (rp RoutePatterns) Compile() (*regexp.Regexp, error) {
+	patterns := make([]string, len(rp))
+	for i, p := range rp {
+		p = strings.ReplaceAll(p, "**", ".+")
+		p = strings.ReplaceAll(p, "*", "[^/]+")
+		if !strings.HasSuffix(p, "/") {
+			p += "/?"
+		}
+		patterns[i] = p
+	}
+
+	pattern := fmt.Sprintf("^(%s)$", strings.Join(patterns, "|"))
+	re, err := regexp.Compile(pattern)
+	if err != nil {
+		return nil, xerrors.Errorf("compile regex %q: %w", pattern, err)
+	}
+
+	return re, nil
+}

coderd/httpmw/patternmatcher/routepatterns_test.go

@@ -0,0 +1,135 @@
+package patternmatcher_test
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/require"
+
+	"github.com/coder/coder/coderd/httpmw/patternmatcher"
+)
+
+func Test_RoutePatterns(t *testing.T) {
+	t.Parallel()
+
+	cases := []struct {
+		name        string
+		patterns    []string
+		errContains string
+		output      string
+	}{
+		{
+			name:     "Empty",
+			patterns: []string{},
+			output:   "^()$",
+		},
+		{
+			name: "Single",
+			patterns: []string{
+				"/api",
+			},
+			output: "^(/api/?)$",
+		},
+		{
+			name: "TrailingSlash",
+			patterns: []string{
+				"/api/",
+			},
+			output: "^(/api/)$",
+		},
+		{
+			name: "Multiple",
+			patterns: []string{
+				"/api",
+				"/api2",
+			},
+			output: "^(/api/?|/api2/?)$",
+		},
+		{
+			name: "Star",
+			patterns: []string{
+				"/api/*",
+			},
+			output: "^(/api/[^/]+/?)$",
+		},
+		{
+			name: "StarStar",
+			patterns: []string{
+				"/api/**",
+			},
+			output: "^(/api/.+/?)$",
+		},
+		{
+			name: "TelemetryPatterns",
+			patterns: []string{
+				"/api",
+				"/api/**",
+				"/@*/*/apps/**",
+				"/%40*/*/apps/**",
+				"/gitauth/*/callback",
+			},
+			output: "^(/api/?|/api/.+/?|/@[^/]+/[^/]+/apps/.+/?|/%40[^/]+/[^/]+/apps/.+/?|/gitauth/[^/]+/callback/?)$",
+		},
+		{
+			name: "Slash",
+			patterns: []string{
+				"/",
+			},
+			output: "^(/)$",
+		},
+		{
+			name: "SlashStar",
+			patterns: []string{
+				"/*",
+			},
+			output: "^(/[^/]+/?)$",
+		},
+		{
+			name: "SlashStarStar",
+			patterns: []string{
+				"/**",
+			},
+			output: "^(/.+/?)$",
+		},
+		{
+			name: "SlashSlash",
+			patterns: []string{
+				"//",
+				"/api//v1",
+			},
+			output: "^(//|/api//v1/?)$",
+		},
+		{
+			name: "Invalid",
+			patterns: []string{
+				"/api(",
+			},
+			errContains: "compile regex",
+		},
+	}
+
+	for _, c := range cases {
+		c := c
+		t.Run(c.name, func(t *testing.T) {
+			t.Parallel()
+
+			rp := patternmatcher.RoutePatterns(c.patterns)
+			re, err := rp.Compile()
+			if c.errContains != "" {
+				require.Error(t, err)
+				require.ErrorContains(t, err, c.errContains)
+
+				require.Panics(t, func() {
+					_ = rp.MustCompile()
+				})
+			} else {
+				require.NoError(t, err)
+				require.Equal(t, c.output, re.String())
+
+				require.NotPanics(t, func() {
+					re := rp.MustCompile()
+					require.Equal(t, c.output, re.String())
+				})
+			}
+		})
+	}
+}

coderd/tracing/httpmw.go

@@ -10,17 +10,31 @@ import (
 	"go.opentelemetry.io/otel/propagation"
 	semconv "go.opentelemetry.io/otel/semconv/v1.11.0"
 	"go.opentelemetry.io/otel/trace"
+
+	"github.com/coder/coder/coderd/httpmw/patternmatcher"
 )
 
 // Middleware adds tracing to http routes.
 func Middleware(tracerProvider trace.TracerProvider) func(http.Handler) http.Handler {
+	// We only want to create spans on the following route patterns, however
+	// we want the middleware to be very high in the middleware stack so it can
+	// capture the entire request.
+	re := patternmatcher.RoutePatterns{
+		"/api",
+		"/api/**",
+		"/@*/*/apps/**",
+		"/%40*/*/apps/**",
+		"/gitauth/*/callback",
+	}.MustCompile()
+
 	var tracer trace.Tracer
 	if tracerProvider != nil {
 		tracer = tracerProvider.Tracer(TracerName)
 	}
+
 	return func(next http.Handler) http.Handler {
 		return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
-			if tracer == nil {
+			if tracer == nil || !re.MatchString(r.URL.Path) {
 				next.ServeHTTP(rw, r)
 				return
 			}

coderd/tracing/httpmw_test.go

@@ -0,0 +1,96 @@
+package tracing_test
+
+import (
+	"context"
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"sync/atomic"
+	"testing"
+
+	"go.opentelemetry.io/otel/trace"
+
+	"github.com/go-chi/chi/v5"
+	"github.com/stretchr/testify/require"
+
+	"github.com/coder/coder/coderd/tracing"
+	"github.com/coder/coder/testutil"
+)
+
+type fakeTracer struct {
+	startCalled int64
+}
+
+var _ trace.TracerProvider = &fakeTracer{}
+var _ trace.Tracer = &fakeTracer{}
+
+// Tracer implements trace.TracerProvider.
+func (f *fakeTracer) Tracer(_ string, _ ...trace.TracerOption) trace.Tracer {
+	return f
+}
+
+// Start implements trace.Tracer.
+func (f *fakeTracer) Start(ctx context.Context, _ string, _ ...trace.SpanStartOption) (context.Context, trace.Span) {
+	atomic.AddInt64(&f.startCalled, 1)
+	return ctx, tracing.NoopSpan
+}
+
+func Test_Middleware(t *testing.T) {
+	t.Parallel()
+
+	t.Run("OnlyRunsOnExpectedRoutes", func(t *testing.T) {
+		t.Parallel()
+
+		cases := []struct {
+			path string
+			runs bool
+		}{
+			// Should pass.
+			{"/api", true},
+			{"/api/v0", true},
+			{"/api/v2", true},
+			{"/api/v2/workspaces/", true},
+			{"/api/v2/workspaces", true},
+			{"/@hi/hi/apps/hi", true},
+			{"/@hi/hi/apps/hi/hi", true},
+			{"/@hi/hi/apps/hi/hi", true},
+			{"/%40hi/hi/apps/hi", true},
+			{"/%40hi/hi/apps/hi/hi", true},
+			{"/%40hi/hi/apps/hi/hi", true},
+			{"/gitauth/hi/callback", true},
+
+			// Other routes that should not be collected.
+			{"/index.html", false},
+			{"/static/coder_linux_amd64", false},
+			{"/workspaces", false},
+			{"/templates", false},
+			{"/@hi/hi/terminal", false},
+		}
+
+		for _, c := range cases {
+			c := c
+
+			name := strings.ReplaceAll(strings.TrimPrefix(c.path, "/"), "/", "_")
+			t.Run(name, func(t *testing.T) {
+				t.Parallel()
+
+				fake := &fakeTracer{}
+
+				rw := &tracing.StatusWriter{ResponseWriter: httptest.NewRecorder()}
+				r := httptest.NewRequest("GET", c.path, nil)
+
+				ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitLong)
+				defer cancel()
+				ctx = context.WithValue(ctx, chi.RouteCtxKey, chi.NewRouteContext())
+				r = r.WithContext(ctx)
+
+				tracing.Middleware(fake)(http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
+					rw.WriteHeader(http.StatusNoContent)
+				})).ServeHTTP(rw, r)
+
+				didRun := atomic.LoadInt64(&fake.startCalled) == 1
+				require.Equal(t, c.runs, didRun, "expected middleware to run/not run")
+			})
+		}
+	})
+}

coderd/tracing/status_writer.go

@@ -23,6 +23,13 @@ type StatusWriter struct {
 	wroteHeader bool
 }
 
+func StatusWriterMiddleware(next http.Handler) http.Handler {
+	return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
+		sw := &StatusWriter{ResponseWriter: rw}
+		next.ServeHTTP(sw, r)
+	})
+}
+
 func (w *StatusWriter) WriteHeader(status int) {
 	if !w.wroteHeader {
 		w.Status = status

coderd/tracing/util.go

@@ -18,16 +18,7 @@ func init() {
 const TracerName = "coderd"
 
 func FuncName() string {
-	fnpc, _, _, ok := runtime.Caller(1)
-	if !ok {
-		return ""
-	}
-	fn := runtime.FuncForPC(fnpc)
-	name := fn.Name()
-	if i := strings.LastIndex(name, "/"); i > 0 {
-		name = name[i+1:]
-	}
-	return name
+	return FuncNameSkip(1)
 }
 
 func FuncNameSkip(skip int) string {
@@ -42,3 +33,11 @@ func FuncNameSkip(skip int) string {
 	}
 	return name
 }
+
+// RunWithoutSpan runs the given function with the span stripped from the
+// context and replaced with a no-op span. This is useful for avoiding logs
+// being added to span (to save money).
+func RunWithoutSpan(ctx context.Context, fn func(ctx context.Context)) {
+	ctx = trace.ContextWithSpan(ctx, NoopSpan)
+	fn(ctx)
+}

codersdk/client.go

@@ -187,11 +187,15 @@ func (c *Client) Request(ctx context.Context, method, path string, body interfac
 		tmp.Inject(ctx, hc)
 	}
 
+	// We already capture most of this information in the span (minus
+	// the request body which we don't want to capture anyways).
 	ctx = slog.With(ctx,
 		slog.F("method", req.Method),
 		slog.F("url", req.URL.String()),
 	)
-	c.Logger.Debug(ctx, "sdk request", slog.F("body", string(reqBody)))
+	tracing.RunWithoutSpan(ctx, func(ctx context.Context) {
+		c.Logger.Debug(ctx, "sdk request", slog.F("body", string(reqBody)))
+	})
 
 	resp, err := c.HTTPClient.Do(req)
 	if err != nil {
@@ -218,12 +222,15 @@ func (c *Client) Request(ctx context.Context, method, path string, body interfac
 		}
 	}
 
-	c.Logger.Debug(ctx, "sdk response",
-		slog.F("status", resp.StatusCode),
-		slog.F("body", string(respBody)),
-		slog.F("trace_id", resp.Header.Get("X-Trace-Id")),
-		slog.F("span_id", resp.Header.Get("X-Span-Id")),
-	)
+	// See above for why this is not logged to the span.
+	tracing.RunWithoutSpan(ctx, func(ctx context.Context) {
+		c.Logger.Debug(ctx, "sdk response",
+			slog.F("status", resp.StatusCode),
+			slog.F("body", string(respBody)),
+			slog.F("trace_id", resp.Header.Get("X-Trace-Id")),
+			slog.F("span_id", resp.Header.Get("X-Span-Id")),
+		)
+	})
 
 	return resp, err
 }