Skip to content

Commit 1dcbf62

Browse files
mcp/server: enable server logging (#501)
mcp/server.go: implement server‑side logging - Thread a *slog.Logger through server paths to improve debuggability - Introduce no‑op discard handler + ensureLogger so loggers are never nil - Use ensured loggers in Server - address todo comments related to adding logging support All tests are passing and no functionality should change with this PR Fixes #170
1 parent 49047ae commit 1dcbf62

File tree

3 files changed

+72
-3
lines changed

3 files changed

+72
-3
lines changed

mcp/logging.go

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -88,6 +88,23 @@ type LoggingHandler struct {
8888
handler slog.Handler
8989
}
9090

91+
// discardHandler is a slog.Handler that drops all logs.
92+
// TODO: use slog.DiscardHandler when we require Go 1.24+.
93+
type discardHandler struct{}
94+
95+
func (discardHandler) Enabled(context.Context, slog.Level) bool { return false }
96+
func (discardHandler) Handle(context.Context, slog.Record) error { return nil }
97+
func (discardHandler) WithAttrs([]slog.Attr) slog.Handler { return discardHandler{} }
98+
func (discardHandler) WithGroup(string) slog.Handler { return discardHandler{} }
99+
100+
// ensureLogger returns l if non-nil, otherwise a discard logger.
101+
func ensureLogger(l *slog.Logger) *slog.Logger {
102+
if l != nil {
103+
return l
104+
}
105+
return slog.New(discardHandler{})
106+
}
107+
91108
// NewLoggingHandler creates a [LoggingHandler] that logs to the given [ServerSession] using a
92109
// [slog.JSONHandler].
93110
func NewLoggingHandler(ss *ServerSession, opts *LoggingHandlerOptions) *LoggingHandler {

mcp/server.go

Lines changed: 33 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ import (
1212
"encoding/json"
1313
"fmt"
1414
"iter"
15+
"log/slog"
1516
"maps"
1617
"net/url"
1718
"path/filepath"
@@ -54,6 +55,8 @@ type Server struct {
5455
type ServerOptions struct {
5556
// Optional instructions for connected clients.
5657
Instructions string
58+
// If non-nil, log server activity.
59+
Logger *slog.Logger
5760
// If non-nil, called when "notifications/initialized" is received.
5861
InitializedHandler func(context.Context, *InitializedRequest)
5962
// PageSize is the maximum number of items to return in a single page for
@@ -130,6 +133,10 @@ func NewServer(impl *Implementation, options *ServerOptions) *Server {
130133
opts.GetSessionID = randText
131134
}
132135

136+
if opts.Logger == nil { // ensure we have a logger
137+
opts.Logger = ensureLogger(nil)
138+
}
139+
133140
return &Server{
134141
impl: impl,
135142
opts: opts,
@@ -695,6 +702,7 @@ func (s *Server) ResourceUpdated(ctx context.Context, params *ResourceUpdatedNot
695702
sessions := slices.Collect(maps.Keys(subscribedSessions))
696703
s.mu.Unlock()
697704
notifySessions(sessions, notificationResourceUpdated, params)
705+
s.opts.Logger.Info("resource updated notification sent", "uri", params.URI, "subscriber_count", len(sessions))
698706
return nil
699707
}
700708

@@ -712,6 +720,7 @@ func (s *Server) subscribe(ctx context.Context, req *SubscribeRequest) (*emptyRe
712720
s.resourceSubscriptions[req.Params.URI] = make(map[*ServerSession]bool)
713721
}
714722
s.resourceSubscriptions[req.Params.URI][req.Session] = true
723+
s.opts.Logger.Info("resource subscribed", "uri", req.Params.URI, "session_id", req.Session.ID())
715724

716725
return &emptyResult{}, nil
717726
}
@@ -733,6 +742,7 @@ func (s *Server) unsubscribe(ctx context.Context, req *UnsubscribeRequest) (*emp
733742
delete(s.resourceSubscriptions, req.Params.URI)
734743
}
735744
}
745+
s.opts.Logger.Info("resource unsubscribed", "uri", req.Params.URI, "session_id", req.Session.ID())
736746

737747
return &emptyResult{}, nil
738748
}
@@ -751,8 +761,10 @@ func (s *Server) unsubscribe(ctx context.Context, req *UnsubscribeRequest) (*emp
751761
// It need not be called on servers that are used for multiple concurrent connections,
752762
// as with [StreamableHTTPHandler].
753763
func (s *Server) Run(ctx context.Context, t Transport) error {
764+
s.opts.Logger.Info("server run start")
754765
ss, err := s.Connect(ctx, t, nil)
755766
if err != nil {
767+
s.opts.Logger.Error("server connect failed", "error", err)
756768
return err
757769
}
758770

@@ -764,8 +776,14 @@ func (s *Server) Run(ctx context.Context, t Transport) error {
764776
select {
765777
case <-ctx.Done():
766778
ss.Close()
779+
s.opts.Logger.Error("server run cancelled", "error", ctx.Err())
767780
return ctx.Err()
768781
case err := <-ssClosed:
782+
if err != nil {
783+
s.opts.Logger.Error("server session ended with error", "error", err)
784+
} else {
785+
s.opts.Logger.Info("server session ended")
786+
}
769787
return err
770788
}
771789
}
@@ -781,6 +799,7 @@ func (s *Server) bind(mcpConn Connection, conn *jsonrpc2.Connection, state *Serv
781799
s.mu.Lock()
782800
s.sessions = append(s.sessions, ss)
783801
s.mu.Unlock()
802+
s.opts.Logger.Info("server session connected", "session_id", ss.ID())
784803
return ss
785804
}
786805

@@ -796,6 +815,7 @@ func (s *Server) disconnect(cc *ServerSession) {
796815
for _, subscribedSessions := range s.resourceSubscriptions {
797816
delete(subscribedSessions, cc)
798817
}
818+
s.opts.Logger.Info("server session disconnected", "session_id", cc.ID())
799819
}
800820

801821
// ServerSessionOptions configures the server session.
@@ -820,7 +840,14 @@ func (s *Server) Connect(ctx context.Context, t Transport, opts *ServerSessionOp
820840
state = opts.State
821841
onClose = opts.onClose
822842
}
823-
return connect(ctx, t, s, state, onClose)
843+
844+
s.opts.Logger.Info("server connecting")
845+
ss, err := connect(ctx, t, s, state, onClose)
846+
if err != nil {
847+
s.opts.Logger.Error("server connect error", "error", err)
848+
return nil, err
849+
}
850+
return ss, nil
824851
}
825852

826853
// TODO: (nit) move all ServerSession methods below the ServerSession declaration.
@@ -840,9 +867,11 @@ func (ss *ServerSession) initialized(ctx context.Context, params *InitializedPar
840867
})
841868

842869
if !wasInit {
870+
ss.server.opts.Logger.Error("initialized before initialize")
843871
return nil, fmt.Errorf("%q before %q", notificationInitialized, methodInitialize)
844872
}
845873
if wasInitd {
874+
ss.server.opts.Logger.Error("duplicate initialized notification")
846875
return nil, fmt.Errorf("duplicate %q received", notificationInitialized)
847876
}
848877
if ss.server.opts.KeepAlive > 0 {
@@ -851,6 +880,7 @@ func (ss *ServerSession) initialized(ctx context.Context, params *InitializedPar
851880
if h := ss.server.opts.InitializedHandler; h != nil {
852881
h(ctx, serverRequestFor(ss, params))
853882
}
883+
ss.server.opts.Logger.Info("session initialized")
854884
return nil, nil
855885
}
856886

@@ -1088,6 +1118,7 @@ func (ss *ServerSession) handle(ctx context.Context, req *jsonrpc.Request) (any,
10881118
case methodInitialize, methodPing, notificationInitialized:
10891119
default:
10901120
if !initialized {
1121+
ss.server.opts.Logger.Error("method invalid during initialization", "method", req.Method)
10911122
return nil, fmt.Errorf("method %q is invalid during session initialization", req.Method)
10921123
}
10931124
}
@@ -1144,6 +1175,7 @@ func (ss *ServerSession) setLevel(_ context.Context, params *SetLoggingLevelPara
11441175
ss.updateState(func(state *ServerSessionState) {
11451176
state.LogLevel = params.Level
11461177
})
1178+
ss.server.opts.Logger.Info("client log level set", "level", params.Level)
11471179
return &emptyResult{}, nil
11481180
}
11491181

mcp/streamable.go

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -68,6 +68,10 @@ type StreamableHTTPOptions struct {
6868
//
6969
// [§2.1.5]: https://modelcontextprotocol.io/specification/2025-06-18/basic/transports#sending-messages-to-the-server
7070
JSONResponse bool
71+
72+
// Logger specifies the logger to use.
73+
// If nil, do not log.
74+
Logger *slog.Logger
7175
}
7276

7377
// NewStreamableHTTPHandler returns a new [StreamableHTTPHandler].
@@ -83,6 +87,11 @@ func NewStreamableHTTPHandler(getServer func(*http.Request) *Server, opts *Strea
8387
if opts != nil {
8488
h.opts = *opts
8589
}
90+
91+
if h.opts.Logger == nil { // ensure we have a logger
92+
h.opts.Logger = ensureLogger(nil)
93+
}
94+
8695
return h
8796
}
8897

@@ -368,6 +377,8 @@ type StreamableServerTransport struct {
368377
// StreamableHTTPOptions.JSONResponse is exported.
369378
jsonResponse bool
370379

380+
logger *slog.Logger
381+
371382
// connection is non-nil if and only if the transport has been connected.
372383
connection *streamableServerConn
373384
}
@@ -382,6 +393,7 @@ func (t *StreamableServerTransport) Connect(ctx context.Context) (Connection, er
382393
stateless: t.Stateless,
383394
eventStore: t.EventStore,
384395
jsonResponse: t.jsonResponse,
396+
logger: t.logger,
385397
incoming: make(chan jsonrpc.Message, 10),
386398
done: make(chan struct{}),
387399
streams: make(map[string]*stream),
@@ -408,6 +420,8 @@ type streamableServerConn struct {
408420
jsonResponse bool
409421
eventStore EventStore
410422

423+
logger *slog.Logger
424+
411425
incoming chan jsonrpc.Message // messages from the client to the server
412426

413427
mu sync.Mutex // guards all fields below
@@ -755,7 +769,7 @@ func (c *streamableServerConn) respondSSE(stream *stream, w http.ResponseWriter,
755769
}
756770
if _, err := writeEvent(w, e); err != nil {
757771
// Connection closed or broken.
758-
// TODO(#170): log when we add server-side logging.
772+
c.logger.Warn("error writing event", "error", err)
759773
return false
760774
}
761775
writes++
@@ -774,7 +788,13 @@ func (c *streamableServerConn) respondSSE(stream *stream, w http.ResponseWriter,
774788
// simplify.
775789
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
776790
} else {
777-
// TODO(#170): log when we add server-side logging
791+
if ctx.Err() != nil {
792+
// Client disconnected or cancelled the request.
793+
c.logger.Error("stream context done", "error", ctx.Err())
794+
} else {
795+
// Some other error.
796+
c.logger.Error("error receiving message", "error", err)
797+
}
778798
}
779799
return
780800
}

0 commit comments

Comments
 (0)