diff --git a/docs/CHANGES.md b/docs/CHANGES.md index a7e00d335a..1446a33288 100644 --- a/docs/CHANGES.md +++ b/docs/CHANGES.md @@ -7,6 +7,20 @@ Not release notes. Each entry is written as of the change that produced it and i code moves on; where an entry disagrees with the code, the code wins. +## Claude SessionEnd hand-off + +Claude Code computes the grace it gives SessionEnd hooks from `settings.json` timeouts only; a +plugin's `hooks.json` timeout is used for matching but never for that computation, so kcap's +SessionEnd hook gets the 1.5 s floor and is killed — after it has already killed the watcher whose +parent-exit watchdog would otherwise have ended the session. The hook therefore reads its payload, +re-invokes itself with `--detached`, pipes the payload to that child and exits, all before the +server-URL git probes and the global spool drain that `Program.cs` runs ahead of every hook. The +continuation runs the unchanged session-end path — spool fallback and `ended_at` idempotency +included — under the 15 s `HookBudget` that used to be the hook's, with its output in the session +log and its own session so neither Claude's abort nor a closing terminal can reach it. Only +SessionEnd is handed off: SubagentStop is already `async` in `hooks.json`, and the others honour +their timeouts. + ## Review flows and reviewer selection Review flows use a vendor-neutral catalog-start v2 protocol: reserved `spec-review`/`code-review` diff --git a/src/Capacitor.Cli/Commands/Harness/ClaudeHookCommand.cs b/src/Capacitor.Cli/Commands/Harness/ClaudeHookCommand.cs index aca59c1ee6..727875ab42 100644 --- a/src/Capacitor.Cli/Commands/Harness/ClaudeHookCommand.cs +++ b/src/Capacitor.Cli/Commands/Harness/ClaudeHookCommand.cs @@ -19,11 +19,12 @@ namespace Capacitor.Cli.Commands.Harness; /// public static class ClaudeHookCommand { // Hard ceiling on the best-effort pre-POST drain (watcher kill + inline transcript - // drain) for session-end / subagent-stop. Claude kills the SessionEnd hook at its - // configured timeout (15s); a slow or retrying remote call in the drain could consume - // all of it (the HTTP retry helper alone allows up to 30s) and the session-end POST - // would never be sent, leaving the session stuck "Active". 8s leaves ample headroom to - // send the POST; the server's StopAndDrain + the "kcap import" hint recover the rest. + // drain) for session-end / subagent-stop. Session-end runs in the detached continuation + // (ClaudeSessionEndHandoff) under HookBudget's 15s, subagent-stop inside the hook; either + // way a slow or retrying remote call in the drain could consume the whole budget (the HTTP + // retry helper alone allows up to 30s) and the lifecycle POST would never be sent, leaving + // the session stuck "Active". 8s leaves ample headroom to send the POST; the server's + // StopAndDrain + the "kcap import" hint recover the rest. static readonly TimeSpan PreHookDrainCap = TimeSpan.FromSeconds(8); public static Task Handle(string baseUrl, TextReader stdin, long processStart = 0, diff --git a/src/Capacitor.Cli/Commands/HookBudget.cs b/src/Capacitor.Cli/Commands/HookBudget.cs index e1d5e30603..efade6e6ca 100644 --- a/src/Capacitor.Cli/Commands/HookBudget.cs +++ b/src/Capacitor.Cli/Commands/HookBudget.cs @@ -6,6 +6,11 @@ namespace Capacitor.Cli.Commands; /// Per-event hook-timeout ceilings (mirror kcap/hooks/hooks.json) and a /// safety-adjusted "remaining" computed from a process-start timestamp, so the /// hook always leaves time to spool + exit before Claude's kill. +/// +/// Claude honours the hooks.json timeout for every event except SessionEnd, which it +/// caps at 1.5 s for plugin hooks; that hook hands off to a detached continuation +/// (), and the 15 s here is the +/// continuation's budget, not the hook's. /// public static class HookBudget { public static readonly TimeSpan Safety = TimeSpan.FromMilliseconds(1500); diff --git a/src/Capacitor.Cli/Harness/Claude/ClaudeSessionEndHandoff.cs b/src/Capacitor.Cli/Harness/Claude/ClaudeSessionEndHandoff.cs new file mode 100644 index 0000000000..44e87dd825 --- /dev/null +++ b/src/Capacitor.Cli/Harness/Claude/ClaudeSessionEndHandoff.cs @@ -0,0 +1,113 @@ +using System.Diagnostics; +using System.Text.Json.Nodes; +using Capacitor.Cli.Core; + +namespace Capacitor.Cli.Harness.Claude; + +/// +/// Hands the Claude SessionEnd event to a detached re-invocation of this hook so the hook +/// itself returns at once: Claude Code caps a plugin's SessionEnd hook at 1.5 s regardless of +/// the hooks.json timeout, and the session-end path cannot fit. The continuation runs that +/// path unchanged under its 15 s budget. Reasoning in docs/CHANGES.md. +/// +static class ClaudeSessionEndHandoff { + public const string DetachedFlag = "--detached"; + + public static bool IsDetached(string[] args) => args.Contains(DetachedFlag); + + public static bool ShouldHandOff(string[] args, string body) => !IsDetached(args) && IsSessionEnd(body); + + static bool IsSessionEnd(string body) { + try { + var name = JsonNode.Parse(body)?["hook_event_name"]?.GetValue(); + + return name is not null + && name.Replace("-", "").Replace("_", "").Equals("sessionend", StringComparison.OrdinalIgnoreCase); + } catch { + return false; + } + } + + /// + /// Starts the detached continuation and feeds it . False when that did + /// not fully happen — the caller then runs the event inline, as before. + /// + public static bool TrySpawn(string[] args, string body) { + Process? process = null; + + try { + var psi = new ProcessStartInfo(Environment.ProcessPath ?? "kcap") { + RedirectStandardInput = true, + RedirectStandardOutput = true, + RedirectStandardError = true, + UseShellExecute = false, + CreateNoWindow = true, + }; + + foreach (var arg in args) psi.ArgumentList.Add(arg); + psi.ArgumentList.Add(DetachedFlag); + + // Same pipe-leak hazard as the watcher spawn: the child must not hold Claude's hook + // pipes open, or Claude waits on them past the hook's own exit. + ProcessHelpers.PreventInheritedHandles(); + + process = WatcherManager.StartProcess(psi); + + if (process is null) { + Console.Error.WriteLine("[kcap] session-end hand-off: failed to start the detached continuation; running inline"); + + return false; + } + + process.StandardInput.Write(body); + process.StandardInput.Close(); + process.StandardOutput.Close(); + process.StandardError.Close(); + + return true; + } catch (Exception ex) { + Console.Error.WriteLine($"[kcap] session-end hand-off failed: {ex.Message}; running inline"); + + // A child that started but never got the full payload must not outlive this failure: + // the inline path is about to do the work, and two owners would double-post. + try { process?.Kill(entireProcessTree: true); } catch { } + + return false; + } finally { + process?.Dispose(); + } + } + + /// + /// The continuation's own setup: output to the session log (its pipes are already closed) and + /// out of the terminal's session so a closing window cannot SIGHUP it mid-drain. + /// + public static void EnterDetached(string body) { + TextWriter writer; + + try { + var logDir = PathHelpers.ConfigPath("logs"); + Directory.CreateDirectory(logDir); + writer = new StreamWriter(Path.Combine(logDir, $"{LogName(body)}.log"), append: true) { AutoFlush = true }; + } catch { + writer = TextWriter.Null; + } + + Console.SetOut(writer); + Console.SetError(writer); + + ProcessHelpers.DetachFromControllingTerminal(); + } + + // The watcher's log name for a well-formed id, so the two interleave in one file; anything + // else (the id is payload data) stays inside the logs directory under a fixed name. + internal static string LogName(string body) { + try { + var sessionId = JsonNode.Parse(body)?["session_id"]?.GetValue()?.Replace("-", ""); + + if (sessionId is { Length: > 0 } && sessionId.All(char.IsAsciiLetterOrDigit)) return sessionId; + } catch { } + + return "claude-session-end"; + } +} diff --git a/src/Capacitor.Cli/Program.cs b/src/Capacitor.Cli/Program.cs index a7a0cb9c94..1bf58ae89c 100644 --- a/src/Capacitor.Cli/Program.cs +++ b/src/Capacitor.Cli/Program.cs @@ -77,6 +77,19 @@ var hookProcessStart = System.Diagnostics.Stopwatch.GetTimestamp(); var isHook = command == "hook"; +// Claude kills a SessionEnd hook after 1.5 s (ClaudeSessionEndHandoff), so the hand-off sits +// ahead of ResolveServerUrl's git probes and the global spool drain, each of which can spend it. +string? claudeHookBody = null; +if (isHook && args.Contains("--claude")) { + try { claudeHookBody = await Console.In.ReadToEndAsync(); } catch { claudeHookBody = ""; } + + if (ClaudeSessionEndHandoff.IsDetached(args)) { + ClaudeSessionEndHandoff.EnterDetached(claudeHookBody); + } else if (ClaudeSessionEndHandoff.ShouldHandOff(args, claudeHookBody) && ClaudeSessionEndHandoff.TrySpawn(args, claudeHookBody)) { + return 0; + } +} + // Agent-spawned commands owe an output contract, or must leave no orphaned child, so an unusable // server URL must not kill them mid-contract — EnsureAbsolute throws for them instead of exiting. // Interactive commands keep exiting 2 with the actionable hint, which is the right UX with a user @@ -798,7 +811,7 @@ await AgentHookPoster.DrainSpoolsAsync( sessionId: null); // current session unknown here — reading stdin now would consume it } if (args.Contains("--claude")) { - return await ClaudeHookCommand.Handle(baseUrl!, Console.In, processStart: hookProcessStart); + return await ClaudeHookCommand.Handle(baseUrl!, new StringReader(claudeHookBody!), processStart: hookProcessStart); } if (args.Contains("--codex")) { return await CodexHookCommand.Handle(baseUrl!, Console.In, hookProcessStart); diff --git a/src/Capacitor.Cli/WatcherManager.cs b/src/Capacitor.Cli/WatcherManager.cs index 5a642e55dc..c196f034fb 100644 --- a/src/Capacitor.Cli/WatcherManager.cs +++ b/src/Capacitor.Cli/WatcherManager.cs @@ -50,8 +50,8 @@ internal static string GetWatcherDir() { internal static Func? SpawnOverrideForTesting; /// - /// Test seam for the ACTUAL Process.Start call inside and - /// . Distinct from , + /// Test seam for the ACTUAL Process.Start call inside , + /// and ClaudeSessionEndHandoff.TrySpawn. Distinct from , /// which only SpawnForKeyAsync consults and so cannot observe those methods at all. /// /// Needed because both call static Process.Start inside a catch-all, and the finalize @@ -63,7 +63,7 @@ internal static string GetWatcherDir() { /// internal static Func? ProcessStarterForTesting; - static Process? StartProcess(ProcessStartInfo psi) => + internal static Process? StartProcess(ProcessStartInfo psi) => ProcessStarterForTesting is { } fake ? fake(psi) : Process.Start(psi); internal static string BuildSpawnArgs( diff --git a/test/Capacitor.Cli.Tests.Integration/ClaudeSessionEndHandoffTests.cs b/test/Capacitor.Cli.Tests.Integration/ClaudeSessionEndHandoffTests.cs new file mode 100644 index 0000000000..9a6539adad --- /dev/null +++ b/test/Capacitor.Cli.Tests.Integration/ClaudeSessionEndHandoffTests.cs @@ -0,0 +1,89 @@ +using System.Diagnostics; +using System.Text.Json.Nodes; +using Capacitor.Cli.Core; +using WireMock.RequestBuilders; +using WireMock.ResponseBuilders; +using WireMock.Server; + +namespace Capacitor.Cli.Tests.Integration; + +/// +/// Real-binary proof that the Claude SessionEnd hook returns inside Claude Code's 1.5 s grace +/// while the session-end still reaches the server. The server stalls /hooks/session-end +/// for longer than the hook is allowed to live, so the only way the POST can arrive is from a +/// process that outlived the hook. +/// +public class ClaudeSessionEndHandoffTests : IDisposable { + static readonly TimeSpan ServerStall = TimeSpan.FromSeconds(3); + + [TempDir] public required TempDir Tmp { get; init; } + [TempDaemonPaths] public required TempDaemonStore Daemons { get; init; } + + readonly WireMockServer _server = WireMockServer.Start(); + + public void Dispose() => _server.Stop(); + + [Test] + public async Task Hook_returns_at_once_and_the_detached_continuation_posts_session_end() { + var sid = Guid.NewGuid().ToString("N"); + var transcript = Tmp.CreateFile("t.jsonl", """{"type":"user","uuid":"u1","message":{"role":"user","content":"hi"}}""" + "\n"); + var configDir = Tmp.CreateDir("cfg"); + + _server.Given(Request.Create().WithPath("/hooks/session-end").UsingPost()) + .RespondWith(Response.Create().WithStatusCode(200).WithBody("{}").WithDelay(ServerStall)); + _server.Given(Request.Create().WithPath("/hooks/transcript").UsingPost()) + .RespondWith(Response.Create().WithStatusCode(200).WithBody("""{"processed":0}""")); + + var psi = KcapProcess.StartInfo(Daemons.Store, "hook", "--claude", "--no-update-check"); + psi.WorkingDirectory = Tmp.Path; + psi.Environment["KCAP_CONFIG_DIR"] = configDir; + psi.Environment["KCAP_URL"] = _server.Url!; + + var payload = new JsonObject { + ["hook_event_name"] = "SessionEnd", + ["session_id"] = sid, + ["transcript_path"] = transcript, + ["cwd"] = Tmp.Path, + ["reason"] = "exit", + }.ToJsonString(); + + var clock = Stopwatch.StartNew(); + using var hook = Process.Start(psi) ?? throw new InvalidOperationException("Failed to start kcap"); + await hook.StandardInput.WriteAsync(payload); + hook.StandardInput.Close(); + var stdout = hook.StandardOutput.ReadToEndAsync(); + var stderr = hook.StandardError.ReadToEndAsync(); + await hook.WaitForExitAsync(); + clock.Stop(); + + await Assert.That(hook.ExitCode).IsEqualTo(0).Because(await stderr); + await Assert.That(await stdout).IsEmpty(); + // The ticket's bar: well inside the 1.5 s grace, on a session with a transcript to drain. + await Assert.That(clock.Elapsed).IsLessThan(TimeSpan.FromSeconds(1)).Because($"stderr: {await stderr}"); + + // The hook is gone; the continuation has today's 15 s budget and must wait out the stall. + var posted = await WaitForSessionEndAsync(TimeSpan.FromSeconds(20)); + + await Assert.That(posted).IsNotNull().Because("no /hooks/session-end reached the server"); + await Assert.That(posted!["session_id"]?.GetValue()).IsEqualTo(sid); + await Assert.That(posted["reason"]?.GetValue()).IsEqualTo("exit"); + await Assert.That(posted["ended_at"]?.GetValue()).IsNotNull(); + + // The continuation's output lands in the session log, where the watcher's already goes. + var log = Path.Combine(configDir, "logs", $"{sid}.log"); + await Assert.That(File.Exists(log)).IsTrue(); + await Assert.That(SharedFileText.ReadAllText(log)).Contains($"Inline drain for {sid}"); + } + + async Task WaitForSessionEndAsync(TimeSpan budget) { + var deadline = DateTime.UtcNow + budget; + + while (DateTime.UtcNow < deadline) { + var entries = _server.FindLogEntries(Request.Create().WithPath("/hooks/session-end").UsingPost()); + if (entries.Count > 0) return JsonNode.Parse(entries[0].RequestMessage.Body!); + await Task.Delay(100); + } + + return null; + } +} diff --git a/test/Capacitor.Cli.Tests.Unit/Harness/Claude/ClaudeSessionEndHandoffTests.cs b/test/Capacitor.Cli.Tests.Unit/Harness/Claude/ClaudeSessionEndHandoffTests.cs new file mode 100644 index 0000000000..6405bb921e --- /dev/null +++ b/test/Capacitor.Cli.Tests.Unit/Harness/Claude/ClaudeSessionEndHandoffTests.cs @@ -0,0 +1,149 @@ +using System.Diagnostics; +using Capacitor.Cli.Harness.Claude; + +namespace Capacitor.Cli.Tests.Unit.Harness.Claude; + +/// +/// Claude Code gives a plugin-sourced SessionEnd hook 1.5 s, so the hook must hand the real +/// work to a detached continuation and return. These cover the hand-off decision and the shape +/// of the spawned process; the end-to-end timing lives in the integration suite. +/// +// Bare: WatcherManager.ProcessStarterForTesting is a mutable production static that every +// spawn path reads, and Dispose resets it. +[NotInParallel] +public class ClaudeSessionEndHandoffTests : IDisposable { + static readonly string[] HookArgs = ["hook", "--claude", "--no-update-check"]; + + const string SessionEndBody = + """{"hook_event_name":"SessionEnd","session_id":"9dc27753-7645-4e46-91ec-c2d69973c152","reason":"exit"}"""; + + public void Dispose() => WatcherManager.ProcessStarterForTesting = null; + + [Test] + [Arguments("SessionEnd")] + [Arguments("session-end")] + [Arguments("session_end")] + public async Task SessionEnd_is_handed_off(string eventName) { + var body = $$"""{"hook_event_name":"{{eventName}}","session_id":"abc"}"""; + + await Assert.That(ClaudeSessionEndHandoff.ShouldHandOff(HookArgs, body)).IsTrue(); + } + + [Test] + [Arguments("""{"hook_event_name":"SessionStart","session_id":"abc"}""")] + [Arguments("""{"hook_event_name":"Stop","session_id":"abc"}""")] + [Arguments("""{"hook_event_name":"SubagentStop","session_id":"abc"}""")] + [Arguments("""{"session_id":"abc"}""")] + [Arguments("not json")] + [Arguments("")] + public async Task Other_events_and_malformed_payloads_stay_inline(string body) { + await Assert.That(ClaudeSessionEndHandoff.ShouldHandOff(HookArgs, body)).IsFalse(); + } + + [Test] + public async Task The_detached_continuation_never_hands_off_again() { + string[] detached = [..HookArgs, ClaudeSessionEndHandoff.DetachedFlag]; + + await Assert.That(ClaudeSessionEndHandoff.IsDetached(detached)).IsTrue(); + await Assert.That(ClaudeSessionEndHandoff.ShouldHandOff(detached, SessionEndBody)).IsFalse(); + } + + [Test] + public async Task Spawn_reinvokes_this_binary_with_the_hook_args_plus_the_detached_flag() { + ProcessStartInfo? seen = null; + WatcherManager.ProcessStarterForTesting = psi => { seen = psi; return null; }; + + var spawned = ClaudeSessionEndHandoff.TrySpawn(HookArgs, SessionEndBody); + + // A null start is a failed spawn: the caller falls back to the inline path. + await Assert.That(spawned).IsFalse(); + await Assert.That(seen).IsNotNull(); + await Assert.That(seen!.FileName).IsEqualTo(Environment.ProcessPath); + await Assert.That(seen.ArgumentList).IsEquivalentTo(["hook", "--claude", "--no-update-check", ClaudeSessionEndHandoff.DetachedFlag]); + // Detached from Claude's pipes: every std stream is a private pipe the hook closes at once. + await Assert.That(seen.RedirectStandardInput).IsTrue(); + await Assert.That(seen.RedirectStandardOutput).IsTrue(); + await Assert.That(seen.RedirectStandardError).IsTrue(); + await Assert.That(seen.UseShellExecute).IsFalse(); + // The continuation resolves the server URL itself, from the same cwd — the hook skipped + // that work, so it has nothing to hand down. + await Assert.That(seen.Environment.TryGetValue("KCAP_URL", out var url) ? url : null) + .IsEqualTo(Environment.GetEnvironmentVariable("KCAP_URL")); + await Assert.That(seen.WorkingDirectory).IsEqualTo(""); + } + + [Test] + public async Task Spawn_pipes_the_hook_payload_to_the_continuation_stdin() { + Skip.When(OperatingSystem.IsWindows(), "uses /bin/sh to stand in for the continuation"); + + using var tmp = new TempDir(); + var sink = tmp.PathTo("stdin.txt"); + + // Stand in for the kcap continuation with a shell that copies stdin to a file, keeping the + // redirects the hand-off asked for so the write path under test is the real one. + WatcherManager.ProcessStarterForTesting = psi => { + var stub = new ProcessStartInfo("/bin/sh") { + RedirectStandardInput = psi.RedirectStandardInput, + RedirectStandardOutput = psi.RedirectStandardOutput, + RedirectStandardError = psi.RedirectStandardError, + UseShellExecute = false, + }; + stub.ArgumentList.Add("-c"); + stub.ArgumentList.Add($"cat > '{sink}'"); + return Process.Start(stub); + }; + + var spawned = ClaudeSessionEndHandoff.TrySpawn(HookArgs, SessionEndBody); + + await Assert.That(spawned).IsTrue(); + + var deadline = DateTime.UtcNow.AddSeconds(10); + while (DateTime.UtcNow < deadline && (!File.Exists(sink) || new FileInfo(sink).Length < SessionEndBody.Length)) + await Task.Delay(50); + + await Assert.That(File.ReadAllText(sink)).IsEqualTo(SessionEndBody); + } + + [Test] + public async Task Spawn_failure_is_reported_not_thrown() { + WatcherManager.ProcessStarterForTesting = _ => throw new InvalidOperationException("no exec"); + + await Assert.That(ClaudeSessionEndHandoff.TrySpawn(HookArgs, SessionEndBody)).IsFalse(); + } + + [Test] + public async Task A_child_that_never_receives_the_payload_is_killed_before_the_inline_fallback() { + Skip.When(OperatingSystem.IsWindows(), "uses /bin/sh to stand in for the continuation"); + + // A started child whose stdin was not redirected: the payload write throws after the + // process exists, the shape of any post-start failure. + var pid = 0; + var identity = ""; + WatcherManager.ProcessStarterForTesting = _ => { + var stub = new ProcessStartInfo("/bin/sh") { UseShellExecute = false }; + stub.ArgumentList.Add("-c"); + stub.ArgumentList.Add("sleep 30"); + var child = Process.Start(stub)!; + // TrySpawn disposes its handle, so the pid plus start identity is captured here. + pid = child.Id; + identity = PidIdentity.Capture(pid); + return child; + }; + + var spawned = ClaudeSessionEndHandoff.TrySpawn(HookArgs, SessionEndBody); + + await Assert.That(spawned).IsFalse(); + await Assert.That(pid).IsNotEqualTo(0); + await PidIdentity.WaitUntilGoneAsync(pid, identity, TimeSpan.FromSeconds(10)); + } + + [Test] + [Arguments("""{"session_id":"9dc27753-7645-4e46-91ec-c2d69973c152"}""", "9dc2775376454e4691ecc2d69973c152")] + [Arguments("""{"session_id":"../../etc/passwd"}""", "claude-session-end")] + [Arguments("""{"session_id":""}""", "claude-session-end")] + [Arguments("""{}""", "claude-session-end")] + [Arguments("not json", "claude-session-end")] + public async Task Log_name_is_the_watcher_key_or_a_fixed_name(string body, string expected) { + await Assert.That(ClaudeSessionEndHandoff.LogName(body)).IsEqualTo(expected); + } +}