| // 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()); |
| } |
| } |