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                | "--finish-session"
171                | "-h"
172                | "--help"
173        )
174    })
175}
176
177fn flag_value(args: &[String], flag: &str) -> Option<String> {
178    let mut it = args.iter();
179    while let Some(arg) = it.next() {
180        if arg == flag {
181            return it.next().cloned();
182        }
183        if let Some(value) = arg.strip_prefix(flag).and_then(|r| r.strip_prefix('=')) {
184            return Some(value.to_string());
185        }
186    }
187    None
188}
189
190/// The runtime directory, made private when missing.
191fn run_dir() -> PathBuf {
192    let dir = crate::runtime_dir();
193    if !dir.exists() {
194        use std::os::unix::fs::DirBuilderExt as _;
195        let _ = std::fs::DirBuilder::new()
196            .recursive(true)
197            .mode(0o700)
198            .create(&dir);
199    }
200    dir
201}
202
203fn env_num(key: &str) -> Option<u64> {
204    std::env::var(key).ok()?.trim().parse().ok()
205}
206
207fn admit_budget() -> Duration {
208    if let Some(ms) = env_num("LJOS_HOOK_ADMIT_MS") {
209        return Duration::from_millis(ms);
210    }
211    // The queue and the work share the hook's wall budget. A slot that
212    // never comes is judged in this process once that budget is spent.
213    Duration::from_millis(ADMIT_MS.min(crate::HOOK_WALL_BUDGET_MS))
214}
215
216enum Ask {
217    NoServer,
218    Refused(String),
219}
220
221/// A turn from the server, or with no server, the single-flight lock.
222/// The error says why no turn came within the budget.
223fn wait_turn() -> Result<(Held, u64), String> {
224    let dir = run_dir();
225    let sock = dir.join("hookd.sock");
226    let deadline = started() + admit_budget();
227    // No server can listen on a path this long; do not wait for one.
228    if sock.as_os_str().len() > SOCKET_PATH_MAX {
229        return flight(&dir, deadline);
230    }
231    match ask(&sock, deadline) {
232        Ok(turn) => return Ok(turn),
233        Err(Ask::Refused(why)) => return Err(why),
234        Err(Ask::NoServer) => {}
235    }
236    let _starting = start_server(&dir);
237    let retry_until = (Instant::now() + Duration::from_millis(200)).min(deadline);
238    while Instant::now() < retry_until {
239        std::thread::sleep(Duration::from_millis(5));
240        match ask(&sock, deadline) {
241            Ok(turn) => return Ok(turn),
242            Err(Ask::Refused(why)) => return Err(why),
243            Err(Ask::NoServer) => {}
244        }
245    }
246    flight(&dir, deadline)
247}
248
249fn ask(sock: &Path, deadline: Instant) -> Result<(Held, u64), Ask> {
250    let mut stream = UnixStream::connect(sock).map_err(|_| Ask::NoServer)?;
251    let left = deadline.saturating_duration_since(Instant::now());
252    if left.is_zero() {
253        return Err(Ask::Refused(format!(
254            "no slot within {} ms",
255            admit_budget().as_millis()
256        )));
257    }
258    // The server answers `late` at the deadline itself; the margin is for
259    // a server that stopped answering.
260    let _ = stream.set_read_timeout(Some(left + Duration::from_millis(250)));
261    writeln!(stream, "wait {}", left.as_millis()).map_err(|_| Ask::NoServer)?;
262    let mut line = String::new();
263    let mut reader = BufReader::new(stream.try_clone().map_err(|_| Ask::NoServer)?);
264    match reader.read_line(&mut line) {
265        // A server that went away before it answered: the remaining
266        // budget goes to the single-flight lock.
267        Ok(0) => Err(Ask::NoServer),
268        Ok(_) => {
269            let mut words = line.split_whitespace();
270            match (words.next(), words.next()) {
271                (Some("go"), waited) => Ok((
272                    Held::Slot(stream),
273                    waited.and_then(|w| w.parse().ok()).unwrap_or(0),
274                )),
275                (Some("full"), waiting) => Err(Ask::Refused(format!(
276                    "{} hook calls are already waiting for a slot",
277                    waiting.unwrap_or("too many")
278                ))),
279                _ => Err(Ask::Refused(format!(
280                    "no slot came free within {} ms",
281                    admit_budget().as_millis()
282                ))),
283            }
284        }
285        Err(_) => Err(Ask::Refused(format!(
286            "the hook server did not answer within {} ms",
287            admit_budget().as_millis()
288        ))),
289    }
290}
291
292/// The inode, size and mtime of the file at `path`; `None` when it is gone.
293fn binary_stamp(path: &Path) -> Option<(u64, u64, i64)> {
294    let meta = std::fs::metadata(path).ok()?;
295    Some((meta.ino(), meta.len(), meta.mtime()))
296}
297
298fn open_lock(path: &Path) -> Option<std::fs::File> {
299    std::fs::OpenOptions::new()
300        .create(true)
301        .append(true)
302        .mode(0o600)
303        .open(path)
304        .ok()
305}
306
307fn try_flock(file: &std::fs::File) -> bool {
308    // SAFETY: flock on a descriptor `file` owns; the lock goes with it.
309    unsafe { libc::flock(file.as_raw_fd(), libc::LOCK_EX | libc::LOCK_NB) == 0 }
310}
311
312/// Start `ljos hookd` unless another call is starting one. The returned
313/// lock is held while this call waits for the socket, so a burst starts
314/// one server, not one each.
315fn start_server(dir: &Path) -> Option<std::fs::File> {
316    use std::os::unix::process::CommandExt as _;
317    let lock = open_lock(&dir.join("hookd.start"))?;
318    if !try_flock(&lock) {
319        return None;
320    }
321    let exe = std::env::current_exe().ok()?;
322    let mut cmd = std::process::Command::new(exe);
323    cmd.arg("hookd")
324        .env_clear()
325        .stdin(std::process::Stdio::null())
326        .stdout(std::process::Stdio::null())
327        .stderr(std::process::Stdio::null());
328    for key in [
329        "PATH",
330        "HOME",
331        "USER",
332        "XDG_RUNTIME_DIR",
333        "TMPDIR",
334        "LJOS_HOOK_SLOTS",
335        "LJOS_HOOK_QUEUE",
336    ] {
337        if let Some(val) = std::env::var_os(key) {
338            cmd.env(key, val);
339        }
340    }
341    // SAFETY: setsid is async-signal-safe and touches only the child.
342    unsafe {
343        cmd.pre_exec(|| {
344            libc::setsid();
345            Ok(())
346        });
347    }
348    let _ = cmd.spawn();
349    Some(lock)
350}
351
352fn flight(dir: &Path, deadline: Instant) -> Result<(Held, u64), String> {
353    let asked = Instant::now();
354    let Some(file) = open_lock(&dir.join("hookd.flight")) else {
355        return Err("no hook server, and the single-flight lock cannot be opened".into());
356    };
357    loop {
358        if try_flock(&file) {
359            let waited = u64::try_from(asked.elapsed().as_millis()).unwrap_or(u64::MAX);
360            return Ok((Held::Flight(file), waited));
361        }
362        if Instant::now() >= deadline {
363            return Err(format!(
364                "no hook server, and the single-flight lock stayed taken for {} ms",
365                admit_budget().as_millis()
366            ));
367        }
368        std::thread::sleep(Duration::from_millis(5));
369    }
370}
371
372/// How many hook calls may run at once: `LJOS_HOOK_SLOTS`, else the CPU
373/// count between 2 and 8.
374fn slots() -> usize {
375    env_num("LJOS_HOOK_SLOTS")
376        .and_then(|n| usize::try_from(n).ok())
377        .filter(|n| *n > 0)
378        .unwrap_or_else(|| {
379            std::thread::available_parallelism()
380                .map_or(2, std::num::NonZeroUsize::get)
381                .clamp(2, 8)
382        })
383}
384
385fn queue_cap() -> usize {
386    env_num("LJOS_HOOK_QUEUE")
387        .and_then(|n| usize::try_from(n).ok())
388        .unwrap_or(QUEUE_CAP)
389}
390
391struct Turns {
392    running: usize,
393    queue: std::collections::VecDeque<u64>,
394    next: u64,
395    last: Instant,
396}
397
398struct Gate {
399    turns: Mutex<Turns>,
400    moved: Condvar,
401    slots: usize,
402    cap: usize,
403}
404
405impl Gate {
406    fn lock(&self) -> std::sync::MutexGuard<'_, Turns> {
407        self.turns
408            .lock()
409            .unwrap_or_else(std::sync::PoisonError::into_inner)
410    }
411
412    fn idle(&self) -> bool {
413        let turns = self.lock();
414        turns.running == 0 && turns.queue.is_empty() && turns.last.elapsed() > IDLE
415    }
416
417    /// No call holds a slot or waits for one.
418    fn drained(&self) -> bool {
419        let turns = self.lock();
420        turns.running == 0 && turns.queue.is_empty()
421    }
422
423    /// One call: queue it, hand it a slot in order, and take the slot back
424    /// when the caller closes the socket, exits or holds it past [`HOLD`].
425    fn serve(&self, stream: &UnixStream) {
426        let _ = stream.set_read_timeout(Some(Duration::from_secs(1)));
427        let mut line = String::new();
428        if BufReader::new(stream).read_line(&mut line).is_err() {
429            return;
430        }
431        let ms = line
432            .strip_prefix("wait ")
433            .and_then(|v| v.trim().parse().ok())
434            .unwrap_or(ADMIT_MS)
435            .min(crate::CURSOR_GATE_DEADLINE_MS);
436        let asked = Instant::now();
437        let deadline = asked + Duration::from_millis(ms);
438        let mut turns = self.lock();
439        turns.last = asked;
440        if turns.queue.len() >= self.cap {
441            let waiting = turns.queue.len();
442            drop(turns);
443            let _ = writeln!(&mut &*stream, "full {waiting}");
444            return;
445        }
446        let ticket = turns.next;
447        turns.next += 1;
448        turns.queue.push_back(ticket);
449        loop {
450            if turns.queue.front() == Some(&ticket) && turns.running < self.slots {
451                turns.queue.pop_front();
452                turns.running += 1;
453                break;
454            }
455            let left = deadline.saturating_duration_since(Instant::now());
456            if left.is_zero() {
457                turns.queue.retain(|t| *t != ticket);
458                drop(turns);
459                self.moved.notify_all();
460                let _ = writeln!(&mut &*stream, "late");
461                return;
462            }
463            turns = self
464                .moved
465                .wait_timeout(turns, left)
466                .unwrap_or_else(std::sync::PoisonError::into_inner)
467                .0;
468        }
469        drop(turns);
470        self.moved.notify_all();
471        let waited = asked.elapsed().as_millis();
472        if writeln!(&mut &*stream, "go {waited}").is_ok() {
473            let _ = stream.set_read_timeout(Some(HOLD));
474            let mut buf = [0u8; 64];
475            while matches!((&mut &*stream).read(&mut buf), Ok(n) if n > 0) {}
476        }
477        let mut turns = self.lock();
478        turns.running -= 1;
479        turns.last = Instant::now();
480        drop(turns);
481        self.moved.notify_all();
482    }
483}
484
485#[cfg(target_os = "linux")]
486fn same_user(stream: &UnixStream) -> bool {
487    let mut cred = libc::ucred {
488        pid: 0,
489        uid: 0,
490        gid: 0,
491    };
492    let mut len = libc::socklen_t::try_from(std::mem::size_of::<libc::ucred>()).unwrap_or(0);
493    // SAFETY: SO_PEERCRED writes one ucred into `cred`, of `len` bytes.
494    let rc = unsafe {
495        libc::getsockopt(
496            stream.as_raw_fd(),
497            libc::SOL_SOCKET,
498            libc::SO_PEERCRED,
499            std::ptr::addr_of_mut!(cred).cast(),
500            &mut len,
501        )
502    };
503    // SAFETY: geteuid only reads the process identity.
504    rc == 0 && cred.uid == unsafe { libc::geteuid() }
505}
506
507#[cfg(target_os = "macos")]
508fn same_user(stream: &UnixStream) -> bool {
509    let mut uid: libc::uid_t = 0;
510    let mut gid: libc::gid_t = 0;
511    // SAFETY: getpeereid writes the peer's euid and egid into the two locals.
512    let rc = unsafe { libc::getpeereid(stream.as_raw_fd(), &mut uid, &mut gid) };
513    // SAFETY: geteuid only reads the process identity.
514    rc == 0 && uid == unsafe { libc::geteuid() }
515}
516
517#[cfg(not(any(target_os = "linux", target_os = "macos")))]
518fn same_user(_stream: &UnixStream) -> bool {
519    true
520}
521
522/// `ljos hookd`: hand out hook slots on `hookd.sock` in the runtime
523/// directory until idle. A second server finds the lock taken and exits
524/// 0, so starting one is safe at any time. The server also exits when its
525/// socket is removed or replaced.
526#[must_use]
527pub fn serve() -> i32 {
528    let dir = run_dir();
529    let Some(lock) = open_lock(&dir.join("hookd.lock")) else {
530        eprintln!(
531            "ljos hookd: cannot open {}",
532            dir.join("hookd.lock").display()
533        );
534        return 1;
535    };
536    if !try_flock(&lock) {
537        return 0;
538    }
539    let sock = dir.join("hookd.sock");
540    let _ = std::fs::remove_file(&sock);
541    let listener = match UnixListener::bind(&sock) {
542        Ok(listener) => listener,
543        Err(e) => {
544            eprintln!("ljos hookd: cannot listen on {}: {e}", sock.display());
545            return 1;
546        }
547    };
548    let _ = std::fs::set_permissions(&sock, std::fs::Permissions::from_mode(0o600));
549    let ino = std::fs::metadata(&sock).map(|m| m.ino()).unwrap_or(0);
550    // The binary this server runs. An install replaces the file under its
551    // path; the server then exits as soon as no call holds or waits for a
552    // slot, and the next call starts one from the installed binary.
553    let exe = std::env::current_exe().ok();
554    let exe_stamp = exe.as_deref().and_then(binary_stamp);
555    let gate = Arc::new(Gate {
556        turns: Mutex::new(Turns {
557            running: 0,
558            queue: std::collections::VecDeque::new(),
559            next: 0,
560            last: Instant::now(),
561        }),
562        moved: Condvar::new(),
563        slots: slots(),
564        cap: queue_cap(),
565    });
566    {
567        let gate = Arc::clone(&gate);
568        let sock = sock.clone();
569        std::thread::spawn(move || loop {
570            std::thread::sleep(Duration::from_secs(2));
571            if !std::fs::metadata(&sock).is_ok_and(|m| m.ino() == ino) {
572                std::process::exit(0);
573            }
574            let replaced = exe
575                .as_deref()
576                .is_some_and(|path| binary_stamp(path) != exe_stamp);
577            if gate.idle() || (replaced && gate.drained()) {
578                let _ = std::fs::remove_file(&sock);
579                std::process::exit(0);
580            }
581        });
582    }
583    for conn in listener.incoming() {
584        let Ok(stream) = conn else { continue };
585        if !same_user(&stream) {
586            continue;
587        }
588        let gate = Arc::clone(&gate);
589        let _ = std::thread::Builder::new()
590            .name("hookd-call".into())
591            .stack_size(128 * 1024)
592            .spawn(move || gate.serve(&stream));
593    }
594    drop(lock);
595    0
596}
597
598fn times_path() -> PathBuf {
599    crate::runtime_dir().join("hook-times.log")
600}
601
602/// Append one timing row: `kind`, the unix time, the call's duration and
603/// the time it waited on a lock, in milliseconds. `kind` is `hook` for an
604/// answered call, `refused` for one the queue turned away and `book` for
605/// a bookkeeping job.
606pub fn note_time(kind: &str, took: Duration, waited: Duration) {
607    let path = times_path();
608    if std::fs::metadata(&path).is_ok_and(|m| m.len() > LOG_CAP) {
609        let _ = std::fs::rename(&path, path.with_extension("log.1"));
610    }
611    let Some(mut file) = open_lock(&path) else {
612        return;
613    };
614    let now = std::time::SystemTime::now()
615        .duration_since(std::time::UNIX_EPOCH)
616        .map_or(0, |d| d.as_secs());
617    // One write per line: calls append at once, and a short O_APPEND
618    // write is not split by another writer's.
619    let line = format!("{kind} {now} {} {}\n", took.as_millis(), waited.as_millis());
620    let _ = file.write_all(line.as_bytes());
621}
622
623/// The 95th percentile of `values`, or `None` when there are none.
624fn p95(values: &mut [u64]) -> Option<u64> {
625    if values.is_empty() {
626        return None;
627    }
628    values.sort_unstable();
629    let rank = (values.len() * 95).div_ceil(100).max(1) - 1;
630    Some(values[rank])
631}
632
633/// Hook latency and lock waits from the timing log, for `ljos doctor`.
634#[derive(Debug, Default, PartialEq, Eq)]
635pub struct Timings {
636    pub calls: usize,
637    pub p95_ms: Option<u64>,
638    pub admit_p95_ms: Option<u64>,
639    pub refused: usize,
640    pub book_jobs: usize,
641    pub book_lock_p95_ms: Option<u64>,
642}
643
644/// [`Timings`] from the log text.
645#[must_use]
646pub fn timings_of(text: &str) -> Timings {
647    let mut took = Vec::new();
648    let mut admit = Vec::new();
649    let mut book = Vec::new();
650    let mut refused = 0;
651    for line in text.lines() {
652        let mut words = line.split_whitespace();
653        let kind = words.next();
654        let _at = words.next();
655        let (Some(ms), Some(wait)) = (
656            words.next().and_then(|w| w.parse::<u64>().ok()),
657            words.next().and_then(|w| w.parse::<u64>().ok()),
658        ) else {
659            continue;
660        };
661        match kind {
662            Some("hook") => {
663                took.push(ms);
664                admit.push(wait);
665            }
666            Some("refused") => refused += 1,
667            Some("book") => book.push(wait),
668            _ => {}
669        }
670    }
671    Timings {
672        calls: took.len(),
673        p95_ms: p95(&mut took),
674        admit_p95_ms: p95(&mut admit),
675        refused,
676        book_jobs: book.len(),
677        book_lock_p95_ms: p95(&mut book),
678    }
679}
680
681/// The doctor's line for hook latency and lock waits.
682#[must_use]
683pub fn timings_line() -> String {
684    let path = times_path();
685    let mut text = std::fs::read_to_string(path.with_extension("log.1")).unwrap_or_default();
686    text.push_str(&std::fs::read_to_string(&path).unwrap_or_default());
687    let t = timings_of(&text);
688    let ms = |v: Option<u64>| v.map_or_else(|| "-".to_string(), |v| format!("{v} ms"));
689    if t.calls == 0 && t.refused == 0 && t.book_jobs == 0 {
690        return "no hook calls timed yet".to_string();
691    }
692    format!(
693        "p95 {} over {} gate calls; queue wait p95 {}; {} refused by the queue; \
694         book lock wait p95 {} over {} jobs",
695        ms(t.p95_ms),
696        t.calls,
697        ms(t.admit_p95_ms),
698        t.refused,
699        ms(t.book_lock_p95_ms),
700        t.book_jobs
701    )
702}
703
704#[cfg(test)]
705mod tests {
706    use super::*;
707
708    #[test]
709    fn only_a_plain_hook_is_admitted() {
710        let args = |v: &[&str]| v.iter().map(|s| (*s).to_string()).collect::<Vec<_>>();
711        assert!(admitted_command(&args(&["hook"])));
712        assert!(admitted_command(&args(&["hook", "--event", "PreToolUse"])));
713        assert!(admitted_command(&args(&["hook", "--prompt"])));
714        assert!(!admitted_command(&args(&["hook", "--git-commit"])));
715        assert!(!admitted_command(&args(&["hook", "--runner=gemini"])));
716        assert!(!admitted_command(&args(&["hook", "--drain"])));
717        assert!(!admitted_command(&args(&[
718            "hook",
719            "--finish-session",
720            "job.json"
721        ])));
722        assert!(!admitted_command(&args(&["note", "x"])));
723        assert!(!admitted_command(&args(&[])));
724    }
725
726    #[test]
727    fn the_event_flag_reads_both_spellings() {
728        let args = |v: &[&str]| v.iter().map(|s| (*s).to_string()).collect::<Vec<_>>();
729        assert_eq!(
730            flag_value(&args(&["hook", "--event", "Stop"]), "--event").as_deref(),
731            Some("Stop")
732        );
733        assert_eq!(
734            flag_value(&args(&["hook", "--event=Stop"]), "--event").as_deref(),
735            Some("Stop")
736        );
737        assert_eq!(flag_value(&args(&["hook"]), "--event"), None);
738    }
739
740    #[test]
741    fn timings_read_p95_and_waits_from_the_log() {
742        let mut text = String::new();
743        for ms in 1..=100 {
744            text.push_str(&format!("hook 0 {ms} {}\n", ms / 10));
745        }
746        text.push_str("refused 0 3000 0\nbook 0 40 900\nbook 0 10 5\ngarbage\n");
747        let t = timings_of(&text);
748        assert_eq!(t.calls, 100);
749        assert_eq!(t.p95_ms, Some(95));
750        assert_eq!(t.admit_p95_ms, Some(9));
751        assert_eq!(t.refused, 1);
752        assert_eq!(t.book_jobs, 2);
753        assert_eq!(t.book_lock_p95_ms, Some(900));
754        assert_eq!(timings_of(""), Timings::default());
755    }
756
757    #[test]
758    fn a_full_queue_and_a_late_turn_are_refused_in_order() {
759        let gate = Arc::new(Gate {
760            turns: Mutex::new(Turns {
761                running: 0,
762                queue: std::collections::VecDeque::new(),
763                next: 0,
764                last: Instant::now(),
765            }),
766            moved: Condvar::new(),
767            slots: 1,
768            cap: 1,
769        });
770        let pair = || UnixStream::pair().unwrap();
771        let call = |gate: &Arc<Gate>, ms: u64| {
772            let (mine, theirs) = pair();
773            let gate = Arc::clone(gate);
774            std::thread::spawn(move || gate.serve(&theirs));
775            writeln!(&mut &mine, "wait {ms}").unwrap();
776            mine.set_read_timeout(Some(Duration::from_secs(3))).unwrap();
777            let mut line = String::new();
778            BufReader::new(mine.try_clone().unwrap())
779                .read_line(&mut line)
780                .expect("hook slot hung");
781            (mine, line)
782        };
783        let (first, said) = call(&gate, 1000);
784        assert!(said.starts_with("go "), "{said}");
785        let (mine, theirs) = pair();
786        {
787            let gate = Arc::clone(&gate);
788            std::thread::spawn(move || gate.serve(&theirs));
789        }
790        writeln!(&mut &mine, "wait 2000").unwrap();
791        std::thread::sleep(Duration::from_millis(100));
792        let (_third, said) = call(&gate, 1000);
793        assert_eq!(said.trim(), "full 1");
794        drop(first);
795        mine.set_read_timeout(Some(Duration::from_secs(3))).unwrap();
796        let mut line = String::new();
797        BufReader::new(mine.try_clone().unwrap())
798            .read_line(&mut line)
799            .expect("queued slot hung");
800        assert!(line.starts_with("go "), "{line}");
801        let (_late, said) = call(&gate, 50);
802        assert_eq!(said.trim(), "late");
803    }
804}