From 94c097bc6c1109dff3568281e2d89d71d7eaa52e Mon Sep 17 00:00:00 2001
From: Lukasz Raczylo <lukasz@raczylo.com>
Date: Tue, 18 Nov 2025 17:27:55 +0000
Subject: [PATCH] fixup! Race condition in parseGraphQLQuery result pooling

---
 debug_routing.go | 143 +++++++++++++++++++++++++++++++++++++++++++++++
 server.go        |  11 ++++
 2 files changed, 154 insertions(+)
 create mode 100644 debug_routing.go

diff --git a/debug_routing.go b/debug_routing.go
new file mode 100644
index 0000000..b51356e
--- /dev/null
+++ b/debug_routing.go
@@ -0,0 +1,143 @@
+package main
+
+import (
+	"fmt"
+	"strings"
+
+	fiber "github.com/gofiber/fiber/v2"
+	"github.com/graphql-go/graphql/language/ast"
+	"github.com/graphql-go/graphql/language/parser"
+	"github.com/graphql-go/graphql/language/source"
+	libpack_logger "github.com/lukaszraczylo/graphql-monitoring-proxy/logging"
+)
+
+// debugParseGraphQLQuery provides detailed logging for mutation routing analysis
+// This is automatically called when LOG_LEVEL=DEBUG to help identify routing issues
+//
+// It logs:
+//   - GraphQL query structure (operations, selections, directives)
+//   - Final routing decision (which endpoint was chosen)
+//   - Automatic detection of mutations routed to wrong endpoints
+//
+// To enable: Set LOG_LEVEL=DEBUG and restart the proxy
+func debugParseGraphQLQuery(c *fiber.Ctx, query string) {
+	if cfg == nil || cfg.Logger == nil {
+		return
+	}
+
+	cfg.Logger.Info(&libpack_logger.LogMessage{
+		Message: "=== DEBUG: Parsing GraphQL Query ===",
+		Pairs: map[string]interface{}{
+			"query_length":  len(query),
+			"query_preview": truncateString(query, 100),
+		},
+	})
+
+	// Parse the query
+	src := source.NewSource(&source.Source{
+		Body: []byte(query),
+		Name: "Debug GraphQL request",
+	})
+
+	p, err := parser.Parse(parser.ParseParams{Source: src})
+	if err != nil {
+		cfg.Logger.Error(&libpack_logger.LogMessage{
+			Message: "DEBUG: Failed to parse query",
+			Pairs:   map[string]interface{}{"error": err.Error()},
+		})
+		return
+	}
+
+	cfg.Logger.Info(&libpack_logger.LogMessage{
+		Message: "DEBUG: Query parsed successfully",
+		Pairs: map[string]interface{}{
+			"definitions_count": len(p.Definitions),
+		},
+	})
+
+	// Analyze each definition
+	for i, d := range p.Definitions {
+		if oper, ok := d.(*ast.OperationDefinition); ok {
+			operationType := strings.ToLower(oper.Operation)
+			operationName := "unnamed"
+			if oper.Name != nil {
+				operationName = oper.Name.Value
+			}
+
+			// Count selections
+			selectionCount := 0
+			if oper.SelectionSet != nil {
+				selectionCount = len(oper.GetSelectionSet().Selections)
+			}
+
+			cfg.Logger.Info(&libpack_logger.LogMessage{
+				Message: fmt.Sprintf("DEBUG: Definition #%d (OperationDefinition)", i),
+				Pairs: map[string]interface{}{
+					"operation_type":  operationType,
+					"operation_name":  operationName,
+					"selection_count": selectionCount,
+					"is_mutation":     operationType == "mutation",
+					"directive_count": len(oper.Directives),
+				},
+			})
+
+			// Log selections for mutations
+			if operationType == "mutation" && oper.SelectionSet != nil {
+				for j, sel := range oper.GetSelectionSet().Selections {
+					if field, ok := sel.(*ast.Field); ok {
+						cfg.Logger.Info(&libpack_logger.LogMessage{
+							Message: fmt.Sprintf("DEBUG: Mutation field #%d", j),
+							Pairs: map[string]interface{}{
+								"field_name": field.Name.Value,
+							},
+						})
+					}
+				}
+			}
+		} else if frag, ok := d.(*ast.FragmentDefinition); ok {
+			cfg.Logger.Info(&libpack_logger.LogMessage{
+				Message: fmt.Sprintf("DEBUG: Definition #%d (FragmentDefinition)", i),
+				Pairs: map[string]interface{}{
+					"fragment_name": frag.Name.Value,
+				},
+			})
+		}
+	}
+
+	// Now run the actual parsing to see the result
+	result := parseGraphQLQuery(c)
+
+	cfg.Logger.Info(&libpack_logger.LogMessage{
+		Message: "DEBUG: Final routing decision",
+		Pairs: map[string]interface{}{
+			"operation_type":  result.operationType,
+			"operation_name":  result.operationName,
+			"active_endpoint": result.activeEndpoint,
+			"should_block":    result.shouldBlock,
+			"should_ignore":   result.shouldIgnore,
+			"write_endpoint":  cfg.Server.HostGraphQL,
+			"read_endpoint":   cfg.Server.HostGraphQLReadOnly,
+			"is_using_write":  result.activeEndpoint == cfg.Server.HostGraphQL,
+		},
+	})
+
+	// Check for potential issues
+	if result.operationType == "mutation" && result.activeEndpoint != cfg.Server.HostGraphQL {
+		cfg.Logger.Error(&libpack_logger.LogMessage{
+			Message: "DEBUG: ⚠️  BUG DETECTED: Mutation routed to wrong endpoint!",
+			Pairs: map[string]interface{}{
+				"expected_endpoint": cfg.Server.HostGraphQL,
+				"actual_endpoint":   result.activeEndpoint,
+			},
+		})
+	}
+
+	if result.operationType == "mutation" && strings.Contains(strings.ToLower(result.activeEndpoint), "read") {
+		cfg.Logger.Error(&libpack_logger.LogMessage{
+			Message: "DEBUG: ⚠️  CRITICAL: Mutation endpoint contains 'read' in URL!",
+			Pairs: map[string]interface{}{
+				"endpoint": result.activeEndpoint,
+			},
+		})
+	}
+}
diff --git a/server.go b/server.go
index 3c9783d..35b0288 100644
--- a/server.go
+++ b/server.go
@@ -272,6 +272,17 @@ func processGraphQLRequest(c *fiber.Ctx) error {
 
 	// Parse the GraphQL query
 	parsedResult := parseGraphQLQuery(c)
+
+	// Debug logging for mutation routing analysis (enabled when LOG_LEVEL=DEBUG)
+	if cfg.LogLevel == "DEBUG" {
+		var m map[string]interface{}
+		if err := json.Unmarshal(c.Body(), &m); err == nil {
+			if query, ok := m["query"].(string); ok {
+				debugParseGraphQLQuery(c, query)
+			}
+		}
+	}
+
 	if parsedResult.shouldBlock {
 		return c.Status(fiber.StatusForbidden).SendString("Request blocked")
 	}