blob: 86e3204e7a9d3ec12ea77d775679ad6eb113e670 [file]
// Copyright 2026 The Fuchsia Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
use anyhow::Context as _;
use fidl_fuchsia_feedback as ffeedback;
use fidl_fuchsia_mem as fmem;
use fuchsia_async as fasync;
use fuchsia_async::TimeoutExt;
use fuchsia_inspect::Inspector;
use fuchsia_runtime as fruntime;
use futures::future::BoxFuture;
use starnix_c_file_buffer::CFileBuffer;
use starnix_core::task::ThreadLockupInfo;
use starnix_logging::{log_debug, log_error, log_warn};
use std::collections::{BTreeSet, HashMap};
use uuid::Uuid;
use zx::{self, Task};
// We use `inspector_print_debug_info` directly instead of
// `backtrace_request_thread` because `backtrace_request_thread` relies on the
// exception mechanism (crashsvc). If we use exceptions, the exception is
// attributed to the main Starnix kernel process (which detects the lockup),
// not the process containing the locked-up thread. This would prevent
// crashsvc from accessing the correct thread state and stack. By holding the
// thread handle directly, we can inspect it regardless of its process.
// SAFETY: This declares external C symbols from the Zircon inspector library.
unsafe extern "C" {
fn inspector_print_debug_info(
out: *mut std::ffi::c_void,
process: zx::sys::zx_handle_t,
thread: zx::sys::zx_handle_t,
);
}
async fn dump_thread_backtrace<'a>(
thread: &zx::Thread,
file_buffer: &'a mut CFileBuffer,
timeout: zx::MonotonicDuration,
) -> Result<&'a str, anyhow::Error> {
let _suspend_token = thread.suspend()?;
// Wait for suspended signal asynchronously.
fasync::OnSignals::new(thread, zx::Signals::THREAD_SUSPENDED)
.on_timeout(timeout, || Err(zx::Status::TIMED_OUT))
.await?;
// Reset the buffer to overwrite previous contents.
file_buffer.reset().map_err(|e| anyhow::anyhow!("Failed to reset CFileBuffer: {}", e))?;
// SAFETY: Calling FFI is safe when passing valid handles.
unsafe {
let process_self = fruntime::process_self().raw_handle();
let file_ptr = file_buffer.file();
inspector_print_debug_info(
file_ptr.as_raw() as *mut std::ffi::c_void,
process_self,
thread.raw_handle(),
);
}
let data = file_buffer.data();
let backtrace_str = str::from_utf8(data)?;
Ok(backtrace_str)
}
const LOCKUP_DETECTOR_INTERVAL_MINUTES: i64 = 2;
const RCU_STALL_THRESHOLD_SAMPLES: u32 = 4;
struct ActiveRcuRead {
consecutive_polls_active: u32,
first_seen: zx::MonotonicInstant,
last_counter_index: u8,
}
struct RcuStall {
thread: zx::Thread,
koid: zx::Koid,
first_seen: zx::MonotonicInstant,
}
#[derive(Default)]
struct Lockups {
long_running: Vec<ThreadLockupInfo>,
current_koids: BTreeSet<zx::Koid>,
newly_locked: Vec<ThreadLockupInfo>,
}
#[derive(Default)]
struct LockupDetectorContext {
event_id: Option<String>,
reported_lockup_koids: BTreeSet<zx::Koid>,
reported_rcu_koids: BTreeSet<zx::Koid>,
active_rcu_reads: HashMap<zx::Koid, ActiveRcuRead>,
}
fn format_thread_names(thread_names: BTreeSet<String>) -> String {
let mut names_str = thread_names.into_iter().collect::<Vec<_>>().join(", ");
let max_annotation_len = ffeedback::MAX_ANNOTATION_VALUE_LENGTH as usize;
if names_str.len() > max_annotation_len {
let mut limit = max_annotation_len - 3;
while !names_str.is_char_boundary(limit) {
limit -= 1;
}
names_str.truncate(limit);
names_str.push_str("...");
}
names_str
}
fn build_annotations(lockups: &Lockups, rcu_stalls: &Vec<RcuStall>) -> Vec<ffeedback::Annotation> {
let koids_str =
format!("{:?}", lockups.current_koids.iter().map(|k| k.raw_koid()).collect::<Vec<_>>());
let rcu_koids_str =
format!("{:?}", rcu_stalls.iter().map(|k| k.koid.raw_koid()).collect::<Vec<_>>());
let mut thread_names = BTreeSet::new();
for registered in &lockups.long_running {
let name = if let Ok(name) = registered.thread.get_name() {
format!("{}({})", name, registered.koid.raw_koid())
} else {
format!("koid-{}", registered.koid.raw_koid())
};
thread_names.insert(name);
}
let mut rcu_thread_names = BTreeSet::new();
for stall in rcu_stalls {
let name = if let Ok(name) = stall.thread.get_name() {
format!("{}({})", name, stall.koid.raw_koid())
} else {
format!("koid-{}", stall.koid.raw_koid())
};
rcu_thread_names.insert(name);
}
vec![
ffeedback::Annotation { key: "starnix.lockup_thread_koids".to_string(), value: koids_str },
ffeedback::Annotation {
key: "starnix.lockup_thread_names".to_string(),
value: format_thread_names(thread_names),
},
ffeedback::Annotation {
key: "starnix.rcu_lockup_thread_koids".to_string(),
value: rcu_koids_str,
},
ffeedback::Annotation {
key: "starnix.rcu_lockup_thread_names".to_string(),
value: format_thread_names(rcu_thread_names),
},
]
}
async fn report_lockups(
context: &mut LockupDetectorContext,
lockups: Lockups,
rcu_stalls: Vec<RcuStall>,
) -> anyhow::Result<()> {
let event_id_str = context.event_id.get_or_insert_with(|| Uuid::new_v4().to_string()).clone();
let mut file_buffer = CFileBuffer::new(1024 * 1024)
.map_err(|e| anyhow::anyhow!("Failed to create CFileBuffer: {}", e))?;
let reporter =
fuchsia_component::client::connect_to_protocol::<ffeedback::CrashReporterMarker>()
.context("Failed to connect to CrashReporter")?;
let annotations = build_annotations(&lockups, &rcu_stalls);
let threads: BTreeSet<_> = lockups
.newly_locked
.into_iter()
.map(|info| (info.thread, info.koid))
.chain(rcu_stalls.iter().map(|stall| (stall.thread.unowned(), stall.koid)))
.collect();
for (thread, koid) in threads {
let bt = dump_thread_backtrace(
&thread,
&mut file_buffer,
zx::MonotonicDuration::from_seconds(1),
)
.await
.with_context(|| format!("Failed to dump backtrace for thread {}", koid.raw_koid()))?;
log_error!("Locked thread backtrace:\n{}", bt);
let size = bt.len() as u64;
let vmo = zx::Vmo::create(size).context("Failed to create VMO")?;
vmo.write(bt.as_bytes(), 0).context("Failed to write backtrace to VMO")?;
let report = ffeedback::CrashReport {
program_name: Some("starnix_kernel".to_string()),
crash_signature: Some("fuchsia-starnix_kernel-thread-lockup".to_string()),
is_fatal: Some(false),
specific_report: Some(ffeedback::SpecificCrashReport::TextBacktrace(
ffeedback::TextBacktraceCrashReport {
fuchsia_backtrace: Some(fmem::Buffer { vmo, size }),
thread_name: thread.get_name().ok().map(|name| name.to_string()),
thread_koid: Some(koid.raw_koid()),
..Default::default()
},
)),
annotations: Some(annotations.clone()),
event_id: Some(event_id_str.clone()),
..Default::default()
};
reporter.file_report(report).await.context("Failed to call file_report")?.map_err(|e| {
anyhow::anyhow!("Failed to file crash report for thread {}: {:?}", koid.raw_koid(), e)
})?;
log_debug!("Filed crash report for thread lockup (thread {}).", koid.raw_koid());
context.reported_lockup_koids.insert(koid);
}
Ok(())
}
fn check_lockups(context: &mut LockupDetectorContext) -> Lockups {
let long_running = starnix_core::task::ThreadLockupDetector::get_long_running_threads(
zx::MonotonicDuration::from_minutes(LOCKUP_DETECTOR_INTERVAL_MINUTES),
);
let current_koids: BTreeSet<zx::Koid> = long_running.iter().map(|r| r.koid).collect();
// Clean up threads that are no longer locked up.
context.reported_lockup_koids.retain(|koid| current_koids.contains(koid));
if long_running.is_empty() {
return Lockups::default();
}
// Identify newly locked threads.
let newly_locked: Vec<_> = long_running
.iter()
.filter(|r| !context.reported_lockup_koids.contains(&r.koid))
.cloned()
.collect();
if newly_locked.is_empty() {
return Lockups::default();
}
log_error!(
"Detected threads locked up for more than {} minutes: {:?}",
LOCKUP_DETECTOR_INTERVAL_MINUTES,
current_koids
);
Lockups { long_running, current_koids, newly_locked }
}
fn check_rcu_stalls(context: &mut LockupDetectorContext) -> Vec<RcuStall> {
let now = zx::MonotonicInstant::get();
let mut active_koids = std::collections::HashSet::new();
let mut stalled_threads = vec![];
starnix_core::task::ThreadLockupDetector::active_rcu_read_locks(
|thread, koid, counter_index| {
active_koids.insert(koid);
let stall_info = context.active_rcu_reads.get(&koid);
let (count, first_seen) = match stall_info {
Some(info) => {
if info.last_counter_index != counter_index {
// Counter index changed, progress was made.
(1, now)
} else {
(info.consecutive_polls_active + 1, info.first_seen)
}
}
None => (1, now),
};
context.active_rcu_reads.insert(
koid,
ActiveRcuRead {
consecutive_polls_active: count,
first_seen,
last_counter_index: counter_index,
},
);
if count >= RCU_STALL_THRESHOLD_SAMPLES
&& !context.reported_rcu_koids.contains(&koid)
&& let Ok(thread_dup) = thread.duplicate_handle(zx::Rights::SAME_RIGHTS)
{
context.reported_rcu_koids.insert(koid);
stalled_threads.push(RcuStall { thread: thread_dup, koid, first_seen });
}
},
);
context.active_rcu_reads.retain(|koid, _| active_koids.contains(koid));
context.reported_rcu_koids.retain(|koid| active_koids.contains(koid));
for stall in &stalled_threads {
log_warn!(
"RCU Stall detected: Thread {} has held RCU read lock for {}ms.",
stall.koid.raw_koid(),
(zx::MonotonicInstant::get() - stall.first_seen).into_millis(),
);
}
stalled_threads
}
pub fn start_thread_lockup_detector() -> fasync::Task<()> {
fasync::Task::spawn(async {
let mut context = LockupDetectorContext::default();
loop {
fasync::Timer::new(zx::MonotonicInstant::after(zx::MonotonicDuration::from_minutes(
LOCKUP_DETECTOR_INTERVAL_MINUTES,
)))
.await;
let _waiting_guard = starnix_core::task::ThreadLockupDetector::pause_tracking();
let rcu_stalls = check_rcu_stalls(&mut context);
let lockups = check_lockups(&mut context);
if let Err(e) = report_lockups(&mut context, lockups, rcu_stalls).await {
log_warn!("Error in thread lockup detector: {:?}", e);
}
}
})
}
/// Creates a lazy inspect node that exports information about currently locked threads.
///
/// When the node is read, it queries the `ThreadLockupDetector` for all threads that have been
/// running longer than the `LOCKUP_DETECTOR_INTERVAL_MINUTES` threshold and records their KOIDs
/// and names as properties of the node.
pub fn inspect_lazy_node_callback() -> BoxFuture<'static, Result<Inspector, anyhow::Error>> {
Box::pin(async {
let inspector = Inspector::default();
let long_running = starnix_core::task::ThreadLockupDetector::get_long_running_threads(
zx::MonotonicDuration::from_minutes(LOCKUP_DETECTOR_INTERVAL_MINUTES),
);
for info in long_running {
let name = info
.thread
.get_name()
.map(|n| n.to_string())
.unwrap_or_else(|_| "unknown".to_string());
inspector.root().record_string(info.koid.raw_koid().to_string(), name);
}
Ok(inspector)
})
}
#[cfg(test)]
mod tests {
use super::*;
use std::sync::{Arc, Barrier};
#[fuchsia::test]
async fn test_rcu_lockup_detector() {
let barrier = Arc::new(Barrier::new(2));
let barrier_clone = barrier.clone();
// Spawn a thread that holds an RCU read lock.
let thread = std::thread::spawn(move || {
let _guard = starnix_core::task::ThreadLockupDetector::track();
let _scope = fuchsia_rcu::RcuReadScope::new();
barrier_clone.wait(); // Synchronize with the main test thread.
barrier_clone.wait(); // Block until test finishes.
});
barrier.wait(); // Wait for thread to acquire lock.
let mut context = LockupDetectorContext::default();
// Run check_rcu_stalls.
// We need to run it multiple times to trigger the stall.
// Threshold is RCU_STALL_THRESHOLD_SAMPLES = 4.
// 1st sample
let candidates = check_rcu_stalls(&mut context);
assert!(candidates.is_empty());
assert_eq!(context.active_rcu_reads.len(), 1);
let koid = *context.active_rcu_reads.keys().next().unwrap();
assert_eq!(context.active_rcu_reads.get(&koid).unwrap().consecutive_polls_active, 1);
// 2nd and 3rd samples
for i in 2..=3 {
let candidates = check_rcu_stalls(&mut context);
assert!(candidates.is_empty());
assert_eq!(context.active_rcu_reads.get(&koid).unwrap().consecutive_polls_active, i);
}
// 4th sample (should return candidate)
let candidates = check_rcu_stalls(&mut context);
assert_eq!(candidates.len(), 1);
assert_eq!(candidates[0].koid, koid);
assert_eq!(context.active_rcu_reads.get(&koid).unwrap().consecutive_polls_active, 4);
barrier.wait(); // Allow thread to exit.
thread.join().unwrap();
// Run check again, thread should be gone.
let candidates = check_rcu_stalls(&mut context);
assert!(candidates.is_empty());
assert!(context.active_rcu_reads.is_empty());
}
}