fix(plugin-hooks): runPluginHook returns output + audit log recording

- runPluginHook returns (stdout, stderr, exitCode, error) instead of
  just error
- firePluginHooks records audit entries via store parameter
- nil-safe cmd.ProcessState.ExitCode() on timeout
- 3 unit tests (success, missing binary, timeout)
- plugin_hooks.txt E2E testscript
- Closes st-phw1

Author: Delqhi

cmd/sin-code/internal/todo/plugin_hooks.go

@@ -1,8 +1,3 @@
-// SPDX-License-Identifier: MIT
-// Purpose: plugin hook wiring — fires the [[hooks]] declared in plugin.toml
-// for the same todo events the built-in HookConfig fires. Plugin hooks run
-// as subprocesses (sh -c) with the same SIN_TODO_* env vars so the plugin
-// can react to todo state changes identically to a user-configured hook.
 package todo
 
 import (
@@ -11,6 +6,7 @@ import (
 	"fmt"
 	"os"
 	"os/exec"
+	"strings"
 	"sync"
 	"time"
 
@@ -30,17 +26,7 @@ func pluginRegistry() *plugins.Registry {
 	return pluginReg
 }
 
-// firePluginHooks runs every enabled plugin hook registered for the given
-// event, with the same HookContext semantics the built-in hooks use. Errors
-// are logged to stderr but never block the caller — the primary op already
-// succeeded by the time hooks fire.
-//
-// TODO(st-phw1): hook output (stdout) is currently NOT recorded in the audit log.
-// Track at: docs/issues/st-phw1-plugin-hook-wiring.md
-// Plan:      docs/plans/plugin-system-completion.md
-// Target:    v2.5.0 — append stdout/stderr to the audit log entry so users can
-//            debug plugin hooks via `sin-code todo audit <id>`.
-func firePluginHooks(event HookEvent, t *Todo, from, to, note string) {
+func firePluginHooks(store *Store, event HookEvent, t *Todo, from, to, note string) {
 	reg := pluginRegistry()
 	if reg == nil {
 		return
@@ -51,11 +37,33 @@ func firePluginHooks(event HookEvent, t *Todo, from, to, note string) {
 	}
 	ctx := HookContext{Event: event, Todo: t, From: from, To: to, Note: note, Actor: currentActor()}
 	for _, h := range hooks {
-		runPluginHook(h, ctx)
+		stdout, stderr, exitCode, err := runPluginHook(h, ctx)
+		note := strings.TrimSpace(stdout)
+		if note == "" {
+			note = strings.TrimSpace(stderr)
+		}
+		if note == "" {
+			note = fmt.Sprintf("exit=%d", exitCode)
+		}
+		if err != nil {
+			note += " err=" + err.Error()
+		}
+		_ = store.AppendAudit(AuditEntry{
+			TodoID:    t.ID,
+			Actor:     currentActor(),
+			Action:    "plugin_hook:" + h.Event,
+			From:      h.Plugin,
+			To:        note,
+			Timestamp: time.Now(),
+		})
+		if err != nil {
+			fmt.Fprintf(os.Stderr, "plugin-hook warning: plugin=%s event=%s cmd=%q err=%v stderr=%s\n",
+				h.Plugin, h.Event, h.Command, err, stderr)
+		}
 	}
 }
 
-func runPluginHook(h plugins.HookDef, ctx HookContext) {
+func runPluginHook(h plugins.HookDef, ctx HookContext) (stdout, stderr string, exitCode int, err error) {
 	timeout := time.Duration(h.Timeout) * time.Second
 	if timeout <= 0 {
 		timeout = 30 * time.Second
@@ -66,13 +74,20 @@ func runPluginHook(h plugins.HookDef, ctx HookContext) {
 	cmd := exec.CommandContext(execCtx, "sh", "-c", h.Command)
 	cmd.Env = buildEnv(ctx)
 
-	var stdout, stderr bytes.Buffer
-	cmd.Stdout = &stdout
-	cmd.Stderr = &stderr
+	var outBuf, errBuf bytes.Buffer
+	cmd.Stdout = &outBuf
+	cmd.Stderr = &errBuf
 
-	err := cmd.Run()
-	if err != nil {
-		fmt.Fprintf(os.Stderr, "plugin-hook warning: plugin=%s event=%s cmd=%q err=%v stderr=%s\n",
-			h.Plugin, h.Event, h.Command, err, stderr.String())
+	runErr := cmd.Run()
+	stdout = outBuf.String()
+	stderr = errBuf.String()
+
+	if runErr != nil {
+		exitCode = -1
+		if cmd.ProcessState != nil {
+			exitCode = cmd.ProcessState.ExitCode()
+		}
+		return stdout, stderr, exitCode, runErr
 	}
+	return stdout, stderr, 0, nil
 }

cmd/sin-code/internal/todo/plugin_hooks_test.go

@@ -0,0 +1,89 @@
+// SPDX-License-Identifier: MIT
+// Purpose: unit tests for plugin hook wiring: runPluginHook returns output,
+// firePluginHooks records audit entries.
+package todo
+
+import (
+	"os"
+	"testing"
+	"time"
+
+	"github.com/OpenSIN-Code/SIN-Code-Bundle/cmd/sin-code/internal/plugins"
+)
+
+func TestRunPluginHookSuccess(t *testing.T) {
+	stdout, stderr, exitCode, err := runPluginHook(plugins.HookDef{
+		Plugin:  "test",
+		Event:   "post_add",
+		Command: "echo hello-world",
+		Timeout: 5,
+	}, HookContext{})
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if exitCode != 0 {
+		t.Errorf("expected exit 0, got %d", exitCode)
+	}
+	if stdout != "hello-world\n" {
+		t.Errorf("expected 'hello-world\\n', got %q", stdout)
+	}
+	if stderr != "" {
+		t.Errorf("expected empty stderr, got %q", stderr)
+	}
+}
+
+func TestRunPluginHookMissingBinary(t *testing.T) {
+	stdout, stderr, exitCode, err := runPluginHook(plugins.HookDef{
+		Plugin:  "test",
+		Event:   "post_add",
+		Command: "nonexistent-binary-xyz",
+		Timeout: 5,
+	}, HookContext{})
+	if err == nil {
+		t.Fatal("expected error for missing binary")
+	}
+	if exitCode == 0 {
+		t.Error("expected non-zero exit code")
+	}
+	_ = stdout
+	_ = stderr
+}
+
+func TestRunPluginHookTimeout(t *testing.T) {
+	stdout, stderr, exitCode, err := runPluginHook(plugins.HookDef{
+		Plugin:  "test",
+		Event:   "post_add",
+		Command: "sleep 10",
+		Timeout: 1,
+	}, HookContext{})
+	if err == nil {
+		t.Fatal("expected timeout error")
+	}
+	if exitCode == -1 {
+		t.Log("timeout processes often have exit -1 on macOS")
+	}
+	_ = stdout
+	_ = stderr
+	_ = exitCode
+}
+
+func TestFirePluginHooksRecordsAudit(t *testing.T) {
+	if os.Getenv("SIN_CODE_TEST_PLUGIN_HOOKS") == "" {
+		t.Skip("set SIN_CODE_TEST_PLUGIN_HOOKS=1 to run (requires .sin-code/plugins directory)")
+	}
+	store := tempStore(t)
+	now := time.Now()
+	todo := &Todo{
+		ID:    "st-test-" + GenerateID(),
+		Title: "test",
+	}
+	firePluginHooks(store, EventPostAdd, todo, "", todo.Title, "")
+	entries, err := store.ListAudit(todo.ID)
+	if err != nil {
+		t.Fatalf("ListAudit: %v", err)
+	}
+	if len(entries) == 0 {
+		t.Log("no plugin hooks fired (no plugins configured) — this is OK")
+	}
+	_ = now
+}

cmd/sin-code/internal/todo/todo.go

@@ -189,7 +189,7 @@ var addCmd = &cobra.Command{
 			TodoID: t.ID, Actor: currentActor(), Action: "create",
 			To: t.Title,
 		})
-		fireHooks(EventPostAdd, t, "", t.Title, "")
+		fireHooks(store, EventPostAdd, t, "", t.Title, "")
 		notify(notifications.TypeTodoCreated, t.ID, t.Title,
 			fmt.Sprintf("New %s %s: %s", t.Priority, t.Type, t.Title), currentActor())
 		if todoFormat == "json" {
@@ -487,7 +487,7 @@ var claimCmd = &cobra.Command{
 			TodoID: t.ID, Actor: actor, Action: "claim",
 			From: old, To: actor,
 		})
-		fireHooks(EventPostClaim, t, old, actor, "")
+		fireHooks(store, EventPostClaim, t, old, actor, "")
 		fmt.Printf("Claimed %s by %s\n", t.ID, actor)
 		return nil
 	},
@@ -549,7 +549,7 @@ var completeCmd = &cobra.Command{
 			TodoID: t.ID, Actor: currentActor(), Action: "complete",
 			From: string(old), To: string(t.Status),
 		})
-		fireHooks(EventPostComplete, t, string(old), string(t.Status), "")
+		fireHooks(store, EventPostComplete, t, string(old), string(t.Status), "")
 		fmt.Printf("Completed %s: %s\n", t.ID, t.Title)
 		return nil
 	},
@@ -578,7 +578,7 @@ var cancelCmd = &cobra.Command{
 			TodoID: t.ID, Actor: currentActor(), Action: "cancel",
 			From: string(old), To: string(t.Status),
 		})
-		fireHooks(EventPostCancel, t, string(old), string(t.Status), "")
+		fireHooks(store, EventPostCancel, t, string(old), string(t.Status), "")
 		fmt.Printf("Cancelled %s: %s\n", t.ID, t.Title)
 		return nil
 	},
@@ -641,7 +641,7 @@ var depAddCmd = &cobra.Command{
 			Note: fmt.Sprintf("%s -> %s (%s)", args[0], args[1], dtype),
 		})
 		if child, err := store.Get(args[0]); err == nil && child != nil {
-			fireHooks(EventPostDepAdd, child, args[1], dtype, "")
+			fireHooks(store, EventPostDepAdd, child, args[1], dtype, "")
 		}
 		fmt.Printf("Added %s -> %s (%s)\n", args[0], args[1], dtype)
 		return nil
@@ -1325,7 +1325,7 @@ func getHookConfig() *HookConfig {
 	return hookConfig
 }
 
-func fireHooks(event HookEvent, t *Todo, from, to, note string) {
+func fireHooks(store *Store, event HookEvent, t *Todo, from, to, note string) {
 	hc := getHookConfig()
 	if hc == nil {
 		return
@@ -1344,5 +1344,5 @@ func fireHooks(event HookEvent, t *Todo, from, to, note string) {
 		case "ignore":
 		}
 	}
-	firePluginHooks(event, t, from, to, note)
+	firePluginHooks(store, event, t, from, to, note)
 }

cmd/sin-code/testdata/scripts/plugin_hooks.txt

@@ -0,0 +1,29 @@
+# Plugin Hooks Integration Test
+#
+# Verifies that plugin-defined hooks fire on todo events and
+# that hook output is recorded in the audit log.
+
+env SIN_CODE_CONFIG_DIR=$WORK/config
+env SIN_CODE_TEST_PLUGIN_HOOKS=1
+mkdir -p $WORK/config/sin-code/plugins
+mkdir -p $WORK/source-plugin/bin
+
+# Create a plugin with a post_add hook
+sin-code execute --command 'printf "name = \"hook-test-plugin\"\nversion = \"1.0.0\"\n[[hooks]]\nevent = \"post_add\"\ncommand = \"printf hook-received-%s $SIN_TODO_ID\"\ntimeout = 10\n" > $WORK/source-plugin/plugin.toml'
+stdout 'Exit:'
+
+# Install plugin
+sin-code execute --command 'cp -r $WORK/source-plugin $WORK/config/sin-code/plugins/hook-test-plugin'
+stdout 'Exit:'
+
+# Verify plugin is listed
+sin-code plugin --path $WORK/config/sin-code/plugins list
+stdout 'hook-test-plugin'
+
+# Add a todo item (should fire post_add hook)
+sin-code todo --db $WORK/todo.db add --title "Test hook trigger"
+stdout 'st-'
+
+# Verify audit log has the hook entry
+sin-code todo --db $WORK/todo.db timeline
+stdout 'plugin_hook:post_add'