Tests: tests that depend on wall-clock time or font loads pass on a loaded machine

On a machine busy with other builds, four tests each failed once and
passed when run again alone.

The two render tests that count the rasters a drag moves draw content
painted with a pattern or showing a symbol, whose raster key holds the
font generation. The fonts change even while a test holds
fonts_steady(): the first lookup by family name catalogs the installed
fonts, and resolving a cataloged family or a fallback character loads a
face. When that happened between the two frames of a drag, the count
was 0. The new with_fonts_unchanged runs a step up to 100 times, until
the generation is the same after a run as before it, and the two tests
take their frames from it. The second render test,
a_moved_group_draws_the_shadow_of_the_instance_art_in_it_while_interacting,
was not seen failing but has the same fault.

The screenshot test's allow_due moved the capture's due time but not
its 8 s wall-clock deadline, so on a slow run the reply was the timeout
error. allow_due now also sets the deadline to f64::MAX; the two timeout
tests set it in the past themselves.

The persistent control server test gave the server 2 s to wait for
each request, 120 ms to read a line and 150 ms to write a reply. It now
gives the line and the reply 1 s each and the wait 30 s. The handler
sleeps 1.25 s, longer than both budgets, so a deadline kept from the
first request still runs out.

The idle expiry test read until the server closed the connection after
its 150 ms idle budget, and the client gave up after 3 s, so a pause of
about 3 s in the server's thread failed it with TimedOut. Every test in
control_server/tests.rs that waits for the server to reply, to close a
connection or to return its slot now waits up to WAIT (20 s), and
line_timeouts() gives the wait for a request and the reply 30 s. The
budgets under test stay 120 and 150 ms (1 s in the persistent test).

apps/vectorcraft/src/control_server/tests.rs

@@ -4,12 +4,18 @@ fn short_timeouts() -> ConnectionTimeouts {
     ConnectionTimeouts { idle: Duration::from_millis(150), line: Duration::from_millis(120), write: Duration::from_millis(150) }
 }
 
-/// The short line deadline, with idle and reply budgets longer than the tests' 3 s waits. On a
-/// busy machine either thread can pause for more than 150 ms between connecting and sending, or
-/// between starting a reply and writing it, and a short budget then closes the connection with no
-/// reply.
+/// How long a test waits for the server to reply or to close a connection. The wait only ends a
+/// test whose server never does either; the budgets under test are 120 and 150 ms, and 1 s in the
+/// persistent test. On a busy machine the server's thread can pause for seconds before or between
+/// its reads and writes, and a wait of a few seconds then fails a server that closes the
+/// connection on time.
+const WAIT: Duration = Duration::from_secs(20);
+
+/// The short line deadline, with idle and reply budgets longer than [`WAIT`]. On a busy machine
+/// either thread can pause for more than 150 ms between connecting and sending, or between
+/// starting a reply and writing it, and a short budget then closes the connection with no reply.
 fn line_timeouts() -> ConnectionTimeouts {
-    ConnectionTimeouts { idle: Duration::from_secs(10), write: Duration::from_secs(10), ..short_timeouts() }
+    ConnectionTimeouts { idle: Duration::from_secs(30), write: Duration::from_secs(30), ..short_timeouts() }
 }
 
 fn socket_fixture(
@@ -27,12 +33,12 @@ fn socket_fixture(
     });
     let client = TcpStream::connect(addr).unwrap();
     socket2::SockRef::from(&client).set_recv_buffer_size(4096).unwrap();
-    client.set_read_timeout(Some(Duration::from_secs(3))).unwrap();
+    client.set_read_timeout(Some(WAIT)).unwrap();
     (client, done, worker)
 }
 
 fn expect_socket_deadline(client: TcpStream, done: Receiver<()>, worker: std::thread::JoinHandle<()>) {
-    let stopped = done.recv_timeout(Duration::from_secs(3)).is_ok();
+    let stopped = done.recv_timeout(WAIT).is_ok();
     // Always unblock the old implementation too, so a failed regression leaves no worker behind.
     let _ = client.shutdown(std::net::Shutdown::Both);
     drop(client);
@@ -93,7 +99,7 @@ fn trickled_control_line_has_an_absolute_deadline() {
             std::thread::sleep(Duration::from_millis(20));
         }
     });
-    let stopped = done.recv_timeout(Duration::from_secs(3)).is_ok();
+    let stopped = done.recv_timeout(WAIT).is_ok();
     stop.store(true, Ordering::SeqCst);
     // Both socket copies belong to this fixture; shutdown cleans up the baseline failure as well.
     let _ = client.shutdown(std::net::Shutdown::Both);
@@ -110,26 +116,31 @@ fn a_nonreading_control_peer_cannot_retain_the_writer() {
     expect_socket_deadline(client, done, worker);
 }
 
+/// Each request gets its own line and reply budgets. The handler takes longer than both budgets,
+/// so a deadline kept from the previous request runs out. The line and reply budgets are 1 s, and
+/// the idle budget is 30 s, longer than the client's [`WAIT`]: on a busy machine either thread can
+/// pause for more than the short budgets of [`short_timeouts`] between starting a budget and the
+/// read or write it covers.
 #[test]
 fn persistent_control_requests_get_fresh_transport_deadlines() {
-    let timeouts = ConnectionTimeouts { idle: Duration::from_secs(2), ..short_timeouts() };
+    let timeouts = ConnectionTimeouts { idle: Duration::from_secs(30), line: Duration::from_secs(1), write: Duration::from_secs(1) };
     let (mut client, done, worker) = socket_fixture(timeouts, |_, _| {
         // Application processing is not transport time; begin the reply budget afterwards.
-        std::thread::sleep(Duration::from_millis(200));
+        std::thread::sleep(Duration::from_millis(1250));
         Some(json!({"ok": true}))
     });
     let mut reader = BufReader::new(client.try_clone().unwrap());
     for id in [1, 2] {
         // The client sends each line in one write. `writeln!` on the socket sends the JSON in many
-        // small writes, and when the machine is busy, a pause of more than the 120 ms line deadline
-        // between two of them closes the connection.
+        // small writes, and when the machine is busy, a pause of more than the line deadline between
+        // two of them closes the connection.
         client.write_all(format!("{}\n", json!({"id": id, "method": "inspect"})).as_bytes()).unwrap();
         let mut line = String::new();
         reader.read_line(&mut line).unwrap();
         assert_eq!(serde_json::from_str::<Value>(&line).unwrap(), json!({"id": id, "ok": true}));
     }
     client.shutdown(std::net::Shutdown::Write).unwrap();
-    done.recv_timeout(Duration::from_secs(3)).unwrap();
+    done.recv_timeout(WAIT).unwrap();
     worker.join().unwrap();
 }
 
@@ -155,7 +166,7 @@ fn timed_out_worker_returns_its_connection_slot() {
     let (tx, _rx) = channel();
     let worker = spawn_connection(stream, tx, egui::Context::default(), slot, short_timeouts()).unwrap();
     let start = std::time::Instant::now();
-    while open.load(Ordering::SeqCst) == MAX_CONNECTIONS && start.elapsed() < Duration::from_secs(3) {
+    while open.load(Ordering::SeqCst) == MAX_CONNECTIONS && start.elapsed() < WAIT {
         std::thread::sleep(Duration::from_millis(10));
     }
     let released = open.load(Ordering::SeqCst) < MAX_CONNECTIONS;
@@ -322,7 +333,7 @@ fn tcp_connection_is_closed_after_junk() {
         serve_lines(read, s, |_, _| Some(json!({"ok": true})));
     });
     let mut c = TcpStream::connect(addr).unwrap();
-    c.set_read_timeout(Some(Duration::from_secs(5))).unwrap();
+    c.set_read_timeout(Some(WAIT)).unwrap();
     c.write_all(b"{\"id\":7,\"method\":\"x\"}\nhello\n{\"method\":\"y\"}\n").unwrap();
     let mut text = String::new();
     c.read_to_string(&mut text).unwrap(); // returns at EOF: the server closed the connection
@@ -373,7 +384,7 @@ fn extra_connections_are_refused() {
     // Idle connections are accepted in order and held open.
     let held: Vec<TcpStream> = (0..16).map(|_| TcpStream::connect(addr).unwrap()).collect();
     let mut extra = TcpStream::connect(addr).unwrap();
-    extra.set_read_timeout(Some(Duration::from_secs(5))).unwrap();
+    extra.set_read_timeout(Some(WAIT)).unwrap();
     let mut line = String::new();
     BufReader::new(&mut extra).read_line(&mut line).unwrap();
     assert!(line.contains("too many control connections"), "{line}");

crates/render/src/fx/tests.rs

@@ -4,7 +4,7 @@ use vectorcraft_doc::{Appearance, Document, Effect, Node};
 use vectorcraft_geom::{Affine, Rect, shapes};
 
 use super::{DRAG_PIXEL_BUDGET, Drawn, PIXEL_BUDGET, drag_scale, filter_region, filter_region_within, pan_margin};
-use crate::tests_fontchange::fonts_steady;
+use crate::tests_fontchange::{fonts_steady, with_fonts_unchanged};
 use crate::{RenderOptions, Rendered, Renderer};
 
 /// #1706: the raster a shadow or glow is filtered in stays within the pixel budget however
@@ -758,17 +758,26 @@ fn a_moved_group_draws_the_shadow_of_the_instance_art_in_it_while_interacting()
     let (view, still) = (Affine::scale(2.0), RenderOptions { background: Some([255, 255, 255, 255]), ..Default::default() });
     let live = RenderOptions { interacting: true, ..still.clone() };
     let fresh = |d: &Document| Renderer::new().render(d, 200, 200, view, &still);
-    let mut r = Renderer::new();
-    let first = r.render(&base, 200, 200, view, &still);
+    // Content that shows a symbol reads the fonts, so the frames come from a run in which the
+    // fonts stayed the same.
+    let moves = [(3.0, 0.0), (5.5, 2.0)];
+    let (first, frames) = with_fonts_unchanged(|| {
+        let mut r = Renderer::new();
+        let first = r.render(&base, 200, 200, view, &still);
+        let frames = moves.map(|(dx, dy)| {
+            let d = moved(dx, dy);
+            let frame = r.render(&d, 200, 200, view, &live).pixels;
+            (r.stats.moved, frame == fresh(&d).pixels)
+        });
+        (first, frames)
+    });
     assert!(first.pixels == fresh(&base).pixels);
     // The shadow, 4 pt right of the art's right edge at x 50, at (104, 70) in pixels.
     assert!(lum(first.pixel(104, 70)) < WHITE, "{:?}", first.pixel(104, 70));
     // Moves on whole pixels (2 a point): the moved shadow lies where a fresh renderer draws it.
-    for (dx, dy) in [(3.0, 0.0), (5.5, 2.0)] {
-        let d = moved(dx, dy);
-        let frame = r.render(&d, 200, 200, view, &live).pixels;
-        assert_eq!(r.stats.moved, 1, "the shadow moved by ({dx}, {dy})");
-        assert!(frame == fresh(&d).pixels, "moved by ({dx}, {dy})");
+    for ((dx, dy), (count, same)) in moves.into_iter().zip(frames) {
+        assert_eq!(count, 1, "the shadow moved by ({dx}, {dy})");
+        assert!(same, "moved by ({dx}, {dy})");
     }
 }
 
@@ -783,12 +792,15 @@ fn moved_rasters_need_the_same_content_and_effects() {
     let (view, still) = (Affine::scale(2.0), RenderOptions { background: Some([255, 255, 255, 255]), ..Default::default() });
     let live = RenderOptions { interacting: true, ..still.clone() };
     // `before` drawn, then `after` while interacting: the rasters drawn moved, and whether the
-    // frame is what a fresh renderer draws.
+    // frame is what a fresh renderer draws. Content painted with a pattern reads the fonts, so
+    // the counts come from a run in which the fonts stayed the same.
     let drag = |before: &Document, after: &Document| {
-        let mut r = Renderer::new();
-        let _ = r.render(before, 200, 200, view, &still);
-        let frame = r.render(after, 200, 200, view, &live).pixels;
-        (r.stats.moved, frame == Renderer::new().render(after, 200, 200, view, &still).pixels)
+        with_fonts_unchanged(|| {
+            let mut r = Renderer::new();
+            let _ = r.render(before, 200, 200, view, &still);
+            let frame = r.render(after, 200, 200, view, &live).pixels;
+            (r.stats.moved, frame == Renderer::new().render(after, 200, 200, view, &still).pixels)
+        })
     };
     // `d`'s object moved 5, 3 (10, 6 pixels), then changed by `edit`.
     let moved = |d: &Document, patterns: bool, edit: &dyn Fn(&mut Node)| {

crates/render/src/tests/fontchange.rs

@@ -26,6 +26,23 @@ pub(crate) fn adding_fonts() -> RwLockWriteGuard<'static, ()> {
     FONTS.write().unwrap_or_else(PoisonError::into_inner)
 }
 
+/// What `step` returns from a run in which the fonts stayed the same. The fonts can change while
+/// [`fonts_steady`] is held: the first lookup by family name catalogs the installed fonts, and
+/// resolving a cataloged family, or a character no loaded font has, loads a face. `step` runs up
+/// to 100 times, until [`vectorcraft_text::FontDb::generation`] is the same after a run as before
+/// it.
+pub(crate) fn with_fonts_unchanged<T>(mut step: impl FnMut() -> T) -> T {
+    let db = vectorcraft_text::FontDb::global();
+    for _ in 0..100 {
+        let before = db.generation();
+        let out = step();
+        if db.generation() == before {
+            return out;
+        }
+    }
+    panic!("the fonts changed during each of 100 runs");
+}
+
 /// The bundled Source Serif 4 renamed `family` (as long as the original name).
 fn serif_as(family: &str) -> Vec<u8> {
     let mut data = include_bytes!("../../../../assets/fonts/SourceSerif4-Regular.ttf").to_vec();

crates/ui-egui/src/tests/screenshots.rs

@@ -59,12 +59,16 @@ fn issued(out: &egui::FullOutput) -> Option<egui::ScreenshotCallback> {
     })
 }
 
-/// Make an admitted capture due now: the settle policy measures wall-clock animation time, which
-/// a test must not race. The frame count in `issue_screenshots` still proves the settle passes.
+/// Make an admitted capture due now, with no deadline: the settle policy and the deadline both
+/// measure wall-clock time, which a test must not race. The frame count in `issue_screenshots`
+/// still proves the settle passes, and the timeout tests set the deadline in the past themselves.
 fn allow_due(app: &mut VectorcraftApp) {
     for queued in &mut app.queued_screenshots {
         queued.due_ms = f64::MIN;
     }
+    for pending in &mut app.pending_screenshots {
+        pending.deadline_ms = f64::MAX;
+    }
 }
 
 /// Run full frames until the capture is issued (bounded: a failure is an error, not a hang).