hook: log gate decision and agent spawn outcomes

The old hook was silent about why it did or didn't launch an agent —
when nothing fired, it was impossible to tell whether the event was
gated out, a pending chunk was served, or spawn_agent silently
returned None. Logs now cover each of those cases:

  hook_event=... surface_hooks=[...] gated_in=true/false
  serving pending chunk (N bytes); skipping agent cycles
  surface-observe: spawned pid 501605 (log: ...)
  surface-observe: spawn_agent returned None
  surface-observe: skipped — pid 501605 in phase "surface"

Rename surface_phase_busy to surface_phase_blocker and have it
return the pid + phase that's blocking, so stale-pid scenarios are
diagnosable from the log instead of needing a live ps walk.

Co-Authored-By: Proof of Concept <poc@bcachefs.org>
This commit is contained in:
ProofOfConcept 2026-04-16 18:38:50 -04:00
commit 199ce0ecdc
3 changed files with 221 additions and 30 deletions

188
Cargo.lock generated
View file

@ -492,11 +492,13 @@ dependencies = [
"http-body-util", "http-body-util",
"hyper", "hyper",
"hyper-util", "hyper-util",
"imagesize",
"json-five", "json-five",
"libc", "libc",
"log", "log",
"memchr", "memchr",
"memmap2", "memmap2",
"notify-debouncer-mini",
"paste", "paste",
"peg", "peg",
"ratatui", "ratatui",
@ -1038,6 +1040,15 @@ version = "1.3.0"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "42703706b716c37f96a77aea830392ad231f44c9e9a67872fa5548707e11b11c" checksum = "42703706b716c37f96a77aea830392ad231f44c9e9a67872fa5548707e11b11c"
[[package]]
name = "fsevent-sys"
version = "4.1.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "76ee7a02da4d231650c7cea31349b889be2f45ddb3ef3032d2ec8185f6313fd2"
dependencies = [
"libc",
]
[[package]] [[package]]
name = "futures" name = "futures"
version = "0.3.32" version = "0.3.32"
@ -1363,6 +1374,12 @@ dependencies = [
"winapi-util", "winapi-util",
] ]
[[package]]
name = "imagesize"
version = "0.14.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "09e54e57b4c48b40f7aec75635392b12b3421fa26fe8b4332e63138ed278459c"
[[package]] [[package]]
name = "indexmap" name = "indexmap"
version = "2.14.0" version = "2.14.0"
@ -1403,6 +1420,26 @@ version = "0.1.15"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c8fae54786f62fb2918dcfae3d568594e50eb9b5c25bf04371af6fe7516452fb" checksum = "c8fae54786f62fb2918dcfae3d568594e50eb9b5c25bf04371af6fe7516452fb"
[[package]]
name = "inotify"
version = "0.11.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "bd5b3eaf1a28b758ac0faa5a4254e8ab2705605496f1b1f3fbbc3988ad73d199"
dependencies = [
"bitflags 2.11.0",
"inotify-sys",
"libc",
]
[[package]]
name = "inotify-sys"
version = "0.1.5"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "e05c02b5e89bff3b946cedeca278abc628fe811e604f027c45a8aa3cf793d0eb"
dependencies = [
"libc",
]
[[package]] [[package]]
name = "instability" name = "instability"
version = "0.3.12" version = "0.3.12"
@ -1502,6 +1539,26 @@ dependencies = [
"thiserror 2.0.18", "thiserror 2.0.18",
] ]
[[package]]
name = "kqueue"
version = "1.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "eac30106d7dce88daf4a3fcb4879ea939476d5074a9b7ddd0fb97fa4bed5596a"
dependencies = [
"kqueue-sys",
"libc",
]
[[package]]
name = "kqueue-sys"
version = "1.0.4"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ed9625ffda8729b85e45cf04090035ac368927b8cebc34898e7c120f52e4838b"
dependencies = [
"bitflags 1.3.2",
"libc",
]
[[package]] [[package]]
name = "lab" name = "lab"
version = "0.11.0" version = "0.11.0"
@ -1724,6 +1781,45 @@ dependencies = [
"memchr", "memchr",
] ]
[[package]]
name = "notify"
version = "8.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "4d3d07927151ff8575b7087f245456e549fea62edf0ec4e565a5ee50c8402bc3"
dependencies = [
"bitflags 2.11.0",
"fsevent-sys",
"inotify",
"kqueue",
"libc",
"log",
"mio",
"notify-types",
"walkdir",
"windows-sys 0.60.2",
]
[[package]]
name = "notify-debouncer-mini"
version = "0.7.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "17849edfaabd9a5fef1c606d99cfc615a8e99f7ac4366406d86c7942a3184cf2"
dependencies = [
"log",
"notify",
"notify-types",
"tempfile",
]
[[package]]
name = "notify-types"
version = "2.1.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "42b8cfee0e339a0337359f3c88165702ac6e600dc01c0cc9579a92d62b08477a"
dependencies = [
"bitflags 2.11.0",
]
[[package]] [[package]]
name = "num-conv" name = "num-conv"
version = "0.2.1" version = "0.2.1"
@ -3740,7 +3836,16 @@ version = "0.52.0"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "282be5f36a8ce781fad8c8ae18fa3f9beff57ec1b52cb3de0789201425d9a33d" checksum = "282be5f36a8ce781fad8c8ae18fa3f9beff57ec1b52cb3de0789201425d9a33d"
dependencies = [ dependencies = [
"windows-targets", "windows-targets 0.52.6",
]
[[package]]
name = "windows-sys"
version = "0.60.2"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f2f500e4d28234f72040990ec9d39e3a6b950f9f22d3dba18416c35882612bcb"
dependencies = [
"windows-targets 0.53.5",
] ]
[[package]] [[package]]
@ -3758,14 +3863,31 @@ version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "9b724f72796e036ab90c1021d4780d4d3d648aca59e491e6b98e725b84e99973" checksum = "9b724f72796e036ab90c1021d4780d4d3d648aca59e491e6b98e725b84e99973"
dependencies = [ dependencies = [
"windows_aarch64_gnullvm", "windows_aarch64_gnullvm 0.52.6",
"windows_aarch64_msvc", "windows_aarch64_msvc 0.52.6",
"windows_i686_gnu", "windows_i686_gnu 0.52.6",
"windows_i686_gnullvm", "windows_i686_gnullvm 0.52.6",
"windows_i686_msvc", "windows_i686_msvc 0.52.6",
"windows_x86_64_gnu", "windows_x86_64_gnu 0.52.6",
"windows_x86_64_gnullvm", "windows_x86_64_gnullvm 0.52.6",
"windows_x86_64_msvc", "windows_x86_64_msvc 0.52.6",
]
[[package]]
name = "windows-targets"
version = "0.53.5"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "4945f9f551b88e0d65f3db0bc25c33b8acea4d9e41163edf90dcd0b19f9069f3"
dependencies = [
"windows-link",
"windows_aarch64_gnullvm 0.53.1",
"windows_aarch64_msvc 0.53.1",
"windows_i686_gnu 0.53.1",
"windows_i686_gnullvm 0.53.1",
"windows_i686_msvc 0.53.1",
"windows_x86_64_gnu 0.53.1",
"windows_x86_64_gnullvm 0.53.1",
"windows_x86_64_msvc 0.53.1",
] ]
[[package]] [[package]]
@ -3774,48 +3896,96 @@ version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "32a4622180e7a0ec044bb555404c800bc9fd9ec262ec147edd5989ccd0c02cd3" checksum = "32a4622180e7a0ec044bb555404c800bc9fd9ec262ec147edd5989ccd0c02cd3"
[[package]]
name = "windows_aarch64_gnullvm"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "a9d8416fa8b42f5c947f8482c43e7d89e73a173cead56d044f6a56104a6d1b53"
[[package]] [[package]]
name = "windows_aarch64_msvc" name = "windows_aarch64_msvc"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "09ec2a7bb152e2252b53fa7803150007879548bc709c039df7627cabbd05d469" checksum = "09ec2a7bb152e2252b53fa7803150007879548bc709c039df7627cabbd05d469"
[[package]]
name = "windows_aarch64_msvc"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b9d782e804c2f632e395708e99a94275910eb9100b2114651e04744e9b125006"
[[package]] [[package]]
name = "windows_i686_gnu" name = "windows_i686_gnu"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "8e9b5ad5ab802e97eb8e295ac6720e509ee4c243f69d781394014ebfe8bbfa0b" checksum = "8e9b5ad5ab802e97eb8e295ac6720e509ee4c243f69d781394014ebfe8bbfa0b"
[[package]]
name = "windows_i686_gnu"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "960e6da069d81e09becb0ca57a65220ddff016ff2d6af6a223cf372a506593a3"
[[package]] [[package]]
name = "windows_i686_gnullvm" name = "windows_i686_gnullvm"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "0eee52d38c090b3caa76c563b86c3a4bd71ef1a819287c19d586d7334ae8ed66" checksum = "0eee52d38c090b3caa76c563b86c3a4bd71ef1a819287c19d586d7334ae8ed66"
[[package]]
name = "windows_i686_gnullvm"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "fa7359d10048f68ab8b09fa71c3daccfb0e9b559aed648a8f95469c27057180c"
[[package]] [[package]]
name = "windows_i686_msvc" name = "windows_i686_msvc"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "240948bc05c5e7c6dabba28bf89d89ffce3e303022809e73deaefe4f6ec56c66" checksum = "240948bc05c5e7c6dabba28bf89d89ffce3e303022809e73deaefe4f6ec56c66"
[[package]]
name = "windows_i686_msvc"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "1e7ac75179f18232fe9c285163565a57ef8d3c89254a30685b57d83a38d326c2"
[[package]] [[package]]
name = "windows_x86_64_gnu" name = "windows_x86_64_gnu"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "147a5c80aabfbf0c7d901cb5895d1de30ef2907eb21fbbab29ca94c5b08b1a78" checksum = "147a5c80aabfbf0c7d901cb5895d1de30ef2907eb21fbbab29ca94c5b08b1a78"
[[package]]
name = "windows_x86_64_gnu"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "9c3842cdd74a865a8066ab39c8a7a473c0778a3f29370b5fd6b4b9aa7df4a499"
[[package]] [[package]]
name = "windows_x86_64_gnullvm" name = "windows_x86_64_gnullvm"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "24d5b23dc417412679681396f2b49f3de8c1473deb516bd34410872eff51ed0d" checksum = "24d5b23dc417412679681396f2b49f3de8c1473deb516bd34410872eff51ed0d"
[[package]]
name = "windows_x86_64_gnullvm"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "0ffa179e2d07eee8ad8f57493436566c7cc30ac536a3379fdf008f47f6bb7ae1"
[[package]] [[package]]
name = "windows_x86_64_msvc" name = "windows_x86_64_msvc"
version = "0.52.6" version = "0.52.6"
source = "registry+https://github.com/rust-lang/crates.io-index" source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "589f6da84c646204747d1270a2a5661ea66ed1cced2631d546fdfb155959f9ec" checksum = "589f6da84c646204747d1270a2a5661ea66ed1cced2631d546fdfb155959f9ec"
[[package]]
name = "windows_x86_64_msvc"
version = "0.53.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d6bbff5f0aada427a1e5a6da5f1f98158182f26556f345ac9e04d36d0ebed650"
[[package]] [[package]]
name = "wit-bindgen" name = "wit-bindgen"
version = "0.51.0" version = "0.51.0"

View file

@ -259,17 +259,25 @@ impl AgentCycleState {
// to start while an older agent finishes out its post-surface // to start while an older agent finishes out its post-surface
// phases is the whole point — surface can run at a higher cadence // phases is the whole point — surface can run at a higher cadence
// than the full organize/observe tail. // than the full organize/observe tail.
if surface_phase_busy(&state_dir) { if let Some((blocking_pid, phase)) = surface_phase_blocker(&state_dir) {
self.log(format_args!("surface-observe already in surface phase\n")); self.log(format_args!(
"surface-observe: skipped — pid {} in phase {:?}\n", blocking_pid, phase));
} else { } else {
if transcript.size > 0 { if transcript.size > 0 {
fs::write(&offset_path, transcript.size.to_string()).ok(); fs::write(&offset_path, transcript.size.to_string()).ok();
} }
if let Some(result) = consciousness::agent::oneshot::spawn_agent( match consciousness::agent::oneshot::spawn_agent(
"surface-observe", &state_dir, &session.session_id) { "surface-observe", &state_dir, &session.session_id) {
self.log(format_args!("spawned surface-observe pid {}\n", result.child.id())); Some(result) => {
self.log(format_args!(
"surface-observe: spawned pid {} (log: {})\n",
result.child.id(), result.log_path.display()));
self.agent_spawned("surface-observe", "surface", result); self.agent_spawned("surface-observe", "surface", result);
} }
None => {
self.log(format_args!("surface-observe: spawn_agent returned None\n"));
}
}
} }
(surfaced_keys, None) (surfaced_keys, None)
@ -309,11 +317,15 @@ impl AgentCycleState {
} }
fs::write(&offset_path, transcript.size.to_string()).ok(); fs::write(&offset_path, transcript.size.to_string()).ok();
if let Some(result) = consciousness::agent::oneshot::spawn_agent( match consciousness::agent::oneshot::spawn_agent(
"reflect", &state_dir, &session.session_id) { "reflect", &state_dir, &session.session_id) {
self.log(format_args!("reflect: spawned pid {}\n", result.child.id())); Some(result) => {
self.log(format_args!("reflect: spawned pid {} (log: {})\n",
result.child.id(), result.log_path.display()));
self.agent_spawned("reflect", "step-0", result); self.agent_spawned("reflect", "step-0", result);
} }
None => self.log(format_args!("reflect: spawn_agent returned None\n")),
}
reflection reflection
} }
@ -338,33 +350,38 @@ impl AgentCycleState {
} }
fs::write(&offset_path, transcript.size.to_string()).ok(); fs::write(&offset_path, transcript.size.to_string()).ok();
if let Some(result) = consciousness::agent::oneshot::spawn_agent( match consciousness::agent::oneshot::spawn_agent(
"journal", &state_dir, &session.session_id) { "journal", &state_dir, &session.session_id) {
self.log(format_args!("journal: spawned pid {}\n", result.child.id())); Some(result) => {
self.log(format_args!("journal: spawned pid {} (log: {})\n",
result.child.id(), result.log_path.display()));
self.agent_spawned("journal", "step-0", result); self.agent_spawned("journal", "step-0", result);
} }
None => self.log(format_args!("journal: spawn_agent returned None\n")),
}
} }
} }
/// Is there a live agent in `state_dir` currently in the "surface" phase? /// If a live agent in `state_dir` is currently in the "surface" phase,
/// Inspects pid-<N> files; their content is the phase string, kept fresh /// return its pid + phase string. Inspects pid-<N> files; their content
/// by bail-no-competing.sh on each step transition. /// is the phase string, kept fresh by bail-no-competing.sh on each step
fn surface_phase_busy(state_dir: &Path) -> bool { /// transition. Stale pid files (process already dead) are ignored.
let Ok(entries) = fs::read_dir(state_dir) else { return false; }; fn surface_phase_blocker(state_dir: &Path) -> Option<(i32, String)> {
let entries = fs::read_dir(state_dir).ok()?;
for entry in entries.flatten() { for entry in entries.flatten() {
let fname = entry.file_name(); let fname = entry.file_name();
let fname_s = fname.to_string_lossy(); let fname_s = fname.to_string_lossy();
let Some(pid_str) = fname_s.strip_prefix("pid-") else { continue; }; let Some(pid_str) = fname_s.strip_prefix("pid-") else { continue; };
let Ok(pid) = pid_str.parse::<i32>() else { continue; }; let Ok(pid) = pid_str.parse::<i32>() else { continue; };
// Is the process alive?
let alive = unsafe { libc::kill(pid, 0) } == 0; let alive = unsafe { libc::kill(pid, 0) } == 0;
if !alive { continue; } if !alive { continue; }
let phase = fs::read_to_string(entry.path()).unwrap_or_default(); let phase = fs::read_to_string(entry.path()).unwrap_or_default();
if phase.trim() == "surface" { let phase = phase.trim().to_string();
return true; if phase == "surface" {
return Some((pid, phase));
} }
} }
false None
} }
/// Format agent cycle output for injection into a Claude Code session. /// Format agent cycle output for injection into a Claude Code session.

View file

@ -188,10 +188,14 @@ fn hook(session: &HookSession) -> String {
} }
if let Some(chunk) = pop_pending_chunk(&session.state_dir, &session.session_id) { if let Some(chunk) = pop_pending_chunk(&session.state_dir, &session.session_id) {
let _ = writeln!(log_f, "serving pending chunk ({} bytes); skipping agent cycles", chunk.len());
out.push_str(&chunk); out.push_str(&chunk);
} else { } else {
let cfg = consciousness::config::get(); let cfg = consciousness::config::get();
if cfg.surface_hooks.iter().any(|h| h == &session.hook_event) { let gated_in = cfg.surface_hooks.iter().any(|h| h == &session.hook_event);
let _ = writeln!(log_f, "hook_event={} surface_hooks={:?} gated_in={}",
session.hook_event, cfg.surface_hooks, gated_in);
if gated_in {
let cycle_output = run_agent_cycles(&session); let cycle_output = run_agent_cycles(&session);
out.push_str(&format_agent_output(&cycle_output)); out.push_str(&format_agent_output(&cycle_output));
} }