Skip to content

feat(mcp): log tool call (function name + arguments) #194

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.

Sign up for GitHub

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

Merged
merged 1 commit into from
Jul 22, 2025
Merged

feat(mcp): log tool call (function name + arguments) #194

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .gitignore
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
_output/
.idea/
.vscode/
.docusaurus/
Expand Down
2 changes: 1 addition & 1 deletion pkg/http/authorization.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -69,7 +69,7 @@ func AuthorizationMiddleware(requireOAuth bool, serverURL string, oidcProvider *
http.Error(w, "Unauthorized: Invalid token", http.StatusUnauthorized)
return
}

if oidcProvider != nil {
// If OIDC Provider is configured, this token must be validated against it.
if err := validateTokenWithOIDC(r.Context(), oidcProvider, token, audience); err != nil {
Expand Down
17 changes: 17 additions & 0 deletions pkg/mcp/common_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,13 +1,18 @@
package mcp

import (
"bytes"
"context"
"encoding/json"
"flag"
"fmt"
"k8s.io/klog/v2"
"k8s.io/klog/v2/textlogger"
"net/http/httptest"
"os"
"path/filepath"
"runtime"
"strconv"
"testing"
"time"

Expand Down Expand Up @@ -100,6 +105,7 @@ func TestMain(m *testing.M) {
type mcpContext struct {
profile Profile
listOutput output.Output
logLevel int

staticConfig *config.StaticConfig
clientOptions []transport.ClientOption
Expand All @@ -111,6 +117,8 @@ type mcpContext struct {
mcpServer *Server
mcpHttpServer *httptest.Server
mcpClient *client.Client
klogState klog.State
logBuffer bytes.Buffer
}

func (c *mcpContext) beforeEach(t *testing.T) {
Expand All @@ -133,6 +141,13 @@ func (c *mcpContext) beforeEach(t *testing.T) {
if c.before != nil {
c.before(c)
}
// Set up logging
c.klogState = klog.CaptureState()
flags := flag.NewFlagSet("test", flag.ContinueOnError)
klog.InitFlags(flags)
_ = flags.Set("v", strconv.Itoa(c.logLevel))
klog.SetLogger(textlogger.NewLogger(textlogger.NewConfig(textlogger.Verbosity(c.logLevel), textlogger.Output(&c.logBuffer))))
// MCP Server
if c.mcpServer, err = NewServer(Configuration{
Profile: c.profile,
ListOutput: c.listOutput,
Expand All @@ -146,6 +161,7 @@ func (c *mcpContext) beforeEach(t *testing.T) {
t.Fatal(err)
return
}
// MCP Client
if err = c.mcpClient.Start(c.ctx); err != nil {
t.Fatal(err)
return
Expand All @@ -168,6 +184,7 @@ func (c *mcpContext) afterEach() {
c.mcpServer.Close()
_ = c.mcpClient.Close()
c.mcpHttpServer.Close()
c.klogState.Restore()
}

func testCase(t *testing.T, test func(c *mcpContext)) {
Expand Down
9 changes: 9 additions & 0 deletions pkg/mcp/mcp.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package mcp
import (
"context"
"fmt"
"k8s.io/klog/v2"
"net/http"
"slices"

Expand Down Expand Up @@ -56,6 +57,7 @@ func NewServer(configuration Configuration) (*Server, error) {
server.WithPromptCapabilities(true),
server.WithToolCapabilities(true),
server.WithLogging(),
server.WithToolHandlerMiddleware(toolCallLoggingMiddleware),
),
}
if err := s.reloadKubernetesClient(); err != nil {
Expand Down Expand Up @@ -165,3 +167,10 @@ func contextFunc(ctx context.Context, r *http.Request) context.Context {

return ctx
}

func toolCallLoggingMiddleware(next server.ToolHandlerFunc) server.ToolHandlerFunc {
return func(ctx context.Context, ctr mcp.CallToolRequest) (*mcp.CallToolResult, error) {
Copy link
Member

@ardaguclu ardaguclu Jul 18, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Based on this commit mark3labs/mcp-go@baa7153, CallToolRequest contains headers. Would you think it would be useful logging some of the values in here like user-agent, etc.?. Would it be useful for us or unnecessary noise?

Copy link
Member Author

@manusa manusa Jul 18, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe with more verbosity, similar to kube-ctl.

  1. log tool call with 5
  2. log request headers with 7

But I'm not even sure if this would be that useful for users

Copy link
Member

@ardaguclu ardaguclu Jul 18, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually this middleware https://github.com/manusa/kubernetes-mcp-server/blob/775fa21bd1345eee52fea6089c119821c0d95c9e/pkg/http/middleware.go#L12 logs all the requests (if verbosity is set to 5 or higher). Maybe we can log the headers in there (only the ones that are not carrying sensitive data).

In which scenario this middleware will be useful?. Request is seen in the audit logs and verifying that it actually results in tool call?

Copy link
Member Author

@manusa manusa Jul 18, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually this middleware...
This works for HTTP but not for STDIO (for example).

IMO is good to have both and also keep them separate.
An HTTP call might eventually become a tool call or not, especially now that we're working on auth (e.g. we get an HTTP request but auth blocks it).

In which scenario this middleware will be useful?.

The user who made the request was building an MCP proxy and wasn't able to see any effects on the MCP server. They wanted to know if the tool was actually being called.
There are multiple places where the calls can be logged (MCP Client, MCP Host, etc.), I guess that this is yet another tracing point.
I understand it can be interesting to trace where the tool call chain was broken.

Copy link
Member

@ardaguclu ardaguclu Jul 18, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good points and make sense to me.

Copy link
Member Author

@manusa manusa Jul 22, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm checking, but the Header field hasn't been added yet in v0.0.34:
mark3labs/mcp-go@v0.34.0...main

We can add the finer trace once v0.35.0 is out

klog.V(5).Infof("mcp tool call: %s(%v)", ctr.Params.Name, ctr.Params.Arguments)
return next(ctx, ctr)
}
}
29 changes: 27 additions & 2 deletions pkg/mcp/mcp_tools_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
package mcp

import (
"github.com/mark3labs/mcp-go/mcp"
"k8s.io/utils/ptr"
"regexp"
"strings"
"testing"

"github.com/mark3labs/mcp-go/mcp"

"github.com/manusa/kubernetes-mcp-server/pkg/config"
)

Expand Down Expand Up @@ -116,3 +117,27 @@ func TestDisabledTools(t *testing.T) {
})
})
}

func TestToolCallLogging(t *testing.T) {
testCaseWithContext(t, &mcpContext{logLevel: 5}, func(c *mcpContext) {
_, _ = c.callTool("configuration_view", map[string]interface{}{
"minified": false,
})
t.Run("Logs tool name", func(t *testing.T) {
expectedLog := "mcp tool call: configuration_view("
if !strings.Contains(c.logBuffer.String(), expectedLog) {
t.Errorf("Expected log to contain '%s', got: %s", expectedLog, c.logBuffer.String())
}
})
t.Run("Logs tool call arguments", func(t *testing.T) {
expected := `"mcp tool call: configuration_view\((.+)\)"`
m := regexp.MustCompile(expected).FindStringSubmatch(c.logBuffer.String())
if len(m) != 2 {
t.Fatalf("Expected log entry to contain arguments, got %s", c.logBuffer.String())
}
if m[1] != "map[minified:false]" {
t.Errorf("Expected log arguments to be 'map[minified:false]', got %s", m[1])
}
})
})
}
Loading