Fix extension startup error diagnostics

commit: 966d045f7872b7d5d706235dbdc70609a8f75ed7
author: patriceckhart · 2mo ago · 2026-07-26 10:00 UTC
parent: 210ef98
signature: unsigned
refs: tag: v0.3.9

3 files · +108 -10

M docs/extensions.md +2 -1


@@ -644,7 +644,8 @@ Useful while developing an extension: edit, save, `/reload-ext`,
644	644		done. Explicit `--ext` paths are remembered and reloaded alongside
645	645		discovered extensions. The temporary reload status reports each load
646	646		error in red, including its message, and dismisses itself after five
647		-	seconds.
	647	+	seconds. Subprocess startup and handshake errors include the exact stderr
	648	+	log path for the failed extension.
648	649
649	650		### TypeScript / Python
650	651


@@ -644,7 +644,8 @@ Useful while developing an extension: edit, save, `/reload-ext`,
644		done. Explicit `--ext` paths are remembered and reloaded alongside	644		done. Explicit `--ext` paths are remembered and reloaded alongside
645		discovered extensions. The temporary reload status reports each load	645		discovered extensions. The temporary reload status reports each load
646		error in red, including its message, and dismisses itself after five	646		error in red, including its message, and dismisses itself after five
647	-	seconds.	647	+	seconds. Subprocess startup and handshake errors include the exact stderr
			648	+	log path for the failed extension.
648			649
649		### TypeScript / Python	650		### TypeScript / Python
650			651

M packages/agent/extensions/manager.go +36 -9


@@ -553,17 +553,39 @@ func (m Manager) spawn(ctx context.Context, ext Extension) error {
553	553		cmd.Stderr = logFile
554	554		isolateExtensionProcess(cmd)
555	555
556		-	stdin, err := cmd.StdinPipe()
	556	+	var stdin io.WriteCloser
	557	+	var stdout io.ReadCloser
	558	+	started := false
	559	+	cleanup := true
	560	+	defer func() {
	561	+	if !cleanup {
	562	+	return
	563	+	}
	564	+	if stdin != nil {
	565	+	_ = stdin.Close()
	566	+	}
	567	+	if stdout != nil {
	568	+	_ = stdout.Close()
	569	+	}
	570	+	if started {
	571	+	_ = cmd.Process.Kill()
	572	+	_ = cmd.Wait()
	573	+	}
	574	+	_ = logFile.Close()
	575	+	}()
	576	+
	577	+	stdin, err = cmd.StdinPipe()
557	578		if err != nil {
558		-	return err
	579	+	return fmt.Errorf("stdin pipe (stderr log: %s): %w", logPath, err)
559	580		}
560		-	stdout, err := cmd.StdoutPipe()
	581	+	stdout, err = cmd.StdoutPipe()
561	582		if err != nil {
562		-	return err
	583	+	return fmt.Errorf("stdout pipe (stderr log: %s): %w", logPath, err)
563	584		}
564	585		if err := cmd.Start(); err != nil {
565		-	return fmt.Errorf("spawn: %w", err)
	586	+	return fmt.Errorf("spawn (stderr log: %s): %w", logPath, err)
566	587		}
	588	+	started = true
567	589		ext.cmd = cmd
568	590		ext.stdin = stdin
569	591		ext.stdout = stdout

@@ -574,14 +596,17 @@ func (m Manager) spawn(ctx context.Context, ext Extension) error {
574	596		scanner := bufio.NewScanner(stdout)
575	597		scanner.Buffer(make([]byte, 0, 641024), 41024*1024)
576	598		if !scanner.Scan() {
577		-	return fmt.Errorf("extension exited before hello: %w", scanner.Err())
	599	+	if err := scanner.Err(); err != nil {
	600	+	return fmt.Errorf("read hello (stderr log: %s): %w", logPath, err)
	601	+	}
	602	+	return fmt.Errorf("extension exited before hello (stderr log: %s)", logPath)
578	603		}
579	604		var hello extproto.HelloFromExt
580	605		if err := json.Unmarshal(scanner.Bytes(), &hello); err != nil {
581		-	return fmt.Errorf("parse hello: %w", err)
	606	+	return fmt.Errorf("parse hello (stderr log: %s): %w", logPath, err)
582	607		}
583	608		if hello.Type != "hello" \|\| hello.Name == "" {
584		-	return fmt.Errorf("first frame must be hello (got %q)", hello.Type)
	609	+	return fmt.Errorf("first frame must be hello (got %q; stderr log: %s)", hello.Type, logPath)
585	610		}
586	611		// Trust the manifest's name; ignore mismatch from the hello.
587	612		ext.helloAck = true

@@ -597,9 +622,11 @@ func (m Manager) spawn(ctx context.Context, ext Extension) error {
597	622		DataDir: ext.Dir,
598	623		})
599	624		if _, err := stdin.Write(ack); err != nil {
600		-	return fmt.Errorf("send hello_ack: %w", err)
	625	+	return fmt.Errorf("send hello_ack (stderr log: %s): %w", logPath, err)
601	626		}
602	627
	628	+	cleanup = false
	629	+
603	630		// Spin up the read loop now that the handshake is done.
604	631		go m.readLoop(ext, scanner)
605	632

 	cmd.Stderr = logFile
 	isolateExtensionProcess(cmd)
-	stdin, err := cmd.StdinPipe()
+	var stdin io.WriteCloser
+	var stdout io.ReadCloser
+	started := false
+	cleanup := true
+	defer func() {
+		if !cleanup {
+			return
+		}
+		if stdin != nil {
+			_ = stdin.Close()
+		}
+		if stdout != nil {
+			_ = stdout.Close()
+		}
+		if started {
+			_ = cmd.Process.Kill()
+			_ = cmd.Wait()
+		}
+		_ = logFile.Close()
+	}()
+	stdin, err = cmd.StdinPipe()
 	if err != nil {
-		return err
+		return fmt.Errorf("stdin pipe (stderr log: %s): %w", logPath, err)
 	}
-	stdout, err := cmd.StdoutPipe()
+	stdout, err = cmd.StdoutPipe()
 	if err != nil {
-		return err
+		return fmt.Errorf("stdout pipe (stderr log: %s): %w", logPath, err)
 	}
 	if err := cmd.Start(); err != nil {
-		return fmt.Errorf("spawn: %w", err)
+		return fmt.Errorf("spawn (stderr log: %s): %w", logPath, err)
 	}
+	started = true
 	ext.cmd = cmd
 	ext.stdin = stdin
 	ext.stdout = stdout
 	scanner := bufio.NewScanner(stdout)
 	scanner.Buffer(make([]byte, 0, 64*1024), 4*1024*1024)
 	if !scanner.Scan() {
-		return fmt.Errorf("extension exited before hello: %w", scanner.Err())
+		if err := scanner.Err(); err != nil {
+			return fmt.Errorf("read hello (stderr log: %s): %w", logPath, err)
+		}
+		return fmt.Errorf("extension exited before hello (stderr log: %s)", logPath)
 	}
 	var hello extproto.HelloFromExt
 	if err := json.Unmarshal(scanner.Bytes(), &hello); err != nil {
-		return fmt.Errorf("parse hello: %w", err)
+		return fmt.Errorf("parse hello (stderr log: %s): %w", logPath, err)
 	}
 	if hello.Type != "hello" || hello.Name == "" {
-		return fmt.Errorf("first frame must be hello (got %q)", hello.Type)
+		return fmt.Errorf("first frame must be hello (got %q; stderr log: %s)", hello.Type, logPath)
 	}
 	// Trust the manifest's name; ignore mismatch from the hello.
 	ext.helloAck = true
 		DataDir:         ext.Dir,
 	})
 	if _, err := stdin.Write(ack); err != nil {
-		return fmt.Errorf("send hello_ack: %w", err)
+		return fmt.Errorf("send hello_ack (stderr log: %s): %w", logPath, err)
 	}
+	cleanup = false
 	// Spin up the read loop now that the handshake is done.
 	go m.readLoop(ext, scanner)

M packages/agent/extensions/manager_test.go +70 -0


@@ -119,6 +119,76 @@ done
119	119		}
120	120		}
121	121
	122	+	func TestDiscoverReportsLogWhenExtensionExitsBeforeHello(t *testing.T) {
	123	+	if runtime.GOOS == "windows" {
	124	+	t.Skip("mock extension uses /bin/sh; skip on windows")
	125	+	}
	126	+
	127	+	tmp := t.TempDir()
	128	+	extDir := filepath.Join(tmp, "extensions", "broken")
	129	+	if err := os.MkdirAll(extDir, 0o755); err != nil {
	130	+	t.Fatal(err)
	131	+	}
	132	+	script := "#!/bin/sh\nprintf '%s\\n' 'compile failed' >&2\nexit 1\n"
	133	+	if err := os.WriteFile(filepath.Join(extDir, "run.sh"), []byte(script), 0o755); err != nil {
	134	+	t.Fatal(err)
	135	+	}
	136	+	if err := os.WriteFile(filepath.Join(extDir, "extension.json"), []byte(`{"name":"broken","exec":"./run.sh"}`), 0o644); err != nil {
	137	+	t.Fatal(err)
	138	+	}
	139	+
	140	+	mgr := New(tmp, "", "0.0.0-test", "", "", nil)
	141	+	errs := mgr.Discover(context.Background())
	142	+	if len(errs) != 1 {
	143	+	t.Fatalf("discover errors = %v, want one", errs)
	144	+	}
	145	+	logPath := filepath.Join(tmp, "logs", "ext-broken.log")
	146	+	got := errs[0].Error()
	147	+	if strings.Contains(got, "%!w") {
	148	+	t.Fatalf("error contains formatting artifact: %s", got)
	149	+	}
	150	+	if !strings.Contains(got, "extension exited before hello") \|\| !strings.Contains(got, logPath) {
	151	+	t.Fatalf("error does not explain failure and identify stderr log: %s", got)
	152	+	}
	153	+	logData, err := os.ReadFile(logPath)
	154	+	if err != nil {
	155	+	t.Fatalf("read extension log: %v", err)
	156	+	}
	157	+	if !strings.Contains(string(logData), "compile failed") {
	158	+	t.Fatalf("extension stderr missing from log: %s", logData)
	159	+	}
	160	+	}
	161	+
	162	+	func TestSpawnCleansUpProcessAfterInvalidHello(t *testing.T) {
	163	+	if runtime.GOOS == "windows" {
	164	+	t.Skip("mock extension uses /bin/sh; skip on windows")
	165	+	}
	166	+
	167	+	tmp := t.TempDir()
	168	+	extDir := filepath.Join(tmp, "broken")
	169	+	if err := os.MkdirAll(extDir, 0o755); err != nil {
	170	+	t.Fatal(err)
	171	+	}
	172	+	scriptPath := filepath.Join(extDir, "run.sh")
	173	+	script := "#!/bin/sh\nprintf '%s\\n' 'not-json'\nwhile IFS= read -r line; do :; done\n"
	174	+	if err := os.WriteFile(scriptPath, []byte(script), 0o755); err != nil {
	175	+	t.Fatal(err)
	176	+	}
	177	+
	178	+	ext := &Extension{Manifest: Manifest{Name: "broken", Exec: "./run.sh"}, Dir: extDir}
	179	+	mgr := New(tmp, "", "0.0.0-test", "", "", nil)
	180	+	err := mgr.spawn(context.Background(), ext)
	181	+	if err == nil \|\| !strings.Contains(err.Error(), "parse hello") {
	182	+	t.Fatalf("spawn error = %v, want parse hello failure", err)
	183	+	}
	184	+	if ext.cmd == nil \|\| ext.cmd.ProcessState == nil {
	185	+	t.Fatal("failed handshake process was not reaped")
	186	+	}
	187	+	if _, err := ext.logFile.WriteString("after cleanup"); err == nil {
	188	+	t.Fatal("failed handshake log file was not closed")
	189	+	}
	190	+	}
	191	+
122	192		func TestDiscoverLoadsThemeOnlyExtension(t *testing.T) {
123	193		tmp := t.TempDir()
124	194		extDir := filepath.Join(tmp, "extensions", "theme-only")


@@ -119,6 +119,76 @@ done
119	}	119		}
120	}	120		}
121		121
		122	+	func TestDiscoverReportsLogWhenExtensionExitsBeforeHello(t *testing.T) {
		123	+	if runtime.GOOS == "windows" {
		124	+	t.Skip("mock extension uses /bin/sh; skip on windows")
		125	+	}
		126	+
		127	+	tmp := t.TempDir()
		128	+	extDir := filepath.Join(tmp, "extensions", "broken")
		129	+	if err := os.MkdirAll(extDir, 0o755); err != nil {
		130	+	t.Fatal(err)
		131	+	}
		132	+	script := "#!/bin/sh\nprintf '%s\\n' 'compile failed' >&2\nexit 1\n"
		133	+	if err := os.WriteFile(filepath.Join(extDir, "run.sh"), []byte(script), 0o755); err != nil {
		134	+	t.Fatal(err)
		135	+	}
		136	+	if err := os.WriteFile(filepath.Join(extDir, "extension.json"), []byte(`{"name":"broken","exec":"./run.sh"}`), 0o644); err != nil {
		137	+	t.Fatal(err)
		138	+	}
		139	+
		140	+	mgr := New(tmp, "", "0.0.0-test", "", "", nil)
		141	+	errs := mgr.Discover(context.Background())
		142	+	if len(errs) != 1 {
		143	+	t.Fatalf("discover errors = %v, want one", errs)
		144	+	}
		145	+	logPath := filepath.Join(tmp, "logs", "ext-broken.log")
		146	+	got := errs[0].Error()
		147	+	if strings.Contains(got, "%!w") {
		148	+	t.Fatalf("error contains formatting artifact: %s", got)
		149	+	}
		150	+	if !strings.Contains(got, "extension exited before hello") \|\| !strings.Contains(got, logPath) {
		151	+	t.Fatalf("error does not explain failure and identify stderr log: %s", got)
		152	+	}
		153	+	logData, err := os.ReadFile(logPath)
		154	+	if err != nil {
		155	+	t.Fatalf("read extension log: %v", err)
		156	+	}
		157	+	if !strings.Contains(string(logData), "compile failed") {
		158	+	t.Fatalf("extension stderr missing from log: %s", logData)
		159	+	}
		160	+	}
		161	+
		162	+	func TestSpawnCleansUpProcessAfterInvalidHello(t *testing.T) {
		163	+	if runtime.GOOS == "windows" {
		164	+	t.Skip("mock extension uses /bin/sh; skip on windows")
		165	+	}
		166	+
		167	+	tmp := t.TempDir()
		168	+	extDir := filepath.Join(tmp, "broken")
		169	+	if err := os.MkdirAll(extDir, 0o755); err != nil {
		170	+	t.Fatal(err)
		171	+	}
		172	+	scriptPath := filepath.Join(extDir, "run.sh")
		173	+	script := "#!/bin/sh\nprintf '%s\\n' 'not-json'\nwhile IFS= read -r line; do :; done\n"
		174	+	if err := os.WriteFile(scriptPath, []byte(script), 0o755); err != nil {
		175	+	t.Fatal(err)
		176	+	}
		177	+
		178	+	ext := &Extension{Manifest: Manifest{Name: "broken", Exec: "./run.sh"}, Dir: extDir}
		179	+	mgr := New(tmp, "", "0.0.0-test", "", "", nil)
		180	+	err := mgr.spawn(context.Background(), ext)
		181	+	if err == nil \|\| !strings.Contains(err.Error(), "parse hello") {
		182	+	t.Fatalf("spawn error = %v, want parse hello failure", err)
		183	+	}
		184	+	if ext.cmd == nil \|\| ext.cmd.ProcessState == nil {
		185	+	t.Fatal("failed handshake process was not reaped")
		186	+	}
		187	+	if _, err := ext.logFile.WriteString("after cleanup"); err == nil {
		188	+	t.Fatal("failed handshake log file was not closed")
		189	+	}
		190	+	}
		191	+
122	func TestDiscoverLoadsThemeOnlyExtension(t *testing.T) {	192		func TestDiscoverLoadsThemeOnlyExtension(t *testing.T) {
123	tmp := t.TempDir()	193		tmp := t.TempDir()
124	extDir := filepath.Join(tmp, "extensions", "theme-only")	194		extDir := filepath.Join(tmp, "extensions", "theme-only")