witchcraft-go-server icon indicating copy to clipboard operation
witchcraft-go-server copied to clipboard

improvement: Refactor internal middleware to shorten overall stacktrace

Open bmoylan opened this issue 1 year ago • 1 comments
trafficstars

Stacktraces encountered by http requests are long because there are several wrapping middlewares which each add two lines to logged errors. This PR refactors route registration and the internal middlware implementations to reduce the overall size of logged errors.

Overall this reduces the length of stacktrace logs from within endpoints by 26 lines and about 2900 bytes:

Example before

github.com/palantir/witchcraft-go-server/v2/integration.TestLogging.func1.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/integration/server_test.go:411
net/http.HandlerFunc.ServeHTTP
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/net/http/server.go:2136
github.com/palantir/witchcraft-go-server/v2/wrouter.(*rootRouter).Register.func1.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:147
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRoutePanicRecovery.func10.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:122
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.panicRecoveryMiddleware.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:137
github.com/palantir/witchcraft-go-logging/wlog/wapp.RunWithRecoveryLoggingWithError
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/palantir/witchcraft-go-logging/wlog/wapp/fatal.go:66
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.panicRecoveryMiddleware
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:136
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRoutePanicRecovery.func10
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:121
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeRequestHandlerWithNext).HandleRequest
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:162
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRouteLogTraceSpan.func9
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:112
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeRequestHandlerWithNext).HandleRequest
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:162
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRouteRequestLog.func8
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:43
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeRequestHandlerWithNext).HandleRequest
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:162
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestMetricRequestMeter.func6
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:189
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeRequestHandlerWithNext).HandleRequest
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:162
github.com/palantir/witchcraft-go-server/v2/wrouter.(*rootRouter).Register.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:150
net/http.HandlerFunc.ServeHTTP
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/net/http/server.go:2136
github.com/palantir/witchcraft-go-server/v2/wrouter/whttprouter.(*router).Register.(*Router).Handler.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/julienschmidt/httprouter/router.go:275
github.com/julienschmidt/httprouter.(*Router).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/julienschmidt/httprouter/router.go:387
github.com/palantir/witchcraft-go-server/v2/wrouter/whttprouter.(*router).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/whttprouter/routerimpl.go:71
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewStrictTransportSecurityHeader.func7
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:210
github.com/palantir/witchcraft-go-server/v2/wrouter.(*requestHandlerWithNext).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:262
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestExtractIDs.func5
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:155
github.com/palantir/witchcraft-go-server/v2/wrouter.(*requestHandlerWithNext).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:262
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestContextLoggers.func4
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:84
github.com/palantir/witchcraft-go-server/v2/wrouter.(*requestHandlerWithNext).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:262
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestContextMetricsRegistry.func3
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:95
github.com/palantir/witchcraft-go-server/v2/wrouter.(*requestHandlerWithNext).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:262
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestPanicRecovery.func2.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:49
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.panicRecoveryMiddleware.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:137
github.com/palantir/witchcraft-go-logging/wlog/wapp.RunWithRecoveryLoggingWithError
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/palantir/witchcraft-go-logging/wlog/wapp/fatal.go:66
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.panicRecoveryMiddleware
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:136

Example After:

github.com/palantir/witchcraft-go-server/v2/integration.TestLogging.func1.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/integration/server_test.go:411
net/http.HandlerFunc.ServeHTTP
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/net/http/server.go:2136
github.com/palantir/witchcraft-go-server/v2/wrouter.(*rootRouter).Register.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:146
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.NewRouteTelemetry.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:67
github.com/palantir/witchcraft-go-logging/wlog/wapp.RunWithFatalLogging
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/palantir/witchcraft-go-logging/wlog/wapp/fatal.go:53
github.com/palantir/witchcraft-go-server/v2/witchcraft/internal/middleware.NewRouteTelemetry
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/route.go:66
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeRequestHandlerWithNext).HandleRequest
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:176
github.com/palantir/witchcraft-go-server/v2/wrouter.(*routeHandler).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:166
github.com/palantir/witchcraft-go-server/v2/wrouter/whttprouter.(*router).Register.(*Router).Handler.func1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/julienschmidt/httprouter/router.go:275
github.com/julienschmidt/httprouter.(*Router).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/julienschmidt/httprouter/router.go:387
github.com/palantir/witchcraft-go-server/v2/wrouter/whttprouter.(*router).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/whttprouter/routerimpl.go:71
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestTelemetry.func2.1
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:151
github.com/palantir/witchcraft-go-logging/wlog/wapp.RunWithFatalLogging
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/vendor/github.com/palantir/witchcraft-go-logging/wlog/wapp/fatal.go:53
github.com/palantir/witchcraft-go-server/v2/witchcraft.(*Server).addMiddleware.NewRequestTelemetry.func2
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/witchcraft/internal/middleware/request.go:76
github.com/palantir/witchcraft-go-server/v2/wrouter.(*requestHandlerWithNext).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:276
github.com/palantir/witchcraft-go-server/v2/wrouter.(*rootRouter).ServeHTTP
	/Volumes/git/src/github.com/palantir/witchcraft-go-server/wrouter/router_root.go:103
net/http.serverHandler.ServeHTTP
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/net/http/server.go:2938
net/http.(*conn).serve
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/net/http/server.go:2009
runtime.goexit
	/opt/homebrew/Cellar/[email protected]/1.21.8/libexec/src/runtime/asm_arm64.s:1197

This change is Reviewable

bmoylan avatar Apr 13 '24 04:04 bmoylan

I will likely end up breaking this into multiple PRs so the diffs are more traceable, but this is a start

bmoylan avatar Apr 23 '24 03:04 bmoylan