mirror of
https://github.com/storytold/lightcraft.git
synced 2026-10-14 11:17:05 -04:00
FreeBSD CI: three more flaky tests made deterministic
import_reads_files_off_the_ui_thread_and_can_be_cancelled: the probe was
a 150 ms sleep judged by a 300 ms wall-clock frame budget, which the
loaded FreeBSD QEMU VM can miss. It now waits on the sleeping-NAS gate of
tests_offline, which can also let a counted number of reads through:
frames must go on while every read is held (a watchdog records a frame
that waited), one batch is let through and joins the catalog, then
Cancel and wake: the files being read finish and nothing new starts.
compare_at_one_to_one_gets_a_sharp_window_per_pane ("both originals stay
decoded"): the media cache takes its budget from the process-wide memory
budget, which settings_dialog_by_keyboard_and_clicks sets to 1 GB for a
moment (and left there when it failed on FreeBSD). That leaves a 512 MiB
share, too small for two 24 MP originals (288 MB each), so one pane's
was evicted. compare_at now gives its session the default 768 MiB share;
LIGHTCRAFT_MEMORY_MB=1024 reproduces the failure without this.
dropping_the_lock_frees_the_library_while_another_thread_spawns_processes:
"the spawning thread never got a child off the ground" when a spawn took
longer than the 2 s of lock cycles. The cycles now go on until at least
5 children were spawned during them (at most a minute).
Co-Authored-By: Claude Opus 5.5 <[email protected]>
This commit is contained in:
1 parent
16dbb90499
commit
3b4279fc24
3 files changed
+77
-47
No files matched your search
@@ -126,33 +126,40 @@ fn the_library_is_free_once_dropped_even_if_a_child_holds_a_copy() {
|
|||||||
|
|
||||||
/// Issue #680, as it happens in practice: one thread spawns cheap children while another acquires,
|
/// Issue #680, as it happens in practice: one thread spawns cheap children while another acquires,
|
||||||
/// drops and re-acquires the lock on its own directory. Every acquire must succeed (before the fix
|
/// drops and re-acquires the lock on its own directory. Every acquire must succeed (before the fix
|
||||||
/// a few per cent were refused with `InUse(None)`). Bounded: about two seconds of cycles, pass or fail.
|
/// a few per cent were refused with `InUse(None)`). Bounded: about two seconds of cycles, and on a
|
||||||
|
/// slow or loaded machine (the FreeBSD CI VM, where a spawn can take longer than that) until a few
|
||||||
|
/// children have been spawned during them, at most a minute.
|
||||||
#[cfg(unix)]
|
#[cfg(unix)]
|
||||||
#[test]
|
#[test]
|
||||||
fn dropping_the_lock_frees_the_library_while_another_thread_spawns_processes() {
|
fn dropping_the_lock_frees_the_library_while_another_thread_spawns_processes() {
|
||||||
use std::sync::Arc;
|
use std::sync::Arc;
|
||||||
use std::sync::atomic::{AtomicBool, Ordering};
|
use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
|
||||||
|
use std::time::{Duration, Instant};
|
||||||
|
|
||||||
|
/// Children spawned while the lock cycles, at least, before the test may stop.
|
||||||
|
const CHILDREN: usize = 5;
|
||||||
|
|
||||||
let dir = temp_dir("spawn");
|
let dir = temp_dir("spawn");
|
||||||
let stop = Arc::new(AtomicBool::new(false));
|
let stop = Arc::new(AtomicBool::new(false));
|
||||||
|
let count = Arc::new(AtomicUsize::new(0));
|
||||||
let spawner = {
|
let spawner = {
|
||||||
let stop = Arc::clone(&stop);
|
let (stop, count) = (Arc::clone(&stop), Arc::clone(&count));
|
||||||
std::thread::spawn(move || {
|
std::thread::spawn(move || {
|
||||||
let mut spawned = 0usize;
|
|
||||||
while !stop.load(Ordering::Relaxed) {
|
while !stop.load(Ordering::Relaxed) {
|
||||||
if let Ok(mut c) = std::process::Command::new("true").stdout(std::process::Stdio::null()).stderr(std::process::Stdio::null()).spawn()
|
if let Ok(mut c) = std::process::Command::new("true").stdout(std::process::Stdio::null()).stderr(std::process::Stdio::null()).spawn()
|
||||||
{
|
{
|
||||||
let _ = c.wait();
|
let _ = c.wait();
|
||||||
spawned += 1;
|
count.fetch_add(1, Ordering::Relaxed);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
spawned
|
count.load(Ordering::Relaxed)
|
||||||
})
|
})
|
||||||
};
|
};
|
||||||
let deadline = std::time::Instant::now() + std::time::Duration::from_secs(2);
|
let t0 = Instant::now();
|
||||||
|
let enough = |cycles: usize| (cycles >= 200_000 || t0.elapsed() >= Duration::from_secs(2)) && count.load(Ordering::Relaxed) >= CHILDREN;
|
||||||
let mut cycles = 0usize;
|
let mut cycles = 0usize;
|
||||||
let mut refused = Vec::new();
|
let mut refused = Vec::new();
|
||||||
while cycles < 200_000 && std::time::Instant::now() < deadline {
|
while !enough(cycles) && t0.elapsed() < Duration::from_secs(60) {
|
||||||
match LibraryLock::acquire(&dir, "LightCraft") {
|
match LibraryLock::acquire(&dir, "LightCraft") {
|
||||||
Ok(l) => assert!(l.held()), // dropped here: the next cycle must get it back
|
Ok(l) => assert!(l.held()), // dropped here: the next cycle must get it back
|
||||||
Err(e) => refused.push(format!("cycle {cycles}: {e:?}")),
|
Err(e) => refused.push(format!("cycle {cycles}: {e:?}")),
|
||||||
|
|||||||
@@ -1,11 +1,11 @@
|
|||||||
//! Slow or offline drives never stall a frame (issue #104): with an injected file-system probe
|
//! Slow or offline drives never stall a frame (issue #104): with an injected file-system probe
|
||||||
//! that does not answer at all until the test lets it (a sleeping NAS), the grid, the Info panel,
|
//! that does not answer at all until the test lets it (a sleeping NAS), the grid, the Info panel,
|
||||||
//! the Rename dialog and the Missing Photos view keep drawing frames, the probe never runs on the
|
//! the Rename dialog, the Missing Photos view and an import keep drawing frames, the probe never
|
||||||
//! UI thread, and the background answers arrive once the drive wakes up.
|
//! runs on the UI thread, and the background answers arrive once the drive wakes up.
|
||||||
//!
|
//!
|
||||||
//! The NAS is a gate, not a sleep: a frame that waited for the drive would wait for good (until a
|
//! The NAS is a gate, not a sleep: a frame that waited for the drive would wait for good (until a
|
||||||
//! watchdog gives up and records it), so the test needs no frame-time budget and holds on a slow
|
//! watchdog gives up and records it), so the tests need no frame-time budget and hold on a slow
|
||||||
//! or loaded machine (the FreeBSD CI VM) as it does on a fast one.
|
//! or loaded machine (the FreeBSD CI VM) as they do on a fast one.
|
||||||
|
|
||||||
use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
|
use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
|
||||||
use std::sync::{Arc, Condvar, Mutex};
|
use std::sync::{Arc, Condvar, Mutex};
|
||||||
@@ -20,8 +20,6 @@ use crate::headless::Headless;
|
|||||||
use crate::state::{RightPanel, ViewMode};
|
use crate::state::{RightPanel, ViewMode};
|
||||||
use crate::{LightcraftApp, Services};
|
use crate::{LightcraftApp, Services};
|
||||||
|
|
||||||
/// The import test's frame budget (its files take 150 ms each to read).
|
|
||||||
const FRAME_LIMIT: Duration = Duration::from_millis(300);
|
|
||||||
const N: u64 = 12;
|
const N: u64 = 12;
|
||||||
/// How long the drive stays asleep at most: only a frame stuck waiting for it gets this far.
|
/// How long the drive stays asleep at most: only a frame stuck waiting for it gets this far.
|
||||||
const WATCHDOG: Duration = Duration::from_secs(120);
|
const WATCHDOG: Duration = Duration::from_secs(120);
|
||||||
@@ -43,11 +41,13 @@ impl Calls {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
/// The sleeping drive: every file-system call waits until [`Nas::wake`]. A watchdog wakes it
|
/// The sleeping drive: every file-system call waits until [`Nas::wake`] (or takes one of the
|
||||||
/// after [`WATCHDOG`] and records that it had to (some frame was waiting for the drive).
|
/// calls [`Nas::let_through`] allows). A watchdog wakes it after [`WATCHDOG`] and records that it
|
||||||
|
/// had to (some frame was waiting for the drive).
|
||||||
#[derive(Default)]
|
#[derive(Default)]
|
||||||
struct Nas {
|
struct Nas {
|
||||||
awake: Mutex<bool>,
|
/// (awake, calls let through while asleep)
|
||||||
|
state: Mutex<(bool, usize)>,
|
||||||
changed: Condvar,
|
changed: Condvar,
|
||||||
forced: AtomicBool,
|
forced: AtomicBool,
|
||||||
}
|
}
|
||||||
@@ -57,22 +57,30 @@ impl Nas {
|
|||||||
let nas = Arc::new(Nas::default());
|
let nas = Arc::new(Nas::default());
|
||||||
let dog = nas.clone();
|
let dog = nas.clone();
|
||||||
std::thread::spawn(move || {
|
std::thread::spawn(move || {
|
||||||
let awake = dog.awake.lock().unwrap();
|
let state = dog.state.lock().unwrap();
|
||||||
let (mut awake, _) = dog.changed.wait_timeout_while(awake, WATCHDOG, |a| !*a).unwrap();
|
let (mut state, _) = dog.changed.wait_timeout_while(state, WATCHDOG, |s| !s.0).unwrap();
|
||||||
if !*awake {
|
if !state.0 {
|
||||||
dog.forced.store(true, Ordering::SeqCst);
|
dog.forced.store(true, Ordering::SeqCst);
|
||||||
*awake = true;
|
state.0 = true;
|
||||||
dog.changed.notify_all();
|
dog.changed.notify_all();
|
||||||
}
|
}
|
||||||
});
|
});
|
||||||
nas
|
nas
|
||||||
}
|
}
|
||||||
fn wait(&self) {
|
fn wait(&self) {
|
||||||
let awake = self.awake.lock().unwrap();
|
let state = self.state.lock().unwrap();
|
||||||
drop(self.changed.wait_while(awake, |a| !*a).unwrap());
|
let mut state = self.changed.wait_while(state, |s| !s.0 && s.1 == 0).unwrap();
|
||||||
|
if !state.0 {
|
||||||
|
state.1 -= 1;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
/// Answer `n` more calls, then sleep again.
|
||||||
|
fn let_through(&self, n: usize) {
|
||||||
|
self.state.lock().unwrap().1 += n;
|
||||||
|
self.changed.notify_all();
|
||||||
}
|
}
|
||||||
fn wake(&self) {
|
fn wake(&self) {
|
||||||
*self.awake.lock().unwrap() = true;
|
self.state.lock().unwrap().0 = true;
|
||||||
self.changed.notify_all();
|
self.changed.notify_all();
|
||||||
}
|
}
|
||||||
/// The watchdog had to wake the drive: a frame waited for it.
|
/// The watchdog had to wake the drive: a frame waited for it.
|
||||||
@@ -162,24 +170,27 @@ fn offline_originals_never_block_a_frame() {
|
|||||||
}
|
}
|
||||||
|
|
||||||
/// An import whose files take long to read (probe: decoding headers and hashing on a slow drive)
|
/// An import whose files take long to read (probe: decoding headers and hashing on a slow drive)
|
||||||
/// runs on a worker thread: frames stay quick, the probe never runs on the UI thread, and Cancel
|
/// runs on a worker thread: frames go on while the drive holds every read, the probe never runs
|
||||||
/// stops it with what was read so far added.
|
/// on the UI thread, and Cancel stops it with what was read so far added.
|
||||||
#[test]
|
#[test]
|
||||||
fn import_reads_files_off_the_ui_thread_and_can_be_cancelled() {
|
fn import_reads_files_off_the_ui_thread_and_can_be_cancelled() {
|
||||||
let dir = std::env::temp_dir().join(format!("lc-ui-slow-import-{}", std::process::id()));
|
let dir = std::env::temp_dir().join(format!("lc-ui-slow-import-{}", std::process::id()));
|
||||||
let _ = std::fs::remove_dir_all(&dir);
|
let _ = std::fs::remove_dir_all(&dir);
|
||||||
std::fs::create_dir_all(&dir).unwrap();
|
std::fs::create_dir_all(&dir).unwrap();
|
||||||
// enough files that the import is still running when its activity row shows (after 0.5 s)
|
|
||||||
let n = 120;
|
let n = 120;
|
||||||
for i in 0..n {
|
for i in 0..n {
|
||||||
std::fs::write(dir.join(format!("IMG_{i:03}.jpg")), format!("not really a jpeg {i}")).unwrap();
|
std::fs::write(dir.join(format!("IMG_{i:03}.jpg")), format!("not really a jpeg {i}")).unwrap();
|
||||||
}
|
}
|
||||||
let calls = Calls::default();
|
let calls = Calls::default();
|
||||||
|
let nas = Nas::asleep();
|
||||||
let mut s = Session::new();
|
let mut s = Session::new();
|
||||||
let c = calls.clone();
|
let (c, drive, ui_thread) = (calls.clone(), nas.clone(), std::thread::current().id());
|
||||||
s.media.file_probe = Some(Arc::new(move |p: &str| {
|
s.media.file_probe = Some(Arc::new(move |p: &str| {
|
||||||
c.record();
|
c.record();
|
||||||
std::thread::sleep(Duration::from_millis(150));
|
// on the UI thread: answered at once, so a regression fails the thread check, not by hanging
|
||||||
|
if std::thread::current().id() != ui_thread {
|
||||||
|
drive.wait();
|
||||||
|
}
|
||||||
Ok(lightcraft_engine::media::ProbeInfo {
|
Ok(lightcraft_engine::media::ProbeInfo {
|
||||||
width: 60,
|
width: 60,
|
||||||
height: 40,
|
height: 40,
|
||||||
@@ -190,32 +201,35 @@ fn import_reads_files_off_the_ui_thread_and_can_be_cancelled() {
|
|||||||
}));
|
}));
|
||||||
let app = LightcraftApp::new(s, Services { png: None, ..Default::default() });
|
let app = LightcraftApp::new(s, Services { png: None, ..Default::default() });
|
||||||
let mut h = Headless::new(app, [1200.0, 800.0], 1.0);
|
let mut h = Headless::new(app, [1200.0, 800.0], 1.0);
|
||||||
let ui_thread = std::thread::current().id();
|
|
||||||
h.step();
|
h.step();
|
||||||
// The first frame installs fonts; finish the first layout before timing the import.
|
// The first frame installs fonts; finish the first layout before the drive matters.
|
||||||
h.step();
|
h.step();
|
||||||
assert!(h.app.fonts_ready, "the UI is initialized before import timing starts");
|
assert!(h.app.fonts_ready, "the UI is initialized");
|
||||||
let undo0 = h.app.session.undo.len();
|
let undo0 = h.app.session.undo.len();
|
||||||
crate::import::start_paths(&mut h.app, vec![dir.to_string_lossy().to_string()]).unwrap();
|
crate::import::start_paths(&mut h.app, vec![dir.to_string_lossy().to_string()]).unwrap();
|
||||||
// some batches arrive; meanwhile every frame is quick
|
// every read is held: frames go on, and the import's row shows (after 0.5 s) with its ✕
|
||||||
let t0 = Instant::now();
|
frames_while_asleep(&mut h, &nas, 20, "import");
|
||||||
let mut worst = Duration::ZERO;
|
assert!(h.app.import.is_some(), "importing");
|
||||||
while h.app.import.as_ref().is_some_and(|t| t.imported < 8) && t0.elapsed() < Duration::from_secs(60) {
|
|
||||||
let f = Instant::now();
|
|
||||||
h.step();
|
|
||||||
worst = worst.max(f.elapsed());
|
|
||||||
std::thread::sleep(Duration::from_millis(5));
|
|
||||||
}
|
|
||||||
assert!(worst < FRAME_LIMIT, "import frame took {worst:?}");
|
|
||||||
assert!(h.app.import.is_some(), "still importing");
|
|
||||||
let status = h.app.import.as_ref().map(crate::import::ImportTask::status).unwrap_or_default();
|
|
||||||
assert!(status["total"].as_u64().unwrap_or(0) >= 8, "{status}");
|
|
||||||
// Cancel (the ✕ of its row in the activity stack): the files being read finish, nothing new starts
|
|
||||||
let id = h.app.session.activity.list().first().map(|t| t.id).expect("an import row");
|
let id = h.app.session.activity.list().first().map(|t| t.id).expect("an import row");
|
||||||
let cross = format!("activity:cancel:{id}");
|
let cross = format!("activity:cancel:{id}");
|
||||||
assert!(h.step_until(Duration::from_secs(10), |h| h.app.widgets.iter().any(|(w, _)| *w == cross)), "the row shows");
|
assert!(h.step_until(Duration::from_secs(60), |h| h.app.widgets.iter().any(|(w, _)| *w == cross)), "the row shows");
|
||||||
|
assert!(!nas.forced(), "an import frame waited for the sleeping drive");
|
||||||
|
// the drive answers one batch of reads: it joins the catalog while the next batch waits
|
||||||
|
let batch = lightcraft_engine::import::batch_size();
|
||||||
|
nas.let_through(batch);
|
||||||
|
let t0 = Instant::now();
|
||||||
|
while h.app.import.as_ref().is_some_and(|t| t.imported < batch) && t0.elapsed() < Duration::from_secs(60) {
|
||||||
|
h.step();
|
||||||
|
assert!(!nas.forced(), "an import frame waited for the sleeping drive");
|
||||||
|
std::thread::sleep(Duration::from_millis(5));
|
||||||
|
}
|
||||||
|
assert!(h.app.import.is_some(), "still importing");
|
||||||
|
let status = h.app.import.as_ref().map(crate::import::ImportTask::status).unwrap_or_default();
|
||||||
|
assert!(status["imported"].as_u64().unwrap_or(0) >= 8 && status["total"].as_u64().unwrap_or(0) >= 8, "{status}");
|
||||||
|
// Cancel (the ✕ of its row in the activity stack): the files being read finish, nothing new starts
|
||||||
let r = h.request("ui.clickWidget", json!({"id": cross}), Duration::from_secs(10));
|
let r = h.request("ui.clickWidget", json!({"id": cross}), Duration::from_secs(10));
|
||||||
assert_eq!(r["ok"], true, "{r}");
|
assert_eq!(r["ok"], true, "{r}");
|
||||||
|
nas.wake();
|
||||||
let t0 = Instant::now();
|
let t0 = Instant::now();
|
||||||
while h.app.import.is_some() && t0.elapsed() < Duration::from_secs(60) {
|
while h.app.import.is_some() && t0.elapsed() < Duration::from_secs(60) {
|
||||||
h.step();
|
h.step();
|
||||||
|
|||||||
@@ -881,9 +881,18 @@ mod in_the_loupe {
|
|||||||
assert!(window[0].0 > whole[0].0, "over the whole-frame render");
|
assert!(window[0].0 > whole[0].0, "over the whole-frame render");
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// The engine caches' share of the default memory budget (1.5 GiB) on a machine with 6 GiB of
|
||||||
|
/// RAM or more: room for both panes' 24 MP originals (288 MB each as linear float).
|
||||||
|
const COMPARE_CACHE: usize = 768 << 20;
|
||||||
|
|
||||||
/// Compare view of the demo library at `zoom`, settled.
|
/// Compare view of the demo library at `zoom`, settled.
|
||||||
|
///
|
||||||
|
/// The session's cache budget is set here rather than taken from the process-wide memory
|
||||||
|
/// budget, which other tests change while they run (Settings ▸ Performance ▸ 1 GB leaves a
|
||||||
|
/// 512 MiB share, too small for two originals, so one pane's was evicted).
|
||||||
fn compare_at(zoom: crate::state::Zoom) -> Headless {
|
fn compare_at(zoom: crate::state::Zoom) -> Headless {
|
||||||
let (mut h, _) = detail();
|
let (mut h, _) = detail();
|
||||||
|
h.app.session.media.set_budget(COMPARE_CACHE);
|
||||||
let r = h.request("engine.execute", json!({"command": "view.compare"}), T);
|
let r = h.request("engine.execute", json!({"command": "view.compare"}), T);
|
||||||
assert_eq!(r["ok"], true, "{r}");
|
assert_eq!(r["ok"], true, "{r}");
|
||||||
assert_eq!(h.app.ui.view, crate::state::ViewMode::Compare);
|
assert_eq!(h.app.ui.view, crate::state::ViewMode::Compare);
|
||||||
|
|||||||
Reference in new issue
Block a user