Refactor duplicated marshal/log paths and unify sanitized sys tool response logging (#4106)

Recent `SendRequestWithServerID` cleanup left three duplication/safety
gaps: repeated marshal-for-debug blocks, duplicated sys tool handler
skeletons, and unsanitized `sys_list_servers` result logging. This PR
consolidates those paths and closes the sanitization gap.

- **Consolidate marshal-for-debug logic**
- Added `logger.LogMarshaledForDebug(...)` in
`internal/logger/marshal_debug.go`.
  - Replaced repeated marshal+error/success logging blocks in:
    - `internal/guard/wasm.go`
    - `internal/server/guard_init.go`
- Result: one shared marshaling pattern for debug logging across
guard/server paths.

- **Unify sys tool call/error/log skeleton**
- Added `callAndLogSysTool(...)` in `internal/server/tool_registry.go`.
- `sysInitHandler` and `sysListHandler` now share one call path (call
sys server → handle error → marshal/log result → return).

- **Fix sanitization gap in `sys_list_servers` logging**
  - Added shared `marshalAndSanitizeForLog(...)` in `tool_registry.go`.
- `sys_list_servers` response logs now use
`sanitize.SanitizeString(...)`, matching `sys_init` and backend tool
logging behavior.

- **Focused test coverage**
  - Added helper tests for marshal debug utility:
    - `internal/logger/marshal_debug_test.go`
  - Added server tests for log sanitization/error behavior:
    - `internal/server/tool_registry_test.go`

```go
func (us *UnifiedServer) callAndLogSysTool(sessionID, operationName, sysToolName string) (*sdk.CallToolResult, interface{}, error) {
	result, err := us.callSysServer(sysToolName)
	if err != nil {
		logger.LogError("client", "MCP %s call failed, session=%s, error=%v", operationName, sessionID, err)
		return mcp.NewErrorCallToolResult(err)
	}
	logger.LogInfo("client", "MCP %s response, session=%s, result=%s", operationName, sessionID, marshalAndSanitizeForLog(result))
	return nil, result, nil
}
```

> [!WARNING]
>
> <details>
> <summary>Firewall rules blocked me from connecting to one or more
addresses (expand for details)</summary>
>
> #### I tried to connect to the following addresses, but was blocked by
firewall rules:
>
> - `example.com`
> - Triggering command: `/tmp/go-build1793350213/b510/launcher.test
/tmp/go-build1793350213/b510/launcher.test
-test.testlogfile=/tmp/go-build1793350213/b510/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -test.v=true
3350213/b184/_pk-errorsas 64/src/log/slog/-ifaceassert bin/as -p
zevo/backend/isa-atomic -lang=go1.25 /opt/hostedtoolc-buildtags -o
s/attributes.go idRS/k9xnSFeesAm-ifaceassert x_amd64/compile -p
crypto/internal/info -lang=go1.25 x_amd64/compile` (dns block)
> - Triggering command: `/tmp/go-build3990767025/b514/launcher.test
/tmp/go-build3990767025/b514/launcher.test
-test.testlogfile=/tmp/go-build3990767025/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s
/tmp/go-build3990767025/b495/vet.cfg ry=1 -trimpath x_amd64/vet -p
github.com/githupush -lang=go1.25 x_amd64/vet -ato�� .cfg -buildtags
64/pkg/tool/linux_amd64/vet -errorsas -ifaceassert -nilfunc
64/pkg/tool/linu-trimpath` (dns block)
> - Triggering command: `/tmp/go-build848674421/b514/launcher.test
/tmp/go-build848674421/b514/launcher.test
-test.testlogfile=/tmp/go-build848674421/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s know��
l/server/tool_registry_test.go
known-linux-gnu/lib/rustlib/x86_--format=format:%H %ct %D
stable-x86_64-REDACTED-linux-gnu/--end-of-options 6e1dc71b.rlib ccc.rlib
--systemd-cgroup-bool` (dns block)
> - `invalid-host-that-does-not-exist-12345.com`
> - Triggering command: `/tmp/go-build1793350213/b492/config.test
/tmp/go-build1793350213/b492/config.test
-test.testlogfile=/tmp/go-build1793350213/b492/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -test.v=true 3350213/b151/_pk-p o
x_amd64/compile` (dns block)
> - Triggering command: `/tmp/go-build3990767025/b496/config.test
/tmp/go-build3990767025/b496/config.test
-test.testlogfile=/tmp/go-build3990767025/b496/testlog.txt
-test.paniconexit0 -test.timeout=10m0s n-me�� g_.a
pkg/mod/go.opentelemetry.io/otel/exporters/otlp/otlptrace/[email protected]/doc.go
x_amd64/vet -p github.com/segme--norc -lang=go1.17 x_amd64/vet -ato��
MQJZCSQ0B -buildtags x_amd64/vet -errorsas -ifaceassert -nilfunc
ks...&#34;; \
elif c--revs` (dns block)
> - Triggering command: `/tmp/go-build848674421/b496/config.test
/tmp/go-build848674421/b496/config.test
-test.testlogfile=/tmp/go-build848674421/b496/testlog.txt
-test.paniconexit0 -test.timeout=10m0s 05ed�� 05ed-cgu.10.rcgu-errorsas
05ed-cgu.11.rcgu-ifaceassert 05ed-cgu.12.rcgu-nilfunc
05ed-cgu.13.rcgugit 05ed-cgu.14.rcguls-files
pt_build-842ae9a--exclude-standard pt_build-842ae9a--others /usr��
--root .rlib 6b2b26a06.rlib 327.rlib 653.rlib 86b29d.rlib
ive.12123747d8da05ed-cgu.00.rcgu.o` (dns block)
> - `nonexistent.local`
> - Triggering command: `/tmp/go-build1793350213/b510/launcher.test
/tmp/go-build1793350213/b510/launcher.test
-test.testlogfile=/tmp/go-build1793350213/b510/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -test.v=true
3350213/b184/_pk-errorsas 64/src/log/slog/-ifaceassert bin/as -p
zevo/backend/isa-atomic -lang=go1.25 /opt/hostedtoolc-buildtags -o
s/attributes.go idRS/k9xnSFeesAm-ifaceassert x_amd64/compile -p
crypto/internal/info -lang=go1.25 x_amd64/compile` (dns block)
> - Triggering command: `/tmp/go-build3990767025/b514/launcher.test
/tmp/go-build3990767025/b514/launcher.test
-test.testlogfile=/tmp/go-build3990767025/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s
/tmp/go-build3990767025/b495/vet.cfg ry=1 -trimpath x_amd64/vet -p
github.com/githupush -lang=go1.25 x_amd64/vet -ato�� .cfg -buildtags
64/pkg/tool/linux_amd64/vet -errorsas -ifaceassert -nilfunc
64/pkg/tool/linu-trimpath` (dns block)
> - Triggering command: `/tmp/go-build848674421/b514/launcher.test
/tmp/go-build848674421/b514/launcher.test
-test.testlogfile=/tmp/go-build848674421/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s know��
l/server/tool_registry_test.go
known-linux-gnu/lib/rustlib/x86_--format=format:%H %ct %D
stable-x86_64-REDACTED-linux-gnu/--end-of-options 6e1dc71b.rlib ccc.rlib
--systemd-cgroup-bool` (dns block)
> - `slow.example.com`
> - Triggering command: `/tmp/go-build1793350213/b510/launcher.test
/tmp/go-build1793350213/b510/launcher.test
-test.testlogfile=/tmp/go-build1793350213/b510/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -test.v=true
3350213/b184/_pk-errorsas 64/src/log/slog/-ifaceassert bin/as -p
zevo/backend/isa-atomic -lang=go1.25 /opt/hostedtoolc-buildtags -o
s/attributes.go idRS/k9xnSFeesAm-ifaceassert x_amd64/compile -p
crypto/internal/info -lang=go1.25 x_amd64/compile` (dns block)
> - Triggering command: `/tmp/go-build3990767025/b514/launcher.test
/tmp/go-build3990767025/b514/launcher.test
-test.testlogfile=/tmp/go-build3990767025/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s
/tmp/go-build3990767025/b495/vet.cfg ry=1 -trimpath x_amd64/vet -p
github.com/githupush -lang=go1.25 x_amd64/vet -ato�� .cfg -buildtags
64/pkg/tool/linux_amd64/vet -errorsas -ifaceassert -nilfunc
64/pkg/tool/linu-trimpath` (dns block)
> - Triggering command: `/tmp/go-build848674421/b514/launcher.test
/tmp/go-build848674421/b514/launcher.test
-test.testlogfile=/tmp/go-build848674421/b514/testlog.txt
-test.paniconexit0 -test.timeout=10m0s know��
l/server/tool_registry_test.go
known-linux-gnu/lib/rustlib/x86_--format=format:%H %ct %D
stable-x86_64-REDACTED-linux-gnu/--end-of-options 6e1dc71b.rlib ccc.rlib
--systemd-cgroup-bool` (dns block)
> - `this-host-does-not-exist-12345.com`
> - Triggering command: `/tmp/go-build1793350213/b519/mcp.test
/tmp/go-build1793350213/b519/mcp.test
-test.testlogfile=/tmp/go-build1793350213/b519/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -test.v=true
transport/bdp_estimator.go transport/client_stream.go x_amd64/compile
-pthread e/otlptracehttp/--version -fmessage-length=0 x_amd64/compile
3350�� g_.a 3350213/b165/ x_amd64/vet --gdwarf-5 mcpgodebug -o
x_amd64/vet` (dns block)
> - Triggering command: `/tmp/go-build3990767025/b523/mcp.test
/tmp/go-build3990767025/b523/mcp.test
-test.testlogfile=/tmp/go-build3990767025/b523/testlog.txt
-test.paniconexit0 -test.timeout=10m0s -ato�� .cfg -buildtags
0278e5566a20dc05-d -errorsas -ifaceassert -nilfunc
64/pkg/tool/linu-buildtags --ve�� .cfg -tests 64/pkg/tool/linu-nilfunc
1024825-9d38bb40/usr/bin/runc.original [email protected]/depr--version
x_amd64/compile 64/pkg/tool/linu-tests` (dns block)
> - Triggering command: `/tmp/go-build848674421/b523/mcp.test
/tmp/go-build848674421/b523/mcp.test
-test.testlogfile=/tmp/go-build848674421/b523/testlog.txt
-test.paniconexit0 -test.timeout=10m0s ogpt�� q7jvxzdnkys32nfz-errorsas
0ok7l9sshaaz07e8-ifaceassert hw1mmy6a1aekmmsh-nilfunc
4p2kq4dabhq5b2kedocker wmuqycv01jbjtq95inspect ntained/cc
stable-x86_64-un{{.Config.OpenStdin}} stab��
stable-x86_64-REDACTED-linux-gnu/lib/rustlib/x86_64-REDACTED-linux-gnu/lib/libobject-926daa94a00ee/usr/libexec/docker/docker-init
stable-x86_64-REDACTED-linux-gnu/lib/rustlib/x86_64-REDACTED-linux-gnu/lib/libmemchr-48d5b0db80402--version
.1/x64/codeql/tools/linux64/java/lib/jspawnhelper
stable-x86_64-un/usr/libexec/docker/cli-plugins/docker-compose
7a5585.0r6f2y9pmdocker-cli-plugin-metadata
7a5585.0y8i0suihruczucboywd9kbz6/tmp/go-build985941549/b001/_pkg_.a
.1/x64/codeql/tools/linux64/java-trimpath` (dns block)
>
> If you need me to access, download, or install something from one of
these locations, you can either:
>
> - Configure [Actions setup
steps](https://gh.io/copilot/actions-setup-steps) to set up my
environment, which run before the firewall is enabled
> - Add the appropriate URLs or hosts to the custom allowlist in this
repository's [Copilot coding agent
settings](https://github.com/github/gh-aw-mcpg/settings/copilot/coding_agent)
(admins only)
>
> </details>

Author: lpcox

internal/guard/wasm.go

@@ -695,12 +695,15 @@ func (g *WasmGuard) LabelAgent(ctx context.Context, policy interface{}, backend
 		logWasm.Printf("LabelAgent normalizePolicyPayload failed: guard=%s, error=%v", g.name, err)
 		return nil, err
 	}
-	normalizedPolicyJSON, normalizeMarshalErr := json.Marshal(normalizedPolicy)
-	if normalizeMarshalErr != nil {
-		logWasm.Printf("LabelAgent normalized policy (marshal failed): guard=%s, error=%v", g.name, normalizeMarshalErr)
-	} else {
-		logWasm.Printf("LabelAgent normalized policy: guard=%s, policy=%s", g.name, string(normalizedPolicyJSON))
-	}
+	logger.LogMarshaledForDebug(
+		normalizedPolicy,
+		func(policyJSON string) {
+			logWasm.Printf("LabelAgent normalized policy: guard=%s, policy=%s", g.name, policyJSON)
+		},
+		func(marshalErr error) {
+			logWasm.Printf("LabelAgent normalized policy (marshal failed): guard=%s, error=%v", g.name, marshalErr)
+		},
+	)
 	_ = caps
 
 	input, err := buildStrictLabelAgentPayload(normalizedPolicy)
@@ -727,12 +730,15 @@ func (g *WasmGuard) LabelAgent(ctx context.Context, policy interface{}, backend
 		return nil, err
 	}
 
-	resultLogJSON, resultMarshalErr := json.Marshal(result)
-	if resultMarshalErr != nil {
-		logWasm.Printf("LabelAgent parsed response (marshal failed): guard=%s, error=%v", g.name, resultMarshalErr)
-	} else {
-		logWasm.Printf("LabelAgent parsed response: guard=%s, response=%s", g.name, string(resultLogJSON))
-	}
+	logger.LogMarshaledForDebug(
+		result,
+		func(responseJSON string) {
+			logWasm.Printf("LabelAgent parsed response: guard=%s, response=%s", g.name, responseJSON)
+		},
+		func(marshalErr error) {
+			logWasm.Printf("LabelAgent parsed response (marshal failed): guard=%s, error=%v", g.name, marshalErr)
+		},
+	)
 
 	return result, nil
 }

internal/logger/marshal_debug.go

@@ -0,0 +1,14 @@
+package logger
+
+import "encoding/json"
+
+// LogMarshaledForDebug marshals value for debug logging and dispatches to the
+// provided callbacks for success or marshal failure paths.
+func LogMarshaledForDebug(value interface{}, onMarshalSuccess func(string), onMarshalFailure func(error)) {
+	resultJSON, err := json.Marshal(value)
+	if err != nil {
+		onMarshalFailure(err)
+		return
+	}
+	onMarshalSuccess(string(resultJSON))
+}

internal/logger/marshal_debug_test.go

@@ -0,0 +1,54 @@
+package logger
+
+import (
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestLogMarshaledForDebug_Success(t *testing.T) {
+	assert := assert.New(t)
+	require := require.New(t)
+
+	var (
+		gotJSON       string
+		gotMarshalErr error
+	)
+
+	LogMarshaledForDebug(
+		map[string]string{"status": "ok"},
+		func(resultJSON string) {
+			gotJSON = resultJSON
+		},
+		func(err error) {
+			gotMarshalErr = err
+		},
+	)
+
+	require.NoError(gotMarshalErr)
+	assert.JSONEq(`{"status":"ok"}`, gotJSON)
+}
+
+func TestLogMarshaledForDebug_MarshalFailure(t *testing.T) {
+	assert := assert.New(t)
+	require := require.New(t)
+
+	var (
+		gotJSON       string
+		gotMarshalErr error
+	)
+
+	LogMarshaledForDebug(
+		make(chan int),
+		func(resultJSON string) {
+			gotJSON = resultJSON
+		},
+		func(err error) {
+			gotMarshalErr = err
+		},
+	)
+
+	require.Error(gotMarshalErr)
+	assert.Empty(gotJSON)
+}

internal/server/guard_init.go

@@ -351,12 +351,15 @@ func (us *UnifiedServer) ensureGuardInitialized(
 		log.Printf("[DIFC] label_agent returned nil result: server=%s, session=%s, guard=%s", serverID, sessionID, g.Name())
 		return defaultMode, fmt.Errorf("label_agent returned nil result")
 	}
-	resultJSON, marshalErr := json.Marshal(labelAgentResult)
-	if marshalErr != nil {
-		log.Printf("[DIFC] label_agent returned result (failed to serialize for logging): server=%s, session=%s, guard=%s, error=%v", serverID, sessionID, g.Name(), marshalErr)
-	} else {
-		log.Printf("[DIFC] label_agent response: server=%s, session=%s, guard=%s, response=%s", serverID, sessionID, g.Name(), string(resultJSON))
-	}
+	logger.LogMarshaledForDebug(
+		labelAgentResult,
+		func(resultJSON string) {
+			log.Printf("[DIFC] label_agent response: server=%s, session=%s, guard=%s, response=%s", serverID, sessionID, g.Name(), resultJSON)
+		},
+		func(marshalErr error) {
+			log.Printf("[DIFC] label_agent returned result (failed to serialize for logging): server=%s, session=%s, guard=%s, error=%v", serverID, sessionID, g.Name(), marshalErr)
+		},
+	)
 
 	mode := defaultMode
 	if labelAgentResult.DIFCMode != "" {

internal/server/tool_registry.go

@@ -285,9 +285,7 @@ func (us *UnifiedServer) registerToolsFromBackend(serverID string) error {
 			if err != nil {
 				logger.LogError("client", "MCP tool call error, session=%s, tool=%s, error=%v", sessionID, toolNameCopy, err)
 			} else {
-				resultJSON, _ := json.Marshal(data)
-				sanitizedResult := sanitize.SanitizeString(string(resultJSON))
-				logger.LogInfo("client", "MCP tool call response, session=%s, tool=%s, result=%s", sessionID, toolNameCopy, sanitizedResult)
+				logger.LogInfo("client", "MCP tool call response, session=%s, tool=%s, result=%s", sessionID, toolNameCopy, marshalAndSanitizeForLog(data))
 			}
 
 			return result, data, err
@@ -351,6 +349,22 @@ func (us *UnifiedServer) callSysServer(toolName string) (interface{}, error) {
 	return result, nil
 }
 
+func marshalAndSanitizeForLog(value interface{}) string {
+	resultJSON, _ := json.Marshal(value)
+	return sanitize.SanitizeString(string(resultJSON))
+}
+
+func (us *UnifiedServer) callAndLogSysTool(sessionID, operationName, sysToolName string) (*sdk.CallToolResult, interface{}, error) {
+	result, err := us.callSysServer(sysToolName)
+	if err != nil {
+		logger.LogError("client", "MCP %s call failed, session=%s, error=%v", operationName, sessionID, err)
+		return mcp.NewErrorCallToolResult(err)
+	}
+
+	logger.LogInfo("client", "MCP %s response, session=%s, result=%s", operationName, sessionID, marshalAndSanitizeForLog(result))
+	return nil, result, nil
+}
+
 // registerSysTools registers built-in sys tools
 func (us *UnifiedServer) registerSysTools() error {
 	// Create sys_init handler
@@ -392,16 +406,7 @@ func (us *UnifiedServer) registerSysTools() error {
 		logger.LogInfo("client", "MCP session initialized successfully, session=%s, available_servers=%v", sessionID, us.launcher.ServerIDs())
 
 		// Call sys_init
-		result, err := us.callSysServer("sys_init")
-		if err != nil {
-			logger.LogError("client", "MCP session initialization: sys_init call failed, session=%s, error=%v", sessionID, err)
-			return mcp.NewErrorCallToolResult(err)
-		}
-
-		resultJSON, _ := json.Marshal(result)
-		sanitizedResult := sanitize.SanitizeString(string(resultJSON))
-		logger.LogInfo("client", "MCP session initialization complete, session=%s, result=%s", sessionID, sanitizedResult)
-		return nil, result, nil
+		return us.callAndLogSysTool(sessionID, "session initialization", "sys_init")
 	}
 
 	// Register sys_init tool using helper
@@ -431,15 +436,7 @@ func (us *UnifiedServer) registerSysTools() error {
 			return mcp.NewErrorCallToolResult(err)
 		}
 
-		result, err := us.callSysServer("sys_list_servers")
-		if err != nil {
-			logger.LogError("client", "MCP sys_list_servers error, session=%s, error=%v", sessionID, err)
-			return mcp.NewErrorCallToolResult(err)
-		}
-
-		resultJSON, _ := json.Marshal(result)
-		logger.LogInfo("client", "MCP sys_list_servers response, session=%s, result=%s", sessionID, string(resultJSON))
-		return nil, result, nil
+		return us.callAndLogSysTool(sessionID, "sys_list_servers", "sys_list_servers")
 	}
 
 	// Register sys_list_servers tool using helper

internal/server/tool_registry_test.go

@@ -496,6 +496,37 @@ func TestCallSysServer_UnknownTool(t *testing.T) {
 	require.Error(err, "callSysServer with unknown tool should return an error")
 }
 
+func TestMarshalAndSanitizeForLog_RedactsSecrets(t *testing.T) {
+	assert := assert.New(t)
+
+	const secret = "ghp_1234567890123456789012345678901234567890"
+	sanitized := marshalAndSanitizeForLog(map[string]interface{}{
+		"token": secret,
+	})
+
+	assert.Contains(sanitized, "[REDACTED]")
+	assert.NotContains(sanitized, secret)
+}
+
+func TestCallAndLogSysTool_UnknownToolReturnsErrorResult(t *testing.T) {
+	assert := assert.New(t)
+	require := require.New(t)
+
+	cfg := &config.Config{
+		Servers: map[string]*config.ServerConfig{},
+	}
+
+	us, err := NewUnified(context.Background(), cfg)
+	require.NoError(err)
+	defer us.Close()
+
+	result, data, callErr := us.callAndLogSysTool("session-id", "sys test", "nonexistent_tool")
+	require.Error(callErr)
+	require.NotNil(result)
+	assert.Nil(data)
+	assert.True(result.IsError)
+}
+
 // TestRegisterAllToolsParallel_EmptyList verifies that parallel registration with no
 // servers does not block and returns immediately.
 func TestRegisterAllToolsParallel_EmptyList(t *testing.T) {