core: slow-command snotice (slow_command_ms) + a watchdog thread (watchdog_ms) so a blocked core thread is visible instead of a silent freeze

This commit is contained in:
Jean Chevronnet 2026-08-12 12:43:41 +00:00
parent 8309b851f2
commit 6795243d5f
3 changed files with 44 additions and 3 deletions

View file

@ -132,6 +132,10 @@ amu_target = both
# connectclass_required = yes # refuse clients that match no allow class (default no) # connectclass_required = yes # refuse clients that match no allow class (default no)
# --- global connection limits (per-class recvq/hardsendq/softsendq override these) --- # --- 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_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) # max_sendq = 1048576 # max queued output before a slow client is dropped (1 MiB)

View file

@ -4,7 +4,10 @@
use std::collections::HashMap; use std::collections::HashMap;
use std::net::{SocketAddr, TcpStream}; use std::net::{SocketAddr, TcpStream};
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::mpsc::{Receiver, Sender}; use std::sync::mpsc::{Receiver, Sender};
use std::sync::Arc;
use std::time::Instant;
use crate::command::Command; use crate::command::Command;
use crate::config::Config; use crate::config::Config;
@ -118,14 +121,26 @@ impl Ircd {
/// server down with it. State touched before the panic may be left inconsistent, /// 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 /// 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. /// parsers are still written so they can't panic in the first place.
pub fn run(mut self, rx: Receiver<Event>) { /// `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<Event>, busy: Arc<AtomicU64>, base: Instant) {
let slow_ms = self.server.conf_num("slow_command_ms", 200u64);
for ev in rx { 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))) if std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| self.handle_event(ev)))
.is_err() .is_err()
{ {
// the default panic hook already logged the details to stderr // the default panic hook already logged the details to stderr
eprintln!("[core] recovered from a panicking event handler; continuing"); 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"));
}
} }
} }

View file

@ -4,10 +4,11 @@
#![forbid(unsafe_code)] #![forbid(unsafe_code)]
use std::net::TcpListener; use std::net::TcpListener;
use std::sync::atomic::AtomicU64; use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::mpsc; use std::sync::mpsc;
use std::sync::Arc; use std::sync::Arc;
use std::thread; use std::thread;
use std::time::{Duration, Instant};
use echoircd::config::Config; use echoircd::config::Config;
use echoircd::ircd::{Event, Ircd}; use echoircd::ircd::{Event, Ircd};
@ -67,7 +68,28 @@ fn main() {
let core_cfg = cfg.clone(); let core_cfg = cfg.clone();
let core_tx = tx.clone(); // the core self-injects events (DNS results) let core_tx = tx.clone(); // the core self-injects events (DNS results)
let core_counter = counter.clone(); 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 // background timer: drives ping/idle timeouts
let tick_tx = tx.clone(); let tick_tx = tx.clone();