fix(mcp-agent): stream native mcp-server stderr to logs

The previous implementation buffered stderr from the native mcp-server process and only logged the full buffer content when the process exited. This prevented real-time viewing of logs from the server.

This change modifies the native process startup logic (`startProcess_locked`) to use `cmd.StderrPipe()` instead of assigning `cmd.Stderr` to a buffer. A separate goroutine is now launched within the process monitoring goroutine. This new goroutine uses a `bufio.Scanner` to continuously read lines from the stderr pipe and logs them using the Navidrome logger (`log.Info`) with an `[MCP-SERVER]` prefix.

This ensures logs from the native mcp-server appear in Navidrome's logs immediately as they are written.

(Note: Also includes update to McpServerPath constant to point to the native binary.)

Signed-off-by: Deluan <deluan@navidrome.org>
This commit is contained in:
Deluan 2025-04-19 19:42:22 -04:00
parent bcc3643c81
commit c7d7ec306e
2 changed files with 25 additions and 5 deletions

View File

@ -24,6 +24,7 @@ const (
McpAgentName = "mcp" McpAgentName = "mcp"
initializationTimeout = 5 * time.Second initializationTimeout = 5 * time.Second
// McpServerPath defines the location of the MCP server executable or WASM module. // McpServerPath defines the location of the MCP server executable or WASM module.
// McpServerPath = "./core/agents/mcp/mcp-server/mcp-server"
McpServerPath = "./core/agents/mcp/mcp-server/mcp-server.wasm" McpServerPath = "./core/agents/mcp/mcp-server/mcp-server.wasm"
McpToolNameGetBio = "get_artist_biography" McpToolNameGetBio = "get_artist_biography"
McpToolNameGetURL = "get_artist_url" McpToolNameGetURL = "get_artist_url"

View File

@ -1,6 +1,7 @@
package mcp package mcp
import ( import (
"bufio"
"context" "context"
"errors" "errors"
"fmt" "fmt"
@ -197,12 +198,18 @@ func (n *MCPNative) startProcess_locked(ctx context.Context) (stdin io.WriteClos
return nil, nil, nil, fmt.Errorf("native stdout pipe: %w", err) return nil, nil, nil, fmt.Errorf("native stdout pipe: %w", err)
} }
var stderrBuf strings.Builder // Get stderr pipe to stream logs
cmd.Stderr = &stderrBuf stderrPipe, err := cmd.StderrPipe()
if err != nil {
_ = stdinPipe.Close()
_ = stdoutPipe.Close()
return nil, nil, nil, fmt.Errorf("native stderr pipe: %w", err)
}
if err = cmd.Start(); err != nil { if err = cmd.Start(); err != nil {
_ = stdinPipe.Close() _ = stdinPipe.Close()
_ = stdoutPipe.Close() _ = stdoutPipe.Close()
// stderrPipe gets closed implicitly if cmd.Start() fails
return nil, nil, nil, fmt.Errorf("native start: %w", err) return nil, nil, nil, fmt.Errorf("native start: %w", err)
} }
@ -210,12 +217,24 @@ func (n *MCPNative) startProcess_locked(ctx context.Context) (stdin io.WriteClos
currentCmd := cmd // Capture the current cmd pointer for the goroutine currentCmd := cmd // Capture the current cmd pointer for the goroutine
log.Info(ctx, "Native MCP server process started", "pid", currentPid) log.Info(ctx, "Native MCP server process started", "pid", currentPid)
// Start monitoring goroutine // Start monitoring goroutine for process exit
go func() { go func() {
// Start separate goroutine to stream stderr
go func() {
scanner := bufio.NewScanner(stderrPipe)
for scanner.Scan() {
log.Info("[MCP-SERVER] " + scanner.Text())
}
if err := scanner.Err(); err != nil {
log.Error("Error reading MCP server stderr", "pid", currentPid, "error", err)
}
log.Debug("MCP server stderr pipe closed", "pid", currentPid)
}()
waitErr := currentCmd.Wait() // Wait for the specific process this goroutine monitors waitErr := currentCmd.Wait() // Wait for the specific process this goroutine monitors
n.mu.Lock() n.mu.Lock()
stderrStr := stderrBuf.String() // Stderr is now streamed, so we don't capture it here anymore.
log.Warn("Native MCP server process exited", "pid", currentPid, "error", waitErr, "stderr", stderrStr) log.Warn("Native MCP server process exited", "pid", currentPid, "error", waitErr)
// Critical: Check if the agent's current command is STILL the one we were monitoring. // Critical: Check if the agent's current command is STILL the one we were monitoring.
// If it's different, it means cleanup/restart already happened, so we shouldn't cleanup again. // If it's different, it means cleanup/restart already happened, so we shouldn't cleanup again.