diff --git a/internal/api/handlers.go b/internal/api/handlers.go index 37c968e..d522498 100644 --- a/internal/api/handlers.go +++ b/internal/api/handlers.go @@ -3338,22 +3338,27 @@ func (h *Handler) writeRPCResult(w http.ResponseWriter, id json.RawMessage, resu func (h *Handler) forwardProxyEnvelope(ctx context.Context, server string, envelope mcp.Envelope, protocolVersion string) (mcp.ForwardResult, bool) { if h.forwarder == nil { + h.debugf("forward proxy skipped server=%s method=%s reason=no_forwarder", server, envelope.Method) return mcp.ForwardResult{}, false } resolver, ok := h.svc.(interface { ResolveContext(context.Context, string) (mcp.Upstream, error) }) if !ok { + h.debugf("forward proxy skipped server=%s method=%s reason=no_resolver", server, envelope.Method) return mcp.ForwardResult{}, false } upstream, err := resolver.ResolveContext(ctx, server) if err != nil { + h.debugf("forward proxy resolve failed server=%s method=%s err=%v", server, envelope.Method, err) return mcp.ForwardResult{}, false } result, err := h.forwarder.ForwardEnvelope(ctx, upstream, envelope, protocolVersion) if err != nil { + h.debugf("forward proxy upstream failed server=%s method=%s protocol=%s err=%v", server, envelope.Method, protocolVersion, err) return mcp.ForwardResult{}, false } + h.debugf("forward proxy upstream response server=%s method=%s status=%d content_type=%q protocol=%q session_expired=%t", server, envelope.Method, result.StatusCode, result.ContentType, result.ProtocolVersion, result.SessionExpired) return result, true } diff --git a/internal/mcp/client.go b/internal/mcp/client.go index a8ad2a3..7f9aa3d 100644 --- a/internal/mcp/client.go +++ b/internal/mcp/client.go @@ -539,20 +539,25 @@ func (c *Client) invokeHTTP(ctx context.Context, upstream Upstream, tool string, } if len(rpcResp.Error) > 0 && string(rpcResp.Error) != "null" { if isMissingSessionRPCError(rpcResp.Error) { + c.debugf("upstream http tools.call missing session server=%s session=%q status=%d error=%s", upstream.Name, result.SessionID, result.StatusCode, truncateForLog(rpcResp.Error, 600)) if retryErr := c.reinitializeRequiredHTTPSession(ctx, upstream, result.SessionID); retryErr != nil { + c.debugf("upstream http tools.call session retry init failed server=%s session=%q err=%v", upstream.Name, result.SessionID, retryErr) return InvokeResult{}, retryErr } result, err = c.doHTTPEnvelopeWithSessionRetry(ctx, upstream, body, DefaultMCPProtocolVersion) if err != nil { + c.debugf("upstream http tools.call session retry transport failed server=%s err=%v", upstream.Name, err) return InvokeResult{}, err } rpcResp, err = decodeRPCResponse(result, json.RawMessage([]byte("1"))) if err != nil { + c.debugf("upstream http tools.call session retry decode failed server=%s status=%d err=%v", upstream.Name, result.StatusCode, err) return InvokeResult{}, err } } } if len(rpcResp.Error) > 0 && string(rpcResp.Error) != "null" { + c.debugf("upstream http tools.call rpc error server=%s status=%d error=%s", upstream.Name, result.StatusCode, truncateForLog(rpcResp.Error, 600)) return InvokeResult{StatusCode: result.StatusCode, Body: rpcResp.Error, Failed: true}, nil } bodyBytes := rpcResp.Result @@ -755,14 +760,18 @@ func (c *Client) reinitializeRequiredHTTPSession(ctx context.Context, upstream U currentSessionID := c.getSession(upstream.Name) if failedSessionID != "" && currentSessionID != "" && currentSessionID != failedSessionID { + c.debugf("upstream session reinit skipped server=%s failed_session=%q current_session=%q reason=session_already_replaced", upstream.Name, failedSessionID, currentSessionID) return nil } if failedSessionID == "" && currentSessionID != "" { + c.debugf("upstream session reinit skipped server=%s current_session=%q reason=session_already_exists", upstream.Name, currentSessionID) return nil } if failedSessionID != "" { + c.debugf("upstream session reinit clearing server=%s session=%q", upstream.Name, failedSessionID) c.clearSessionIfCurrent(upstream.Name, failedSessionID) } else { + c.debugf("upstream session reinit clearing server=%s session=(none)", upstream.Name) c.clearSession(upstream.Name) } return c.initializeHTTPSessionCandidates(ctx, upstream, true) @@ -782,18 +791,23 @@ func (c *Client) ensureHTTPSessionMode(ctx context.Context, upstream Upstream, r func (c *Client) initializeHTTPSessionCandidates(ctx context.Context, upstream Upstream, requireSession bool) error { var lastErr error for _, protocolVersion := range httpProtocolCandidates() { + c.debugf("upstream session initialize attempt server=%s protocol=%s require_session=%t", upstream.Name, protocolVersion, requireSession) hadSession, err := c.initializeHTTPSession(ctx, upstream, protocolVersion) if err != nil { lastErr = err + c.debugf("upstream session initialize failed server=%s protocol=%s err=%v", upstream.Name, protocolVersion, err) if isProtocolNegotiationError(err) { + c.debugf("upstream session initialize trying fallback server=%s rejected_protocol=%s", upstream.Name, protocolVersion) continue } return err } if !requireSession || hadSession { + c.debugf("upstream session initialize accepted server=%s protocol=%s had_session=%t", upstream.Name, protocolVersion, hadSession) return nil } lastErr = fmt.Errorf("upstream initialize using MCP %s did not return Mcp-Session-Id", protocolVersion) + c.debugf("upstream session initialize rejected server=%s protocol=%s reason=missing_session_id", upstream.Name, protocolVersion) } if lastErr != nil { return lastErr