Keep-alive inactive by default: it froze the Mali display pipeline

The 16 ms keep-alive submits from a 5th thread, racing Slint's
render/present path and the four decode workers on the same wgpu
queue, hung the phone UI for seconds (51 decodes stalled ~6 s).
System survived (no reboot) but it read as a crash. Debug knob
.gallery_keep re-enables it.

Also: jsamp one-shot permission probes (the cgroup/PSI polling
loop flooded the SELinux audit subsystem at ~100 denials/s and
ANR'd the app); cgroup/PSI probing removed (the device has the
cgroup cpu controller disabled, so quota was ruled out anyway).
Sampling at 5 ms. HANDOFF 8.8 records the full findings.
This commit is contained in:
Greg Pomerantz 2026-10-28 12:20:19 -04:00
parent ed52109dba
commit 16526a402a
4 changed files with 286 additions and 5 deletions

View File

@ -632,3 +632,40 @@ Result (Pixel 9 Pro, 120 Hz, 400 px): **zero mid-scroll renders > 4.4 ms**
Perf file: `/sdcard/Download/.gallery_perf.log` (SCR/TICK/APLY/FR). Perf file: `/sdcard/Download/.gallery_perf.log` (SCR/TICK/APLY/FR).
Clear it by restarting the app (writer holds the fd). Clear it by restarting the app (writer holds the fd).
### 8.8 Jank-hunt round 2 + the keep-alive incident (2026-10-28)
Follow-up on "still seeing jank" (post-GPU-texture). Instrumentation:
in-app thread sampler (`src/jsamp.rs`, `/proc/self/task`, knob
`.gallery_jsamp`), per-core cpufreq, cgroup/PSI probes. Findings:
- **Cgroup CPU quota ruled out**: this device's unified hierarchy has the
`cpu` controller DISABLED (`cgroup.controllers` = `memory` only; no
`cpu.max` file) — no per-app bandwidth cap exists.
- **`/proc` facts**: utime/stime are USER_HZ ticks (1/100 s), so
per-thread CPU deltas are 10 ms-quantized. The app's SELinux context
DENIES `/proc/stat`, `/proc/pressure/cpu`, and the unified cgroup files
(even the app's own cgroup), but allows `/proc/self/task/*` and
cpufreq `scaling_cur_freq`. **A denied read in a tight loop is an ANR:
each denial is an audit event; ~100/s froze the whole phone.**
jsamp now probes readability once and disables denied features forever.
- **Real profile** (single verified 120 Hz swipe, 370 frames): steady
scroll = 1.5–2.5 ms frames, **zero spikes**. All 20–40 ms frames were
the first frame after an input pause (15–100 ms) — resume/warm-up
cost; ~820 MHz little-core clock during spikes vs 1.95 GHz between
(EAS downclock in the gap, not a cgroup/driver block). Swipe starts
after only 2 s pauses: zero spikes; only >10 s app idle pays the big
(43 ms) cold frame.
- **KEEP-ALIVE INCIDENT (phone freeze)**: the `gputex::Keepalive`
thread (16 ms buffer-copy submits on Slint's wgpu queue from a 5th
thread) made the display pipeline FREEZE on Mali G715 during a 14-min
session — phone UI hung for seconds, 51 in-flight decodes stalled ~6 s
(workers also `write_texture` on the same queue). System did not
reboot (system_server/surfaceflinger 5-day uptime), but the user
experience was "crashing my phone". **Root lesson: do not run
concurrent submitters on Slint's Mali queue.** Keep-alive is now
INACTIVE BY DEFAULT (debug knob `.gallery_keep`), the jsamp sampler is
off (knob `.gallery_jsamp`), and both are REMOVE-after-hunt.
- Status: mid-gesture 20–28 ms warm-up frames can still occur without
keep-alive (~1 per 10 s of scrolling); cold-start-after-idle frame is
40 ms. User finger-verification of the keep-alive-free build pending.

View File

@ -22,7 +22,7 @@
//! `upload_rgba` returns `None` and the caller delivers the RGBA8 bytes //! `upload_rgba` returns `None` and the caller delivers the RGBA8 bytes
//! the old way (`Image::from_rgba8`). //! the old way (`Image::from_rgba8`).
use std::sync::OnceLock; use std::sync::{Arc, OnceLock, atomic::AtomicBool};
/// The wgpu 30.x crate re-exported by Slint (same version it renders with). /// The wgpu 30.x crate re-exported by Slint (same version it renders with).
pub use slint::wgpu_30::wgpu; pub use slint::wgpu_30::wgpu;
@ -95,3 +95,70 @@ pub fn upload_rgba(rgba: &[u8], width: u32, height: u32) -> Option<wgpu::Texture
); );
Some(texture) Some(texture)
} }
/// GPU pipeline keep-alive.
///
/// INTENDED: keep the wgpu/Vulkan submission path warm so frames after a
/// 30–80 ms input micro-pause don't pay 23–46 ms of wake-up.
///
/// **DISABLED BY DEFAULT (2026-10-28).** On the Pixel 9 Pro (Mali G715)
/// the 16 ms submission stream from a 5th thread, racing Slint's own
/// render/present path AND the four decode workers on the SAME queue, made
/// the display pipeline freeze — the whole phone UI hung for seconds and
/// 51 in-flight decodes stalled ~6 s. Concurrent submitters on one Mali
/// queue are not safe in practice. Re-enable only via the debug knob
/// `/sdcard/Download/.gallery_keep` (REMOVE after the hunt).
pub struct Keepalive {
stop: Arc<AtomicBool>,
}
static KEEP_BUFS: OnceLock<(wgpu::Buffer, wgpu::Buffer)> = OnceLock::new();
impl Keepalive {
/// Spawn the keep-alive thread. INACTIVE unless the debug knob
/// `/sdcard/Download/.gallery_keep` exists.
pub fn start() -> Self {
#[cfg(target_os = "android")]
if !std::path::Path::new("/sdcard/Download/.gallery_keep").exists() {
log::info!("gputex: keep-alive inactive (default off; .gallery_keep to enable)");
return Self { stop: Arc::new(AtomicBool::new(true)) };
}
let stop = Arc::new(AtomicBool::new(false));
let stop_t = stop.clone();
std::thread::Builder::new()
.name("gpu-keep".into())
.spawn(move || {
crate::prio::set_self_nice(10); // must never jank the UI thread
while !stop_t.load(std::sync::atomic::Ordering::Relaxed) {
if let Some((device, queue)) = GPU.get() {
let (src, dst) = KEEP_BUFS.get_or_init(|| {
let desc = wgpu::BufferDescriptor {
label: Some("gallery-keep"),
size: 16,
usage: wgpu::BufferUsages::COPY_SRC | wgpu::BufferUsages::COPY_DST,
mapped_at_creation: false,
};
let a = device.create_buffer(&desc);
let b = device.create_buffer(&desc);
queue.write_buffer(&a, 0, &[0u8; 16]);
(a, b)
});
let mut enc =
device.create_command_encoder(&wgpu::CommandEncoderDescriptor::default());
enc.copy_buffer_to_buffer(src, 0, dst, 0, 8);
queue.submit(Some(enc.finish()));
}
std::thread::sleep(std::time::Duration::from_millis(16));
}
})
.ok();
log::info!("gputex: keep-alive started");
Self { stop }
}
/// Signal the thread to stop (does not join; drop is immediate).
pub fn stop(&mut self) {
self.stop.store(true, std::sync::atomic::Ordering::Relaxed);
log::info!("gputex: keep-alive stopped");
}
}

154
src/jsamp.rs Normal file
View File

@ -0,0 +1,154 @@
//! In-app thread sampler (jank hunt; REMOVE after).
//!
//! The phone is non-rooted, so an external sampler (shell uid) cannot read
//! the app's /proc. This samples `/proc/self/task` from inside the app at
//! 1 ms: per target thread, the scheduler state, wchan (what it waits in),
//! and CPU-time delta — enough to decide, for any FR spike, whether the
//! UI thread was ON-CPU doing work or WAITING (futex/GPU fence), and what
//! the decode workers and the Mali driver threads (`mali-compiler` =
//! shader compilation, `mali-event-hand`) were doing meanwhile.
//!
//! Enabled by `/sdcard/Download/.gallery_jsamp`; output goes to
//! `/sdcard/Download/.gallery_jsamp.log` in the process's monotonic clock
//! (same `now_ms` as SCR/TICK/FR, so windows line up exactly).
#![cfg(target_os = "android")]
use std::io::Write as _;
use std::time::Duration;
const KNOB: &str = "/sdcard/Download/.gallery_jsamp";
const OUT: &str = "/sdcard/Download/.gallery_jsamp.log";
pub fn start() {
if !std::path::Path::new(KNOB).exists() {
return;
}
std::thread::Builder::new()
.name("jsamp".into())
.spawn(move || {
// nice 0: at +10 the sampler starved exactly during the CPU
// contention we try to observe (no samples in the spike
// window).
crate::prio::set_self_nice(0);
// ONE-SHOT permission probes. CRITICAL: SELinux-denied reads
// must never be retried in a tight loop — each denial is an
// audit event, and ~100/s of them flooded the audit subsystem
// and ANR'd the whole app.
let can_task = std::fs::read_dir("/proc/self/task").is_ok();
let can_cpufreq = std::fs::read_to_string(
"/sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq",
)
.is_ok();
let _ = (can_task, can_cpufreq);
// append (not truncate): SELinux denies create+truncate on the
// fresh path; analysis takes the last lines.
let mut out = match std::fs::OpenOptions::new()
.create(true)
.append(true)
.open(OUT)
{
Ok(f) => std::io::BufWriter::new(f),
Err(e) => {
log::error!("jsamp: open {OUT}: {e}");
return;
}
};
// tid -> (comm, last_cpu_us); comm cached (read once per tid)
let mut last: std::collections::HashMap<u32, (String, u64)> =
std::collections::HashMap::new();
let mut skipped: std::collections::HashSet<u32> = std::collections::HashSet::new();
let mut tick = 0u32;
loop {
tick += 1;
if tick % 250 == 0 {
last.clear(); // tids may change (mali pairs get recreated)
skipped.clear();
}
let ts = crate::now_ms();
let dir = std::fs::read_dir("/proc/self/task");
if can_task {
if let Ok(dir) = dir {
for ent in dir.flatten() {
let tid: u32 = match ent.file_name().to_string_lossy().parse() {
Ok(t) => t,
Err(_) => continue,
};
let known_interesting = last.get(&tid).map(|(c, _)| {
c == "android_main"
|| c.starts_with("thumb-")
|| c.starts_with("mali-")
|| c == "slint vsync"
|| c == "gpu-keep"
}).unwrap_or(false);
if !known_interesting && !last.contains_key(&tid) && !skipped.contains(&tid) {
let comm = match std::fs::read_to_string(format!("/proc/self/task/{tid}/comm")) {
Ok(c) => c.trim().to_string(),
Err(_) => continue,
};
let interesting = comm == "android_main"
|| comm.starts_with("thumb-")
|| comm.starts_with("mali-")
|| comm == "slint vsync"
|| comm == "gpu-keep";
if !interesting {
skipped.insert(tid); // cache the negative too
continue;
}
last.entry(tid).or_insert_with(|| (comm, 0));
}
let (comm, prev) = match last.get(&tid) {
Some(v) => (v.0.clone(), v.1),
None => continue,
};
// stat: pid (comm) state ppid ... utime(14) stime(15)
let stat = match std::fs::read_to_string(format!("/proc/self/task/{tid}/stat")) {
Ok(s) => s,
Err(_) => continue,
};
let close = match stat.rfind(')') {
Some(i) => i,
None => continue,
};
let fields: Vec<&str> = stat[close + 2..].split_whitespace().collect();
let state = fields.first().copied().unwrap_or("?");
// utime/stime are USER_HZ ticks (1/100 s) -> us
let cpu_us = fields
.get(11) // utime (0-based after comm: state=0 ppid=1 ... utime=11)
.and_then(|s| s.parse::<u64>().ok())
.unwrap_or(0)
* 10_000
+ fields
.get(12)
.and_then(|s| s.parse::<u64>().ok())
.unwrap_or(0)
* 10_000;
let wchan = std::fs::read_to_string(format!("/proc/self/task/{tid}/wchan"))
.map(|w| w.trim().to_string())
.unwrap_or_default();
let delta = cpu_us.saturating_sub(prev);
let _ =
writeln!(out, "JS {ts:11.2} {tid} {comm} {state} {wchan} dcpu={delta}");
last.insert(tid, (comm, cpu_us));
}
}
}
// Per-core frequency: is the CPU in a low-clock state during
// a spike? (Readability probed once at start — never retry a
// denied path; the cgroup/PSI probes were removed after they
// ANR'd the app via audit flooding.)
if can_cpufreq {
let freq0 = std::fs::read_to_string(
"/sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq",
)
.ok()
.map(|s| s.trim().to_string())
.unwrap_or_default();
let _ = writeln!(out, "JSCP {ts:11.2} freq0={freq0}");
}
let _ = out.flush();
std::thread::sleep(Duration::from_millis(5));
}
})
.ok();
log::info!("jsamp: sampling started");
}

View File

@ -76,6 +76,8 @@
slint::include_modules!(); slint::include_modules!();
pub mod db; pub mod db;
#[cfg(target_os = "android")]
pub mod jsamp;
pub mod gputex; pub mod gputex;
pub mod images; pub mod images;
pub mod scan; pub mod scan;
@ -626,7 +628,7 @@ fn install_frame_logger(window: &Main) {
/// mistaken for jank). /// mistaken for jank).
static NOW_T0: std::sync::OnceLock<std::time::Instant> = std::sync::OnceLock::new(); static NOW_T0: std::sync::OnceLock<std::time::Instant> = std::sync::OnceLock::new();
#[inline] #[inline]
fn now_ms() -> f64 { pub(crate) fn now_ms() -> f64 {
let t0 = NOW_T0.get_or_init(std::time::Instant::now); let t0 = NOW_T0.get_or_init(std::time::Instant::now);
t0.elapsed().as_secs_f64() * 1000.0 t0.elapsed().as_secs_f64() * 1000.0
} }
@ -1212,12 +1214,33 @@ fn android_main(app: slint::android::AndroidApp) {
// (Start/Resume/Pause/Stop/SaveState/ConfigChanged/...) while Slint owns // (Start/Resume/Pause/Stop/SaveState/ConfigChanged/...) while Slint owns
// the event loop. This is Slint's one first-class Android lifecycle hook: // the event loop. This is Slint's one first-class Android lifecycle hook:
// M5 re-checks storage permission on Resume (user returned from Settings). // M5 re-checks storage permission on Resume (user returned from Settings).
// Jank hunt (REMOVE after): in-app thread sampler, gated by knob.
jsamp::start();
// GPU pipeline keep-alive (gputex): started on Start/Resume, stopped
// on Pause/Stop (battery). INACTIVE BY DEFAULT — on Mali it froze the
// display pipeline (see gputex::Keepalive docs). Debug knob:
// .gallery_keep.
slint::android::init_with_event_listener(app, |event| { slint::android::init_with_event_listener(app, |event| {
use slint::android::android_activity::{MainEvent, PollEvent}; use slint::android::android_activity::{MainEvent, PollEvent};
if let PollEvent::Main(MainEvent::Resume { .. } | MainEvent::Start { .. }) = event { // Fn (not FnMut): mutable state in a static.
static KEEPALIVE: std::sync::Mutex<Option<gputex::Keepalive>> =
std::sync::Mutex::new(None);
match event {
PollEvent::Main(MainEvent::Resume { .. } | MainEvent::Start { .. }) => {
log::info!("gallery: app resumed"); log::info!("gallery: app resumed");
if KEEPALIVE.lock().unwrap().is_none() {
*KEEPALIVE.lock().unwrap() = Some(gputex::Keepalive::start());
}
// TODO(M5): storage::recheck_permission() // TODO(M5): storage::recheck_permission()
} }
PollEvent::Main(MainEvent::Pause { .. } | MainEvent::Stop { .. }) => {
if let Some(mut k) = KEEPALIVE.lock().unwrap().take() {
k.stop();
}
}
_ => {}
}
}) })
.unwrap(); .unwrap();