Skip to content

Commit 85b2ef7

Browse files
authored
fix(docker): observable spawn decision + accurate transport error label (#696) (#708)
Related #696 The v0.40.0 docker-isolation spawn already direct-execs the resolved bundle path on macOS, but two diagnosability defects made the field failure look like a bare-docker spawn: - transport error reported c.config.Command (always "docker") instead of the resolved finalCommand actually exec'd, so a successful direct-exec of an absolute bundle path looked identical to a bare-docker spawn. - no INFO-level spawn-decision log to tell direct-exec from shell-wrap. ## Changes - connection_stdio.go: transport error reports finalCommand (real argv[0]) - connection_docker.go: INFO logs for direct-exec vs login-shell-wrap fallback - shellwrap/testhooks.go: cross-package test seam (well-known paths + cache reset) - connection_docker_integration_test.go: real-resolver #696 repro (bundle/path/ unresolvable legs) + status/spawn no-divergence guard - connection_docker_exec_e2e_test.go: recording-shim proves OS execs abs path ## Testing - go test -race ./internal/upstream/core/ ./internal/shellwrap/ green - golangci-lint v2 clean
1 parent 060fd75 commit 85b2ef7

5 files changed

Lines changed: 375 additions & 1 deletion

File tree

internal/shellwrap/testhooks.go

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
package shellwrap
2+
3+
// This file exposes a few narrowly-scoped test seams so that packages OTHER
4+
// than shellwrap (notably internal/upstream/core) can build hermetic
5+
// integration tests over the docker-path resolution + spawn chain — e.g. the
6+
// GitHub #696 "Docker Desktop installed but docker is not on the spawn PATH"
7+
// scenario, which can only be reproduced end-to-end by driving the REAL
8+
// ResolveDockerPath (not a stub) under a controlled PATH and well-known-path
9+
// list, then feeding its result through core.setupDockerIsolation.
10+
//
11+
// They are intentionally named *ForTest and do nothing a caller would want in
12+
// production; keeping them in a non-_test.go file is the only way to make them
13+
// reachable from a sibling package's test binary (Go's export_test.go trick is
14+
// package-local). Do NOT call these outside tests.
15+
16+
// SetWellKnownDockerPathsForTest overrides the well-known docker install
17+
// locations probed by ResolveDockerPath and returns a restore func that
18+
// reinstalls the previous list. Pass a func returning the absolute path(s) of a
19+
// fake docker binary to simulate a Docker Desktop bundle that is reachable only
20+
// off the standard spawn PATH.
21+
func SetWellKnownDockerPathsForTest(fn func() []string) (restore func()) {
22+
prev := wellKnownDockerPathsFn
23+
wellKnownDockerPathsFn = fn
24+
return func() { wellKnownDockerPathsFn = prev }
25+
}
26+
27+
// ResetDockerPathCacheForTest clears the process-wide docker-path resolution
28+
// cache (path, source, error, expiry) so a test starts from a clean slate
29+
// regardless of what an earlier test or the host environment resolved.
30+
func ResetDockerPathCacheForTest() {
31+
resetDockerPathCacheForTest()
32+
}

internal/upstream/core/connection_docker.go

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -110,6 +110,14 @@ func (c *Client) setupDockerIsolation(command string, args []string) (dockerComm
110110
resolved, resErr := resolveDockerBinary(c.logger)
111111
switch {
112112
case resErr == nil && isDirectExecutable(resolved) && dockerDaemonEnvGuaranteed():
113+
// INFO (not Debug): make the spawn decision observable in main.log so a
114+
// field report like #696 ("docker installed but not on PATH") can be
115+
// triaged from one line — which docker binary was chosen and that it was
116+
// exec'd DIRECTLY rather than shell-wrapped with bare `docker`.
117+
c.logger.Info("Docker spawn: direct-exec of resolved docker binary",
118+
zap.String("server", c.config.Name),
119+
zap.String("docker_path", resolved),
120+
zap.Bool("shell_wrapped", false))
113121
return resolved, finalArgs, false
114122
case resErr != nil:
115123
c.logger.Warn("Could not resolve docker to an absolute path; falling back to bare 'docker' via login shell (isolated server may fail if docker is not on the spawn PATH)",
@@ -132,6 +140,14 @@ func (c *Client) setupDockerIsolation(command string, args []string) (dockerComm
132140
if isDirectExecutable(resolved) {
133141
dockerBin = resolved
134142
}
143+
// INFO: the login-shell fallback is the ONLY path that can produce #696's
144+
// `command not found: docker`, so surface that we took it (and whether we at
145+
// least wrap the resolved absolute path vs. bare `docker`).
146+
c.logger.Info("Docker spawn: login-shell wrap fallback",
147+
zap.String("server", c.config.Name),
148+
zap.String("docker_command", dockerBin),
149+
zap.Bool("docker_resolved", isDirectExecutable(resolved)),
150+
zap.Bool("shell_wrapped", true))
135151
shellCmd, shellArgs := c.wrapWithUserShell(dockerBin, finalArgs)
136152
return shellCmd, shellArgs, true
137153
}
Lines changed: 89 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,89 @@
1+
package core
2+
3+
import (
4+
"context"
5+
"os"
6+
"os/exec"
7+
"path/filepath"
8+
"runtime"
9+
"strings"
10+
"testing"
11+
"time"
12+
13+
"github.com/smart-mcp-proxy/mcpproxy-go/internal/shellwrap"
14+
15+
"github.com/stretchr/testify/assert"
16+
"github.com/stretchr/testify/require"
17+
)
18+
19+
// writeRecordingDockerShim writes a fake `docker` shell script that appends its
20+
// own argv[0] (the path it was invoked as) to recordFile and exits 0. It lets a
21+
// test prove, at the OS-exec level, HOW docker was launched: a direct-exec
22+
// records the absolute bundle path, while a bare-`docker` login-shell wrap would
23+
// either fail (`command not found`) or record just "docker".
24+
func writeRecordingDockerShim(t *testing.T, dir, recordFile string) string {
25+
t.Helper()
26+
name := "docker"
27+
if runtime.GOOS == osWindows {
28+
name = "docker.bat"
29+
}
30+
p := filepath.Join(dir, name)
31+
script := "#!/bin/sh\nprintf '%s\\n' \"$0\" >> " + shellSingleQuote(recordFile) + "\nexit 0\n"
32+
if err := os.WriteFile(p, []byte(script), 0o755); err != nil {
33+
t.Fatalf("write recording docker shim: %v", err)
34+
}
35+
return p
36+
}
37+
38+
func shellSingleQuote(s string) string {
39+
return "'" + strings.ReplaceAll(s, "'", `'\''`) + "'"
40+
}
41+
42+
// TestE2E_DockerSpawnExecsAbsoluteBundlePath is the behavioral end-to-end proof
43+
// for #696. It drives the REAL shellwrap.ResolveDockerPath + setupDockerIsolation
44+
// chain under the field scenario (Docker Desktop bundle present, docker absent
45+
// from the spawn PATH and login shell), then ACTUALLY execs the resulting
46+
// (command, args) the way connection_stdio would. A recording shim captures the
47+
// path it was invoked as.
48+
//
49+
// The assertion is the crux of the bug report: the process is launched by its
50+
// ABSOLUTE bundle path — so it CANNOT produce `zsh:1: command not found: docker`
51+
// — proving the spawn pipeline (not just setupDockerIsolation's return value)
52+
// uses the resolved binary.
53+
func TestE2E_DockerSpawnExecsAbsoluteBundlePath(t *testing.T) {
54+
if runtime.GOOS == osWindows {
55+
t.Skip("shim is a /bin/sh script; unix-only")
56+
}
57+
useRealDockerResolver(t)
58+
forceDockerDaemonEnvGOOS(t, osDarwin)
59+
60+
bundleDir := t.TempDir()
61+
recordFile := filepath.Join(t.TempDir(), "invocations.log")
62+
bundleDocker := writeRecordingDockerShim(t, bundleDir, recordFile)
63+
64+
restore := shellwrap.SetWellKnownDockerPathsForTest(func() []string { return []string{bundleDocker} })
65+
t.Cleanup(restore)
66+
// Spawn PATH and login shell cannot resolve docker — only the well-known
67+
// bundle probe can (the exact #696 condition).
68+
t.Setenv("PATH", t.TempDir())
69+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
70+
71+
c := newIsolatedTestClient()
72+
cmd, args, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
73+
require.False(t, shellWrapped, "#696: bundle-resolved docker must be direct-exec'd")
74+
75+
// Exec it exactly as connection_stdio would (exec.CommandContext(cmd, args...)).
76+
ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
77+
defer cancel()
78+
execCmd := exec.CommandContext(ctx, cmd, args...)
79+
require.NoError(t, execCmd.Run(), "spawning the resolved docker binary must succeed")
80+
81+
recorded, err := os.ReadFile(recordFile)
82+
require.NoError(t, err, "the docker shim must have been invoked and recorded its argv[0]")
83+
got := strings.TrimSpace(string(recorded))
84+
85+
assert.Equal(t, bundleDocker, got,
86+
"#696: docker must be exec'd by its absolute bundle path, got %q", got)
87+
assert.NotEqual(t, "docker", got, "#696: must not be launched as bare 'docker'")
88+
require.True(t, filepath.IsAbs(got), "argv[0] must be absolute, got %q", got)
89+
}
Lines changed: 229 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,229 @@
1+
package core
2+
3+
import (
4+
"fmt"
5+
"path/filepath"
6+
"runtime"
7+
"strings"
8+
"testing"
9+
10+
"github.com/smart-mcp-proxy/mcpproxy-go/internal/shellwrap"
11+
12+
"github.com/stretchr/testify/assert"
13+
"github.com/stretchr/testify/require"
14+
"go.uber.org/zap"
15+
"go.uber.org/zap/zaptest/observer"
16+
)
17+
18+
// newObservedIsolatedClient returns an isolated test client whose logger feeds
19+
// an in-memory observer, so tests can assert on the spawn-decision INFO logs.
20+
func newObservedIsolatedClient(t *testing.T) (*Client, *observer.ObservedLogs) {
21+
t.Helper()
22+
core, recorded := observer.New(zap.InfoLevel)
23+
c := newIsolatedTestClient()
24+
c.logger = zap.New(core)
25+
return c, recorded
26+
}
27+
28+
// TestSpawnDecisionIsObservable_DirectExec asserts the #696 diagnosability fix:
29+
// the direct-exec branch emits an INFO line carrying the resolved docker_path so
30+
// a field report can be triaged from main.log alone.
31+
func TestSpawnDecisionIsObservable_DirectExec(t *testing.T) {
32+
if runtime.GOOS == osWindows {
33+
t.Skip("unix fake-binary fixture")
34+
}
35+
useRealDockerResolver(t)
36+
forceDockerDaemonEnvGOOS(t, osDarwin)
37+
38+
bundleDocker := writeFakeDockerExecutable(t)
39+
restore := shellwrap.SetWellKnownDockerPathsForTest(func() []string { return []string{bundleDocker} })
40+
t.Cleanup(restore)
41+
t.Setenv("PATH", t.TempDir())
42+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
43+
44+
c, recorded := newObservedIsolatedClient(t)
45+
_, _, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
46+
require.False(t, shellWrapped)
47+
48+
entries := recorded.FilterMessage("Docker spawn: direct-exec of resolved docker binary").All()
49+
require.Len(t, entries, 1, "direct-exec must log exactly one observable spawn-decision line")
50+
fields := entries[0].ContextMap()
51+
assert.Equal(t, bundleDocker, fields["docker_path"], "spawn log must record the resolved absolute docker path")
52+
assert.Equal(t, false, fields["shell_wrapped"])
53+
}
54+
55+
// TestSpawnDecisionIsObservable_ShellWrapFallback asserts the fallback branch is
56+
// equally observable and flags whether docker even resolved — the one path that
57+
// can yield #696's `command not found: docker`.
58+
func TestSpawnDecisionIsObservable_ShellWrapFallback(t *testing.T) {
59+
orig := resolveDockerBinary
60+
t.Cleanup(func() { resolveDockerBinary = orig })
61+
resolveDockerBinary = func(_ *zap.Logger) (string, error) {
62+
return "", fmt.Errorf("docker not found")
63+
}
64+
65+
c, recorded := newObservedIsolatedClient(t)
66+
_, _, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
67+
require.True(t, shellWrapped)
68+
69+
entries := recorded.FilterMessage("Docker spawn: login-shell wrap fallback").All()
70+
require.Len(t, entries, 1, "shell-wrap fallback must log exactly one observable spawn-decision line")
71+
fields := entries[0].ContextMap()
72+
assert.Equal(t, true, fields["shell_wrapped"])
73+
assert.Equal(t, false, fields["docker_resolved"], "unresolved docker must be flagged in the spawn log")
74+
assert.Equal(t, cmdDocker, fields["docker_command"], "fallback with no resolution wraps bare 'docker'")
75+
}
76+
77+
// These tests close the integration gap behind GitHub #696: the existing
78+
// connection_docker_test.go suite STUBS resolveDockerBinary, so it proves the
79+
// gating logic in isolation but never exercises the REAL
80+
// shellwrap.ResolveDockerPath -> setupDockerIsolation chain. The #696 field
81+
// failure ("docker installed via Docker Desktop but not on the spawn PATH"
82+
// still spawns bare `docker` and dies with `command not found: docker`) can
83+
// only be reproduced — or refuted — by driving the real resolver end-to-end.
84+
//
85+
// useRealDockerResolver pins resolveDockerBinary to the production resolver
86+
// (un-stubbing any leakage from a sibling test) and clears the process-wide
87+
// docker-path cache so resolution starts from a clean slate.
88+
func useRealDockerResolver(t *testing.T) {
89+
t.Helper()
90+
orig := resolveDockerBinary
91+
resolveDockerBinary = shellwrap.ResolveDockerPath
92+
shellwrap.ResetDockerPathCacheForTest()
93+
t.Cleanup(func() {
94+
resolveDockerBinary = orig
95+
shellwrap.ResetDockerPathCacheForTest()
96+
})
97+
}
98+
99+
// TestIntegration_DockerOnlyAtBundlePath_DirectExecs is the faithful #696
100+
// reproduction: on macOS, Docker Desktop's CLI lives only inside the app bundle
101+
// (/Applications/Docker.app/Contents/Resources/bin/docker) and is absent from
102+
// the spawn PATH. The real resolver must discover it via the well-known-path
103+
// probe, and setupDockerIsolation must DIRECT-EXEC that absolute path — never
104+
// fall back to a `$SHELL -l -c "docker run …"` wrap with bare `docker` (which is
105+
// what the login shell cannot resolve and what the field report shows failing).
106+
func TestIntegration_DockerOnlyAtBundlePath_DirectExecs(t *testing.T) {
107+
if runtime.GOOS == osWindows {
108+
t.Skip("well-known bundle probe + login-shell fallback are unix-only")
109+
}
110+
useRealDockerResolver(t)
111+
forceDockerDaemonEnvGOOS(t, osDarwin) // matches the affected hosts
112+
113+
// Docker exists ONLY at a "bundle" path, off the spawn PATH.
114+
bundleDocker := writeFakeDockerExecutable(t)
115+
restore := shellwrap.SetWellKnownDockerPathsForTest(func() []string { return []string{bundleDocker} })
116+
t.Cleanup(restore)
117+
118+
// Spawn PATH excludes the bundle dir (the #696 condition) and the login
119+
// shell can't find docker either, so the well-known probe is the ONLY way to
120+
// resolve it.
121+
t.Setenv("PATH", t.TempDir())
122+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
123+
124+
c := newIsolatedTestClient()
125+
cmd, args, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
126+
127+
require.False(t, shellWrapped,
128+
"#696: docker resolved at the bundle path MUST be direct-exec'd, not shell-wrapped with bare docker")
129+
assert.Equal(t, bundleDocker, cmd,
130+
"#696: spawn must exec the resolved absolute bundle path, got %q", cmd)
131+
assert.NotEqual(t, cmdDocker, cmd, "#696: spawn must not degrade to bare 'docker'")
132+
require.True(t, filepath.IsAbs(cmd), "spawn command must be absolute, got %q", cmd)
133+
require.NotEmpty(t, args)
134+
assert.Equal(t, cmdRun, args[0], "args must be raw argv (first token 'run'), got %v", args)
135+
for _, a := range args {
136+
assert.NotContains(t, a, " run ", "args must be raw argv tokens, not a shell -c string: %v", args)
137+
}
138+
}
139+
140+
// TestIntegration_DockerOnPath_DirectExecs covers the other real resolution
141+
// leg: when docker IS on the spawn PATH, exec.LookPath resolves it to an
142+
// absolute path and the spawn direct-execs it.
143+
func TestIntegration_DockerOnPath_DirectExecs(t *testing.T) {
144+
if runtime.GOOS == osWindows {
145+
t.Skip("unix fake-binary fixture")
146+
}
147+
useRealDockerResolver(t)
148+
forceDockerDaemonEnvGOOS(t, osDarwin)
149+
150+
pathDocker := writeFakeDockerExecutable(t)
151+
// Put the fake docker's dir on PATH so exec.LookPath finds it first.
152+
t.Setenv("PATH", filepath.Dir(pathDocker))
153+
// No well-known override needed; LookPath should win before the probe.
154+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
155+
156+
c := newIsolatedTestClient()
157+
cmd, args, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
158+
159+
require.False(t, shellWrapped, "docker on PATH must resolve to an absolute path and direct-exec")
160+
assert.Equal(t, pathDocker, cmd, "spawn must exec the LookPath-resolved absolute path, got %q", cmd)
161+
require.NotEmpty(t, args)
162+
assert.Equal(t, cmdRun, args[0])
163+
}
164+
165+
// TestIntegration_DockerUnresolvable_FallsBackToBareDocker proves the worst
166+
// case (#696 absent): when docker is nowhere — not on PATH, not at a well-known
167+
// path, not in the login shell — the spawn falls back to a login-shell wrap of
168+
// bare `docker`. This is the ONLY path that should ever produce the field
169+
// failure's `command not found: docker`, and it requires docker to be genuinely
170+
// absent (not merely off PATH).
171+
func TestIntegration_DockerUnresolvable_FallsBackToBareDocker(t *testing.T) {
172+
if runtime.GOOS == osWindows {
173+
t.Skip("unix login-shell fallback")
174+
}
175+
useRealDockerResolver(t)
176+
forceDockerDaemonEnvGOOS(t, osDarwin)
177+
178+
// No docker anywhere: empty PATH, well-known list points at nothing, login
179+
// shell sabotaged so its lookup fails too.
180+
restore := shellwrap.SetWellKnownDockerPathsForTest(func() []string { return nil })
181+
t.Cleanup(restore)
182+
t.Setenv("PATH", t.TempDir())
183+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
184+
185+
c := newIsolatedTestClient()
186+
_, shellArgs, shellWrapped := c.setupDockerIsolation(c.config.Command, c.config.Args)
187+
188+
require.True(t, shellWrapped, "unresolvable docker must fall back to the login-shell wrap")
189+
require.NotEmpty(t, shellArgs)
190+
cmdStr := shellArgs[len(shellArgs)-1]
191+
assert.True(t, strings.HasPrefix(cmdStr, "docker run"),
192+
"only a genuinely-absent docker should degrade to bare 'docker', got %q", cmdStr)
193+
}
194+
195+
// TestIntegration_StatusAndSpawnResolverDoNotDiverge guards the invariant the
196+
// #696 v0.39.1 report worried about ("detection discovers docker_path but the
197+
// spawn doesn't use it"). docker_status.docker_path (server.dockerPathResolver)
198+
// and the spawn (core.resolveDockerBinary) both call shellwrap.ResolveDockerPath
199+
// and share ONE process-wide cache, so for a given environment they MUST agree.
200+
// If a future refactor gives the status panel its own resolver, this test
201+
// fails — surfacing exactly the divergence the field reports feared.
202+
func TestIntegration_StatusAndSpawnResolverDoNotDiverge(t *testing.T) {
203+
if runtime.GOOS == osWindows {
204+
t.Skip("unix fake-binary fixture")
205+
}
206+
useRealDockerResolver(t)
207+
208+
bundleDocker := writeFakeDockerExecutable(t)
209+
restore := shellwrap.SetWellKnownDockerPathsForTest(func() []string { return []string{bundleDocker} })
210+
t.Cleanup(restore)
211+
t.Setenv("PATH", t.TempDir())
212+
t.Setenv("SHELL", "/nonexistent/shell-must-not-be-invoked")
213+
214+
// Spawn side (the value setupDockerIsolation would exec).
215+
spawnPath, err := resolveDockerBinary(zap.NewNop())
216+
require.NoError(t, err)
217+
218+
// Status side reports the SAME resolution branch + path from the shared cache.
219+
source := shellwrap.ResolveDockerSource(zap.NewNop())
220+
statusPath, err := shellwrap.ResolveDockerPath(zap.NewNop())
221+
require.NoError(t, err)
222+
223+
assert.Equal(t, bundleDocker, spawnPath, "spawn must resolve the bundle path")
224+
assert.Equal(t, spawnPath, statusPath, "status and spawn must resolve to the SAME docker path (no divergence)")
225+
assert.Equal(t, shellwrap.DockerSourceBundled, source,
226+
"status must report the bundled source matching the spawn resolution")
227+
assert.True(t, isDirectExecutable(statusPath),
228+
"the path docker_status reports must itself satisfy the direct-exec contract")
229+
}

0 commit comments

Comments
 (0)