From 63f0d6a459f26c236f0f4b5ebd87af2270c85ae0 Mon Sep 17 00:00:00 2001 From: StephanHCB Date: Tue, 16 May 2023 19:28:30 +0200 Subject: [PATCH] feat(RELTEC-11181): add context cancellation logging --- internal/web/middleware/cancellogger.go | 24 ++++++++++++++++++++++++ internal/web/server/server.go | 10 ++++++++++ 2 files changed, 34 insertions(+) create mode 100644 internal/web/middleware/cancellogger.go diff --git a/internal/web/middleware/cancellogger.go b/internal/web/middleware/cancellogger.go new file mode 100644 index 0000000..28e5a56 --- /dev/null +++ b/internal/web/middleware/cancellogger.go @@ -0,0 +1,24 @@ +package middleware + +import ( + "context" + aulogging "github.com/StephanHCB/go-autumn-logging" + "net/http" +) + +func ConstructContextCancellationLoggerMiddleware(description string) func(http.Handler) http.Handler { + middleware := func(next http.Handler) http.Handler { + fn := func(w http.ResponseWriter, r *http.Request) { + ctx := r.Context() // next might change it so must remember it here + + next.ServeHTTP(w, r) + + cause := context.Cause(ctx) + if cause != nil { + aulogging.Logger.NoCtx().Warn().WithErr(cause).Printf("context '%s' is closed: %s", description, cause.Error()) + } + } + return http.HandlerFunc(fn) + } + return middleware +} diff --git a/internal/web/server/server.go b/internal/web/server/server.go index 5dad74c..6624b1e 100644 --- a/internal/web/server/server.go +++ b/internal/web/server/server.go @@ -55,6 +55,7 @@ func (s *Impl) WireUp(ctx context.Context) { if s.Router == nil { s.Logging.Logger().Ctx(ctx).Info().Print("creating router and setting up filter chain") s.Router = chi.NewRouter() + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("Top")) requestid.RequestIDHeader = apmhttp.W3CTraceparentHeader loggermiddleware.RequestIdFieldName = "trace.id" @@ -69,30 +70,39 @@ func (s *Impl) WireUp(ctx context.Context) { middleware.TraceContextFetcherForResponseHeaders = middleware.RestoreOrCreateTraceContextWithoutAPM s.Logging.Logger().NoCtx().Warn().Printf("Elastic APM not configured or disabled, skipping middleware.") } + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("ElasticApm")) // build a request specific logger (includes request id and some fields) and add it to the request context s.Router.Use(loggermiddleware.AddZerologLoggerToContext) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("AddZerologLoggerToContext")) // request logging requestlogging.Setup() s.Router.Use(chimiddleware.Logger) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("Logger")) // trap panics in requests and log stack trace s.Router.Use(middleware.PanicRecoverer) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("PanicRecoverer")) // add request id to response, so it can be found in header s.Router.Use(requestidinresponse.AddRequestIdHeaderToResponse) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("AddRequestIdHeaderToResponse")) s.Router.Use(corsheader.CorsHandling) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("CorsHandling")) requestmetrics.Setup() s.Router.Use(requestmetrics.RecordRequestMetrics) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("RecordRequestMetrics")) _ = jwt.Setup(s.IdentityProvider.GetKeySet(ctx), s.CustomConfiguration) s.Router.Use(jwt.JwtValidator) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("JwtValidator")) timeout.RequestTimeoutSeconds = s.RequestTimeoutSeconds s.Router.Use(timeout.AddRequestTimeout) + s.Router.Use(middleware.ConstructContextCancellationLoggerMiddleware("AddRequestTimeout")) } s.HealthCtl.WireUp(ctx, s.Router)