-
Notifications
You must be signed in to change notification settings - Fork 270
mcp/server: enable server logging #501
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 3 commits
75c5927
cf6bc8d
1228679
6b09469
f394f40
95f6e87
410e871
5704be0
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -12,6 +12,7 @@ import ( | |
| "encoding/json" | ||
| "fmt" | ||
| "iter" | ||
| "log/slog" | ||
| "maps" | ||
| "net/url" | ||
| "path/filepath" | ||
|
|
@@ -35,8 +36,9 @@ const DefaultPageSize = 1000 | |
| // sessions by using [Server.Run]. | ||
| type Server struct { | ||
| // fixed at creation | ||
| impl *Implementation | ||
| opts ServerOptions | ||
| impl *Implementation | ||
| opts ServerOptions | ||
| logger *slog.Logger | ||
|
||
|
|
||
| mu sync.Mutex | ||
| prompts *featureSet[*serverPrompt] | ||
|
|
@@ -53,6 +55,8 @@ type Server struct { | |
| type ServerOptions struct { | ||
| // Optional instructions for connected clients. | ||
| Instructions string | ||
| // Logger is used for server-side logging. If nil, disable logging. | ||
|
||
| Logger *slog.Logger | ||
| // If non-nil, called when "notifications/initialized" is received. | ||
| InitializedHandler func(context.Context, *InitializedRequest) | ||
| // PageSize is the maximum number of items to return in a single page for | ||
|
|
@@ -132,6 +136,7 @@ func NewServer(impl *Implementation, options *ServerOptions) *Server { | |
| return &Server{ | ||
| impl: impl, | ||
| opts: opts, | ||
| logger: ensureLogger(opts.Logger), | ||
| prompts: newFeatureSet(func(p *serverPrompt) string { return p.prompt.Name }), | ||
| tools: newFeatureSet(func(t *serverTool) string { return t.tool.Name }), | ||
| resources: newFeatureSet(func(r *serverResource) string { return r.resource.URI }), | ||
|
|
@@ -659,6 +664,7 @@ func (s *Server) ResourceUpdated(ctx context.Context, params *ResourceUpdatedNot | |
| sessions := slices.Collect(maps.Keys(subscribedSessions)) | ||
| s.mu.Unlock() | ||
| notifySessions(sessions, notificationResourceUpdated, params) | ||
| s.logger.Info("resource updated notification sent", "uri", params.URI, "subscriber_count", len(sessions)) | ||
| return nil | ||
| } | ||
|
|
||
|
|
@@ -676,6 +682,7 @@ func (s *Server) subscribe(ctx context.Context, req *SubscribeRequest) (*emptyRe | |
| s.resourceSubscriptions[req.Params.URI] = make(map[*ServerSession]bool) | ||
| } | ||
| s.resourceSubscriptions[req.Params.URI][req.Session] = true | ||
| s.logger.Info("resource subscribed", "uri", req.Params.URI, "session_id", req.Session.ID()) | ||
|
|
||
| return &emptyResult{}, nil | ||
| } | ||
|
|
@@ -697,6 +704,7 @@ func (s *Server) unsubscribe(ctx context.Context, req *UnsubscribeRequest) (*emp | |
| delete(s.resourceSubscriptions, req.Params.URI) | ||
| } | ||
| } | ||
| s.logger.Info("resource unsubscribed", "uri", req.Params.URI, "session_id", req.Session.ID()) | ||
|
|
||
| return &emptyResult{}, nil | ||
| } | ||
|
|
@@ -715,8 +723,10 @@ func (s *Server) unsubscribe(ctx context.Context, req *UnsubscribeRequest) (*emp | |
| // It need not be called on servers that are used for multiple concurrent connections, | ||
| // as with [StreamableHTTPHandler]. | ||
| func (s *Server) Run(ctx context.Context, t Transport) error { | ||
| s.logger.Info("server run start") | ||
| ss, err := s.Connect(ctx, t, nil) | ||
| if err != nil { | ||
| s.logger.Error("server connect failed", "error", err) | ||
| return err | ||
| } | ||
|
|
||
|
|
@@ -728,8 +738,14 @@ func (s *Server) Run(ctx context.Context, t Transport) error { | |
| select { | ||
| case <-ctx.Done(): | ||
| ss.Close() | ||
| s.logger.Info("server run cancelled", "error", ctx.Err()) | ||
| return ctx.Err() | ||
| case err := <-ssClosed: | ||
| if err != nil { | ||
| s.logger.Error("server session ended with error", "error", err) | ||
| } else { | ||
| s.logger.Info("server session ended") | ||
| } | ||
| return err | ||
| } | ||
| } | ||
|
|
@@ -745,6 +761,7 @@ func (s *Server) bind(mcpConn Connection, conn *jsonrpc2.Connection, state *Serv | |
| s.mu.Lock() | ||
| s.sessions = append(s.sessions, ss) | ||
| s.mu.Unlock() | ||
| s.logger.Info("server session connected", "session_id", ss.ID()) | ||
| return ss | ||
| } | ||
|
|
||
|
|
@@ -760,6 +777,7 @@ func (s *Server) disconnect(cc *ServerSession) { | |
| for _, subscribedSessions := range s.resourceSubscriptions { | ||
| delete(subscribedSessions, cc) | ||
| } | ||
| s.logger.Info("server session disconnected", "session_id", cc.ID()) | ||
| } | ||
|
|
||
| // ServerSessionOptions configures the server session. | ||
|
|
@@ -784,7 +802,14 @@ func (s *Server) Connect(ctx context.Context, t Transport, opts *ServerSessionOp | |
| state = opts.State | ||
| onClose = opts.onClose | ||
| } | ||
| return connect(ctx, t, s, state, onClose) | ||
|
|
||
| s.logger.Info("server connecting") | ||
| ss, err := connect(ctx, t, s, state, onClose) | ||
| if err != nil { | ||
| s.logger.Error("server connect error", "error", err) | ||
| return nil, err | ||
| } | ||
| return ss, nil | ||
| } | ||
|
|
||
| // TODO: (nit) move all ServerSession methods below the ServerSession declaration. | ||
|
|
@@ -804,9 +829,11 @@ func (ss *ServerSession) initialized(ctx context.Context, params *InitializedPar | |
| }) | ||
|
|
||
| if !wasInit { | ||
| ss.server.logger.Warn("initialized before initialize") | ||
|
||
| return nil, fmt.Errorf("%q before %q", notificationInitialized, methodInitialize) | ||
| } | ||
| if wasInitd { | ||
| ss.server.logger.Warn("duplicate initialized notification") | ||
| return nil, fmt.Errorf("duplicate %q received", notificationInitialized) | ||
| } | ||
| if ss.server.opts.KeepAlive > 0 { | ||
|
|
@@ -815,6 +842,7 @@ func (ss *ServerSession) initialized(ctx context.Context, params *InitializedPar | |
| if h := ss.server.opts.InitializedHandler; h != nil { | ||
| h(ctx, serverRequestFor(ss, params)) | ||
| } | ||
| ss.server.logger.Info("session initialized") | ||
| return nil, nil | ||
| } | ||
|
|
||
|
|
@@ -1052,6 +1080,7 @@ func (ss *ServerSession) handle(ctx context.Context, req *jsonrpc.Request) (any, | |
| case methodInitialize, methodPing, notificationInitialized: | ||
| default: | ||
| if !initialized { | ||
| ss.server.logger.Warn("method invalid during initialization", "method", req.Method) | ||
| return nil, fmt.Errorf("method %q is invalid during session initialization", req.Method) | ||
| } | ||
| } | ||
|
|
@@ -1108,6 +1137,7 @@ func (ss *ServerSession) setLevel(_ context.Context, params *SetLoggingLevelPara | |
| ss.updateState(func(state *ServerSessionState) { | ||
| state.LogLevel = params.Level | ||
| }) | ||
| ss.server.logger.Info("client log level set", "level", params.Level) | ||
| return &emptyResult{}, nil | ||
| } | ||
|
|
||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -12,6 +12,7 @@ import ( | |
| "fmt" | ||
| "io" | ||
| "iter" | ||
| "log/slog" | ||
| "math" | ||
| "math/rand/v2" | ||
| "net/http" | ||
|
|
@@ -39,6 +40,7 @@ const ( | |
| type StreamableHTTPHandler struct { | ||
| getServer func(*http.Request) *Server | ||
| opts StreamableHTTPOptions | ||
| logger *slog.Logger | ||
|
||
|
|
||
| onTransportDeletion func(sessionID string) // for testing only | ||
|
|
||
|
|
@@ -67,6 +69,10 @@ type StreamableHTTPOptions struct { | |
| // | ||
| // [§2.1.5]: https://modelcontextprotocol.io/specification/2025-06-18/basic/transports#sending-messages-to-the-server | ||
| JSONResponse bool | ||
|
|
||
| // Logger specifies the logger to use. | ||
| // If nil, do not log. | ||
| Logger *slog.Logger | ||
| } | ||
|
|
||
| // NewStreamableHTTPHandler returns a new [StreamableHTTPHandler]. | ||
|
|
@@ -82,6 +88,12 @@ func NewStreamableHTTPHandler(getServer func(*http.Request) *Server, opts *Strea | |
| if opts != nil { | ||
| h.opts = *opts | ||
| } | ||
|
|
||
| if h.opts.Logger == nil { // ensure we have a logger | ||
| h.opts.Logger = ensureLogger(nil) | ||
| } | ||
| h.logger = h.opts.Logger | ||
|
|
||
| return h | ||
| } | ||
|
|
||
|
|
@@ -367,6 +379,8 @@ type StreamableServerTransport struct { | |
| // StreamableHTTPOptions.JSONResponse is exported. | ||
| jsonResponse bool | ||
|
|
||
| logger *slog.Logger | ||
|
|
||
| // connection is non-nil if and only if the transport has been connected. | ||
| connection *streamableServerConn | ||
| } | ||
|
|
@@ -381,6 +395,7 @@ func (t *StreamableServerTransport) Connect(ctx context.Context) (Connection, er | |
| stateless: t.Stateless, | ||
| eventStore: t.EventStore, | ||
| jsonResponse: t.jsonResponse, | ||
| logger: t.logger, | ||
| incoming: make(chan jsonrpc.Message, 10), | ||
| done: make(chan struct{}), | ||
| streams: make(map[string]*stream), | ||
|
|
@@ -407,6 +422,8 @@ type streamableServerConn struct { | |
| jsonResponse bool | ||
| eventStore EventStore | ||
|
|
||
| logger *slog.Logger | ||
|
|
||
| incoming chan jsonrpc.Message // messages from the client to the server | ||
|
|
||
| mu sync.Mutex // guards all fields below | ||
|
|
@@ -754,7 +771,7 @@ func (c *streamableServerConn) respondSSE(stream *stream, w http.ResponseWriter, | |
| } | ||
| if _, err := writeEvent(w, e); err != nil { | ||
| // Connection closed or broken. | ||
| // TODO(#170): log when we add server-side logging. | ||
| c.logger.Warn("error writing event", "error", err) | ||
| return false | ||
| } | ||
| writes++ | ||
|
|
@@ -773,7 +790,13 @@ func (c *streamableServerConn) respondSSE(stream *stream, w http.ResponseWriter, | |
| // simplify. | ||
| http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError) | ||
| } else { | ||
| // TODO(#170): log when we add server-side logging | ||
| if ctx.Err() != nil { | ||
| // Client disconnected or cancelled the request. | ||
| c.logger.Info("stream context done", "error", ctx.Err()) | ||
| } else { | ||
| // Some other error. | ||
| c.logger.Warn("error receiving message", "error", err) | ||
| } | ||
| } | ||
| return | ||
| } | ||
|
|
||
Uh oh!
There was an error while loading. Please reload this page.