From a7e24b9512b429d7ffbb298dc1f9028141da3762 Mon Sep 17 00:00:00 2001 From: Bryan Mark Date: Mon, 12 Oct 2026 00:58:28 +0900 Subject: [PATCH] M12: XFA script time limits start when the engine is ready (#1081) * M12: XFA script time limits start when the engine is ready An XFA script's wall-clock limit (1 s for scripts that run unasked, such as initialize and calculate) also counted the engine's start-up: the script thread, a new boa Context, and for the first script in a process the engine's own one-time set-up (~60-170 ms when idle, shared by every script starting at the same moment). On a busy machine a trivial initialize script could pass 1 s, be abandoned, and so turn all of the form's scripts off, with the error only in the JavaScript console. That made two ui-egui xfa.rs tests flaky (xfa_buttons_run_their_scripts_in_the_app, messages_from_scripts_run_on_open_show_right_away): under full CPU load 25 of 40 runs of the test binary failed, and none of 40 with this change. - run_within: the script calls `started` once the engine is ready, and the time limit runs from then. Start-up has a cap of its own (10 s), so a caller still never waits forever. - run_here: a once-per-process warm-up script takes the engine's first use, so the first form script's timed part drops from ~52 ms to under ~11 ms. - FormCalc (no engine to start) signals at once, as before. - Tests: a slow start doesn't abandon a script; the script's own time, and start-up, are still capped. The UI tests print the script console when they fail. Runaway scripts are still abandoned at the same limits (runaway_xfa_calculations_at_open_end_quickly_with_a_report). Co-Authored-By: Claude Opus 5.5 * Add arcanii to the contributor names Co-Authored-By: Claude Opus 5.5 --------- Co-authored-by: Claude Opus 5.5 Co-authored-by: Brandon Thomas --- ROADMAP.md | 1 + contributors/people.toml | 5 ++ crates/js/src/formcalc.rs | 6 ++- crates/js/src/tests.rs | 31 +++++++++++ crates/js/src/xfa.rs | 102 ++++++++++++++++++++++++++++-------- crates/ui-egui/tests/xfa.rs | 6 +-- 6 files changed, 124 insertions(+), 27 deletions(-) diff --git a/ROADMAP.md b/ROADMAP.md index c4f216b6..87ecc1a1 100644 --- a/ROADMAP.md +++ b/ROADMAP.md @@ -136,6 +136,7 @@ Ranked; detail and the full milestone table in [docs/roadmap.md](docs/roadmap.md Newest first: the date, what moved, and the new overall estimate. - **2026-10-11 (M7, watermark placement):** A watermark can be moved from the page centre by a horizontal and a vertical offset in points: Add/Update Watermark has an "Offset from centre" row (the preview follows it, for text and for pictures) and `doc_watermark` takes `offset_x` and `offset_y`. A non-finite offset is refused instead of written into the page. `edit.watermark-appearance` stays partial: no offset from the page edge or in page units, no print/screen-only variants, no repeat. Image and PDF watermarks, already shipped, no longer appear as missing. The overall estimate is unchanged. +- **2026-10-11 (M12, XFA script time limits):** An XFA script's time limit (1 s for scripts that run unasked, on open and on every change) counted the engine's start-up too: the script's thread, a new context and, for the first script in a process, the engine's own set-up (≈ 60–170 ms when idle). On a busy machine a trivial initialize script could pass the limit, be abandoned and turn the form's scripts off; that made `xfa_buttons_run_their_scripts_in_the_app` and `messages_from_scripts_run_on_open_show_right_away` flaky (under full CPU load 25 of 40 runs of the test binary failed, with "ran longer than 1.0 s and was abandoned" in the console). The limit now runs from when the engine is ready; start-up has its own 10 s cap, so nothing waits forever, and a trivial warm-up script takes the first-in-process set-up. Under the same load none of 40 runs fails, and runaway scripts are abandoned as before. The two UI tests print the script console when they fail. Overall unchanged. - **2026-10-10 (M14, interface size):** Preferences ▸ Interface size scales the whole interface (50–250 %, setting `ui_scale`, control option `ui-scale`); 50 % brings an interface the system draws at 200 % back to 100 % (#456). Auto, the default, follows the desktop's text scaling: on Linux and the BSDs the desktop app reads GNOME's `text-scaling-factor` once at launch, so with Large Text (1.25) on a 1× display the interface no longer draws 13 px labels that show their pixels next to the system's text. The size is egui's zoom factor, so `pixels_per_point` grows with it and page rasters stay one texel per screen pixel; egui's own ⌘+/⌘− interface zoom is turned off so those keys stay page zoom. Still missing: KDE's font DPI and Windows' "Make text bigger" aren't read (both scale only text there), and egui's text is still greyscale-antialiased without the system's gamma, so small text looks rougher than GTK's at 100 %. - **2026-10-10 (M14, #496):** Shortcut displays share a UI formatter across toolbar search, registry menus, command palette, Help and tooltips. Modifier and key names use a dedicated catalog context in every bundled translation; missing entries keep the English key name rather than a command translation. German shows Strg/Umschalt/Entf, macOS retains its symbols, and runtime language changes refresh the display. Regression coverage checks localized layout widths, English/German switching, platform conventions and unchanged command execution. Milestone and effort estimates unchanged. diff --git a/contributors/people.toml b/contributors/people.toml index c685b584..3f346cd5 100644 --- a/contributors/people.toml +++ b/contributors/people.toml @@ -74,3 +74,8 @@ sync_github_name = true [people.jay-tau] sync_github_name = true + +[people.arcanii] +real_name = "Bryan Mark" +display_name = "Arcanii" +sync_github_name = false diff --git a/crates/js/src/formcalc.rs b/crates/js/src/formcalc.rs index 0fc07164..5942391b 100644 --- a/crates/js/src/formcalc.rs +++ b/crates/js/src/formcalc.rs @@ -2543,7 +2543,11 @@ pub(crate) fn run_formcalc_at( /// [`run_formcalc`] on its own thread, abandoned after `timeout` (and told to stop itself then). pub fn run_formcalc_within(script: &str, event: &XfaEvent, doc: &XfaDoc, root: XfaNode, limits: Limits, timeout: std::time::Duration) -> XfaOutcome { let (script, event, doc) = (script.to_string(), event.clone(), doc.clone()); - run_within("pdfcraft-formcalc", timeout, move || run_formcalc_at(&script, &event, &doc, root, limits, Some(timeout))) + // FormCalc has no engine to start: its time (and its own deadline) begins at once. + run_within("pdfcraft-formcalc", timeout, move |started| { + started(); + run_formcalc_at(&script, &event, &doc, root, limits, Some(timeout)) + }) } #[cfg(test)] diff --git a/crates/js/src/tests.rs b/crates/js/src/tests.rs index cb8b9974..e0c9a24e 100644 --- a/crates/js/src/tests.rs +++ b/crates/js/src/tests.rs @@ -544,6 +544,37 @@ mod xfa_model { let o = go("xfa.host.messageBox(new Array(100000).join('x'));", "form1[0].page1[0]", "click"); assert!(matches!(&o.effects[0], XfaEffect::MessageBox(m) if m.chars().count() <= 4_097)); } + + #[test] + fn a_slow_engine_start_does_not_count_against_the_script() { + let ms = std::time::Duration::from_millis; + // On a busy machine the engine can take longer to start than a script may run: the + // script still runs (abandoning it would turn the form's scripts off). + let o = run_within_limits("test", ms(10_000), ms(500), move |started| { + std::thread::sleep(ms(1_500)); + started(); + XfaOutcome { result: Some("ran".into()), ..Default::default() } + }); + assert!(!o.abandoned, "{o:?}"); + assert_eq!(o.result.as_deref(), Some("ran")); + // The script's own time counts from then. + let o = run_within_limits("test", ms(10_000), ms(200), move |started| { + started(); + std::thread::sleep(ms(2_000)); + XfaOutcome::default() + }); + assert!(o.abandoned && o.error.as_deref().is_some_and(|e| e.contains("ran longer")), "{o:?}"); + // Start-up has a limit of its own, so nobody waits forever for an engine. + let o = run_within_limits("test", ms(200), ms(10_000), move |started| { + std::thread::sleep(ms(2_000)); + started(); + XfaOutcome::default() + }); + assert!(o.abandoned && o.error.as_deref().is_some_and(|e| e.contains("to start")), "{o:?}"); + // A script that finishes without saying it started (refused at once) isn't abandoned. + let o = run_within_limits("test", ms(10_000), ms(200), |_| XfaOutcome { error: Some("refused".into()), ..Default::default() }); + assert!(!o.abandoned && o.error.as_deref() == Some("refused"), "{o:?}"); + } } mod formcalc { diff --git a/crates/js/src/xfa.rs b/crates/js/src/xfa.rs index c6995ba2..e9a11c7d 100644 --- a/crates/js/src/xfa.rs +++ b/crates/js/src/xfa.rs @@ -1345,7 +1345,7 @@ pub fn run_xfa(script: &str, event: &XfaEvent, doc: &XfaDoc, root: &XfaNode, lim let spawned = std::thread::Builder::new() .name("pdfcraft-xfa-js".into()) .stack_size(crate::SCRIPT_STACK) - .spawn_scoped(scope, || run_here(script, event, doc, root.clone(), limits)); + .spawn_scoped(scope, || run_here(script, event, doc, root.clone(), limits, &|| {})); match spawned { Ok(thread) => thread.join().unwrap_or_else(|_| failed("the script stopped with an internal error".into())), Err(e) => failed(format!("the script engine could not start: {e}")), @@ -1353,56 +1353,112 @@ pub fn run_xfa(script: &str, event: &XfaEvent, doc: &XfaDoc, root: &XfaNode, lim }) } #[cfg(target_arch = "wasm32")] - run_here(script, event, doc, root.clone(), limits) + run_here(script, event, doc, root.clone(), limits, &|| {}) } -/// [`run_xfa`] with a time limit: a script still running after `timeout` (loops inside -/// nested function calls can run for hours within the engine's per-frame loop limit) is left -/// on its thread, which ends when the engine's own limits stop it, and an outcome with -/// `abandoned` set comes back at once. In the browser build there are no threads: the script -/// runs to its limits. +/// [`run_xfa`] with a time limit: a script still running `timeout` after the engine is ready +/// (loops inside nested function calls can run for hours within the engine's per-frame loop +/// limit) is left on its thread, which ends when the engine's own limits stop it, and an +/// outcome with `abandoned` set comes back at once. In the browser build there are no +/// threads: the script runs to its limits. pub fn run_xfa_within(script: &str, event: &XfaEvent, doc: &XfaDoc, root: XfaNode, limits: Limits, timeout: std::time::Duration) -> XfaOutcome { if let Some(why) = refuse(script) { return XfaOutcome { error: Some(why), ..Default::default() }; } let (script, event, doc) = (script.to_string(), event.clone(), doc.clone()); - run_within("pdfcraft-xfa-js", timeout, move || run_here(&script, &event, &doc, root, limits)) + run_within("pdfcraft-xfa-js", timeout, move |started| run_here(&script, &event, &doc, root, limits, started)) } +/// Longest the script engine may take to be ready for a script (its thread and context, and +/// for the first script in a process the engine's own set-up) before the script is abandoned. +/// It doesn't count against the script's time: on a busy machine the start alone can take +/// longer than the tightest limit, and abandoning a script turns the form's scripts off. +const ENGINE_START_LIMIT: std::time::Duration = std::time::Duration::from_secs(10); + /// Run `script` on its own thread (with the script stack) and wait at most `timeout` for its -/// outcome; past that the thread is abandoned and the outcome says so. On wasm there are no -/// threads: the script runs here. -pub(crate) fn run_within(name: &str, timeout: std::time::Duration, script: impl FnOnce() -> XfaOutcome + Send + 'static) -> XfaOutcome { +/// outcome, counted from when it calls `started` (once the engine is ready); past that the +/// thread is abandoned and the outcome says so. On wasm there are no threads: the script runs +/// here. +pub(crate) fn run_within(name: &str, timeout: std::time::Duration, script: impl FnOnce(&dyn Fn()) -> XfaOutcome + Send + 'static) -> XfaOutcome { + run_within_limits(name, ENGINE_START_LIMIT, timeout, script) +} + +/// [`run_within`] with the engine's start-up limit given. +pub(crate) fn run_within_limits( + name: &str, + start_limit: std::time::Duration, + timeout: std::time::Duration, + script: impl FnOnce(&dyn Fn()) -> XfaOutcome + Send + 'static, +) -> XfaOutcome { #[cfg(not(target_arch = "wasm32"))] { + use std::sync::mpsc::RecvTimeoutError; + use std::time::Instant; + enum Step { + Started, + Done(XfaOutcome), + } let failed = |why: String| XfaOutcome { error: Some(why), ..Default::default() }; + let abandoned = |why: String| XfaOutcome { error: Some(why), abandoned: true, ..Default::default() }; let (tx, rx) = std::sync::mpsc::channel(); let spawned = std::thread::Builder::new().name(name.into()).stack_size(crate::SCRIPT_STACK).spawn(move || { // The receiver is gone when the caller stopped waiting: nothing to report then. - let _ = tx.send(script()); + let started = tx.clone(); + let outcome = script(&move || { + let _ = started.send(Step::Started); + }); + let _ = tx.send(Step::Done(outcome)); }); if let Err(e) = spawned { return failed(format!("the script engine could not start: {e}")); } - match rx.recv_timeout(timeout) { - Ok(o) => o, - Err(std::sync::mpsc::RecvTimeoutError::Timeout) => XfaOutcome { - error: Some(format!("the script ran longer than {:.1} s and was abandoned", timeout.as_secs_f64())), - abandoned: true, - ..Default::default() - }, - Err(std::sync::mpsc::RecvTimeoutError::Disconnected) => failed("the script stopped with an internal error".into()), + // Wait for the engine within its start-up limit, then for the script within its own. + let (mut running, mut limit) = (false, start_limit); + let mut deadline = Instant::now().checked_add(limit); + loop { + let left = deadline.map_or(limit, |d| d.saturating_duration_since(Instant::now())); + match rx.recv_timeout(left) { + Ok(Step::Done(o)) => return o, + Ok(Step::Started) => { + // A second call changes nothing: the script's time has already begun. + if !running { + (running, limit) = (true, timeout); + deadline = Instant::now().checked_add(limit); + } + } + Err(RecvTimeoutError::Timeout) if running => { + return abandoned(format!("the script ran longer than {:.1} s and was abandoned", timeout.as_secs_f64())); + } + Err(RecvTimeoutError::Timeout) => { + return abandoned(format!("the script engine took longer than {:.0} s to start", start_limit.as_secs_f64())); + } + Err(RecvTimeoutError::Disconnected) => return failed("the script stopped with an internal error".into()), + } } } #[cfg(target_arch = "wasm32")] { - let _ = (name, timeout); - script() + let _ = (name, start_limit, timeout); + script(&|| {}) } } -fn run_here(script: &str, event: &XfaEvent, doc: &XfaDoc, root: XfaNode, limits: Limits) -> XfaOutcome { +/// The first script in a process sets the engine up (its built-ins, parser and compiler come +/// into use): a trivial script takes that on, so a form's script is never timed with it. +fn warm_up() { + static WARM: std::sync::Once = std::sync::Once::new(); + // `call_once_force`: a poisoned `Once` (a panic while warming up) only means warming up again. + WARM.call_once_force(|_| { + let mut ctx = Context::default(); + let _ = ctx.eval(Source::from_bytes(b"(function () { return eval('0'); }).call({})")); + }); +} + +/// `started` is called once the engine is ready: a time limit on the script runs from then. +fn run_here(script: &str, event: &XfaEvent, doc: &XfaDoc, root: XfaNode, limits: Limits, started: &dyn Fn()) -> XfaOutcome { + warm_up(); let mut ctx = Context::default(); + started(); ctx.runtime_limits_mut().set_loop_iteration_limit(limits.loop_iterations); ctx.runtime_limits_mut().set_recursion_limit(limits.recursion); let host_state = XHost::new(root, &event.target, doc); diff --git a/crates/ui-egui/tests/xfa.rs b/crates/ui-egui/tests/xfa.rs index 587972d5..ccae2ea5 100644 --- a/crates/ui-egui/tests/xfa.rs +++ b/crates/ui-egui/tests/xfa.rs @@ -135,10 +135,10 @@ fn xfa_buttons_run_their_scripts_in_the_app() { }; assert!(!names(&h).iter().any(|n| n == "amount_2")); click_field(&mut h, "addRow"); - assert!(names(&h).iter().any(|n| n == "amount_2"), "{:?}", names(&h)); + assert!(names(&h).iter().any(|n| n == "amount_2"), "{:?}; script console: {:?}", names(&h), h.state().js_console.log); // The message box shows as a notice. click_field(&mut h, "hello"); - h.get_by_label_contains("Hello 2"); + assert!(h.query_by_label_contains("Hello 2").is_some(), "script console: {:?}", h.state().js_console.log); } #[test] @@ -147,7 +147,7 @@ fn messages_from_scripts_run_on_open_show_right_away() { .replace("if (qty.rawValue === null) qty.rawValue = 2;", r#"xfa.host.messageBox("Welcome to the form"); xfa.host.print();"#); let mut h = open(pdfcraft_xfa::fixtures::shell(&tpl)); h.run_steps(2); - h.get_by_label_contains("Welcome to the form"); + assert!(h.query_by_label_contains("Welcome to the form").is_some(), "script console: {:?}", h.state().js_console.log); assert_eq!(h.state().dialog, None, "an initialize script can't open the Print dialog"); let id = h.state().views[0].id; assert!(h.state_mut().session.take_js_output(id).is_empty(), "nothing waits for the next edit");