Skip to main content

ljos_cli/
hookd.rs

1//! One admission point for `ljos hook`. Every tool call on a host used to
2//! start a full hook process at once, so a burst of thirty calls from six
3//! seats was thirty processes contending for the same CPUs and memory.
4//! `ljos hookd`, one per user, hands out a fixed number of slots over a
5//! unix socket, in the order the calls asked. A gate that gets no slot
6//! is judged in this process: the queue allows, it does not deny.
7//!
8//! The judging stays in the calling process. The guard reads that
9//! process's parent, session and cgroup to tell the runner's call from a
10//! tool's, and a server judging on its behalf would have to take the
11//! caller's word for all of them.
12//!
13//! When no server answers, the first call starts one, and the calls that
14//! meet no server take one host-wide lock in turn. A missing server costs
15//! throughput, never the cap.
16
17use std::io::{BufRead, BufReader, Read, Write};
18use std::os::unix::fs::{MetadataExt, OpenOptionsExt, PermissionsExt};
19use std::os::unix::io::AsRawFd;
20use std::os::unix::net::{UnixListener, UnixStream};
21use std::path::{Path, PathBuf};
22use std::sync::atomic::{AtomicU64, Ordering};
23use std::sync::{Arc, Condvar, Mutex, OnceLock};
24use std::time::{Duration, Instant};
25
26/// The longest a call waits for a slot. The runner's gate deadline counts
27/// from the call's start, so the wait and the work share that budget.
28pub const ADMIT_MS: u64 = 3_000;
29/// Calls waiting at once before the next one is judged here instead.
30pub const QUEUE_CAP: usize = 64;
31/// A slot held this long is taken back, so a stopped call cannot keep it.
32const HOLD: Duration = Duration::from_secs(10);
33/// An idle server exits after this long; the next call starts another.
34const IDLE: Duration = Duration::from_secs(900);
35/// The timing log is cut back past this size.
36const LOG_CAP: u64 = 256 * 1024;
37/// The longest socket path a `sockaddr_un` takes everywhere ljos runs:
38/// 104 bytes with the NUL on macOS, 108 on Linux.
39const SOCKET_PATH_MAX: usize = 103;
40
41static STARTED: OnceLock<Instant> = OnceLock::new();
42static STDIN: Mutex<Option<Vec<u8>>> = Mutex::new(None);
43static HELD: Mutex<Option<Held>> = Mutex::new(None);
44static WAITED_MS: AtomicU64 = AtomicU64::new(0);
45
46/// What keeps this call's turn: a slot from the server, or the
47/// single-flight lock when there was no server. Dropping it gives the
48/// turn to the next call.
49enum Held {
50    Slot(#[allow(dead_code)] UnixStream),
51    Flight(#[allow(dead_code)] std::fs::File),
52}
53
54/// When this process started its hook call. Deadlines count from here,
55/// so time spent in the queue is spent from the same budget.
56#[must_use]
57pub fn started() -> Instant {
58    *STARTED.get_or_init(Instant::now)
59}
60
61/// What is left of `budget_ms`, counted from [`started`].
62#[must_use]
63pub fn left_of(budget_ms: u64) -> Duration {
64    Duration::from_millis(budget_ms).saturating_sub(started().elapsed())
65}
66
67/// The stdin [`admit`] read to learn the call's event, for the hook to
68/// judge. `None` when admission did not read it.
69#[must_use]
70pub fn take_stdin() -> Option<Vec<u8>> {
71    STDIN
72        .lock()
73        .unwrap_or_else(std::sync::PoisonError::into_inner)
74        .take()
75}
76
77/// Wait for this hook call's turn before any heavy start-up. Returns at
78/// once for anything but a plain `ljos hook`. A gate that gets no turn
79/// within [`ADMIT_MS`], or finds no server, is judged in this process.
80/// That path calls policyd directly. It does not deny for the queue.
81pub fn admit() {
82    let _ = started();
83    let args: Vec<String> = std::env::args().skip(1).collect();
84    if !admitted_command(&args)
85        || std::env::var_os("LJOS_IN_HOOK").is_some()
86        || std::env::var("LJOS_HOOKD").is_ok_and(|v| v == "off")
87    {
88        return;
89    }
90    let mut bytes = Vec::new();
91    if std::io::stdin().read_to_end(&mut bytes).is_err() {
92        return;
93    }
94    let event = flag_value(&args, "--event");
95    if !args.iter().any(|a| a == "--prompt") {
96        if let Some(code) = crate::answer_cursor_read_bytes(&bytes) {
97            std::process::exit(code);
98        }
99    }
100    let input = String::from_utf8_lossy(&bytes).into_owned();
101    *STDIN
102        .lock()
103        .unwrap_or_else(std::sync::PoisonError::into_inner) = Some(bytes);
104    // These two events are judged on preToolUse. Answer them before a
105    // slot, so a slow server cannot turn an allow into exit 2.
106    // The direct path has already loaded the seat env. A promoted rule
107    // may still ask the pack once. Record the call first: a bare seat
108    // binds the conversation from that record after this process exits.
109    if !args.iter().any(|a| a == "--prompt") {
110        if let Some((output, code)) = crate::cursor_side_answer(&input, event.as_deref()) {
111            let call = crate::hook_call_as(&input, event.as_deref());
112            crate::bind_call_conversation(&input, &call);
113            let _ = crate::subagent::note_hook_call(&input, &call.event);
114            std::process::exit(crate::emit_side_answer(
115                &input,
116                event.as_deref(),
117                &output,
118                code,
119            ));
120        }
121    }
122    let gate = !args.iter().any(|a| a == "--prompt")
123        && crate::is_gate_event(&crate::hook_call_as(&input, event.as_deref()).event);
124    match wait_turn() {
125        Ok((held, waited)) => {
126            WAITED_MS.store(waited, Ordering::Relaxed);
127            *HELD
128                .lock()
129                .unwrap_or_else(std::sync::PoisonError::into_inner) = Some(held);
130        }
131        Err(why) => {
132            note_time("allowed", started().elapsed(), Duration::ZERO);
133            eprintln!("ljos hook: hook queue: {why}; the call is judged in this process");
134            let _ = (gate, input, event);
135        }
136    }
137}
138
139/// Give this call's turn to the next one and log how long the call took.
140/// The gate's answer calls this once it is written.
141pub fn release() {
142    let held = HELD
143        .lock()
144        .unwrap_or_else(std::sync::PoisonError::into_inner)
145        .take();
146    if held.is_some() {
147        let waited = Duration::from_millis(WAITED_MS.load(Ordering::Relaxed));
148        note_time("hook", started().elapsed(), waited);
149    }
150}
151
152/// Whether `args` (after the program name) are a hook call that reads a
153/// payload and answers it. The git and runner forms, `--text` and the
154/// queue's own verbs are not admitted here.
155fn admitted_command(args: &[String]) -> bool {
156    if args.first().map(String::as_str) != Some("hook") {
157        return false;
158    }
159    !args.iter().skip(1).any(|a| {
160        let name = a.split('=').next().unwrap_or(a);
161        matches!(
162            name,
163            "--text"
164                | "--git-commit"
165                | "--git-hook"
166                | "--brief-once"
167                | "--runner"
168                | "--drain"
169                | "--apply-book"
170                | "-h"
171                | "--help"
172        )
173    })
174}
175
176fn flag_value(args: &[String], flag: &str) -> Option<String> {
177    let mut it = args.iter();
178    while let Some(arg) = it.next() {
179        if arg == flag {
180            return it.next().cloned();
181        }
182        if let Some(value) = arg.strip_prefix(flag).and_then(|r| r.strip_prefix('=')) {
183            return Some(value.to_string());
184        }
185    }
186    None
187}
188
189/// The runtime directory, made private when missing.
190fn run_dir() -> PathBuf {
191    let dir = crate::runtime_dir();
192    if !dir.exists() {
193        use std::os::unix::fs::DirBuilderExt as _;
194        let _ = std::fs::DirBuilder::new()
195            .recursive(true)
196            .mode(0o700)
197            .create(&dir);
198    }
199    dir
200}
201
202fn env_num(key: &str) -> Option<u64> {
203    std::env::var(key).ok()?.trim().parse().ok()
204}
205
206fn admit_budget() -> Duration {
207    Duration::from_millis(env_num("LJOS_HOOK_ADMIT_MS").unwrap_or(ADMIT_MS))
208}
209
210enum Ask {
211    NoServer,
212    Refused(String),
213}
214
215/// A turn from the server, or with no server, the single-flight lock.
216/// The error says why no turn came within the budget.
217fn wait_turn() -> Result<(Held, u64), String> {
218    let dir = run_dir();
219    let sock = dir.join("hookd.sock");
220    let deadline = started() + admit_budget();
221    // No server can listen on a path this long; do not wait for one.
222    if sock.as_os_str().len() > SOCKET_PATH_MAX {
223        return flight(&dir, deadline);
224    }
225    match ask(&sock, deadline) {
226        Ok(turn) => return Ok(turn),
227        Err(Ask::Refused(why)) => return Err(why),
228        Err(Ask::NoServer) => {}
229    }
230    let _starting = start_server(&dir);
231    let retry_until = (Instant::now() + Duration::from_millis(200)).min(deadline);
232    while Instant::now() < retry_until {
233        std::thread::sleep(Duration::from_millis(5));
234        match ask(&sock, deadline) {
235            Ok(turn) => return Ok(turn),
236            Err(Ask::Refused(why)) => return Err(why),
237            Err(Ask::NoServer) => {}
238        }
239    }
240    flight(&dir, deadline)
241}
242
243fn ask(sock: &Path, deadline: Instant) -> Result<(Held, u64), Ask> {
244    let mut stream = UnixStream::connect(sock).map_err(|_| Ask::NoServer)?;
245    let left = deadline.saturating_duration_since(Instant::now());
246    if left.is_zero() {
247        return Err(Ask::Refused(format!(
248            "no slot within {} ms",
249            admit_budget().as_millis()
250        )));
251    }
252    // The server answers `late` at the deadline itself; the margin is for
253    // a server that stopped answering.
254    let _ = stream.set_read_timeout(Some(left + Duration::from_millis(250)));
255    writeln!(stream, "wait {}", left.as_millis()).map_err(|_| Ask::NoServer)?;
256    let mut line = String::new();
257    let mut reader = BufReader::new(stream.try_clone().map_err(|_| Ask::NoServer)?);
258    match reader.read_line(&mut line) {
259        // A server that went away before it answered: the remaining
260        // budget goes to the single-flight lock.
261        Ok(0) => Err(Ask::NoServer),
262        Ok(_) => {
263            let mut words = line.split_whitespace();
264            match (words.next(), words.next()) {
265                (Some("go"), waited) => Ok((
266                    Held::Slot(stream),
267                    waited.and_then(|w| w.parse().ok()).unwrap_or(0),
268                )),
269                (Some("full"), waiting) => Err(Ask::Refused(format!(
270                    "{} hook calls are already waiting for a slot",
271                    waiting.unwrap_or("too many")
272                ))),
273                _ => Err(Ask::Refused(format!(
274                    "no slot came free within {} ms",
275                    admit_budget().as_millis()
276                ))),
277            }
278        }
279        Err(_) => Err(Ask::Refused(format!(
280            "the hook server did not answer within {} ms",
281            admit_budget().as_millis()
282        ))),
283    }
284}
285
286/// The inode, size and mtime of the file at `path`; `None` when it is gone.
287fn binary_stamp(path: &Path) -> Option<(u64, u64, i64)> {
288    let meta = std::fs::metadata(path).ok()?;
289    Some((meta.ino(), meta.len(), meta.mtime()))
290}
291
292fn open_lock(path: &Path) -> Option<std::fs::File> {
293    std::fs::OpenOptions::new()
294        .create(true)
295        .append(true)
296        .mode(0o600)
297        .open(path)
298        .ok()
299}
300
301fn try_flock(file: &std::fs::File) -> bool {
302    // SAFETY: flock on a descriptor `file` owns; the lock goes with it.
303    unsafe { libc::flock(file.as_raw_fd(), libc::LOCK_EX | libc::LOCK_NB) == 0 }
304}
305
306/// Start `ljos hookd` unless another call is starting one. The returned
307/// lock is held while this call waits for the socket, so a burst starts
308/// one server, not one each.
309fn start_server(dir: &Path) -> Option<std::fs::File> {
310    use std::os::unix::process::CommandExt as _;
311    let lock = open_lock(&dir.join("hookd.start"))?;
312    if !try_flock(&lock) {
313        return None;
314    }
315    let exe = std::env::current_exe().ok()?;
316    let mut cmd = std::process::Command::new(exe);
317    cmd.arg("hookd")
318        .env_clear()
319        .stdin(std::process::Stdio::null())
320        .stdout(std::process::Stdio::null())
321        .stderr(std::process::Stdio::null());
322    for key in [
323        "PATH",
324        "HOME",
325        "USER",
326        "XDG_RUNTIME_DIR",
327        "TMPDIR",
328        "LJOS_HOOK_SLOTS",
329        "LJOS_HOOK_QUEUE",
330    ] {
331        if let Some(val) = std::env::var_os(key) {
332            cmd.env(key, val);
333        }
334    }
335    // SAFETY: setsid is async-signal-safe and touches only the child.
336    unsafe {
337        cmd.pre_exec(|| {
338            libc::setsid();
339            Ok(())
340        });
341    }
342    let _ = cmd.spawn();
343    Some(lock)
344}
345
346fn flight(dir: &Path, deadline: Instant) -> Result<(Held, u64), String> {
347    let asked = Instant::now();
348    let Some(file) = open_lock(&dir.join("hookd.flight")) else {
349        return Err("no hook server, and the single-flight lock cannot be opened".into());
350    };
351    loop {
352        if try_flock(&file) {
353            let waited = u64::try_from(asked.elapsed().as_millis()).unwrap_or(u64::MAX);
354            return Ok((Held::Flight(file), waited));
355        }
356        if Instant::now() >= deadline {
357            return Err(format!(
358                "no hook server, and the single-flight lock stayed taken for {} ms",
359                admit_budget().as_millis()
360            ));
361        }
362        std::thread::sleep(Duration::from_millis(5));
363    }
364}
365
366/// How many hook calls may run at once: `LJOS_HOOK_SLOTS`, else the CPU
367/// count between 2 and 8.
368fn slots() -> usize {
369    env_num("LJOS_HOOK_SLOTS")
370        .and_then(|n| usize::try_from(n).ok())
371        .filter(|n| *n > 0)
372        .unwrap_or_else(|| {
373            std::thread::available_parallelism()
374                .map_or(2, std::num::NonZeroUsize::get)
375                .clamp(2, 8)
376        })
377}
378
379fn queue_cap() -> usize {
380    env_num("LJOS_HOOK_QUEUE")
381        .and_then(|n| usize::try_from(n).ok())
382        .unwrap_or(QUEUE_CAP)
383}
384
385struct Turns {
386    running: usize,
387    queue: std::collections::VecDeque<u64>,
388    next: u64,
389    last: Instant,
390}
391
392struct Gate {
393    turns: Mutex<Turns>,
394    moved: Condvar,
395    slots: usize,
396    cap: usize,
397}
398
399impl Gate {
400    fn lock(&self) -> std::sync::MutexGuard<'_, Turns> {
401        self.turns
402            .lock()
403            .unwrap_or_else(std::sync::PoisonError::into_inner)
404    }
405
406    fn idle(&self) -> bool {
407        let turns = self.lock();
408        turns.running == 0 && turns.queue.is_empty() && turns.last.elapsed() > IDLE
409    }
410
411    /// No call holds a slot or waits for one.
412    fn drained(&self) -> bool {
413        let turns = self.lock();
414        turns.running == 0 && turns.queue.is_empty()
415    }
416
417    /// One call: queue it, hand it a slot in order, and take the slot back
418    /// when the caller closes the socket, exits or holds it past [`HOLD`].
419    fn serve(&self, stream: &UnixStream) {
420        let _ = stream.set_read_timeout(Some(Duration::from_secs(1)));
421        let mut line = String::new();
422        if BufReader::new(stream).read_line(&mut line).is_err() {
423            return;
424        }
425        let ms = line
426            .strip_prefix("wait ")
427            .and_then(|v| v.trim().parse().ok())
428            .unwrap_or(ADMIT_MS)
429            .min(crate::CURSOR_GATE_DEADLINE_MS);
430        let asked = Instant::now();
431        let deadline = asked + Duration::from_millis(ms);
432        let mut turns = self.lock();
433        turns.last = asked;
434        if turns.queue.len() >= self.cap {
435            let waiting = turns.queue.len();
436            drop(turns);
437            let _ = writeln!(&mut &*stream, "full {waiting}");
438            return;
439        }
440        let ticket = turns.next;
441        turns.next += 1;
442        turns.queue.push_back(ticket);
443        loop {
444            if turns.queue.front() == Some(&ticket) && turns.running < self.slots {
445                turns.queue.pop_front();
446                turns.running += 1;
447                break;
448            }
449            let left = deadline.saturating_duration_since(Instant::now());
450            if left.is_zero() {
451                turns.queue.retain(|t| *t != ticket);
452                drop(turns);
453                self.moved.notify_all();
454                let _ = writeln!(&mut &*stream, "late");
455                return;
456            }
457            turns = self
458                .moved
459                .wait_timeout(turns, left)
460                .unwrap_or_else(std::sync::PoisonError::into_inner)
461                .0;
462        }
463        drop(turns);
464        self.moved.notify_all();
465        let waited = asked.elapsed().as_millis();
466        if writeln!(&mut &*stream, "go {waited}").is_ok() {
467            let _ = stream.set_read_timeout(Some(HOLD));
468            let mut buf = [0u8; 64];
469            while matches!((&mut &*stream).read(&mut buf), Ok(n) if n > 0) {}
470        }
471        let mut turns = self.lock();
472        turns.running -= 1;
473        turns.last = Instant::now();
474        drop(turns);
475        self.moved.notify_all();
476    }
477}
478
479#[cfg(target_os = "linux")]
480fn same_user(stream: &UnixStream) -> bool {
481    let mut cred = libc::ucred {
482        pid: 0,
483        uid: 0,
484        gid: 0,
485    };
486    let mut len = libc::socklen_t::try_from(std::mem::size_of::<libc::ucred>()).unwrap_or(0);
487    // SAFETY: SO_PEERCRED writes one ucred into `cred`, of `len` bytes.
488    let rc = unsafe {
489        libc::getsockopt(
490            stream.as_raw_fd(),
491            libc::SOL_SOCKET,
492            libc::SO_PEERCRED,
493            std::ptr::addr_of_mut!(cred).cast(),
494            &mut len,
495        )
496    };
497    // SAFETY: geteuid only reads the process identity.
498    rc == 0 && cred.uid == unsafe { libc::geteuid() }
499}
500
501#[cfg(target_os = "macos")]
502fn same_user(stream: &UnixStream) -> bool {
503    let mut uid: libc::uid_t = 0;
504    let mut gid: libc::gid_t = 0;
505    // SAFETY: getpeereid writes the peer's euid and egid into the two locals.
506    let rc = unsafe { libc::getpeereid(stream.as_raw_fd(), &mut uid, &mut gid) };
507    // SAFETY: geteuid only reads the process identity.
508    rc == 0 && uid == unsafe { libc::geteuid() }
509}
510
511#[cfg(not(any(target_os = "linux", target_os = "macos")))]
512fn same_user(_stream: &UnixStream) -> bool {
513    true
514}
515
516/// `ljos hookd`: hand out hook slots on `hookd.sock` in the runtime
517/// directory until idle. A second server finds the lock taken and exits
518/// 0, so starting one is safe at any time. The server also exits when its
519/// socket is removed or replaced.
520#[must_use]
521pub fn serve() -> i32 {
522    let dir = run_dir();
523    let Some(lock) = open_lock(&dir.join("hookd.lock")) else {
524        eprintln!(
525            "ljos hookd: cannot open {}",
526            dir.join("hookd.lock").display()
527        );
528        return 1;
529    };
530    if !try_flock(&lock) {
531        return 0;
532    }
533    let sock = dir.join("hookd.sock");
534    let _ = std::fs::remove_file(&sock);
535    let listener = match UnixListener::bind(&sock) {
536        Ok(listener) => listener,
537        Err(e) => {
538            eprintln!("ljos hookd: cannot listen on {}: {e}", sock.display());
539            return 1;
540        }
541    };
542    let _ = std::fs::set_permissions(&sock, std::fs::Permissions::from_mode(0o600));
543    let ino = std::fs::metadata(&sock).map(|m| m.ino()).unwrap_or(0);
544    // The binary this server runs. An install replaces the file under its
545    // path; the server then exits as soon as no call holds or waits for a
546    // slot, and the next call starts one from the installed binary.
547    let exe = std::env::current_exe().ok();
548    let exe_stamp = exe.as_deref().and_then(binary_stamp);
549    let gate = Arc::new(Gate {
550        turns: Mutex::new(Turns {
551            running: 0,
552            queue: std::collections::VecDeque::new(),
553            next: 0,
554            last: Instant::now(),
555        }),
556        moved: Condvar::new(),
557        slots: slots(),
558        cap: queue_cap(),
559    });
560    {
561        let gate = Arc::clone(&gate);
562        let sock = sock.clone();
563        std::thread::spawn(move || loop {
564            std::thread::sleep(Duration::from_secs(2));
565            if !std::fs::metadata(&sock).is_ok_and(|m| m.ino() == ino) {
566                std::process::exit(0);
567            }
568            let replaced = exe
569                .as_deref()
570                .is_some_and(|path| binary_stamp(path) != exe_stamp);
571            if gate.idle() || (replaced && gate.drained()) {
572                let _ = std::fs::remove_file(&sock);
573                std::process::exit(0);
574            }
575        });
576    }
577    for conn in listener.incoming() {
578        let Ok(stream) = conn else { continue };
579        if !same_user(&stream) {
580            continue;
581        }
582        let gate = Arc::clone(&gate);
583        let _ = std::thread::Builder::new()
584            .name("hookd-call".into())
585            .stack_size(128 * 1024)
586            .spawn(move || gate.serve(&stream));
587    }
588    drop(lock);
589    0
590}
591
592fn times_path() -> PathBuf {
593    crate::runtime_dir().join("hook-times.log")
594}
595
596/// Append one timing row: `kind`, the unix time, the call's duration and
597/// the time it waited on a lock, in milliseconds. `kind` is `hook` for an
598/// answered call, `refused` for one the queue turned away and `book` for
599/// a bookkeeping job.
600pub fn note_time(kind: &str, took: Duration, waited: Duration) {
601    let path = times_path();
602    if std::fs::metadata(&path).is_ok_and(|m| m.len() > LOG_CAP) {
603        let _ = std::fs::rename(&path, path.with_extension("log.1"));
604    }
605    let Some(mut file) = open_lock(&path) else {
606        return;
607    };
608    let now = std::time::SystemTime::now()
609        .duration_since(std::time::UNIX_EPOCH)
610        .map_or(0, |d| d.as_secs());
611    // One write per line: calls append at once, and a short O_APPEND
612    // write is not split by another writer's.
613    let line = format!("{kind} {now} {} {}\n", took.as_millis(), waited.as_millis());
614    let _ = file.write_all(line.as_bytes());
615}
616
617/// The 95th percentile of `values`, or `None` when there are none.
618fn p95(values: &mut [u64]) -> Option<u64> {
619    if values.is_empty() {
620        return None;
621    }
622    values.sort_unstable();
623    let rank = (values.len() * 95).div_ceil(100).max(1) - 1;
624    Some(values[rank])
625}
626
627/// Hook latency and lock waits from the timing log, for `ljos doctor`.
628#[derive(Debug, Default, PartialEq, Eq)]
629pub struct Timings {
630    pub calls: usize,
631    pub p95_ms: Option<u64>,
632    pub admit_p95_ms: Option<u64>,
633    pub refused: usize,
634    pub book_jobs: usize,
635    pub book_lock_p95_ms: Option<u64>,
636}
637
638/// [`Timings`] from the log text.
639#[must_use]
640pub fn timings_of(text: &str) -> Timings {
641    let mut took = Vec::new();
642    let mut admit = Vec::new();
643    let mut book = Vec::new();
644    let mut refused = 0;
645    for line in text.lines() {
646        let mut words = line.split_whitespace();
647        let kind = words.next();
648        let _at = words.next();
649        let (Some(ms), Some(wait)) = (
650            words.next().and_then(|w| w.parse::<u64>().ok()),
651            words.next().and_then(|w| w.parse::<u64>().ok()),
652        ) else {
653            continue;
654        };
655        match kind {
656            Some("hook") => {
657                took.push(ms);
658                admit.push(wait);
659            }
660            Some("refused") => refused += 1,
661            Some("book") => book.push(wait),
662            _ => {}
663        }
664    }
665    Timings {
666        calls: took.len(),
667        p95_ms: p95(&mut took),
668        admit_p95_ms: p95(&mut admit),
669        refused,
670        book_jobs: book.len(),
671        book_lock_p95_ms: p95(&mut book),
672    }
673}
674
675/// The doctor's line for hook latency and lock waits.
676#[must_use]
677pub fn timings_line() -> String {
678    let path = times_path();
679    let mut text = std::fs::read_to_string(path.with_extension("log.1")).unwrap_or_default();
680    text.push_str(&std::fs::read_to_string(&path).unwrap_or_default());
681    let t = timings_of(&text);
682    let ms = |v: Option<u64>| v.map_or_else(|| "-".to_string(), |v| format!("{v} ms"));
683    if t.calls == 0 && t.refused == 0 && t.book_jobs == 0 {
684        return "no hook calls timed yet".to_string();
685    }
686    format!(
687        "p95 {} over {} gate calls; queue wait p95 {}; {} refused by the queue; \
688         book lock wait p95 {} over {} jobs",
689        ms(t.p95_ms),
690        t.calls,
691        ms(t.admit_p95_ms),
692        t.refused,
693        ms(t.book_lock_p95_ms),
694        t.book_jobs
695    )
696}
697
698#[cfg(test)]
699mod tests {
700    use super::*;
701
702    #[test]
703    fn only_a_plain_hook_is_admitted() {
704        let args = |v: &[&str]| v.iter().map(|s| (*s).to_string()).collect::<Vec<_>>();
705        assert!(admitted_command(&args(&["hook"])));
706        assert!(admitted_command(&args(&["hook", "--event", "PreToolUse"])));
707        assert!(admitted_command(&args(&["hook", "--prompt"])));
708        assert!(!admitted_command(&args(&["hook", "--git-commit"])));
709        assert!(!admitted_command(&args(&["hook", "--runner=gemini"])));
710        assert!(!admitted_command(&args(&["hook", "--drain"])));
711        assert!(!admitted_command(&args(&["note", "x"])));
712        assert!(!admitted_command(&args(&[])));
713    }
714
715    #[test]
716    fn the_event_flag_reads_both_spellings() {
717        let args = |v: &[&str]| v.iter().map(|s| (*s).to_string()).collect::<Vec<_>>();
718        assert_eq!(
719            flag_value(&args(&["hook", "--event", "Stop"]), "--event").as_deref(),
720            Some("Stop")
721        );
722        assert_eq!(
723            flag_value(&args(&["hook", "--event=Stop"]), "--event").as_deref(),
724            Some("Stop")
725        );
726        assert_eq!(flag_value(&args(&["hook"]), "--event"), None);
727    }
728
729    #[test]
730    fn timings_read_p95_and_waits_from_the_log() {
731        let mut text = String::new();
732        for ms in 1..=100 {
733            text.push_str(&format!("hook 0 {ms} {}\n", ms / 10));
734        }
735        text.push_str("refused 0 3000 0\nbook 0 40 900\nbook 0 10 5\ngarbage\n");
736        let t = timings_of(&text);
737        assert_eq!(t.calls, 100);
738        assert_eq!(t.p95_ms, Some(95));
739        assert_eq!(t.admit_p95_ms, Some(9));
740        assert_eq!(t.refused, 1);
741        assert_eq!(t.book_jobs, 2);
742        assert_eq!(t.book_lock_p95_ms, Some(900));
743        assert_eq!(timings_of(""), Timings::default());
744    }
745
746    #[test]
747    fn a_full_queue_and_a_late_turn_are_refused_in_order() {
748        let gate = Arc::new(Gate {
749            turns: Mutex::new(Turns {
750                running: 0,
751                queue: std::collections::VecDeque::new(),
752                next: 0,
753                last: Instant::now(),
754            }),
755            moved: Condvar::new(),
756            slots: 1,
757            cap: 1,
758        });
759        let pair = || UnixStream::pair().unwrap();
760        let call = |gate: &Arc<Gate>, ms: u64| {
761            let (mine, theirs) = pair();
762            let gate = Arc::clone(gate);
763            std::thread::spawn(move || gate.serve(&theirs));
764            writeln!(&mut &mine, "wait {ms}").unwrap();
765            mine.set_read_timeout(Some(Duration::from_secs(3))).unwrap();
766            let mut line = String::new();
767            BufReader::new(mine.try_clone().unwrap())
768                .read_line(&mut line)
769                .expect("hook slot hung");
770            (mine, line)
771        };
772        let (first, said) = call(&gate, 1000);
773        assert!(said.starts_with("go "), "{said}");
774        let (mine, theirs) = pair();
775        {
776            let gate = Arc::clone(&gate);
777            std::thread::spawn(move || gate.serve(&theirs));
778        }
779        writeln!(&mut &mine, "wait 2000").unwrap();
780        std::thread::sleep(Duration::from_millis(100));
781        let (_third, said) = call(&gate, 1000);
782        assert_eq!(said.trim(), "full 1");
783        drop(first);
784        mine.set_read_timeout(Some(Duration::from_secs(3))).unwrap();
785        let mut line = String::new();
786        BufReader::new(mine.try_clone().unwrap())
787            .read_line(&mut line)
788            .expect("queued slot hung");
789        assert!(line.starts_with("go "), "{line}");
790        let (_late, said) = call(&gate, 50);
791        assert_eq!(said.trim(), "late");
792    }
793}