# Logging from a stdio server

> Break a stdio tool server with one debug line on standard output, watch the client fail to parse the first line, move the line to standard error, and read the reference file-system server's log while an agent calls it.

Page: https://schubergphilis.github.io/ai-training/customizing-agents/logging-from-a-stdio-server/
License: CC BY-SA 4.0, https://creativecommons.org/licenses/by-sa/4.0/

In this lesson one debug line breaks a tool server for our test client,
and we find out why that client can't read the server's reply. The fix
changes where the line goes. Then we read the log of the real
file-system server while an agent calls it.

The previous lesson connected the reference file-system server of the
Model Context Protocol (MCP) project, and showed a stand-in that speaks
the same stdio transport. Here we use that stand-in again. A quick way
to debug a server you write is a `print`, and on this transport a
`print` to standard output is a bug.

## What a debug line does to the stream

On the stdio transport the client starts the server as a child process.
The server reads requests from its standard input and writes its
messages to its standard output, one message per line in JSON-RPC, the
JSON format for Remote Procedure Calls (RPC) that MCP uses. The
specification says a server must not write anything to standard output
that isn't a valid MCP message. A server that wants to log writes to
standard error instead, and the client may show that stream, pass it on
or drop it. The client also shouldn't take output on standard error as
a sign that something failed (Model Context Protocol specification 2026-07-28, modelcontextprotocol.io).
That rule is stdio logging, and the fixture below shows what happens
without it.

The fixture directory for this lesson,
`site/examples/customizing-agents/logging-from-a-stdio-server/`, holds
`server.py`. It answers each request with the stand-in's own code from
`../mcp-first-server/stand_in.py`, so it has the same three read-only
tools and the same scope. Before each answer it calls `log`, which prints
the method and the tool name:

```python
def log(message):
    print(message)
```

`check.py` plays the client. It starts a server and sends one
`tools/call` for `list_directory` on the handbook directory. Then it
reads one line from the server's standard output. It prints that line,
cut at 40 characters, and whether the line parsed as JSON. Last it prints
what the server wrote to standard error. `call_server.py` runs it against
`server.py`.

#### Example: Call the server

Run `call_server.py` in the fixture directory, and compare with the
output below.

```sh
python3 call_server.py
```

Output:

```text
stdout line: debug: tools/call list_directory
parsed: no (Expecting value)
stderr: (empty)
```

The server worked. It got the request, ran the tool and wrote a correct
reply. But `print` writes to standard output by default, so the debug
line went out first, on the line where the client waits for its reply.
The client can't parse `debug: ...` as JSON-RPC, although the server did
its work, and the specification has no rule for what a client does with
such a line. `check.py` stops at the first line it can't parse, while
another client may drop the line, report an error and read on. Either
way the server broke the rule, and you can't count on one outcome.

#### Checkpoint: Why did the client fail?

The client's report says `parsed: no (Expecting value)`, and the line it
read is `debug: tools/call list_directory`. What went wrong?

- The server crashed before it answered, so the client read an empty line from it.
- The client sent a request that was not valid JSON-RPC, so the server answered with an error.
- The debug line went to standard output, and the client read it where it expected the reply.
- The client read standard error by mistake, which is where the debug line is meant to go.

## Move the log to standard error

The fix is one argument. `server_fixed.py` is `server.py` with the `log`
function changed to write to standard error:

```python
def log(message):
    print(message, file=sys.stderr)
```

`call_fixed_server.py` sends the same call to `server_fixed.py`.

#### Example: Call the fixed server

Run `call_fixed_server.py` in the fixture directory, and compare with the
output below.

```sh
python3 call_fixed_server.py
```

Output:

```text
stdout line: {"jsonrpc": "2.0", "id": 1, "result":...
parsed: yes, isError: False
stderr: debug: tools/call list_directory
```

Now the first line on standard output is the reply, and the debug line
is still there, on standard error. You kept the information and the
client gets a clean stream.

MCP also has a logging feature inside the protocol, a `notifications/message`
the server sends to the client. Revision 2026-07-28 deprecates it, and
its registry of deprecated features tells a stdio server to log to
standard error instead (Deprecated Features, Model Context Protocol specification 2026-07-28, modelcontextprotocol.io). So on stdio,
standard error is the place for the server's log, whatever your client
does with it.

#### Checkpoint: Fix the debug line

A colleague's stdio server stopped working with their agent after they
added a `print` of a debug line before each reply. They still need the
debug line for another bug, and they follow MCP revision 2026-07-28. What
do you suggest?

- Delete the print statement, since a stdio server is not allowed to print anything at all.
- Keep the print statement, and write the debug line to standard error.
- Wrap the debug line in a JSON object, so that the client can parse every line it reads.
- Send the debug line to the client as an MCP log notification, inside the protocol.

## Read the log while the agent calls it

A client may ignore the server's standard error (Model Context Protocol specification 2026-07-28, modelcontextprotocol.io), so
to read the log with any agent, send it to a file yourself. Start the
server through `sh -c` with `2>>` and a file name, and `sh` appends
everything the server writes to standard error to that file. Standard
output stays connected to the agent.

The reference file-system server replaces its allowed directories with
the roots the client sends (Filesystem MCP Server, GitHub, modelcontextprotocol/servers, src/filesystem), and it writes its
own messages to standard error. This is its standard error from a run on
October 7, 2026, with version 2026.8.31 and a small test client that
sent one root and then called a tool. The run logged the start on stdio
and the switch to the roots, and nothing for the tool call:

```text
Secure MCP Filesystem Server running on stdio
Updated allowed directories from MCP roots: 1 valid directories
```

The previous lesson showed that Claude Code sends the directory you
started it in as a root (Connect Claude Code to tools via MCP, Claude Code documentation), so under Claude Code the
second line tells you the server took its scope from that directory.
The line counts the directories, so if it says anything other than 1,
remove the server before you ask the agent anything.
On that run `npx` also wrote two `npm notice` lines of its own to
standard error, so your file may hold lines like those too.

#### Pitfall: A library that prints

A developer adds a library to their stdio server, and the library writes
a short banner to standard output the first time it is used, with no
newline after it. In their own test they start the server in a terminal,
type a request, and read the reply by eye, so the banner looks like
harmless extra text in front of the reply. For the agent, the banner and
the reply are one line, and that line isn't a valid message, so the
reply is lost whatever the client does with a bad line. The call fails
or never returns. The rule: on a stdio server, only the code that writes
protocol messages writes to standard output. Send every other line to
standard error, and test the server with a client that parses its
output, as `check.py` does with the first line.

## Exercise

Fix the bug, then read a real server's log. From the root of the course
repository, copy both fixture directories next to each other into an
empty directory, so `server.py` still finds the stand-in, and run the
client against the broken server in the copy:

```sh
mkdir -p /tmp/stdio-log
cp -r site/examples/customizing-agents/mcp-first-server site/examples/customizing-agents/logging-from-a-stdio-server /tmp/stdio-log/
cd /tmp/stdio-log/logging-from-a-stdio-server
python3 call_server.py
```

Change the `log` function in your copy of `server.py` so it writes to
standard error, and run `python3 call_server.py` again. It now prints
what `call_fixed_server.py` printed above.

Then connect the reference server to the handbook copy with its standard
error sent to a file, and start your agent inside the copy, as in the
previous lesson. The server has write tools, so the copy is the only
directory it may see. Claude Code gives the server the directory it
started in as its root (Connect Claude Code to tools via MCP, Claude Code documentation), and the command gives the
same directory as the argument:

```sh
cd /tmp/stdio-log/mcp-first-server/handbook
claude mcp add handbook-log -- sh -c 'exec npx -y @modelcontextprotocol/server-filesystem@2026.8.31 /tmp/stdio-log/mcp-first-server/handbook 2>>/tmp/stdio-log/server.log'
claude
```

In a second terminal, run `tail -F /tmp/stdio-log/server.log`. Ask the
agent to list the files in the handbook and change nothing, and watch the
log while it works. A good result: the log has the two lines shown
above, the agent's list has the four handbook files, and none of the log
lines showed up in the agent's replies. When you're done, remove the server
with `claude mcp remove handbook-log` (Connect Claude Code to tools via MCP, Claude Code documentation). Then ask
yourself: if the server had printed those lines to standard output
instead, how would you have found out, and would you have found out at
all?

Stretch: Add a log line to your fixed copy of server.py that prints the path of each call to standard error, and run call_server.py again to check the stream is still clean.

## Recap

1. On the stdio transport, standard output carries one JSON-RPC message
   per line and nothing else. A server logs to standard error, which the
   client may show, keep or drop, and which isn't a sign of failure
   (Model Context Protocol specification 2026-07-28, modelcontextprotocol.io).
2. A `print` writes to standard output by default, so one debug line
   arrives where the client expects a message. What happens next is up
   to the client: the test client here stops, and another may drop the
   line and report an error. The rule is broken in either case.
3. The fix is to write the line to standard error, which keeps the
   information. MCP revision 2026-07-28 deprecates the in-protocol
   logging feature and points stdio servers to standard error
   (Deprecated Features, Model Context Protocol specification 2026-07-28, modelcontextprotocol.io).
4. To read a server's log with any agent, start it through `sh -c` and
   append its standard error to a file, then read the file in a second
   terminal.

## References

- Model Context Protocol specification 2026-07-28, modelcontextprotocol.io, https://modelcontextprotocol.io/specification/2026-07-28
- Deprecated Features, Model Context Protocol specification 2026-07-28, modelcontextprotocol.io, https://modelcontextprotocol.io/specification/2026-07-28/deprecated
- Filesystem MCP Server, GitHub, modelcontextprotocol/servers, src/filesystem, https://github.com/modelcontextprotocol/servers/tree/main/src/filesystem
- Connect Claude Code to tools via MCP, Claude Code documentation, https://code.claude.com/docs/en/mcp