From f1affbebc81921838e1c2f564eb4f83acf85acc3 Mon Sep 17 00:00:00 2001 From: Dean Sheather Date: Wed, 9 Nov 2022 21:13:04 +0000 Subject: [PATCH 1/5] feat: move tracing middleware higher up the middleware stack --- coderd/coderd.go | 13 +-- coderd/coderdtest/authorize.go | 2 - coderd/httpmw/logger.go | 7 +- coderd/httpmw/patternmatcher/routepatterns.go | 50 ++++++++++ .../patternmatcher/routepatterns_test.go | 99 +++++++++++++++++++ coderd/tracing/httpmw.go | 16 ++- coderd/tracing/util.go | 20 ++-- codersdk/client.go | 21 ++-- 8 files changed, 196 insertions(+), 32 deletions(-) create mode 100644 coderd/httpmw/patternmatcher/routepatterns.go create mode 100644 coderd/httpmw/patternmatcher/routepatterns_test.go diff --git a/coderd/coderd.go b/coderd/coderd.go index 1eaaf01fbf10c..251a14110d1ae 100644 --- a/coderd/coderd.go +++ b/coderd/coderd.go @@ -202,8 +202,9 @@ func New(options *Options) *API { }) r.Use( - httpmw.AttachRequestID, httpmw.Recover(api.Logger), + tracing.Middleware(api.TracerProvider), + httpmw.AttachRequestID, httpmw.ExtractRealIP(api.RealIPConfig), httpmw.Logger(api.Logger), httpmw.Prometheus(options.PrometheusRegistry), @@ -237,7 +238,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, @@ -285,7 +285,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), ) @@ -509,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) { diff --git a/coderd/coderdtest/authorize.go b/coderd/coderdtest/authorize.go index f7636604642f8..1fca7c2e3599e 100644 --- a/coderd/coderdtest/authorize.go +++ b/coderd/coderdtest/authorize.go @@ -47,8 +47,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}, diff --git a/coderd/httpmw/logger.go b/coderd/httpmw/logger.go index 7888d72144b31..73ed1911be9e5 100644 --- a/coderd/httpmw/logger.go +++ b/coderd/httpmw/logger.go @@ -1,6 +1,7 @@ package httpmw import ( + "context" "net/http" "time" @@ -51,7 +52,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) + }) }) } } diff --git a/coderd/httpmw/patternmatcher/routepatterns.go b/coderd/httpmw/patternmatcher/routepatterns.go new file mode 100644 index 0000000000000..c27c64d5e8daf --- /dev/null +++ b/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 +} diff --git a/coderd/httpmw/patternmatcher/routepatterns_test.go b/coderd/httpmw/patternmatcher/routepatterns_test.go new file mode 100644 index 0000000000000..26b71a6dfb6e9 --- /dev/null +++ b/coderd/httpmw/patternmatcher/routepatterns_test.go @@ -0,0 +1,99 @@ +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: "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: "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()) + }) + } + }) + } +} diff --git a/coderd/tracing/httpmw.go b/coderd/tracing/httpmw.go index 97f9755d2e8ff..9776b4990337f 100644 --- a/coderd/tracing/httpmw.go +++ b/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 } diff --git a/coderd/tracing/util.go b/coderd/tracing/util.go index f65e6e784cf90..bcb2ade20a30b 100644 --- a/coderd/tracing/util.go +++ b/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,12 @@ 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, span := trace.NewNoopTracerProvider().Tracer("").Start(ctx, "") + defer span.End() + fn(ctx) +} diff --git a/codersdk/client.go b/codersdk/client.go index ff0df7a76d61a..0325a4d164fdb 100644 --- a/codersdk/client.go +++ b/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 } From 032f1cf7ba7c29bd3bf48804ee0bfd7a18ab61a2 Mon Sep 17 00:00:00 2001 From: Dean Sheather Date: Wed, 9 Nov 2022 21:13:43 +0000 Subject: [PATCH 2/5] fixup! feat: move tracing middleware higher up the middleware stack --- coderd/tracing/util.go | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/coderd/tracing/util.go b/coderd/tracing/util.go index bcb2ade20a30b..89780b77d2ad8 100644 --- a/coderd/tracing/util.go +++ b/coderd/tracing/util.go @@ -38,7 +38,6 @@ func FuncNameSkip(skip int) string { // 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, span := trace.NewNoopTracerProvider().Tracer("").Start(ctx, "") - defer span.End() + ctx = trace.ContextWithSpan(ctx, NoopSpan) fn(ctx) } From d892c2134046ae1a22070eff03dbfd3ebe6720f2 Mon Sep 17 00:00:00 2001 From: Dean Sheather Date: Thu, 17 Nov 2022 14:44:04 +0000 Subject: [PATCH 3/5] fixup! feat: move tracing middleware higher up the middleware stack --- coderd/tracing/httpmw_test.go | 95 +++++++++++++++++++++++++++++++++++ 1 file changed, 95 insertions(+) create mode 100644 coderd/tracing/httpmw_test.go diff --git a/coderd/tracing/httpmw_test.go b/coderd/tracing/httpmw_test.go new file mode 100644 index 0000000000000..9880cfa2d70c0 --- /dev/null +++ b/coderd/tracing/httpmw_test.go @@ -0,0 +1,95 @@ +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 +} + +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") + }) + } + }) +} From 7383e8c016dafb64ae15e1ce9fc4c3709a605384 Mon Sep 17 00:00:00 2001 From: Dean Sheather Date: Thu, 17 Nov 2022 16:14:48 +0000 Subject: [PATCH 4/5] fixup! feat: move tracing middleware higher up the middleware stack --- coderd/coderd.go | 1 + coderd/httpmw/logger.go | 9 +++++++-- coderd/tracing/httpmw_test.go | 1 + coderd/tracing/status_writer.go | 7 +++++++ 4 files changed, 16 insertions(+), 2 deletions(-) diff --git a/coderd/coderd.go b/coderd/coderd.go index 251a14110d1ae..a7908f3f7ca03 100644 --- a/coderd/coderd.go +++ b/coderd/coderd.go @@ -203,6 +203,7 @@ func New(options *Options) *API { r.Use( httpmw.Recover(api.Logger), + tracing.StatusWriterMiddleware, tracing.Middleware(api.TracerProvider), httpmw.AttachRequestID, httpmw.ExtractRealIP(api.RealIPConfig), diff --git a/coderd/httpmw/logger.go b/coderd/httpmw/logger.go index 73ed1911be9e5..e9ee400c5c581 100644 --- a/coderd/httpmw/logger.go +++ b/coderd/httpmw/logger.go @@ -2,6 +2,7 @@ package httpmw import ( "context" + "fmt" "net/http" "time" @@ -12,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)), diff --git a/coderd/tracing/httpmw_test.go b/coderd/tracing/httpmw_test.go index 9880cfa2d70c0..dbd9bdfe83d26 100644 --- a/coderd/tracing/httpmw_test.go +++ b/coderd/tracing/httpmw_test.go @@ -29,6 +29,7 @@ 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 diff --git a/coderd/tracing/status_writer.go b/coderd/tracing/status_writer.go index 18a362176c69e..07a8d1389ca34 100644 --- a/coderd/tracing/status_writer.go +++ b/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 From 343e27d16229e2ae0b20bb3c702ab1bebd0b7b88 Mon Sep 17 00:00:00 2001 From: Dean Sheather Date: Wed, 23 Nov 2022 15:19:17 +0000 Subject: [PATCH 5/5] fixup! feat: move tracing middleware higher up the middleware stack --- .../patternmatcher/routepatterns_test.go | 36 +++++++++++++++++++ 1 file changed, 36 insertions(+) diff --git a/coderd/httpmw/patternmatcher/routepatterns_test.go b/coderd/httpmw/patternmatcher/routepatterns_test.go index 26b71a6dfb6e9..972e22727ad32 100644 --- a/coderd/httpmw/patternmatcher/routepatterns_test.go +++ b/coderd/httpmw/patternmatcher/routepatterns_test.go @@ -29,6 +29,13 @@ func Test_RoutePatterns(t *testing.T) { }, output: "^(/api/?)$", }, + { + name: "TrailingSlash", + patterns: []string{ + "/api/", + }, + output: "^(/api/)$", + }, { name: "Multiple", patterns: []string{ @@ -62,6 +69,35 @@ func Test_RoutePatterns(t *testing.T) { }, 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{