Skip to content
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

Long-running MCP servers , MCP server logging #167

Closed
wants to merge 5 commits into from

Conversation

sheffler
Copy link
Contributor

@sheffler sheffler commented Feb 5, 2025

This PR is a suggestion for how to make MCP servers long running. There may be a cleaner way to do it and you may want to rewrite this.
(But first of all - oterm mcp is great work and I'm using it with llama3.2 :-)

Also, to see what was going on I needed to add debugging logs to MCP and that is described in this PR there: modelcontextprotocol/python-sdk#191

Problem: each call to list-tools or call/tool restarts the python script. With Claude Desktop, servers are long-running and calls to tools are messages sent to that server. My modification keeps the session running and does not restart it if there is already one running. But to do that, an explicit teardown needed to be added.

To Test:
include the "simple_tool" attached and ask ollama:
"Please call the simple tool with 100 and 200."
"Now call it with 250 and 350"

The per-server log is named "mcp-server-Tom5Server.log" and its contents are the following. Note that the server is called once and the tool is invoked twice.

==== Starting Tom5Server ====

[02/05/25 13:11:02] DEBUG    MCP STARTING SERVER TOM5           tom5server.py:14
                    DEBUG    Adding resource              resource_manager.py:32
                    DEBUG    Using selector:               selector_events.py:59
                             KqueueSelector                                     
                    DEBUG    Received message:                     server.py:432
                             root=InitializedNotification(method='              
                             notifications/initialized',                        
                             params=None, jsonrpc='2.0')                        
                    DEBUG    Received message:                     server.py:432
                             <mcp.shared.session.RequestResponder               
                             object at 0x104feedd0>                             
                    INFO     Processing request of type            server.py:454
                             ListToolsRequest                                   
                    DEBUG    Dispatching request of type           server.py:457
                             ListToolsRequest                                   
                    DEBUG    Response sent                         server.py:491
==== Call Tool simple_tool ====

[02/05/25 13:11:16] DEBUG    Received message:                     server.py:432
                             <mcp.shared.session.RequestResponder               
                             object at 0x104fee0b0>                             
                    INFO     Processing request of type            server.py:454
                             CallToolRequest                                    
                    DEBUG    Dispatching request of type           server.py:457
                             CallToolRequest                                    
                    DEBUG    IN SIMPLE_TOOL                     tom5server.py:23
                    DEBUG    Response sent                         server.py:491
                    INFO     Warning: RuntimeWarning: coroutine    server.py:443
                             'Context.report_progress' was never                
                             awaited                                            
==== Call Tool simple_tool ====

[02/05/25 13:11:38] DEBUG    Received message:                     server.py:432
                             <mcp.shared.session.RequestResponder               
                             object at 0x104fee830>                             
                    INFO     Processing request of type            server.py:454
                             CallToolRequest                                    
                    DEBUG    Dispatching request of type           server.py:457
                             CallToolRequest                                    
                    DEBUG    IN SIMPLE_TOOL                     tom5server.py:23
                    DEBUG    Response sent                         server.py:491
                    INFO     Warning: RuntimeWarning: coroutine    server.py:443
                             'Context.report_progress' was never                
                             awaited                                            

The source for the MCP server is this

#
# Small Demo server using FastMCP and illustrating debugging and notification streams
#

import logging
from mcp.server.fastmcp import FastMCP, Context
import time
import asyncio

mcp = FastMCP("Tom5 Server 2024-02-05", debug=True, log_level="DEBUG")

logger = logging.getLogger(__name__)

logger.debug(f"MCP STARTING SERVER TOM5")

@mcp.resource("config://app")
def get_config() -> str:
    """Static configuration data"""
    return "Tom5 Server 2024-02-25"

@mcp.tool()
async def simple_tool(x:float, y:float, ctx:Context) -> str:
    logger.debug("IN SIMPLE_TOOL")
    ctx.report_progress(1, 2)
    return x*y

…exit. Also add logging so messages go to file instead of screen.
@ggozad
Copy link
Owner

ggozad commented Feb 6, 2025

Wow Tom, this is really nice thank you!
I only skimmed through, will go through the PR and get it merged once I have some time.

One thing that comes to mind: Since you already implemented a simple tool, would you like to put some more effort and add some unit tests using your tool? There are a few examples in the tests folder that should help. This way we can expand the MCP features more easily in the future.

@sheffler
Copy link
Contributor Author

sheffler commented Feb 6, 2025

Good morning Yiorgis,

Upon further testing with multiple concurrent servers it seems that this solution is not quite right, so please don't merge it.

When there are multiple servers, the teardown step does not execute cleanly, because the task-groups
are not shutdown in the right sequence. It has to do with the async contexts (__aenter, __aexit) I believe.

I will continue to examine the situation and work towards multiple long-running servers. I will also look at the unit tests.

Thanks again for this nice tool.

@sheffler sheffler closed this Feb 6, 2025
@ggozad
Copy link
Owner

ggozad commented Feb 6, 2025

Hey Tom!
Just wanted to say you can keep it open (set it to draft) if you want. This way I or others can perhaps fix the issues and help you out.
And thanks again for your kind words:)

@sheffler
Copy link
Contributor Author

sheffler commented Feb 6, 2025

Ok. I will mark it as a draft and we can use this thread to discuss the issues around running multiple subprocesses.

Question: One of the things that has been difficult for me in debugging this is observing error log messages since they go to the terminal and textual.app (?) frameworks seems to absorb stderr.

Is there an easy way to direct logging and error output to a file? I used typescript, but I"m wondering if you know a better way.

Thanks.
Tom

@sheffler sheffler reopened this Feb 6, 2025
@sheffler
Copy link
Contributor Author

sheffler commented Feb 6, 2025

Reopen and mark as draft.

@sheffler sheffler marked this pull request as draft February 6, 2025 17:20
@ggozad
Copy link
Owner

ggozad commented Feb 6, 2025

Thanks for re-opening!
To answer your question, you can use textual console.
Assuming you git cloned and use uv:

uv venv
source ./.venv/bin/activate

And then

textual console -x SYSTEM -x EVENT -x DEBUG -x INFO

This is the textual console, with disabled basically all events. Here, you will see all your print()s etc.

You then run oterm in a different terminal by

textual run -c oterm --dev

See here for proper docs and additional things you can do to debug.

@ggozad ggozad changed the title Suggestions: make MCP servers long-running and cleanly terminate upon exit, also add logging to file Long-running MCP servers , MCP server logging Feb 6, 2025
@sheffler
Copy link
Contributor Author

sheffler commented Feb 8, 2025

A few things:

  • removed mcp server logging redirection for now until it is supported by MCP python-sdk. It may not get included for a while.
  • included MCPClient informed by mcp_simple_chatbot in the MCP python-sdk.
  • wrote a proper test and included an example server that illustrates how to set them up
  • discovered a tricky bug in the creation of a list of callables. It seems they are not proper closures in Python (is it a Python bug?) Read more below.

Cleanup

The teardown_mcp_servers method works and has been tested in a set-up with two concurrent MCP servers (a database and the simple example). It seems fragile however.

I think the cleanest way to run servers might be something like the following one day.

await setup_mcp_servers()
await oterm_main()
await teardown_mcp_servers()

Problem

The following structure was problematic.

async def set_mcp_server():
    tool_defs = []
    for server in mcp_servers.items():
        client = MCPClient(...)
	tools = await client.get_available_tools()
        for tool in tools:
	    async def callable():
	        ...
	        do_something_with(client, tool)
	    tool_defs.append(callable)

Instead of creating a list of callables each of which is bound to a different tool and its callable, all of the callables referenced the same values of "client" and "tool". It is as if set_mcp_server.client and set_mcp_server.tool were instance variables and all of the callables referenced them. As such, they all got the last value of client and tool in the iteration. This seems like a Python bug.

@sheffler
Copy link
Contributor Author

sheffler commented Feb 8, 2025

Thanks for the help in understanding how to view logging with Textual. Was a huge help.

@sheffler
Copy link
Contributor Author

sheffler commented Feb 8, 2025

Remove the stderr/errlog override. Forgot to take this out.

@ggozad
Copy link
Owner

ggozad commented Feb 8, 2025

Problem

The following structure was problematic.

async def set_mcp_server():
    tool_defs = []
    for server in mcp_servers.items():
        client = MCPClient(...)
	tools = await client.get_available_tools()
        for tool in tools:
	    async def callable():
	        ...
	        do_something_with(client, tool)
	    tool_defs.append(callable)

Instead of creating a list of callables each of which is bound to a different tool and its callable, all of the callables referenced the same values of "client" and "tool". It is as if set_mcp_server.client and set_mcp_server.tool were instance variables and all of the callables referenced them. As such, they all got the last value of client and tool in the iteration. This seems like a Python bug.

Hey Tom!
No, this is not a python issue, this is my bad for not having tests for MCP ;)
My guess is tool not being in the closure has whatever value the outer scope has, basically the last server in the loop.
It's easy to fix, I will try to do so asap!

@sheffler
Copy link
Contributor Author

sheffler commented Feb 8, 2025

Hi Yiorgis -
I believe this PR is now complete and correct for multiple servers. I've tested it with two servers running and can ask ollama to run tools in each one. I will look at #172 and see if I have a suggestion there.

@ggozad
Copy link
Owner

ggozad commented Feb 12, 2025

Hey Tom!
Thank you so much for this! I apologise for being so late in reviewing this, time is hard to come by these last few days.
Do you mind if I review and commit changes in the same time? It will help me do this faster, but if you prefer that I ask you for changes let me know!

@sheffler
Copy link
Contributor Author

Hi Yirogis -
Please proceed as you see fit! It's fine with me if you rework my changes to fit your style or requirements. I did my best to illustrate how I think the servers could work, and I tested them with two separate running servers myself. I think MCP will be a work in progress.

Thanks for all your good work on this tool.
Tom

@ggozad
Copy link
Owner

ggozad commented Feb 12, 2025

Thanks Tom, from the little that I've seen, you have done an excellent work! Will ping you when I get to it and you can review.

@ggozad
Copy link
Owner

ggozad commented Feb 22, 2025

Hey Tom, I am very sorry for being so late, life changes are overwhelming atm :)
I tried to run off your pr but both the tools that I tried failed to respond...
Here's my config

{
  "theme": "textual-dark",
  "splash-screen": false,
  "keymap": { "newline": "ctrl+n" },
  "tools": [],
  "mcpServers": {
    "memory": {
      "command": "docker",
      "args": ["run", "-i", "--rm", "mcp/memory"]
    },
    "git": {
      "command": "docker",
      "args": [
        "run",
        "--rm",
        "-i",
        "--mount",
        "type=bind,src=/Users/ggozad/dev/open-source/oterm,dst=/projects/oterm",
        "mcp/git"
      ]
    }
  }
}

@sheffler
Copy link
Contributor Author

Hi Yiorgis - are you able to tell if the servers start? Do they respond if you do not include my changes?

@ggozad
Copy link
Owner

ggozad commented Feb 23, 2025

All good I think, cleaned up and pushed a rebased branch in #174
Let's take it there @sheffler, if you can have a look I should be able to finish this today.

@ggozad
Copy link
Owner

ggozad commented Feb 23, 2025

Merged as #174

@ggozad ggozad closed this Feb 23, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants