Add generation of query uuid logs and easier debugging.

go.mod

@@ -7,12 +7,13 @@ require (
 	github.com/buger/jsonparser v1.1.1
 	github.com/gofiber/fiber/v2 v2.50.0
 	github.com/gofrs/flock v0.8.1
+	github.com/google/uuid v1.3.1
 	github.com/gookit/goutil v0.6.14
 	github.com/graphql-go/graphql v0.8.1
 	github.com/json-iterator/go v1.1.12
 	github.com/lukaszraczylo/ask v0.0.0-20230927103145-2ff1123b4415
 	github.com/lukaszraczylo/go-ratecounter v0.1.8
-	github.com/lukaszraczylo/go-simple-graphql v1.1.35
+	github.com/lukaszraczylo/go-simple-graphql v1.1.37
 	github.com/rs/zerolog v1.31.0
 	github.com/stretchr/testify v1.8.4
 	github.com/valyala/fasthttp v1.50.0
@@ -22,9 +23,8 @@ require (
 	github.com/andybalholm/brotli v1.0.6 // indirect
 	github.com/avast/retry-go/v4 v4.5.0 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
-	github.com/google/uuid v1.3.1 // indirect
 	github.com/gookit/color v1.5.4 // indirect
-	github.com/klauspost/compress v1.17.1 // indirect
+	github.com/klauspost/compress v1.17.2 // indirect
 	github.com/kr/pretty v0.3.1 // indirect
 	github.com/mattn/go-colorable v0.1.13 // indirect
 	github.com/mattn/go-isatty v0.0.20 // indirect

go.sum

@@ -27,8 +27,8 @@ github.com/graphql-go/graphql v0.8.1 h1:p7/Ou/WpmulocJeEx7wjQy611rtXGQaAcXGqanuM
 github.com/graphql-go/graphql v0.8.1/go.mod h1:nKiHzRM0qopJEwCITUuIsxk9PlVlwIiiI8pnJEhordQ=
 github.com/json-iterator/go v1.1.12 h1:PV8peI4a0ysnczrg+LtxykD8LfKY9ML6u2jnxaEnrnM=
 github.com/json-iterator/go v1.1.12/go.mod h1:e30LSqwooZae/UwlEbR2852Gd8hjQvJoHmT4TnhNGBo=
-github.com/klauspost/compress v1.17.1 h1:NE3C767s2ak2bweCZo3+rdP4U/HoyVXLv/X9f2gPS5g=
-github.com/klauspost/compress v1.17.1/go.mod h1:ntbaceVETuRiXiv4DpjP66DpAtAGkEQskQzEyD//IeE=
+github.com/klauspost/compress v1.17.2 h1:RlWWUY/Dr4fL8qk9YG7DTZ7PDgME2V4csBXA8L/ixi4=
+github.com/klauspost/compress v1.17.2/go.mod h1:ntbaceVETuRiXiv4DpjP66DpAtAGkEQskQzEyD//IeE=
 github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
 github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE=
 github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk=
@@ -40,8 +40,8 @@ github.com/lukaszraczylo/ask v0.0.0-20230927103145-2ff1123b4415 h1:lvI8Wlbg4PxkR
 github.com/lukaszraczylo/ask v0.0.0-20230927103145-2ff1123b4415/go.mod h1:M+UVdyqZs++xtEPrascaVmZdOMhCnxjZ2SgH+xHpR0c=
 github.com/lukaszraczylo/go-ratecounter v0.1.8 h1:ZYm6Wkn58ZAlFWRmC7PaD4oAYHWcu8/0MUDWGe3PnJQ=
 github.com/lukaszraczylo/go-ratecounter v0.1.8/go.mod h1:TqXEOCtFJStk1i0tkipprv1kiDHGon1MVUisjSTBSKM=
-github.com/lukaszraczylo/go-simple-graphql v1.1.35 h1:51agVc1C5p9VxiZuvk8TwsEAWU+ieNXnmAgRdRXuqFk=
-github.com/lukaszraczylo/go-simple-graphql v1.1.35/go.mod h1:YWMelAXnFs8uknj3Pv2gO8Svzv5k4cAL940MI0n/R0k=
+github.com/lukaszraczylo/go-simple-graphql v1.1.37 h1:8emnfzWTApitNQ+hMHMPeGljL/xlVf/u8oKt26bUXDs=
+github.com/lukaszraczylo/go-simple-graphql v1.1.37/go.mod h1:0d/x8hj9Uus4qiv981fjL56jw8DutJ6WAeTsNWClZ/Y=
 github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
 github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
 github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=

proxy.go

@@ -18,8 +18,7 @@ func createFasthttpClient(timeout int) *fasthttp.Client {
 		TLSConfig: &tls.Config{
 			InsecureSkipVerify: true,
 		},
-		MaxConnsPerHost:               100,
-		MaxIdleConnDuration:           time.Duration(timeout*5) * time.Minute,
+		MaxConnsPerHost:               200,
 		ReadTimeout:                   time.Second * time.Duration(timeout),
 		WriteTimeout:                  time.Second * time.Duration(timeout),
 		DisableHeaderNamesNormalizing: true,
@@ -39,14 +38,14 @@ func proxyTheRequest(c *fiber.Ctx) error {
 
 	proxy.WithClient(cfg.Client.FastProxyClient)
 
-	cfg.Logger.Debug("Proxying the request", map[string]interface{}{"path": c.Path(), "body": string(c.Request().Body()), "headers": c.GetReqHeaders()})
+	cfg.Logger.Debug("Proxying the request", map[string]interface{}{"path": c.Path(), "body": string(c.Request().Body()), "headers": c.GetReqHeaders(), "request_uuid": c.Locals("request_uuid")})
 	err := proxy.DoRedirects(c, cfg.Server.HostGraphQL+c.Path(), 3)
 	if err != nil {
 		cfg.Logger.Error("Can't proxy the request", map[string]interface{}{"error": err.Error()})
 		cfg.Monitoring.Increment(libpack_monitoring.MetricsFailed, nil)
 		return err
 	}
-	cfg.Logger.Debug("Received proxied response", map[string]interface{}{"path": c.Path(), "response_body": string(c.Response().Body()), "response_code": c.Response().StatusCode(), "headers": c.GetRespHeaders()})
+	cfg.Logger.Debug("Received proxied response", map[string]interface{}{"path": c.Path(), "response_body": string(c.Response().Body()), "response_code": c.Response().StatusCode(), "headers": c.GetRespHeaders(), "request_uuid": c.Locals("request_uuid")})
 
 	if c.Response().StatusCode() != 200 {
 		cfg.Monitoring.Increment(libpack_monitoring.MetricsFailed, nil)

server.go

@@ -6,6 +6,7 @@ import (
 
 	fiber "github.com/gofiber/fiber/v2"
 	"github.com/gofiber/fiber/v2/middleware/cors"
+	"github.com/google/uuid"
 
 	jsoniter "github.com/json-iterator/go"
 	libpack_config "github.com/lukaszraczylo/graphql-monitoring-proxy/config"
@@ -25,6 +26,9 @@ func StartHTTPProxy() {
 		AllowOrigins: "*",
 	}))
 
+	// add middleware to check if the request is a GraphQL query
+	server.Use(AddRequestUUID)
+
 	server.Get("/healthz", healthCheck)
 	server.Get("/livez", healthCheck)
 
@@ -38,6 +42,11 @@ func StartHTTPProxy() {
 	}
 }
 
+func AddRequestUUID(c *fiber.Ctx) error {
+	c.Locals("request_uuid", uuid.NewString())
+	return c.Next()
+}
+
 func checkAllowedURLs(c *fiber.Ctx) bool {
 	if len(cfg.Server.AllowURLs) == 0 {
 		return true
@@ -123,11 +132,11 @@ func processGraphQLRequest(c *fiber.Ctx) error {
 		queryCacheHash = calculateHash(c)
 
 		if cachedResponse := cacheLookup(queryCacheHash); cachedResponse != nil {
-			cfg.Logger.Debug("Cache hit", map[string]interface{}{"hash": queryCacheHash, "user_id": extractedUserID})
+			cfg.Logger.Debug("Cache hit", map[string]interface{}{"hash": queryCacheHash, "user_id": extractedUserID, "request_uuid": c.Locals("request_uuid")})
 			c.Send(cachedResponse)
 			wasCached = true
 		} else {
-			cfg.Logger.Debug("Cache miss", map[string]interface{}{"hash": queryCacheHash, "user_id": extractedUserID})
+			cfg.Logger.Debug("Cache miss", map[string]interface{}{"hash": queryCacheHash, "user_id": extractedUserID, "request_uuid": c.Locals("request_uuid")})
 			proxyAndCacheTheRequest(c, queryCacheHash, cache_time)
 		}
 	} else {
@@ -165,13 +174,14 @@ func logAndMonitorRequest(c *fiber.Ctx, userID, opType, opName string, wasCached
 
 	if cfg.Server.AccessLog {
 		cfg.Logger.Info("Request processed", map[string]interface{}{
-			"ip":      c.IP(),
-			"fwd-ip":  string(c.Request().Header.Peek("X-Forwarded-For")),
-			"user_id": userID,
-			"op_type": opType,
-			"op_name": opName,
-			"time":    duration,
-			"cache":   wasCached,
+			"ip":           c.IP(),
+			"fwd-ip":       string(c.Request().Header.Peek("X-Forwarded-For")),
+			"user_id":      userID,
+			"op_type":      opType,
+			"op_name":      opName,
+			"time":         duration,
+			"cache":        wasCached,
+			"request_uuid": c.Locals("request_uuid"),
 		})
 	}