Add optional debug logging behind LOGGING=1 (#69)

* Add optional debug logging behind LOGGING=1.

Log HTTP requests, MCP tool calls, auth header issues, and Render API errors to stderr when LOGGING=1 is set.

Co-authored-by: Cursor <cursoragent@cursor.com>

* Delegate Flush and Unwrap on HTTP logging wrapper.

Streamable MCP uses http.Flusher for SSE; without delegation, LOGGING=1
broke GET /mcp with 500 and skipped flush on upgraded POST responses.

Co-authored-by: Cursor <cursoragent@cursor.com>

---------

Co-authored-by: Cursor <cursoragent@cursor.com>
GitOrigin-RevId: 0f053108388c01411dcdde3ab13513a7c4b842c4

Author: 2 people

cmd/server.go

@@ -7,12 +7,14 @@ import (
 	"time"
 
 	"github.com/mark3labs/mcp-go/server"
+	mcputil "github.com/mark3labs/mcp-go/util"
 	"github.com/render-oss/render-mcp-server/pkg/authn"
 	"github.com/render-oss/render-mcp-server/pkg/cfg"
 	"github.com/render-oss/render-mcp-server/pkg/client"
 	"github.com/render-oss/render-mcp-server/pkg/deploy"
 	"github.com/render-oss/render-mcp-server/pkg/httpcontext"
 	"github.com/render-oss/render-mcp-server/pkg/keyvalue"
+	"github.com/render-oss/render-mcp-server/pkg/logging"
 	"github.com/render-oss/render-mcp-server/pkg/logs"
 	"github.com/render-oss/render-mcp-server/pkg/metrics"
 	"github.com/render-oss/render-mcp-server/pkg/multicontext"
@@ -23,10 +25,16 @@ import (
 )
 
 func Serve(transport string) *server.MCPServer {
+	mcpServerOpts := []server.ServerOption{}
+	if hooks := logging.NewHooks(); hooks != nil {
+		mcpServerOpts = append(mcpServerOpts, server.WithHooks(hooks))
+	}
+
 	// Create MCP server
 	s := server.NewMCPServer(
 		"render-mcp-server",
 		cfg.Version,
+		mcpServerOpts...,
 	)
 
 	c, err := client.NewDefaultClient()
@@ -55,11 +63,14 @@ func Serve(transport string) *server.MCPServer {
 			log.Print("using in-memory session store\n")
 			sessionStore = session.NewInMemoryStore()
 		}
-		streamableServer := server.NewStreamableHTTPServer(s, server.WithHTTPContextFunc(multicontext.MultiHTTPContextFunc(
-			session.ContextWithHTTPSession(sessionStore),
-			authn.ContextWithAPITokenFromHeader,
-			httpcontext.ContextWithHTTPRequest,
-		)))
+		streamableServer := server.NewStreamableHTTPServer(s,
+			server.WithLogger(mcputil.DefaultLogger()),
+			server.WithHTTPContextFunc(multicontext.MultiHTTPContextFunc(
+				session.ContextWithHTTPSession(sessionStore),
+				authn.ContextWithAPITokenFromHeader,
+				httpcontext.ContextWithHTTPRequest,
+			)),
+		)
 
 		mux := http.NewServeMux()
 		mux.Handle("/mcp", streamableServer)
@@ -72,7 +83,7 @@ func Serve(transport string) *server.MCPServer {
 
 		httpServer := &http.Server{
 			Addr:        ":10000",
-			Handler:     mux,
+			Handler:     logging.HTTPMiddleware(mux),
 			ReadTimeout: 5 * time.Second,
 		}
 		err := httpServer.ListenAndServe()

pkg/authn/authn.go

@@ -7,6 +7,7 @@ import (
 	"net/http"
 
 	"github.com/render-oss/render-mcp-server/pkg/cfg"
+	"github.com/render-oss/render-mcp-server/pkg/logging"
 )
 
 const apiTokenKey string = "token"
@@ -28,6 +29,7 @@ func ContextWithAPITokenFromHeader(ctx context.Context, req *http.Request) conte
 	token := req.Header.Get("Authorization")
 
 	if token == "" {
+		logging.Error("auth: no Authorization header on %s %s", req.Method, req.URL.Path)
 		return ctx
 	}
 

pkg/client/client.go

@@ -12,6 +12,7 @@ import (
 	"github.com/render-oss/render-mcp-server/pkg/cfg"
 	"github.com/render-oss/render-mcp-server/pkg/config"
 	"github.com/render-oss/render-mcp-server/pkg/httpcontext"
+	"github.com/render-oss/render-mcp-server/pkg/logging"
 )
 
 var ErrUnauthorized = errors.New("unauthorized")
@@ -42,17 +43,22 @@ func ErrorFromResponse(v any) error {
 	}
 
 	if responseErr.Code == http.StatusUnauthorized {
+		logging.Error("render api: unauthorized (status 401)")
 		return ErrUnauthorized
 	}
 	if responseErr.Code == http.StatusForbidden {
+		logging.Error("render api: forbidden (status 403)")
 		return ErrForbidden
 	}
 
+	var err error
 	if responseErr.Message != nil && *responseErr.Message != "" {
-		return fmt.Errorf("received response code %d: %s", responseErr.Code, *responseErr.Message)
+		err = fmt.Errorf("received response code %d: %s", responseErr.Code, *responseErr.Message)
+	} else {
+		err = fmt.Errorf("received response code %d with empty message", responseErr.Code)
 	}
-
-	return fmt.Errorf("unknown error")
+	logging.Error("render api: %v", err)
+	return err
 }
 
 type ErrorWithCode struct {

pkg/client/client_test.go

@@ -45,6 +45,15 @@ func TestErrorFromResponse(t *testing.T) {
 
 			require.ErrorContains(t, err, "received response code 400: unknown error")
 		})
+
+		t.Run("when body has no message field", func(t *testing.T) {
+			err := client.ErrorFromResponse(&client.ListSnapshotsResponse{
+				Body:         []byte(`{}`),
+				HTTPResponse: &http.Response{StatusCode: 502},
+			})
+
+			require.ErrorContains(t, err, "received response code 502 with empty message")
+		})
 	})
 
 	t.Run("status code < 400", func(t *testing.T) {

pkg/logging/hooks.go

@@ -0,0 +1,43 @@
+package logging
+
+import (
+	"context"
+
+	"github.com/mark3labs/mcp-go/mcp"
+	"github.com/mark3labs/mcp-go/server"
+)
+
+func NewHooks() *server.Hooks {
+	if !enabled() {
+		return nil
+	}
+
+	hooks := &server.Hooks{}
+
+	hooks.AddBeforeCallTool(func(_ context.Context, _ any, message *mcp.CallToolRequest) {
+		Info("tool call start name=%s", message.Params.Name)
+	})
+
+	hooks.AddAfterCallTool(func(_ context.Context, _ any, message *mcp.CallToolRequest, result *mcp.CallToolResult) {
+		if result != nil && result.IsError {
+			Error("tool call failed name=%s error=%s", message.Params.Name, toolResultText(result))
+			return
+		}
+		Info("tool call ok name=%s", message.Params.Name)
+	})
+
+	hooks.AddOnError(func(_ context.Context, _ any, method mcp.MCPMethod, _ any, err error) {
+		Error("mcp error method=%s err=%v", method, err)
+	})
+
+	return hooks
+}
+
+func toolResultText(result *mcp.CallToolResult) string {
+	for _, content := range result.Content {
+		if text, ok := mcp.AsTextContent(content); ok && text.Text != "" {
+			return text.Text
+		}
+	}
+	return "unknown tool error"
+}

pkg/logging/httplog.go

@@ -0,0 +1,40 @@
+package logging
+
+import (
+	"net/http"
+	"time"
+)
+
+type statusResponseWriter struct {
+	http.ResponseWriter
+	status int
+}
+
+func (w *statusResponseWriter) WriteHeader(status int) {
+	w.status = status
+	w.ResponseWriter.WriteHeader(status)
+}
+
+func (w *statusResponseWriter) Flush() {
+	if f, ok := w.ResponseWriter.(http.Flusher); ok {
+		f.Flush()
+	}
+}
+
+func (w *statusResponseWriter) Unwrap() http.ResponseWriter {
+	return w.ResponseWriter
+}
+
+func HTTPMiddleware(next http.Handler) http.Handler {
+	if !enabled() {
+		return next
+	}
+
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		start := time.Now()
+		rw := &statusResponseWriter{ResponseWriter: w, status: http.StatusOK}
+		next.ServeHTTP(rw, r)
+		Info("http request method=%s path=%s status=%d duration=%s remote=%s",
+			r.Method, r.URL.Path, rw.status, time.Since(start).Round(time.Millisecond), r.RemoteAddr)
+	})
+}

pkg/logging/httplog_test.go

@@ -0,0 +1,23 @@
+package logging
+
+import (
+	"net/http"
+	"net/http/httptest"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+func TestHTTPMiddlewareDelegatesFlusher(t *testing.T) {
+	t.Setenv("LOGGING", "1")
+
+	handler := HTTPMiddleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
+		f, ok := w.(http.Flusher)
+		require.True(t, ok, "wrapped ResponseWriter must implement http.Flusher")
+		f.Flush()
+	}))
+
+	rec := httptest.NewRecorder()
+	handler.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, "/mcp", nil))
+	require.True(t, rec.Flushed)
+}

pkg/logging/log.go

@@ -0,0 +1,28 @@
+package logging
+
+import (
+	"log"
+	"os"
+)
+
+const envKey = "LOGGING"
+
+var logger = log.New(os.Stderr, "render-mcp-server: ", log.LstdFlags)
+
+func enabled() bool {
+	return os.Getenv(envKey) == "1"
+}
+
+func Info(format string, args ...any) {
+	if !enabled() {
+		return
+	}
+	logger.Printf("INFO "+format, args...)
+}
+
+func Error(format string, args ...any) {
+	if !enabled() {
+		return
+	}
+	logger.Printf("ERROR "+format, args...)
+}