diff --git a/crates/engine/src/cmd/findfiles/tests.rs b/crates/engine/src/cmd/findfiles/tests.rs index 92f462c3b..ec3ce57e3 100644 --- a/crates/engine/src/cmd/findfiles/tests.rs +++ b/crates/engine/src/cmd/findfiles/tests.rs @@ -66,9 +66,14 @@ fn rules(root: &Path) -> Rules { Rules { home: Some(root.join("Users/me")), user_content: vec![root.to_path_buf()], refused: vec![root.join("refused")] } } -/// The search's progress once it ended (or after 10 seconds). +/// How long a test waits for a search to end or to read a file. The wait only ends a test whose +/// search never ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a +/// search's default 60 s deadline, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + +/// The search's progress once it ended (or after [`WAIT`]). fn wait(s: &Search) -> Progress { - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; loop { let p = s.progress(); if p.end.is_some() || Instant::now() > until { @@ -205,14 +210,17 @@ fn the_search_ends_at_its_limits_and_when_stopped() { fn the_search_answers_at_its_deadline_while_a_walker_is_blocked() { let root = tree("blocked", &["f.ttf"]); let (tx, rx) = mpsc::channel(); + let started = Instant::now(); let s = begin(root.clone(), rules(&root), Limits { seconds: 0.2, ..Limits::default() }, 1, 1, Arc::new(Blocked(Mutex::new(rx)))); std::thread::sleep(Duration::from_millis(300)); let p = s.progress(); + // The search ended when it answered, and it ran no longer than the test has waited. + let waited = started.elapsed().as_secs_f64(); assert_eq!((p.state(), p.stopped()), ("stopped", Some("time")), "{p:?}"); - assert!(p.seconds >= 0.2 && p.seconds < 5.0, "{p:?}"); + assert!(p.seconds >= 0.2 && p.seconds <= waited, "{p:?}, {waited} s"); let (tx2, rx2) = mpsc::channel(); let s2 = begin(root.clone(), rules(&root), Limits::default(), 1, 1, Arc::new(Blocked(Mutex::new(rx2)))); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while s2.progress().read == 0 && Instant::now() < until { std::thread::sleep(Duration::from_millis(2)); } @@ -246,7 +254,7 @@ fn files_found_are_kept_as_they_are_read() { let root = tree("kept", &["a.ttf", "b.ttf", "c.ttf"]); let (tx, rx) = mpsc::channel(); let s = begin(root.clone(), rules(&root), Limits::default(), 1, 2, Arc::new(SecondBlocks(Mutex::new((0, rx))))); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while s.progress().read < 2 && Instant::now() < until { std::thread::sleep(Duration::from_millis(2)); } @@ -426,7 +434,7 @@ fn a_search_starts_with_the_threads_left_and_fails_when_none_is() { assert_eq!(c.err().as_deref(), Some("the search couldn't start: try again in a moment")); drop((tx_a, tx_b)); assert_eq!((wait(&a).end, wait(&b).end), (Some(End::Done), Some(End::Done))); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while POOL.live() > 0 && Instant::now() < until { std::thread::sleep(Duration::from_millis(2)); } diff --git a/crates/engine/src/tests/fontfiles.rs b/crates/engine/src/tests/fontfiles.rs index 72e21755d..32eaefc00 100644 --- a/crates/engine/src/tests/fontfiles.rs +++ b/crates/engine/src/tests/fontfiles.rs @@ -30,9 +30,14 @@ fn session_for(root: &Path) -> Session { s } -/// `text.findFontFiles {}` once the search ended (10 seconds at most). +/// How long a test waits for a search to end or to read a file. The wait only ends a test whose +/// search never ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a +/// search's default `maxSeconds` of 60, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + +/// `text.findFontFiles {}` once the search ended ([`WAIT`] at most). fn finished(s: &mut Session) -> Value { - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; loop { let r = s.execute("text.findFontFiles", &json!({})).unwrap(); if r["state"] != "searching" || Instant::now() > until { @@ -262,7 +267,7 @@ fn stop_ends_only_the_search_it_names() { let search = findfiles::start(root.clone(), s.search_rules.clone(), Limits::default(), 1, 1, Arc::new(Blocked(Mutex::new(rx)))).unwrap(); let fonts = vec![Sought { family: "A".into(), style: "Regular".into(), status: FontMatch::Missing }]; s.font_search = Some(FontSearch { id: 7, folder: root.to_string_lossy().into_owned(), fonts, search }); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while s.execute("text.findFontFiles", &json!({})).unwrap()["searched"]["fontFiles"] != 1 && Instant::now() < until { std::thread::sleep(Duration::from_millis(2)); } diff --git a/crates/engine/src/tests/linkfiles.rs b/crates/engine/src/tests/linkfiles.rs index 4fd26220f..5990b3523 100644 --- a/crates/engine/src/tests/linkfiles.rs +++ b/crates/engine/src/tests/linkfiles.rs @@ -42,9 +42,14 @@ fn placed(s: &mut Session, path: &Path) -> u64 { place(s, &path.to_string_lossy()).0 } -/// `links.findFiles {}` once the search ended (10 seconds at most). +/// How long a test waits for a search to end or to read a file. The wait only ends a test whose +/// search never ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a +/// search's default `maxSeconds` of 60, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + +/// `links.findFiles {}` once the search ended ([`WAIT`] at most). fn finished(s: &mut Session) -> Value { - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; loop { let r = s.execute("links.findFiles", &json!({})).unwrap(); if r["state"] != "searching" || Instant::now() > until { @@ -206,7 +211,7 @@ fn stop_ends_only_the_search_it_names() { let search = findfiles::start(root.clone(), s.search_rules.clone(), Limits::default(), 1, 2, Arc::new(Blocked(Mutex::new(rx)))).unwrap(); let links = vec![Sought { name: "a.png".into(), path: "/gone/a.png".into(), ids: vec![], size: None, hash: None }]; s.link_search = Some(LinkSearch { id: 7, folder: root.to_string_lossy().into_owned(), links, sizes: Arc::default(), search }); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while s.execute("links.findFiles", &json!({})).unwrap()["searched"]["read"] != 1 && Instant::now() < until { std::thread::sleep(Duration::from_millis(2)); } diff --git a/crates/engine/tests/font_folder.rs b/crates/engine/tests/font_folder.rs index 64581651d..b58e79fc1 100644 --- a/crates/engine/tests/font_folder.rs +++ b/crates/engine/tests/font_folder.rs @@ -10,9 +10,14 @@ use serde_json::{Value, json}; use vectorcraft_engine::Session; use vectorcraft_engine::cmd::findfiles::{Rules, plain}; -/// `text.findFontFiles {}` once the search ended (10 seconds at most). +/// How long the test waits for a search to end. The wait only ends the test if the search never +/// ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a search's +/// default `maxSeconds` of 60, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + +/// `text.findFontFiles {}` once the search ended ([`WAIT`] at most). fn finished(s: &mut Session) -> Value { - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; loop { let r = s.execute("text.findFontFiles", &json!({})).unwrap(); if r["state"] != "searching" || Instant::now() > until { diff --git a/crates/mcp/src/tests/concurrency.rs b/crates/mcp/src/tests/concurrency.rs index c2e23a77a..7b9352e52 100644 --- a/crates/mcp/src/tests/concurrency.rs +++ b/crates/mcp/src/tests/concurrency.rs @@ -144,18 +144,22 @@ impl Rig { } } -const LONG: Duration = Duration::from_secs(20); -const QUICK: Duration = Duration::from_secs(3); +/// How long a test waits for the server to start a command, to answer or to log. The wait only ends +/// a test whose server never does. A machine busy with other builds can hold a thread for seconds. +const WAIT: Duration = Duration::from_secs(20); +/// How long [`Slow`]'s long command runs unless it is cancelled: longer than [`WAIT`], so a request +/// that waits behind it is not answered within the wait. +const LONG: Duration = Duration::from_secs(60); #[test] fn ping_is_answered_while_a_command_runs() { let mut rig = Rig::new(LONG, Duration::from_millis(50)); rig.run(1, "document.export"); - assert_eq!(rig.started.recv_timeout(QUICK).unwrap(), "document.export"); + assert_eq!(rig.started.recv_timeout(WAIT).unwrap(), "document.export"); // Past `busy_after` the call counts as long-running. std::thread::sleep(Duration::from_millis(120)); rig.request(2, "ping", json!({})); - let pong = rig.reply(2, QUICK).expect("ping must not wait for the running command"); + let pong = rig.reply(2, WAIT).expect("ping must not wait for the running command"); assert_eq!(pong["result"], json!({})); rig.notify("notifications/cancelled", json!({"requestId": 1})); rig.finish(); @@ -165,11 +169,11 @@ fn ping_is_answered_while_a_command_runs() { fn cancelling_stops_the_running_command_and_sends_no_reply() { let mut rig = Rig::new(LONG, Duration::from_secs(60)); rig.run(1, "document.export"); - rig.started.recv_timeout(QUICK).unwrap(); + rig.started.recv_timeout(WAIT).unwrap(); rig.notify("notifications/cancelled", json!({"requestId": 1, "reason": "user"})); // The engine is free again: the next command runs and answers. rig.run(2, "pdf.preset.list"); - let end = Instant::now() + QUICK; + let end = Instant::now() + WAIT; loop { if rig.log.lock().unwrap().iter().any(|l| l == "cancelled document.export") { break; @@ -187,10 +191,10 @@ fn cancelling_stops_the_running_command_and_sends_no_reply() { fn a_request_that_would_wait_behind_a_long_call_is_refused_as_busy() { let mut rig = Rig::new(LONG, Duration::from_millis(50)); rig.run(1, "document.export"); - rig.started.recv_timeout(QUICK).unwrap(); + rig.started.recv_timeout(WAIT).unwrap(); std::thread::sleep(Duration::from_millis(120)); rig.run(2, "pdf.preset.list"); - let busy = rig.reply(2, QUICK).expect("a busy answer, not a wait"); + let busy = rig.reply(2, WAIT).expect("a busy answer, not a wait"); assert_eq!(busy["error"]["code"], -32003, "{busy}"); assert!(busy["error"]["message"].as_str().unwrap().contains("document.export"), "{busy}"); assert_eq!(busy["error"]["data"]["busy"]["requestId"], "1", "{busy}"); @@ -208,7 +212,7 @@ fn quick_calls_pipelined_together_queue_and_answer_in_order() { rig.run(id, &format!("cmd{id}")); } for id in 1..=4 { - let r = rig.reply(id, QUICK).unwrap_or_else(|| panic!("no reply to {id}")); + let r = rig.reply(id, WAIT).unwrap_or_else(|| panic!("no reply to {id}")); assert!(r.get("error").is_none(), "{r}"); } assert_eq!(*rig.log.lock().unwrap(), ["done cmd1", "done cmd2", "done cmd3", "done cmd4"]); @@ -219,13 +223,13 @@ fn quick_calls_pipelined_together_queue_and_answer_in_order() { fn a_queued_request_that_is_cancelled_never_runs() { let mut rig = Rig::new(LONG, Duration::from_secs(60)); rig.run(1, "document.export"); - rig.started.recv_timeout(QUICK).unwrap(); + rig.started.recv_timeout(WAIT).unwrap(); rig.run(2, "never.runs"); rig.run(3, "quick.last"); // Request 2 may not have been read yet when the cancel is: it is the order of lines that counts. rig.notify("notifications/cancelled", json!({"requestId": 2})); rig.notify("notifications/cancelled", json!({"requestId": 1})); - let r = rig.reply(3, QUICK).expect("the engine goes on to the next request"); + let r = rig.reply(3, WAIT).expect("the engine goes on to the next request"); assert!(r.get("error").is_none(), "{r}"); rig.notify("notifications/cancelled", json!({"requestId": 3})); let log = rig.log.lock().unwrap().clone(); @@ -239,13 +243,13 @@ fn a_queued_request_that_is_cancelled_never_runs() { fn cancelling_an_unknown_or_finished_request_changes_nothing() { let mut rig = Rig::new(Duration::from_millis(10), Duration::from_secs(60)); rig.run(1, "quick"); - assert!(rig.reply(1, QUICK).unwrap().get("result").is_some()); + assert!(rig.reply(1, WAIT).unwrap().get("result").is_some()); rig.notify("notifications/cancelled", json!({"requestId": 1})); rig.notify("notifications/cancelled", json!({"requestId": 99})); rig.notify("notifications/cancelled", json!({"requestId": [1], "reason": "junk"})); rig.notify("notifications/cancelled", json!("junk")); rig.run(2, "quick"); - assert!(rig.reply(2, QUICK).unwrap().get("result").is_some()); + assert!(rig.reply(2, WAIT).unwrap().get("result").is_some()); rig.finish(); } @@ -254,7 +258,7 @@ fn initialize_cannot_be_cancelled() { let mut rig = Rig::new(LONG, Duration::from_secs(60)); rig.request(1, "initialize", json!({})); rig.notify("notifications/cancelled", json!({"requestId": 1})); - assert!(rig.reply(1, QUICK).unwrap().get("result").is_some()); + assert!(rig.reply(1, WAIT).unwrap().get("result").is_some()); rig.finish(); } @@ -264,7 +268,7 @@ fn progress_reaches_a_client_that_gave_a_token_before_the_reply() { rig.request(1, "tools/call", json!({"name": "command_run", "arguments": {"id": "progress.demo"}, "_meta": {"progressToken": "tok"}})); let mut seen = vec![]; let reply = loop { - let v = rig.next(QUICK).expect("a reply"); + let v = rig.next(WAIT).expect("a reply"); if v["method"] == "notifications/progress" { seen.push(v["params"].clone()); } else { @@ -279,7 +283,7 @@ fn progress_reaches_a_client_that_gave_a_token_before_the_reply() { assert_eq!(seen[1]["message"], "page 2"); // Without a token nothing is sent. rig.run(2, "progress.demo"); - let next = rig.next(QUICK).unwrap(); + let next = rig.next(WAIT).unwrap(); assert_eq!(next["id"], 2, "{next}"); rig.finish(); } @@ -321,16 +325,18 @@ fn a_cancelled_export_through_the_real_engine_writes_nothing_and_leaves_the_sess let (started_tx, started) = mpsc::channel(); let thread = std::thread::spawn(move || { let backend = Gated { inner: crate::Headless::with_document(), started: started_tx }; - Server::new(Box::new(backend)).serve(BufReader::new(read), Lines(tx, vec![])).unwrap(); + // Request 2 waits for the cancelled export to return, also when the export ran past the + // default busy limit (2 s) before it saw the cancel. + Server::new(Box::new(backend)).with_busy_after(Duration::from_secs(60)).serve(BufReader::new(read), Lines(tx, vec![])).unwrap(); }); let send = |w: &mut std::io::PipeWriter, v: Value| writeln!(w, "{v}").unwrap(); let params = json!({"name": "command_run", "arguments": {"id": "document.export", "params": {"path": path.to_str().unwrap()}}}); send(&mut to_server, json!({"jsonrpc": "2.0", "id": 1, "method": "tools/call", "params": params})); - started.recv_timeout(QUICK).unwrap(); + started.recv_timeout(WAIT).unwrap(); send(&mut to_server, json!({"jsonrpc": "2.0", "method": "notifications/cancelled", "params": {"requestId": 1}})); // The next request is answered: the cancelled export neither blocks nor breaks the engine. send(&mut to_server, json!({"jsonrpc": "2.0", "id": 2, "method": "tools/call", "params": {"name": "doc_inspect", "arguments": {}}})); - let reply: Value = serde_json::from_str(&replies.recv_timeout(QUICK).unwrap()).unwrap(); + let reply: Value = serde_json::from_str(&replies.recv_timeout(WAIT).unwrap()).unwrap(); assert_eq!(reply["id"], 2, "request 1 is not answered: {reply}"); assert_eq!(reply["result"]["isError"], false, "{reply}"); assert!(!path.exists(), "a cancelled export writes no file"); @@ -344,12 +350,13 @@ fn a_remote_call_stops_waiting_for_the_app_when_cancelled() { let listener = std::net::TcpListener::bind("127.0.0.1:0").unwrap(); let addr = listener.local_addr().unwrap().to_string(); // An app that takes the request and never answers. + let (done, held) = mpsc::channel::<()>(); let app = std::thread::spawn(move || { let (conn, _) = listener.accept().unwrap(); let mut line = String::new(); BufReader::new(conn.try_clone().unwrap()).read_line(&mut line).unwrap(); - // Hold the connection open until the test is done with it. - std::thread::sleep(Duration::from_secs(3)); + // Hold the connection open until the test is done with it (or for `WAIT`). + let _ = held.recv_timeout(WAIT); drop(conn); }); let mut remote = crate::Remote::connect(&addr).unwrap(); @@ -359,10 +366,11 @@ fn a_remote_call_stops_waiting_for_the_app_when_cancelled() { std::thread::sleep(Duration::from_millis(200)); raise.cancel(); }); - let start = Instant::now(); let r = cancel::scope(&token, None, || remote.call("engine.execute", json!({"command": "document.export"}))); let why = r.unwrap_err(); assert!(why.contains("cancelled"), "{why}"); - assert!(start.elapsed() < Duration::from_secs(2), "returned when cancelled, not when the app answered"); + // The app still holds the connection open. + assert!(!app.is_finished(), "returned when cancelled, not when the app answered"); + done.send(()).ok(); app.join().unwrap(); } diff --git a/crates/ui-egui/src/dialogs/find_links/tests.rs b/crates/ui-egui/src/dialogs/find_links/tests.rs index 6db57091f..b85b67634 100644 --- a/crates/ui-egui/src/dialogs/find_links/tests.rs +++ b/crates/ui-egui/src/dialogs/find_links/tests.rs @@ -67,9 +67,14 @@ fn opened_without(app: &mut VectorcraftApp, root: &Path, names: &[&str]) -> Vec< files } -/// Draw the dialog until its search ends (10 seconds at most). +/// How long a test waits for the dialog's search to end. The wait only ends a test whose search +/// never ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a +/// search's default `maxSeconds` of 60, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + +/// Draw the dialog until its search ends ([`WAIT`] at most). fn searched(app: &mut VectorcraftApp) { - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while app.ui.dialog.as_ref().is_some_and(|d| d.str("state") == "searching") && Instant::now() < until { frame(app); std::thread::sleep(Duration::from_millis(5)); diff --git a/crates/ui-egui/src/dialogs/missing_fonts/tests.rs b/crates/ui-egui/src/dialogs/missing_fonts/tests.rs index 2dbfdf810..20266d97b 100644 --- a/crates/ui-egui/src/dialogs/missing_fonts/tests.rs +++ b/crates/ui-egui/src/dialogs/missing_fonts/tests.rs @@ -55,6 +55,11 @@ fn open(app: &mut VectorcraftApp, path: &Path) { crate::io::open_path(app, &path.to_string_lossy()).unwrap(); } +/// How long a test waits for the dialog's search to end. The wait only ends a test whose search +/// never ends. A machine busy with other builds can hold a walker for seconds. It is shorter than a +/// search's default `maxSeconds` of 60, which would end a search that does not end by itself. +const WAIT: Duration = Duration::from_secs(30); + fn kind(app: &VectorcraftApp) -> Option<&str> { app.ui.dialog.as_ref().map(|d| d.kind.as_str()) } @@ -101,7 +106,7 @@ fn the_documents_fonts_folder_is_offered_and_searched_off_the_ui_thread() { let r = super::super::confirm(&mut app).unwrap(); assert!(matches!(r["state"].as_str(), Some("searching" | "done")), "{r}"); assert_eq!(kind(&app), Some(KIND), "the dialog stays open while it searches"); - let until = Instant::now() + Duration::from_secs(10); + let until = Instant::now() + WAIT; while app.ui.dialog.as_ref().is_some_and(|d| d.str("state") == "searching") && Instant::now() < until { frame(&mut app); std::thread::sleep(Duration::from_millis(5));