Skip to content

Commit 6c41ec9

Browse files
authored
refactor: Extract shared LogConnectionError to eliminate duplicate connection error diagnostics (#2524)
Connection error diagnostic logging was duplicated across `mcp/connection.go` and `launcher/log_helpers.go` — each independently printing command/args, error, stderr, and hint analysis for known error strings (`executable file not found`, `EOF`, `broken pipe`). Adding a new diagnostic hint required updating both sites; divergence meant inconsistent output depending on which code path triggered the failure. ## Changes - **`internal/mcp/errors.go`** (new): Defines `ConnectionErrorContext` and `LogConnectionError` — the single source of truth for connection failure diagnostics. Merges hint logic from both original sites: containerization hints (`IsDirectCommand` + `RunningInContainer`) and error-string hints. Fields omit gracefully when zero-valued, so both callers can populate only what they know. - **`internal/mcp/connection.go`**: Replaces ~35-line inline error block with a `LogConnectionError` call passing `{ServerID, Command, Args, StderrOutput}`. - **`internal/launcher/log_helpers.go`**: `logLaunchError` delegates entirely to `mcp.LogConnectionError` with full launcher context (`SessionID`, `Env`, `RunningInContainer`, `IsDirectCommand`, `StartupTimeout`). - **`internal/mcp/errors_test.go`** (new): Tests covering all hint branches, stderr rendering, arg sanitization, and edge cases. ```go // Before: each site had its own copy of this logic if strings.Contains(err.Error(), "executable file not found") || ... { log.Printf("⚠️ Command '%s' not found in PATH", command) ... } // After: one shared function with full context mcp.LogConnectionError(mcp.ConnectionErrorContext{ ServerID: serverID, SessionID: sessionID, Command: serverCfg.Command, Args: serverCfg.Args, Env: serverCfg.Env, RunningInContainer: l.runningInContainer, IsDirectCommand: isDirectCommand, StartupTimeout: l.startupTimeout, }, err) ``` > [!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-build3051059008/b329/launcher.test /tmp/go-build3051059008/b329/launcher.test -test.testlogfile=/tmp/go-build3051059008/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go dsa/ecdsa.go p/bin/bash` (dns block) > - Triggering command: `/tmp/go-build2944181223/b333/launcher.test /tmp/go-build2944181223/b333/launcher.test -test.testlogfile=/tmp/go-build2944181223/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s ortc�� d -n 10 stmain.go ache/go/1.25.8/x64/pkg/tool/linux_amd64/link (compatibility issue with Go 1.25.0). Continuing with other checks...&#34;; \ elif command -v golan telabs/wazero/in/tmp/go-build4284220926/b202/vet.cfg --64 ache/go/1.25.8/x64/pkg/tool/linux_amd64/link -I 1059008/b224/cmd.test /launcher/log_helpers.go ker/docker-init -pthread -Wl,--no-gc-sectdocker-cli-plugin-metadata -fmessage-length=0 ker/docker-init` (dns block) > - Triggering command: `/tmp/go-build2960403912/b329/launcher.test /tmp/go-build2960403912/b329/launcher.test -test.testlogfile=/tmp/go-build2960403912/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true 4181223/b314/_pk/run/containerd/io.containerd.runtime.v2.task/moby/83010862c130074fa53cbdec2f66a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline by/3d68fe704b33a--log-format by/a44f1c6d2c345json by/3d68fe704b33a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline 300bcc2a4ea80026start 64/pkg/tool/linu83010862c130074fa53cbdec2f66a97b6b568134d8551ff471fd0b14e7d12390 /opt/hostedtoolcache/go/1.25.8/x/var/run/docker/runtime-runc/moby d945�� irdJ/-TWaY8JNiNqMr3rjirdJ 64/pkg/tool/linux_amd64/asm /opt/hostedtoolcache/go/1.25.8/xjson /tmp/go-build305/usr/lib/open-iscsi/net-interface-handler 1059008/b165/ x_amd64/compile 4181223/b314/importcfg` (dns block) > - `invalid-host-that-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build3051059008/b314/config.test /tmp/go-build3051059008/b314/config.test -test.testlogfile=/tmp/go-build3051059008/b314/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go Pe6rubutY x_amd64/vet copilot.original/opt/hostedtoolcache/go/1.25.8/x64/pkg/tool/linux_amd64/vet` (dns block) > - Triggering command: `/tmp/go-build2944181223/b318/config.test /tmp/go-build2944181223/b318/config.test -test.testlogfile=/tmp/go-build2944181223/b318/testlog.txt -test.paniconexit0 -test.timeout=10m0s` (dns block) > - `nonexistent.local` > - Triggering command: `/tmp/go-build3051059008/b329/launcher.test /tmp/go-build3051059008/b329/launcher.test -test.testlogfile=/tmp/go-build3051059008/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go dsa/ecdsa.go p/bin/bash` (dns block) > - Triggering command: `/tmp/go-build2944181223/b333/launcher.test /tmp/go-build2944181223/b333/launcher.test -test.testlogfile=/tmp/go-build2944181223/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s ortc�� d -n 10 stmain.go ache/go/1.25.8/x64/pkg/tool/linux_amd64/link (compatibility issue with Go 1.25.0). Continuing with other checks...&#34;; \ elif command -v golan telabs/wazero/in/tmp/go-build4284220926/b202/vet.cfg --64 ache/go/1.25.8/x64/pkg/tool/linux_amd64/link -I 1059008/b224/cmd.test /launcher/log_helpers.go ker/docker-init -pthread -Wl,--no-gc-sectdocker-cli-plugin-metadata -fmessage-length=0 ker/docker-init` (dns block) > - Triggering command: `/tmp/go-build2960403912/b329/launcher.test /tmp/go-build2960403912/b329/launcher.test -test.testlogfile=/tmp/go-build2960403912/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true 4181223/b314/_pk/run/containerd/io.containerd.runtime.v2.task/moby/83010862c130074fa53cbdec2f66a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline by/3d68fe704b33a--log-format by/a44f1c6d2c345json by/3d68fe704b33a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline 300bcc2a4ea80026start 64/pkg/tool/linu83010862c130074fa53cbdec2f66a97b6b568134d8551ff471fd0b14e7d12390 /opt/hostedtoolcache/go/1.25.8/x/var/run/docker/runtime-runc/moby d945�� irdJ/-TWaY8JNiNqMr3rjirdJ 64/pkg/tool/linux_amd64/asm /opt/hostedtoolcache/go/1.25.8/xjson /tmp/go-build305/usr/lib/open-iscsi/net-interface-handler 1059008/b165/ x_amd64/compile 4181223/b314/importcfg` (dns block) > - `slow.example.com` > - Triggering command: `/tmp/go-build3051059008/b329/launcher.test /tmp/go-build3051059008/b329/launcher.test -test.testlogfile=/tmp/go-build3051059008/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true go dsa/ecdsa.go p/bin/bash` (dns block) > - Triggering command: `/tmp/go-build2944181223/b333/launcher.test /tmp/go-build2944181223/b333/launcher.test -test.testlogfile=/tmp/go-build2944181223/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s ortc�� d -n 10 stmain.go ache/go/1.25.8/x64/pkg/tool/linux_amd64/link (compatibility issue with Go 1.25.0). Continuing with other checks...&#34;; \ elif command -v golan telabs/wazero/in/tmp/go-build4284220926/b202/vet.cfg --64 ache/go/1.25.8/x64/pkg/tool/linux_amd64/link -I 1059008/b224/cmd.test /launcher/log_helpers.go ker/docker-init -pthread -Wl,--no-gc-sectdocker-cli-plugin-metadata -fmessage-length=0 ker/docker-init` (dns block) > - Triggering command: `/tmp/go-build2960403912/b329/launcher.test /tmp/go-build2960403912/b329/launcher.test -test.testlogfile=/tmp/go-build2960403912/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true 4181223/b314/_pk/run/containerd/io.containerd.runtime.v2.task/moby/83010862c130074fa53cbdec2f66a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline by/3d68fe704b33a--log-format by/a44f1c6d2c345json by/3d68fe704b33a/usr/lib/networkd-dispatcher/off.d/chrony-onoffline 300bcc2a4ea80026start 64/pkg/tool/linu83010862c130074fa53cbdec2f66a97b6b568134d8551ff471fd0b14e7d12390 /opt/hostedtoolcache/go/1.25.8/x/var/run/docker/runtime-runc/moby d945�� irdJ/-TWaY8JNiNqMr3rjirdJ 64/pkg/tool/linux_amd64/asm /opt/hostedtoolcache/go/1.25.8/xjson /tmp/go-build305/usr/lib/open-iscsi/net-interface-handler 1059008/b165/ x_amd64/compile 4181223/b314/importcfg` (dns block) > - `this-host-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build3051059008/b338/mcp.test /tmp/go-build3051059008/b338/mcp.test -test.testlogfile=/tmp/go-build3051059008/b338/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true 64/src/runtime/c-p zGGbXQmyc ache/go/1.25.8/x-lang=go1.24` (dns block) > - Triggering command: `/tmp/go-build2944181223/b342/mcp.test /tmp/go-build2944181223/b342/mcp.test -test.testlogfile=/tmp/go-build2944181223/b342/testlog.txt -test.paniconexit0 -test.timeout=10m0s -uns�� pkg/mod/github.com/segmentio/asm@v1.1.3/cpu/arm6&#43;30 /tmp/go-build3051059008/b122/vet.cfg x_amd64/link -b copilot/duplicat/usr/bin/runc 64/bin/bash x_amd64/link -o /tmp/go-build3051059008/b297/_pkg_.a -trimpath x_amd64/vet -p qV/wxj7iTUpwRLRu/usr/bin/runc -lang=go1.17 x_amd64/vet` (dns block) > - Triggering command: `/tmp/go-build2960403912/b338/mcp.test /tmp/go-build2960403912/b338/mcp.test -test.testlogfile=/tmp/go-build2960403912/b338/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true` (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> <!-- START COPILOT CODING AGENT TIPS --> --- 📍 Connect Copilot coding agent with [Jira](https://gh.io/cca-jira-docs), [Azure Boards](https://gh.io/cca-azure-boards-docs) or [Linear](https://gh.io/cca-linear-docs) to delegate work to Copilot in one click without leaving your project management tool.
2 parents d4608a1 + 1a97a0e commit 6c41ec9

4 files changed

Lines changed: 540 additions & 54 deletions

File tree

internal/launcher/log_helpers.go

Lines changed: 11 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import (
99
"github.com/github/gh-aw-mcpg/internal/config"
1010
"github.com/github/gh-aw-mcpg/internal/logger"
1111
"github.com/github/gh-aw-mcpg/internal/logger/sanitize"
12+
"github.com/github/gh-aw-mcpg/internal/mcp"
1213
)
1314

1415
// sessionSuffix returns a formatted session suffix for log messages
@@ -69,29 +70,16 @@ func (l *Launcher) logEnvPassthrough(args []string) {
6970

7071
// logLaunchError logs detailed launch failure diagnostics
7172
func (l *Launcher) logLaunchError(serverID, sessionID string, err error, serverCfg *config.ServerConfig, isDirectCommand bool) {
72-
logger.LogErrorWithServer(serverID, "backend", "Failed to launch MCP backend server%s: server=%s%s, error=%v",
73-
sessionSuffix(sessionID), serverID, sessionSuffix(sessionID), err)
74-
log.Printf("[LAUNCHER] ❌ FAILED to launch server '%s'%s", serverID, sessionSuffix(sessionID))
75-
log.Printf("[LAUNCHER] Error: %v", err)
76-
log.Printf("[LAUNCHER] Debug Information:")
77-
log.Printf("[LAUNCHER] - Command: %s", serverCfg.Command)
78-
log.Printf("[LAUNCHER] - Args: %v", sanitize.SanitizeArgs(serverCfg.Args))
79-
log.Printf("[LAUNCHER] - Env vars: %v", sanitize.TruncateSecretMap(serverCfg.Env))
80-
log.Printf("[LAUNCHER] - Running in container: %v", l.runningInContainer)
81-
log.Printf("[LAUNCHER] - Is direct command: %v", isDirectCommand)
82-
log.Printf("[LAUNCHER] - Startup timeout: %v", l.startupTimeout)
83-
84-
if isDirectCommand && l.runningInContainer {
85-
log.Printf("[LAUNCHER] ⚠️ Possible causes:")
86-
log.Printf("[LAUNCHER] - Command '%s' may not be installed in the gateway container", serverCfg.Command)
87-
log.Printf("[LAUNCHER] - Consider using 'container' config instead of 'command'")
88-
log.Printf("[LAUNCHER] - Or add '%s' to the gateway's Dockerfile", serverCfg.Command)
89-
} else if isDirectCommand {
90-
log.Printf("[LAUNCHER] ⚠️ Possible causes:")
91-
log.Printf("[LAUNCHER] - Command '%s' may not be in PATH", serverCfg.Command)
92-
log.Printf("[LAUNCHER] - Check if '%s' is installed: which %s", serverCfg.Command, serverCfg.Command)
93-
log.Printf("[LAUNCHER] - Verify file permissions and execute bit")
94-
}
73+
mcp.LogConnectionError(mcp.ConnectionErrorContext{
74+
ServerID: serverID,
75+
SessionID: sessionID,
76+
Command: serverCfg.Command,
77+
Args: serverCfg.Args,
78+
Env: serverCfg.Env,
79+
RunningInContainer: l.runningInContainer,
80+
IsDirectCommand: isDirectCommand,
81+
StartupTimeout: l.startupTimeout,
82+
}, err)
9583
}
9684

9785
// logTimeoutError logs startup timeout diagnostics

internal/mcp/connection.go

Lines changed: 6 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -131,38 +131,13 @@ func NewConnection(ctx context.Context, serverID, command string, args []string,
131131
cancel()
132132
stderrPipeWriter.Close() // Close pipe to stop the stderr streaming goroutine
133133

134-
// Enhanced error context for debugging
135-
logger.LogErrorMd("backend", "MCP backend connection failed, command=%s, args=%v, error=%v", command, sanitize.SanitizeArgs(expandedArgs), err)
136-
log.Printf("❌ MCP Connection Failed:")
137-
log.Printf(" Command: %s", command)
138-
log.Printf(" Args: %v", sanitize.SanitizeArgs(expandedArgs))
139-
log.Printf(" Error: %v", err)
140-
141-
// Log captured stderr output from the container/process
142134
stderrOutput := strings.TrimSpace(stderrBuf.String())
143-
if stderrOutput != "" {
144-
sanitizedStderr := sanitize.SanitizeString(stderrOutput)
145-
logger.LogErrorMd("backend", "MCP backend stderr output:\n%s", sanitizedStderr)
146-
log.Printf(" 📋 Container/Process stderr output:")
147-
for _, line := range strings.Split(sanitizedStderr, "\n") {
148-
log.Printf(" %s", line)
149-
}
150-
}
151-
152-
// Check if it's a command not found error
153-
if strings.Contains(err.Error(), "executable file not found") ||
154-
strings.Contains(err.Error(), "no such file or directory") {
155-
logger.LogErrorMd("backend", "MCP backend command not found, command=%s", command)
156-
log.Printf(" ⚠️ Command '%s' not found in PATH", command)
157-
log.Printf(" ⚠️ Verify the command is installed and executable")
158-
}
159-
160-
// Check if it's a connection/protocol error
161-
if strings.Contains(err.Error(), "EOF") || strings.Contains(err.Error(), "broken pipe") {
162-
logger.LogErrorMd("backend", "MCP backend connection/protocol error, command=%s", command)
163-
log.Printf(" ⚠️ Process started but terminated unexpectedly")
164-
log.Printf(" ⚠️ Check if the command supports MCP protocol over stdio")
165-
}
135+
LogConnectionError(ConnectionErrorContext{
136+
ServerID: serverID,
137+
Command: command,
138+
Args: expandedArgs,
139+
StderrOutput: stderrOutput,
140+
}, err)
166141

167142
logConn.Printf("Connection failed: command=%s, error=%v", command, err)
168143
return nil, fmt.Errorf("failed to connect: %w", err)

internal/mcp/errors.go

Lines changed: 104 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,104 @@
1+
package mcp
2+
3+
import (
4+
"log"
5+
"strings"
6+
"time"
7+
8+
"github.com/github/gh-aw-mcpg/internal/logger"
9+
"github.com/github/gh-aw-mcpg/internal/logger/sanitize"
10+
)
11+
12+
// ConnectionErrorContext holds all context needed to produce a detailed connection
13+
// failure diagnostic. Fields left at their zero values are omitted from the output.
14+
type ConnectionErrorContext struct {
15+
ServerID string
16+
SessionID string
17+
Command string
18+
Args []string
19+
Env map[string]string
20+
RunningInContainer bool
21+
IsDirectCommand bool
22+
StartupTimeout time.Duration
23+
StderrOutput string
24+
}
25+
26+
// LogConnectionError logs detailed diagnostics for a connection failure, including
27+
// command context, captured stderr, and actionable hints based on the error type
28+
// and execution environment. All callers (launcher and mcp connection) use this
29+
// single function so that hint analysis and output format remain consistent.
30+
func LogConnectionError(errCtx ConnectionErrorContext, err error) {
31+
suffix := ""
32+
if errCtx.SessionID != "" {
33+
suffix = " for session '" + errCtx.SessionID + "'"
34+
}
35+
36+
// Structured log via file logger.
37+
if errCtx.ServerID != "" {
38+
logger.LogErrorWithServer(errCtx.ServerID, "backend",
39+
"MCP backend connection failed%s: server=%s, command=%s, args=%v, error=%v",
40+
suffix, errCtx.ServerID, errCtx.Command, sanitize.SanitizeArgs(errCtx.Args), err)
41+
} else {
42+
logger.LogErrorMd("backend",
43+
"MCP backend connection failed, command=%s, args=%v, error=%v",
44+
errCtx.Command, sanitize.SanitizeArgs(errCtx.Args), err)
45+
}
46+
47+
// Human-readable console output.
48+
if errCtx.ServerID != "" {
49+
log.Printf("[LAUNCHER] ❌ FAILED to connect to server '%s'%s", errCtx.ServerID, suffix)
50+
} else {
51+
log.Printf("[LAUNCHER] ❌ MCP Connection Failed")
52+
}
53+
log.Printf("[LAUNCHER] Error: %v", err)
54+
log.Printf("[LAUNCHER] Debug Information:")
55+
log.Printf("[LAUNCHER] - Command: %s", errCtx.Command)
56+
log.Printf("[LAUNCHER] - Args: %v", sanitize.SanitizeArgs(errCtx.Args))
57+
if len(errCtx.Env) > 0 {
58+
log.Printf("[LAUNCHER] - Env vars: %v", sanitize.TruncateSecretMap(errCtx.Env))
59+
}
60+
if errCtx.RunningInContainer || errCtx.IsDirectCommand {
61+
log.Printf("[LAUNCHER] - Running in container: %v", errCtx.RunningInContainer)
62+
log.Printf("[LAUNCHER] - Is direct command: %v", errCtx.IsDirectCommand)
63+
}
64+
if errCtx.StartupTimeout > 0 {
65+
log.Printf("[LAUNCHER] - Startup timeout: %v", errCtx.StartupTimeout)
66+
}
67+
68+
// Log captured stderr output from the container/process.
69+
if errCtx.StderrOutput != "" {
70+
sanitizedStderr := sanitize.SanitizeString(errCtx.StderrOutput)
71+
logger.LogErrorMd("backend", "MCP backend stderr output:\n%s", sanitizedStderr)
72+
log.Printf("[LAUNCHER] 📋 Process stderr output:")
73+
for _, line := range strings.Split(sanitizedStderr, "\n") {
74+
log.Printf("[LAUNCHER] %s", line)
75+
}
76+
}
77+
78+
// Hints based on execution context (launcher-specific).
79+
if errCtx.IsDirectCommand && errCtx.RunningInContainer {
80+
log.Printf("[LAUNCHER] ⚠️ Possible causes:")
81+
log.Printf("[LAUNCHER] - Command '%s' may not be installed in the gateway container", errCtx.Command)
82+
log.Printf("[LAUNCHER] - Consider using 'container' config instead of 'command'")
83+
log.Printf("[LAUNCHER] - Or add '%s' to the gateway's Dockerfile", errCtx.Command)
84+
} else if errCtx.IsDirectCommand {
85+
log.Printf("[LAUNCHER] ⚠️ Possible causes:")
86+
log.Printf("[LAUNCHER] - Command '%s' may not be in PATH", errCtx.Command)
87+
log.Printf("[LAUNCHER] - Check if '%s' is installed: which %s", errCtx.Command, errCtx.Command)
88+
log.Printf("[LAUNCHER] - Verify file permissions and execute bit")
89+
}
90+
91+
// Hints based on error message content.
92+
errStr := err.Error()
93+
if strings.Contains(errStr, "executable file not found") || strings.Contains(errStr, "no such file or directory") {
94+
logger.LogErrorMd("backend", "MCP backend command not found, command=%s", errCtx.Command)
95+
log.Printf("[LAUNCHER] ⚠️ Command '%s' not found in PATH", errCtx.Command)
96+
log.Printf("[LAUNCHER] ⚠️ Verify the command is installed and executable")
97+
}
98+
99+
if strings.Contains(errStr, "EOF") || strings.Contains(errStr, "broken pipe") {
100+
logger.LogErrorMd("backend", "MCP backend connection/protocol error, command=%s", errCtx.Command)
101+
log.Printf("[LAUNCHER] ⚠️ Process started but terminated unexpectedly")
102+
log.Printf("[LAUNCHER] ⚠️ Check if the command supports MCP protocol over stdio")
103+
}
104+
}

0 commit comments

Comments
 (0)