fix(tui/review): harden logging and thread workers

This commit is contained in:
James Peter
2025-10-14 12:48:48 +11:00
parent 4fc824116c
commit cbdca253fd
11 changed files with 281 additions and 66 deletions
+31 -6
View File
@@ -12,6 +12,7 @@ use crate::onboarding::onboarding_screen::KeyboardHandler;
use crate::onboarding::onboarding_screen::OnboardingScreen;
use crate::onboarding::onboarding_screen::OnboardingScreenArgs;
use crate::slash_command::SlashCommand;
use crate::thread_spawner;
use crate::tui;
use crate::tui::TerminalInfo;
use code_core::config::add_project_allowed_command;
@@ -119,7 +120,21 @@ impl FrameTimer {
if should_spawn {
let timer = Arc::clone(self);
thread::spawn(move || timer.run(tx));
let tx_for_thread = tx.clone();
if thread_spawner::spawn_lightweight("frame-timer", move || timer.run(tx_for_thread)).is_none() {
let mut state = self.state.lock().unwrap();
state.worker_running = false;
let drained = state.deadlines.len();
state.deadlines.clear();
drop(state);
for _ in 0..drained.max(1) {
tx.send(AppEvent::RequestRedraw);
}
tracing::warn!(
drained_deadlines = drained,
"frame timer spawn rejected: background thread limit reached; flushed deadlines"
);
}
}
}
@@ -577,10 +592,15 @@ impl App<'_> {
.is_ok()
{
let pending_redraw = self.pending_redraw.clone();
thread::spawn(move || {
let pending_redraw_for_thread = pending_redraw.clone();
if thread_spawner::spawn_lightweight("redraw-debounce", move || {
thread::sleep(REDRAW_DEBOUNCE);
pending_redraw_for_thread.store(false, Ordering::Release);
})
.is_none()
{
pending_redraw.store(false, Ordering::Release);
});
}
}
}
@@ -1108,6 +1128,7 @@ impl App<'_> {
{
let tx = self.app_event_tx.clone();
let running = self.commit_anim_running.clone();
let running_for_thread = running.clone();
let tick_ms: u64 = self
.config
.tui
@@ -1115,12 +1136,16 @@ impl App<'_> {
.commit_tick_ms
.or(if self.config.tui.stream.responsive { Some(30) } else { None })
.unwrap_or(50);
thread::spawn(move || {
while running.load(Ordering::Relaxed) {
if thread_spawner::spawn_lightweight("commit-anim", move || {
while running_for_thread.load(Ordering::Relaxed) {
thread::sleep(Duration::from_millis(tick_ms));
tx.send(AppEvent::CommitTick);
}
});
})
.is_none()
{
running.store(false, Ordering::Release);
}
}
}
AppEvent::StopCommitAnimation => {
+11 -4
View File
@@ -20,6 +20,7 @@ use code_protocol::custom_prompts::PROMPTS_CMD_PREFIX;
use crate::app_event_sender::AppEventSender;
use crate::auto_drive_style::ComposerStyle;
use crate::thread_spawner;
use crate::bottom_pane::textarea::TextArea;
use crate::bottom_pane::textarea::TextAreaState;
use crate::clipboard_paste::normalize_pasted_path;
@@ -255,7 +256,8 @@ impl ChatComposer {
// phase‑aligned, monotonic scheduler to minimize drift and
// reduce perceived frame skipping under load. We purposely
// avoid very small intervals to keep CPU impact low.
thread::spawn(move || {
let fallback_tx = self.app_event_tx.clone();
if thread_spawner::spawn_lightweight("composer-anim", move || {
use std::time::Instant;
// Default to ~120ms if spinner state is not yet initialized
let default_ms: u64 = 120;
@@ -294,9 +296,14 @@ impl ChatComposer {
next = target;
}
}
});
self.animation_running = Some(animation_flag);
})
.is_none()
{
animation_flag.store(false, Ordering::Relaxed);
fallback_tx.send(crate::app_event::AppEvent::RequestRedraw);
} else {
self.animation_running = Some(animation_flag);
}
}
} else {
// Stop animation thread
+15 -4
View File
@@ -6,6 +6,7 @@ use crate::auto_drive_style::AutoDriveVariant;
use crate::chatwidget::BackgroundOrderTicket;
use crate::glitch_animation;
use crate::user_approval_widget::{ApprovalRequest, UserApprovalWidget};
use crate::thread_spawner;
use bottom_pane_view::BottomPaneView;
use crate::util::buffer::fill_rect;
use code_core::protocol::TokenUsage;
@@ -1234,10 +1235,15 @@ impl BottomPane<'_> {
let dur = Duration::from_secs(4);
self.composer.set_access_mode_hint_for(dur);
let tx = self.app_event_tx.clone();
std::thread::spawn(move || {
let fallback_tx = self.app_event_tx.clone();
if thread_spawner::spawn_lightweight("access-hint", move || {
std::thread::sleep(dur + Duration::from_millis(120));
tx.send(AppEvent::RequestRedraw);
});
})
.is_none()
{
fallback_tx.send(AppEvent::RequestRedraw);
}
self.request_redraw();
}
@@ -1245,10 +1251,15 @@ impl BottomPane<'_> {
self.composer.set_access_mode_label_ephemeral(label, dur);
// Schedule a redraw after expiry without blocking other scheduled frames.
let tx = self.app_event_tx.clone();
std::thread::spawn(move || {
let fallback_tx = self.app_event_tx.clone();
if thread_spawner::spawn_lightweight("access-hint-ephemeral", move || {
std::thread::sleep(dur + Duration::from_millis(120));
tx.send(AppEvent::RequestRedraw);
});
})
.is_none()
{
fallback_tx.send(AppEvent::RequestRedraw);
}
self.request_redraw();
}
@@ -20,6 +20,7 @@ use crate::app_event::AppEvent;
use crate::app_event_sender::AppEventSender;
use crate::chatwidget::BackgroundOrderTicket;
use crate::theme::{custom_theme_is_dark, map_theme_for_palette, palette_mode, PaletteMode};
use crate::thread_spawner;
use super::BottomPane;
use super::bottom_pane_view::BottomPaneView;
@@ -325,7 +326,10 @@ impl ThemeSelectionView {
) {
let tx = self.app_event_tx.clone();
let before_ticket = self.before_ticket.clone();
std::thread::spawn(move || {
let fallback_tx = self.app_event_tx.clone();
let fallback_ticket = self.before_ticket.clone();
let completion_tx = progress_tx.clone();
if thread_spawner::spawn_lightweight("spinner-create", move || {
let rt = match tokio::runtime::Builder::new_multi_thread()
.enable_all()
.build()
@@ -557,7 +561,19 @@ impl ThemeSelectionView {
// Persist + activate
let _ = progress_tx.send(ProgressMsg::CompletedOk { name: display_name, interval, frames: norm_frames });
});
});
})
.is_none()
{
let _ = completion_tx.send(ProgressMsg::CompletedErr {
error: "background worker unavailable".to_string(),
_raw_snippet: String::new(),
});
fallback_tx.send_background_before_next_output_with_ticket(
&fallback_ticket,
"Failed to generate spinner preview: background worker unavailable".to_string(),
);
return;
}
}
/// Spawn a background task that creates a custom theme using the LLM.
@@ -643,7 +659,10 @@ impl ThemeSelectionView {
}
let before_ticket = self.before_ticket.clone();
std::thread::spawn(move || {
let fallback_tx = self.app_event_tx.clone();
let fallback_ticket = self.before_ticket.clone();
let completion_tx = progress_tx.clone();
if thread_spawner::spawn_lightweight("theme-create", move || {
let rt = match tokio::runtime::Builder::new_multi_thread()
.enable_all()
.build()
@@ -884,7 +903,19 @@ impl ThemeSelectionView {
}
let _ = progress_tx.send(ProgressMsg::CompletedThemeOk(name, colors, is_dark));
});
});
})
.is_none()
{
let _ = completion_tx.send(ProgressMsg::CompletedErr {
error: "background worker unavailable".to_string(),
_raw_snippet: String::new(),
});
fallback_tx.send_background_before_next_output_with_ticket(
&fallback_ticket,
"Failed to generate theme: background worker unavailable".to_string(),
);
return;
}
}
}
+19 -4
View File
@@ -21,6 +21,7 @@ use ratatui::style::Style;
use crate::header_wave::{HeaderBorderWeaveEffect, HeaderWaveEffect};
use crate::auto_drive_strings;
use crate::auto_drive_style::AutoDriveVariant;
use crate::thread_spawner;
use code_common::elapsed::format_duration;
use code_common::model_presets::ModelPreset;
@@ -9613,10 +9614,16 @@ impl ChatWidget<'_> {
(ev2, om_for_insert, std::time::Instant::now()),
);
let tx = this.app_event_tx.clone();
std::thread::spawn(move || {
let fallback_tx = tx.clone();
if thread_spawner::spawn_lightweight("exec-flush", move || {
std::thread::sleep(std::time::Duration::from_millis(120));
tx.send(crate::app_event::AppEvent::FlushPendingExecEnds);
});
})
.is_none()
{
let _ = fallback_tx
.send(crate::app_event::AppEvent::FlushPendingExecEnds);
}
}
},
);
@@ -12636,7 +12643,8 @@ fi\n\
}
Some(seconds) => {
let tx = self.app_event_tx.clone();
std::thread::spawn(move || {
let fallback_tx = tx.clone();
if thread_spawner::spawn_lightweight("countdown", move || {
let mut remaining = seconds;
while remaining > 0 {
std::thread::sleep(std::time::Duration::from_secs(1));
@@ -12648,7 +12656,14 @@ fi\n\
break;
}
}
});
})
.is_none()
{
let _ = fallback_tx.send(AppEvent::AutoCoordinatorCountdown {
countdown_id,
seconds_left: 0,
});
}
}
None => {
// Manual approval mode: do not start countdown automatically.
@@ -36,6 +36,7 @@ use crate::app_event::{
};
use crate::app_event_sender::AppEventSender;
use crate::chatwidget::retry::{retry_with_backoff, RetryDecision, RetryError, RetryOptions};
use crate::thread_spawner;
#[cfg(feature = "dev-faults")]
use crate::chatwidget::faults::{fault_to_error, next_fault, FaultScope, InjectedFault};
use code_common::elapsed::format_duration;
@@ -532,7 +533,7 @@ pub(super) fn start_auto_coordinator(
let cancel_token = CancellationToken::new();
let thread_cancel = cancel_token.clone();
std::thread::spawn(move || {
if thread_spawner::spawn_lightweight("auto-coordinator", move || {
if let Err(err) = run_auto_loop(
app_event_tx,
goal_text,
@@ -546,7 +547,12 @@ pub(super) fn start_auto_coordinator(
) {
tracing::error!("auto coordinator loop error: {err:#}");
}
});
})
.is_none()
{
tracing::error!("auto coordinator spawn rejected: background thread limit reached");
return Err(anyhow!("auto coordinator worker unavailable"));
}
Ok(AutoCoordinatorHandle {
tx: thread_tx,
+8 -3
View File
@@ -11,6 +11,7 @@ use serde_json::{self, json, Value};
use tracing::{debug, error, warn};
use crate::app_event::{AutoCoordinatorStatus, AutoObserverStatus, AutoObserverTelemetry};
use crate::thread_spawner;
use super::auto_coordinator::{
extract_first_json_object,
@@ -69,11 +70,16 @@ pub(super) fn start_auto_observer(
let (tx, rx) = mpsc::channel();
let thread_tx = tx.clone();
std::thread::spawn(move || {
if thread_spawner::spawn_lightweight("auto-observer", move || {
if let Err(err) = run_observer_loop(client, rx, coordinator_tx) {
error!("auto observer loop error: {err:#}");
}
});
})
.is_none()
{
error!("auto observer spawn rejected: background thread limit reached");
return Err(anyhow!("auto observer worker unavailable"));
}
Ok(AutoObserverHandle {
tx: thread_tx,
@@ -503,4 +509,3 @@ pub(super) fn build_observer_conversation(
filtered
}
@@ -16,6 +16,7 @@ use crate::tui_event_extensions::handle_rate_limit;
use crate::app_event::AppEvent;
use crate::app_event_sender::AppEventSender;
use crate::thread_spawner;
/// Fire-and-forget helper that refreshes rate limit data using a dedicated model
/// request. Results are funneled back into the main TUI loop via `AppEvent` so
@@ -25,12 +26,18 @@ pub(super) fn start_rate_limit_refresh(
config: Config,
debug_enabled: bool,
) {
std::thread::spawn(move || {
let fallback_tx = app_event_tx.clone();
if thread_spawner::spawn_lightweight("rate-refresh", move || {
if let Err(err) = run_refresh(app_event_tx.clone(), config, debug_enabled) {
let message = format!("Failed to refresh rate limits: {err}");
app_event_tx.send(AppEvent::RateLimitFetchFailed { message });
}
});
})
.is_none()
{
let message = "Failed to refresh rate limits: background worker unavailable".to_string();
fallback_tx.send(AppEvent::RateLimitFetchFailed { message });
}
}
fn run_refresh(
+77 -17
View File
@@ -25,8 +25,12 @@ use code_ollama::DEFAULT_OSS_MODEL;
use code_protocol::config_types::SandboxMode;
use std::fs::OpenOptions;
use std::path::PathBuf;
use std::sync::Once;
use std::sync::OnceLock;
use tracing_appender::non_blocking;
use tracing_appender::rolling;
use tracing_subscriber::filter::LevelFilter;
use tracing_subscriber::prelude::*;
use tracing_subscriber::EnvFilter;
use uuid::Uuid;
@@ -75,6 +79,7 @@ mod terminal_info;
mod text_formatting;
mod text_processing;
mod theme;
mod thread_spawner;
mod util {
pub mod buffer;
pub mod list_window;
@@ -395,7 +400,7 @@ pub async fn run_main(
};
let housekeeping_home = code_home.clone();
let housekeeping_handle = std::thread::spawn(move || {
let housekeeping_handle = thread_spawner::spawn_lightweight("housekeeping", move || {
if let Err(err) = code_core::run_housekeeping_if_due(&housekeeping_home) {
tracing::warn!("code home housekeeping failed: {err}");
}
@@ -478,7 +483,16 @@ pub async fn run_main(
let log_file = log_file_opts.open(log_dir.join("codex-tui.log"))?;
// Wrap file in non‑blocking writer.
let (non_blocking, _guard) = non_blocking(log_file);
let (log_writer, _log_guard) = non_blocking(log_file);
let critical_dir = {
let mut path = code_home.clone();
path.push("logs");
path
};
std::fs::create_dir_all(&critical_dir)?;
let critical_appender = rolling::daily(&critical_dir, "critical.log");
let (critical_writer, _critical_guard) = non_blocking(critical_appender);
let default_filter = if cli.debug {
"code_core=info,code_tui=info,code_browser=info"
@@ -491,12 +505,24 @@ pub async fn run_main(
EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new(default_filter))
};
let _ = tracing_subscriber::fmt()
.with_env_filter(env_filter())
let env_layer = tracing_subscriber::fmt::layer()
.with_target(false)
.with_span_events(tracing_subscriber::fmt::format::FmtSpan::CLOSE)
.with_ansi(false)
.with_writer(non_blocking)
.with_writer(log_writer)
.with_filter(env_filter());
let critical_layer = tracing_subscriber::fmt::layer()
.with_target(false)
.with_ansi(false)
.with_thread_ids(true)
.with_thread_names(true)
.with_writer(critical_writer)
.with_filter(LevelFilter::ERROR);
let _ = tracing_subscriber::registry()
.with(env_layer)
.with(critical_layer)
.try_init();
if cli.oss {
@@ -522,13 +548,56 @@ pub async fn run_main(
theme_configured_explicitly,
);
if let Err(err) = housekeeping_handle.join() {
tracing::warn!("code home housekeeping task panicked: {err:?}");
if let Some(handle) = housekeeping_handle {
if let Err(err) = handle.join() {
tracing::warn!("code home housekeeping task panicked: {err:?}");
}
} else {
tracing::warn!("housekeeping thread spawn skipped: background thread limit reached");
}
run_result.map_err(|err| std::io::Error::other(err.to_string()))
}
pub(crate) fn install_unified_panic_hook() {
static PANIC_HOOK_ONCE: Once = Once::new();
PANIC_HOOK_ONCE.call_once(|| {
let prev_hook = std::panic::take_hook();
std::panic::set_hook(Box::new(move |info| {
let current_thread = std::thread::current();
let thread_name = current_thread.name().unwrap_or("unnamed");
let thread_id = format!("{:?}", current_thread.id());
if let Some(location) = info.location() {
tracing::error!(
thread_name,
thread_id,
file = location.file(),
line = location.line(),
column = location.column(),
panic = %info,
"panic captured"
);
} else {
tracing::error!(
thread_name,
thread_id,
panic = %info,
"panic captured"
);
}
if let Err(err) = crate::tui::restore() {
tracing::warn!("failed to restore terminal after panic: {err}");
}
prev_hook(info);
std::process::exit(1);
}));
});
}
fn run_ratatui_app(
cli: Cli,
mut config: Config,
@@ -538,16 +607,7 @@ fn run_ratatui_app(
theme_configured_explicitly: bool,
) -> color_eyre::Result<ExitSummary> {
color_eyre::install()?;
// Forward panic reports through tracing so they appear in the UI status
// line, but do not swallow the default/color-eyre panic handler.
// Chain to the previous hook so users still get a rich panic report
// (including backtraces) after we restore the terminal.
let prev_hook = std::panic::take_hook();
std::panic::set_hook(Box::new(move |info| {
tracing::error!("panic: {info}");
prev_hook(info);
}));
install_unified_panic_hook();
maybe_apply_terminal_theme_detection(&mut config, theme_configured_explicitly);
let (mut terminal, terminal_info) = tui::init(&config)?;
+67
View File
@@ -0,0 +1,67 @@
use std::sync::atomic::{AtomicUsize, Ordering};
const STACK_SIZE_BYTES: usize = 256 * 1024;
const MAX_BACKGROUND_THREADS: usize = 32;
static ACTIVE_THREADS: AtomicUsize = AtomicUsize::new(0);
struct ThreadCountGuard;
impl ThreadCountGuard {
fn new() -> Self {
Self
}
}
impl Drop for ThreadCountGuard {
fn drop(&mut self) {
ACTIVE_THREADS.fetch_sub(1, Ordering::SeqCst);
}
}
/// Lightweight helper to spawn background threads with a lower stack size and
/// a descriptive, namespaced thread name. Keeps a simple global cap to avoid
/// runaway spawns when review flows create timers repeatedly.
pub(crate) fn spawn_lightweight<F>(name: &str, f: F) -> Option<std::thread::JoinHandle<()>>
where
F: FnOnce() + Send + 'static,
{
let mut observed = ACTIVE_THREADS.load(Ordering::SeqCst);
loop {
if observed >= MAX_BACKGROUND_THREADS {
tracing::error!(
active_threads = observed,
max_threads = MAX_BACKGROUND_THREADS,
thread_name = name,
"background thread spawn rejected: limit reached"
);
return None;
}
match ACTIVE_THREADS.compare_exchange(
observed,
observed + 1,
Ordering::SeqCst,
Ordering::SeqCst,
) {
Ok(_) => break,
Err(updated) => observed = updated,
}
}
let thread_name = format!("code-{name}");
let builder = std::thread::Builder::new()
.name(thread_name)
.stack_size(STACK_SIZE_BYTES);
match builder.spawn(move || {
let _guard = ThreadCountGuard::new();
f();
}) {
Ok(handle) => Some(handle),
Err(error) => {
ACTIVE_THREADS.fetch_sub(1, Ordering::SeqCst);
tracing::error!(thread_name = name, %error, "failed to spawn background thread");
None
}
}
}
+1 -20
View File
@@ -217,26 +217,7 @@ fn query_terminal_info() -> TerminalInfo {
}
fn set_panic_hook() {
// Chain to any previously installed hook so users still get rich reports.
let prev = std::panic::take_hook();
std::panic::set_hook(Box::new(move |panic_info| {
// Always attempt to restore the terminal state before printing the panic.
// This is crucial on Windows and when background threads panic — otherwise
// raw mode, mouse/focus reporting, and the alt screen can be left enabled,
// causing sequences like "[A", "[B", or "[I" to appear and making Ctrl+C
// ineffective. Ignore any restore error as we're already failing.
let _ = restore();
// Delegate to the previous hook (color-eyre or default) to render details.
prev(panic_info);
// Ensure the process terminates. Without exiting here, a panic in a
// background thread (e.g., streaming/agent worker) would leave the main
// UI thread running after we've torn down the terminal, which manifests
// as the "CLI bugs out" behavior described in issue #80.
// Exiting avoids that half‑alive state and returns control to the shell.
std::process::exit(1);
}));
crate::install_unified_panic_hook();
}
/// Restore the terminal to its original state