From 6795243d5f4e4b412300ddf86612d062ac88766d Mon Sep 17 00:00:00 2001 From: reverse Date: Wed, 12 Aug 2026 12:43:41 +0000 Subject: [PATCH] core: slow-command snotice (slow_command_ms) + a watchdog thread (watchdog_ms) so a blocked core thread is visible instead of a silent freeze --- echoircd.conf.example | 4 ++++ src/ircd.rs | 17 ++++++++++++++++- src/main.rs | 26 ++++++++++++++++++++++++-- 3 files changed, 44 insertions(+), 3 deletions(-) diff --git a/echoircd.conf.example b/echoircd.conf.example index e1a1527..94e0152 100644 --- a/echoircd.conf.example +++ b/echoircd.conf.example @@ -132,6 +132,10 @@ amu_target = both # connectclass_required = yes # refuse clients that match no allow class (default no) # --- global connection limits (per-class recvq/hardsendq/softsendq override these) --- +# --- core-thread health (single-threaded core: nothing slow may run inline) --- +# slow_command_ms = 200 # snotice when one event takes at least this long (0 = off) +# watchdog_ms = 5000 # a thread warns to the log if the core is stuck this long (0 = off) + # max_line = 16384 # max bytes in one line / receive queue (default 16 KiB) # max_sendq = 1048576 # max queued output before a slow client is dropped (1 MiB) diff --git a/src/ircd.rs b/src/ircd.rs index fb8e1bd..39945a1 100644 --- a/src/ircd.rs +++ b/src/ircd.rs @@ -4,7 +4,10 @@ use std::collections::HashMap; use std::net::{SocketAddr, TcpStream}; +use std::sync::atomic::{AtomicU64, Ordering}; use std::sync::mpsc::{Receiver, Sender}; +use std::sync::Arc; +use std::time::Instant; use crate::command::Command; use crate::config::Config; @@ -118,14 +121,26 @@ impl Ircd { /// server down with it. State touched before the panic may be left inconsistent, /// so this is a last-resort safety net, not a licence to panic — the untrusted /// parsers are still written so they can't panic in the first place. - pub fn run(mut self, rx: Receiver) { + /// `busy` is a shared marker the watchdog thread samples: it holds the ms-since- + /// `base` at which the current event started (0 = idle), so a stuck handler is + /// visible from outside. Events slower than `slow_command_ms` are also snoticed. + pub fn run(mut self, rx: Receiver, busy: Arc, base: Instant) { + let slow_ms = self.server.conf_num("slow_command_ms", 200u64); for ev in rx { + busy.store((base.elapsed().as_millis() as u64).max(1), Ordering::Relaxed); + let start = Instant::now(); if std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| self.handle_event(ev))) .is_err() { // the default panic hook already logged the details to stderr eprintln!("[core] recovered from a panicking event handler; continuing"); } + busy.store(0, Ordering::Relaxed); + let ms = start.elapsed().as_millis() as u64; + if slow_ms != 0 && ms >= slow_ms { + self.server + .snotice(&format!("slow event: a command took {ms}ms on the core thread")); + } } } diff --git a/src/main.rs b/src/main.rs index 132b5ad..067b610 100644 --- a/src/main.rs +++ b/src/main.rs @@ -4,10 +4,11 @@ #![forbid(unsafe_code)] use std::net::TcpListener; -use std::sync::atomic::AtomicU64; +use std::sync::atomic::{AtomicU64, Ordering}; use std::sync::mpsc; use std::sync::Arc; use std::thread; +use std::time::{Duration, Instant}; use echoircd::config::Config; use echoircd::ircd::{Event, Ircd}; @@ -67,7 +68,28 @@ fn main() { let core_cfg = cfg.clone(); let core_tx = tx.clone(); // the core self-injects events (DNS results) let core_counter = counter.clone(); - let core = thread::spawn(move || Ircd::new(core_cfg, core_tx, core_counter).run(rx)); + // watchdog: the core stores when it started the current event into `core_busy` + // (0 = idle); a separate thread warns if it stays stuck past `watchdog_ms`. + let wd_base = Instant::now(); + let core_busy = Arc::new(AtomicU64::new(0)); + let watchdog_ms = raw_num("watchdog_ms", 5000) as u64; // 0 = off + if watchdog_ms > 0 { + let (wb, base) = (core_busy.clone(), wd_base); + thread::spawn(move || loop { + thread::sleep(Duration::from_millis(1000)); + let cur = wb.load(Ordering::Relaxed); + if cur != 0 { + let stuck = (base.elapsed().as_millis() as u64).saturating_sub(cur); + if stuck > watchdog_ms { + eprintln!( + "[watchdog] core thread stuck ~{stuck}ms on one event — a handler is blocking the whole server" + ); + } + } + }); + } + let (busy, base) = (core_busy, wd_base); + let core = thread::spawn(move || Ircd::new(core_cfg, core_tx, core_counter).run(rx, busy, base)); // background timer: drives ping/idle timeouts let tick_tx = tx.clone();