From 845d3561920be8c823ca9659326a908d3dcf3a5b Mon Sep 17 00:00:00 2001 From: Robert Pirtle Date: Wed, 7 Feb 2024 11:07:44 -0800 Subject: [PATCH] replace request logging mdw w/ decode request mdw --- service/cachemdw/cache.go | 2 ++ service/middleware.go | 25 ++++++------------------- service/service.go | 26 +++++++++++++++++--------- 3 files changed, 25 insertions(+), 28 deletions(-) diff --git a/service/cachemdw/cache.go b/service/cachemdw/cache.go index 756ddd1..1568942 100644 --- a/service/cachemdw/cache.go +++ b/service/cachemdw/cache.go @@ -81,6 +81,8 @@ func IsCacheable( req *decode.EVMRPCRequestEnvelope, ) bool { // TODO: technically, we _could_ cache the "invalid request" response for `null` requests... + // however, doing so will may result in different than expected responses for batch requests + // ie. {error} response vs [{error}] (the not-list is expected) if req == nil { return false } diff --git a/service/middleware.go b/service/middleware.go index 669d652..342e703 100644 --- a/service/middleware.go +++ b/service/middleware.go @@ -95,6 +95,9 @@ func (w bodySaverResponseWriter) Write(b []byte) (int, error) { // - routes single requests to next() func createDecodeRequestMiddleware(next http.HandlerFunc, batchProcessingMiddleware http.HandlerFunc, serviceLogger *logging.ServiceLogger) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { + // capture the initial request time in order to calculate response time & latency at the end + requestStartTimeContext := context.WithValue(r.Context(), RequestStartTimeContextKey, time.Now()) + // skip processing if there is no body content if r.Body == nil { serviceLogger.Trace().Msg("no data in request") @@ -124,7 +127,7 @@ func createDecodeRequestMiddleware(next http.HandlerFunc, batchProcessingMiddlew serviceLogger.Trace(). Any("decoded request", decodedRequest). Msg("successfully decoded single EVM request") - singleDecodedReqContext := context.WithValue(r.Context(), DecodedRequestContextKey, decodedRequest) + singleDecodedReqContext := context.WithValue(requestStartTimeContext, DecodedRequestContextKey, decodedRequest) next.ServeHTTP(w, r.WithContext(singleDecodedReqContext)) return } @@ -137,33 +140,17 @@ func createDecodeRequestMiddleware(next http.HandlerFunc, batchProcessingMiddlew return } if len(batchRequests) == 0 { - // TODO: hardcode or cache error response here? + serviceLogger.Trace().Msg(fmt.Sprintf("request is for an empty batch: %s", rawBody)) next.ServeHTTP(w, r) return } - // TODO: Trace serviceLogger.Trace().Any("batch", batchRequests).Msg("successfully decoded batch of requests") - batchDecodedReqContext := context.WithValue(r.Context(), DecodedBatchRequestContextKey, batchRequests) + batchDecodedReqContext := context.WithValue(requestStartTimeContext, DecodedBatchRequestContextKey, batchRequests) batchProcessingMiddleware.ServeHTTP(w, r.WithContext(batchDecodedReqContext)) } } -// createRequestLoggingMiddleware returns a handler that logs any request to stdout -// and if able to decode the request to a known type adds it as a context key -// To use the decoded request body, get the value from the context and then -// use type assertion to EVMRPCRequestEnvelope. With this middleware, the request body -// can be read once, and then accessed by all future middleware and the final -// http handler. -func createRequestLoggingMiddleware(h http.HandlerFunc, serviceLogger *logging.ServiceLogger) http.HandlerFunc { - return func(w http.ResponseWriter, r *http.Request) { - requestStartTimeContext := context.WithValue(r.Context(), RequestStartTimeContextKey, time.Now()) - h.ServeHTTP(w, r.WithContext(requestStartTimeContext)) - - // TODO: cleanup. is this middleware still useful? should it actually...log the request? lol - } -} - // create the main service middleware for // introspecting and transforming the original request // and the backend origin server(s) response(s) diff --git a/service/service.go b/service/service.go index d4876c1..e853a03 100644 --- a/service/service.go +++ b/service/service.go @@ -53,7 +53,7 @@ func New(ctx context.Context, config config.Config, serviceLogger *logging.Servi // create an http router for registering handlers for a given route mux := http.NewServeMux() - // will run after the proxy middleware handler and is + // AfterProxyFinalizer will run after the proxy middleware handler and is // the final function called after all other middleware // allowing it to access values added to the request context // to do things like metric the response and cache the response @@ -67,7 +67,10 @@ func New(ctx context.Context, config config.Config, serviceLogger *logging.Servi // - response is present in context cacheAfterProxyMiddleware := serviceCache.CachingMiddleware(afterProxyFinalizer) - // create an http handler that will proxy any request to the specified URL + // ProxyRequestMiddleware responds to the client with + // - cached data if present in the context + // - a forwarded request to the appropriate backend + // Backend is decided by the Proxies configuration for a particular host. proxyMiddleware := createProxyRequestMiddleware(cacheAfterProxyMiddleware, config, serviceLogger, []RequestInterceptor{}, []RequestInterceptor{}) // IsCachedMiddleware works in the following way: @@ -76,19 +79,24 @@ func New(ctx context.Context, config config.Config, serviceLogger *logging.Servi // - if not present marks as uncached in context and forwards to next middleware cacheMiddleware := serviceCache.IsCachedMiddleware(proxyMiddleware) - // TODO: docs + // BatchProcessingMiddleware separates a batch into multiple requests and routes each one + // through the single request middleware sequence. + // This allows the sub-requests of a batch to leverage the cache & metric recording. + // Expects non-zero length batch to be in the context. batchMdwConfig := batchmdw.BatchMiddlewareConfig{ ServiceLogger: serviceLogger, ContextKeyDecodedRequestBatch: DecodedBatchRequestContextKey, ContextKeyDecodedRequestSingle: DecodedRequestContextKey, } batchProcessingMiddleware := batchmdw.CreateBatchProcessingMiddleware(cacheMiddleware, &batchMdwConfig) - // TODO: docs - decodeRequestMiddleware := createDecodeRequestMiddleware(cacheMiddleware, batchProcessingMiddleware, serviceLogger) - // create an http handler that will log the request to stdout - // this handler will run before the proxyMiddleware handler - requestLoggingMiddleware := createRequestLoggingMiddleware(decodeRequestMiddleware, serviceLogger) + // DecodeRequestMiddleware captures the request start time & attempts to decode the request body. + // If successful, the decoded request is put into the request context: + // - if decoded as a single EVM request: it forwards it to the single request middleware sequence + // - if decoded as a batch EVM request: it forwards it to the batchProcessingMiddleware + // - if fails to decode: it passes to single request middleware sequence which will proxy the request + // When requests fail to decode, no context value is set. + decodeRequestMiddleware := createDecodeRequestMiddleware(cacheMiddleware, batchProcessingMiddleware, serviceLogger) // register healthcheck handler that can be used during deployment and operations // to determine if the service is ready to receive requests @@ -99,7 +107,7 @@ func New(ctx context.Context, config config.Config, serviceLogger *logging.Servi mux.HandleFunc("/servicecheck", createServicecheckHandler(&service)) // register middleware chain as the default handler for any request to the proxy service - mux.HandleFunc("/", requestLoggingMiddleware) + mux.HandleFunc("/", decodeRequestMiddleware) // create an http server for the caller to start on demand with a call to ProxyService.Run() server := &http.Server{