mcp: log out-of-band errors instead of dropping them (#887)

## Summary

Two error sites in the MCP runtime were previously unobservable:

- **`mcp/shared.go` `startKeepalive`** — when a keepalive ping failed,
the session was closed silently with no indication of why.
- **`mcp/transport.go` `connect`** — `jsonrpc2.OnInternalError` printed
via the package-level `log.Printf`, bypassing the `*slog.Logger`
configured on `ServerOptions`/`ClientOptions`.

Both sites now report through the existing `*slog.Logger` that `Server`
and `Client` already guarantee non-nil via `ensureLogger`. The logger is
threaded into the unexported `startKeepalive` and `connect` helpers as a
parameter — **no new public API surface**.

## Context

Per @jba's [suggestion on
#865](#865 (comment)):

> Maybe we can just use the logger in all the places we currently drop
the error. Then it's still reported, but we don't have to add any API.

This PR is that smaller alternative. It addresses the concrete
observability gap in #218 without expanding `ServerOptions`. PR #865
(the `ErrorHandler` callback proposal) remains open pending community
input on whether a structured callback API is also wanted on top of
logging.

`notifySessions` already logs at `Warn` level on delivery errors and is
intentionally left untouched.

## Test plan

- [x] New regression test `TestKeepAliveFailure_Logged` asserts the
keepalive failure produces a log line on the configured logger.
- [x] Verified the test fails when the new `logger.Error(...)` call is
removed (sanity check that it pins the behavior).
- [x] `go test ./mcp/... -count=1` passes.
- [x] `go vet ./...` clean.
- [x] `go build ./...` clean.

Refs #218

---------

Co-authored-by: Maciej Kisiel <mkisiel@google.com>

Author: ravyg

mcp/client.go

@@ -253,7 +253,7 @@ func (c *Client) capabilities(protocolVersion string) *ClientCapabilities {
 // server, calls or notifications will return an error wrapping
 // [ErrConnectionClosed].
 func (c *Client) Connect(ctx context.Context, t Transport, opts *ClientSessionOptions) (cs *ClientSession, err error) {
-	cs, err = connect(ctx, t, c, (*clientSessionState)(nil), nil)
+	cs, err = connect(ctx, t, c, (*clientSessionState)(nil), nil, c.opts.Logger)
 	if err != nil {
 		return nil, err
 	}
@@ -405,7 +405,7 @@ func (cs *ClientSession) registerElicitationWaiter(elicitationID string) (await
 
 // startKeepalive starts the keepalive mechanism for this client session.
 func (cs *ClientSession) startKeepalive(interval time.Duration) {
-	startKeepalive(cs, interval, &cs.keepaliveCancel)
+	startKeepalive(cs, interval, &cs.keepaliveCancel, cs.client.opts.Logger)
 }
 
 // AddRoots adds the given roots to the client,

mcp/mcp_test.go

@@ -1817,6 +1817,52 @@ func TestKeepAliveFailure(t *testing.T) {
 	})
 }
 
+// TestKeepAliveFailure_Logged verifies that a keepalive ping failure is
+// reported via the configured slog.Logger instead of being silently dropped.
+// Regression test for #218.
+func TestKeepAliveFailure_Logged(t *testing.T) {
+	synctest.Test(t, func(t *testing.T) {
+		ctx := context.Background()
+
+		ct, st := NewInMemoryTransports()
+
+		// Server without keepalive.
+		s := NewServer(testImpl, nil)
+		AddTool(s, greetTool(), sayHi)
+		ss, err := s.Connect(ctx, st, nil)
+		if err != nil {
+			t.Fatal(err)
+		}
+
+		// Client with a short keepalive and a logger that writes to a
+		// buffer so we can assert on its output.
+		var buf bytes.Buffer
+		clientOpts := &ClientOptions{
+			KeepAlive: 50 * time.Millisecond,
+			Logger:    slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelError})),
+		}
+		c := NewClient(testImpl, clientOpts)
+		cs, err := c.Connect(ctx, ct, nil)
+		if err != nil {
+			t.Fatal(err)
+		}
+		defer cs.Close()
+
+		synctest.Wait()
+
+		// Trigger a ping failure by closing the server side.
+		ss.Close()
+
+		time.Sleep(100 * time.Millisecond)
+		synctest.Wait()
+
+		got := buf.String() // slog serializes Write calls internally
+		if !strings.Contains(got, "keepalive ping failed") {
+			t.Errorf("expected keepalive failure to be logged, got log output:\n%s", got)
+		}
+	})
+}
+
 func TestAddTool_DuplicateNoPanicAndNoDuplicate(t *testing.T) {
 	// Adding the same tool pointer twice should not panic and should not
 	// produce duplicates in the server's tool list.

mcp/server.go

@@ -1026,7 +1026,7 @@ func (s *Server) Connect(ctx context.Context, t Transport, opts *ServerSessionOp
 	}
 
 	s.opts.Logger.Info("server connecting")
-	ss, err := connect(ctx, t, s, state, onClose)
+	ss, err := connect(ctx, t, s, state, onClose, s.opts.Logger)
 	if err != nil {
 		s.opts.Logger.Error("server connect error", "error", err)
 		return nil, err
@@ -1531,7 +1531,7 @@ func (ss *ServerSession) Wait() error {
 
 // startKeepalive starts the keepalive mechanism for this server session.
 func (ss *ServerSession) startKeepalive(interval time.Duration) {
-	startKeepalive(ss, interval, &ss.keepaliveCancel)
+	startKeepalive(ss, interval, &ss.keepaliveCancel, ss.server.opts.Logger)
 }
 
 // pageToken is the internal structure for the opaque pagination cursor.

mcp/shared.go

@@ -582,7 +582,10 @@ type keepaliveSession interface {
 // startKeepalive starts the keepalive mechanism for a session.
 // It assigns the cancel function to the provided cancelPtr and starts a goroutine
 // that sends ping messages at the specified interval.
-func startKeepalive(session keepaliveSession, interval time.Duration, cancelPtr *context.CancelFunc) {
+//
+// logger must be non-nil; ping failures (which terminate the keepalive loop and
+// close the session) are reported via logger so they are not silently dropped.
+func startKeepalive(session keepaliveSession, interval time.Duration, cancelPtr *context.CancelFunc, logger *slog.Logger) {
 	ctx, cancel := context.WithCancel(context.Background())
 	// Assign cancel function before starting goroutine to avoid race condition.
 	// We cannot return it because the caller may need to cancel during the
@@ -602,7 +605,9 @@ func startKeepalive(session keepaliveSession, interval time.Duration, cancelPtr
 				err := session.Ping(pingCtx, nil)
 				pingCancel()
 				if err != nil {
-					// Ping failed, close the session
+					// Ping failed; log it before closing the session so the
+					// failure is observable to operators. See #218.
+					logger.Error("keepalive ping failed; closing session", "error", err)
 					_ = session.Close()
 					return
 				}

mcp/transport.go

@@ -10,7 +10,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"log"
+	"log/slog"
 	"net"
 	"os"
 	"sync"
@@ -152,7 +152,9 @@ type handler interface {
 	handle(ctx context.Context, req *jsonrpc.Request) (any, error)
 }
 
-func connect[H handler, State any](ctx context.Context, t Transport, b binder[H, State], s State, onClose func()) (H, error) {
+// connect wires a transport to a binder. logger must be non-nil; it receives
+// jsonrpc2 internal errors that would otherwise be dropped (see #218).
+func connect[H handler, State any](ctx context.Context, t Transport, b binder[H, State], s State, onClose func(), logger *slog.Logger) (H, error) {
 	var zero H
 	mcpConn, err := t.Connect(ctx)
 	if err != nil {
@@ -178,7 +180,9 @@ func connect[H handler, State any](ctx context.Context, t Transport, b binder[H,
 		OnDone: func() {
 			b.disconnect(h)
 		},
-		OnInternalError: func(err error) { log.Printf("jsonrpc2 error: %v", err) },
+		OnInternalError: func(err error) {
+			logger.Error("jsonrpc2 internal error", "error", err)
+		},
 	})
 	assert(preempter.conn != nil, "unbound preempter")
 	return h, nil