aion_server/death_note.rs
1//! The server's death note: a durable record of what is killing the process
2//! on paths that never reach the graceful-shutdown log.
3//!
4//! Two production servers died on 2026-08-16 (pids 52844 and 2681) with
5//! identical faces: the main log ends mid-flight on routine lines — no drain,
6//! no panic output, no OS crash report. This module exists so the third such
7//! death is a diagnosis instead of a mystery. It arms three recorders around
8//! the run loop, writing to `<AION_HOME>/logs/aion-server.death.log`:
9//!
10//! - an **armed/disarmed bracket**: one line when the server boots, one line
11//! when the run scope exits by ordinary control flow (clean shutdown or an
12//! error return, written by [`DeathNote`]'s `Drop`). A note that is armed
13//! but never disarmed, with no other entry, means the process was destroyed
14//! without the run loop seeing it — the `SIGKILL` / raw-`_exit` class no
15//! in-process handler can observe.
16//! - a **panic hook**, chained in front of the previously installed hook,
17//! that records every panic's thread, location, payload, and backtrace. A
18//! panic in a spawned task can be survivable; the entry says so. Death by
19//! panic reads as a `PANIC` entry followed by the drop-written `DISARMED`
20//! line as the unwind leaves the run scope.
21//! - a **termination-signal watcher** for the catchable signals whose default
22//! action kills the process silently (`SIGHUP`, `SIGQUIT`, `SIGUSR1`,
23//! `SIGUSR2`): the note records the signal, then re-applies the signal's
24//! default action so process behaviour is unchanged — the death is noted,
25//! not prevented. `SIGTERM` and `SIGINT` are recorded as observations only:
26//! the graceful drain in [`crate::run`] owns those two, and both watchers
27//! coexist because tokio and this module register through the same
28//! `signal-hook-registry` chain.
29//! - **breadcrumbs**: work sites call [`breadcrumb`] as they begin a unit of
30//! in-flight work (today: every declared action body the server executes),
31//! so a corpse's LAST breadcrumb names what was running when the process
32//! died. The third 2026-08-16 death (pid 25680, ~16:27Z) happened
33//! mid-declared-action with only an ordinary INFO log line to say so; this
34//! makes that fact a note entry the corpse reader sees first.
35//!
36//! # Every entry carries its pid
37//!
38//! One home's note is shared by every server that ever ran against it, and
39//! those lives INTERLEAVE: an unclaimed multi-server boot, a restart's
40//! succession handover, and — routinely, since the birth claim landed — a
41//! second `aion server` that arms, is refused the home, and abandons. So the
42//! frame of every line is `<rfc3339> pid=<pid> <ENTRY>`, and the reader
43//! ([`crate::control::outcome::read_fate`]) SELECTS by pid rather than
44//! scanning a bracket until the next `ARMED`.
45//!
46//! 🔴 That bracket scan was a real defect, measured 2026-08-26: a refused
47//! boot's `ARMED` line landed between a live server's `SIGNAL` and its
48//! `OUTCOME`, the scan stopped there, and `aion server stop` reported "the
49//! bracket never closed … the `kill -9` shape" about a server that had just
50//! drained cleanly with its outcome on disk two lines below. Interleaving is
51//! ORDINARY now, so the framing has to be right rather than the interleaving
52//! rare.
53//!
54//! There is deliberately no reading of the un-framed format that preceded
55//! this one. A line with no `pid=` tag is reported as UNATTRIBUTABLE — the
56//! note is on disk and readable by eye — never guessed onto a pid.
57//!
58//! NOT covered, stated plainly: `SIGKILL`/`SIGSTOP` (uncatchable by kernel
59//! contract); the fatal-fault signals (`SIGSEGV`/`SIGBUS`/`SIGILL`/`SIGFPE`)
60//! and raw `abort()`, whose handlers must run in async-signal context and
61//! therefore require `unsafe` this workspace denies (the OS crash reporter
62//! remains the observer for that class — both 2026-08-16 corpses left no
63//! crash report, which is itself evidence against that class); and a direct
64//! `exit()` that bypasses the run scope. With the note armed, each of those
65//! reads as ARMED-without-DISARMED plus the absence of every entry above — a
66//! narrow, named remainder instead of an anonymous death.
67
68use std::fs::{File, OpenOptions};
69use std::io::Write;
70use std::panic::PanicHookInfo;
71use std::path::{Path, PathBuf};
72use std::sync::atomic::{AtomicBool, Ordering};
73use std::sync::{Arc, Mutex, PoisonError};
74
75use tracing::{error, info, warn};
76
77use crate::ServerError;
78
79/// One death note per process: the panic hook and signal registrations are
80/// process-global, so a second armed instance would double-write every entry.
81static ARMED_ONCE: AtomicBool = AtomicBool::new(false);
82
83/// File name of the death note inside the Aion home's `logs/` directory.
84const NOTE_FILE_NAME: &str = "aion-server.death.log";
85
86/// The death note's path under `home` — the ONE derivation, shared with the
87/// reader ([`crate::control::outcome::read_fate`]) so the writer and the
88/// reader cannot drift apart: a drifted reader would report "the exit left no
89/// recorded account" over a perfectly good note, silently.
90#[must_use]
91pub fn note_path(home: &std::path::Path) -> std::path::PathBuf {
92 home.join("logs").join(NOTE_FILE_NAME)
93}
94
95/// The armed note's breadcrumb route. Work sites reach the note through this
96/// process-global slot because the note's other recorders (panic hook, signal
97/// watcher) are process-global by nature and [`ARMED_ONCE`] already enforces
98/// a single armed note per process. Set by [`DeathNote::arm`], cleared on
99/// disarm; [`breadcrumb`] is a silent no-op in between.
100static BREADCRUMB_SLOT: Mutex<Option<BreadcrumbWriter>> = Mutex::new(None);
101
102/// The pieces [`breadcrumb`] needs: the shared note file and the armed flag
103/// that gates every recorder off after disarm.
104struct BreadcrumbWriter {
105 note: Arc<NoteFile>,
106 armed: Arc<AtomicBool>,
107}
108
109/// Append a `BREADCRUMB` entry to the armed death note, naming work now in
110/// flight so a corpse's last breadcrumb identifies the site that never
111/// finished. A silent no-op when no note is armed (tests, tools, the CLI).
112///
113/// Every note entry is written through to disk (`sync_all`), so call this at
114/// work-start cadence — one entry per declared action body — never inside a
115/// hot loop.
116pub fn breadcrumb(entry: &str) {
117 let slot = BREADCRUMB_SLOT
118 .lock()
119 .unwrap_or_else(PoisonError::into_inner);
120 if let Some(writer) = slot.as_ref()
121 && writer.armed.load(Ordering::SeqCst)
122 {
123 writer.note.write_entry(&format!("BREADCRUMB {entry}"));
124 }
125}
126
127/// What the signal watcher does after noting a signal whose default action
128/// terminates the process. Production re-applies the default action (the
129/// process dies exactly as it would have, but on the record); tests inject a
130/// recorder so the suite is not killed by its own probe.
131type FatalAction = Box<dyn Fn(i32) + Send + Sync>;
132
133/// The armed death note. Constructed by [`DeathNote::arm`] early in the
134/// server run loop; its `Drop` writes the `DISARMED` line, so any ordinary
135/// exit from the run scope — clean shutdown, error return, or a panic
136/// unwinding through it — closes the bracket on the record.
137pub struct DeathNote {
138 note: Arc<NoteFile>,
139 armed: Arc<AtomicBool>,
140 /// Whether the run loop's graceful drain is watching for a termination
141 /// signal yet. See [`DeathNote::drain_owns_termination`].
142 drain_owns_termination: Arc<AtomicBool>,
143 #[cfg(unix)]
144 signals_handle: signal_hook::iterator::Handle,
145 disarm_reason: Option<String>,
146}
147
148impl std::fmt::Debug for DeathNote {
149 fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
150 formatter
151 .debug_struct("DeathNote")
152 .field("path", &self.note.path)
153 .field("armed", &self.armed.load(Ordering::SeqCst))
154 .finish_non_exhaustive()
155 }
156}
157
158impl DeathNote {
159 /// Arm the death note under the resolved Aion home: create
160 /// `<home>/logs/`, open the note file append-only, write the `ARMED`
161 /// line, install the panic hook, and start the signal watcher.
162 ///
163 /// # Errors
164 ///
165 /// Returns [`ServerError::DeathNote`] when a note is already armed in
166 /// this process, when the logs directory or note file cannot be created,
167 /// or when the signal watcher cannot be installed. Arming failures are
168 /// fatal to boot by design: a server that cannot record its own death is
169 /// exactly the server this module exists for.
170 pub fn arm(home: &Path) -> Result<Self, ServerError> {
171 Self::arm_with_fatal_action(home, None)
172 }
173
174 /// [`DeathNote::arm`] with an injectable fatal action. `None` selects the
175 /// production action (re-apply the signal's default, terminating the
176 /// process); tests inject a recorder so the probe signal does not kill
177 /// the test binary. The seam sits on the production path — the injected
178 /// closure replaces only the final kill, never the note write.
179 fn arm_with_fatal_action(
180 home: &Path,
181 fatal_action: Option<FatalAction>,
182 ) -> Result<Self, ServerError> {
183 if ARMED_ONCE
184 .compare_exchange(false, true, Ordering::SeqCst, Ordering::SeqCst)
185 .is_err()
186 {
187 return Err(death_note_error(
188 "a death note is already armed in this process; the panic hook and \
189 signal registrations are process-global and must not be doubled",
190 ));
191 }
192 let logs_dir = home.join("logs");
193 std::fs::create_dir_all(&logs_dir).map_err(|source| {
194 death_note_error(format!(
195 "could not create logs directory `{}`: {source}",
196 logs_dir.display()
197 ))
198 })?;
199 let path = note_path(home);
200 let file = OpenOptions::new()
201 .create(true)
202 .append(true)
203 .open(&path)
204 .map_err(|source| {
205 death_note_error(format!(
206 "could not open death note `{}`: {source}",
207 path.display()
208 ))
209 })?;
210 let note = Arc::new(NoteFile {
211 path,
212 file: Mutex::new(file),
213 pid: std::process::id(),
214 });
215 let build = crate::build_identity::BuildIdentity::current();
216 // No `pid=` in the body: the frame every entry carries already has
217 // it, and two spellings of one fact is how a reader ends up trusting
218 // the wrong one.
219 note.write_entry(&format!(
220 "ARMED version={} build={}",
221 env!("CARGO_PKG_VERSION"),
222 build.line(),
223 ));
224 let armed = Arc::new(AtomicBool::new(true));
225 // False until the run loop is actually watching for a termination
226 // signal — see `drain_owns_termination` for why the boot window is
227 // not the drain's to own.
228 let drain_owns_termination = Arc::new(AtomicBool::new(false));
229 *BREADCRUMB_SLOT
230 .lock()
231 .unwrap_or_else(PoisonError::into_inner) = Some(BreadcrumbWriter {
232 note: Arc::clone(¬e),
233 armed: Arc::clone(&armed),
234 });
235 install_panic_hook(Arc::clone(¬e), Arc::clone(&armed));
236 #[cfg(unix)]
237 let signals_handle = {
238 let action =
239 fatal_action.unwrap_or_else(|| terminate_with_default_action(Arc::clone(¬e)));
240 spawn_signal_watcher(
241 Arc::clone(¬e),
242 Arc::clone(&armed),
243 Arc::clone(&drain_owns_termination),
244 action,
245 )?
246 };
247 #[cfg(not(unix))]
248 drop(fatal_action);
249 info!(path = %note.path.display(), "death note armed");
250 Ok(Self {
251 note,
252 armed,
253 drain_owns_termination,
254 #[cfg(unix)]
255 signals_handle,
256 disarm_reason: None,
257 })
258 }
259
260 /// Declare that the run loop's graceful drain is now watching for a
261 /// termination signal, so the watcher must only OBSERVE one.
262 ///
263 /// 🔴 Before this existed, the watcher observed `SIGTERM`/`SIGINT` from
264 /// the instant the note was armed — which is the instant the home is
265 /// claimed, minutes before the doors open on a large store. Registering a
266 /// handler MASKS the default action, so during the whole boot a
267 /// termination signal was caught, written down, and answered by nobody:
268 /// the drain that "owns the response" was not listening yet. The process
269 /// was un-terminable by `SIGTERM` for the length of its own recovery, and
270 /// then went on to serve as though nothing had been asked of it. Measured
271 /// 2026-08-26: `aion server stop` against a booting server reported
272 /// `still draining` at patience against a server that was not draining,
273 /// and the server came up serving thirty seconds later.
274 ///
275 /// While this is false, a termination signal ABANDONS THE BOOT. That is
276 /// the honest response: no listener is bound, no work has been accepted,
277 /// and there is nothing whatsoever to drain — so the only thing a drain
278 /// could add is delay. The exit is recorded first, and the record the
279 /// process leaves behind is reconciled as a dead incarnation by the next
280 /// boot and removed by `aion server stop`'s own bookkeeping.
281 pub fn drain_owns_termination(&self) {
282 self.drain_owns_termination.store(true, Ordering::SeqCst);
283 }
284
285 /// Path of the note file, for the startup banner and operator docs.
286 #[must_use]
287 pub fn path(&self) -> &Path {
288 &self.note.path
289 }
290
291 /// Close the bracket explicitly with the run loop's own account of how it
292 /// ended. Consumes the note; the `DISARMED` line is written by `Drop`.
293 pub fn disarm(mut self, reason: &str) {
294 self.disarm_reason = Some(reason.to_owned());
295 }
296
297 /// Append the shutdown outcome record as an `OUTCOME` entry, written
298 /// BEFORE disarm so `aion server stop` can read the drain's full result
299 /// after the process is gone ([`crate::control::outcome`] is the
300 /// reader). The death note already owns the "what ended this process"
301 /// seam; extending it with one entry kind keeps a single file and a
302 /// single writer — no parallel outcome channel.
303 ///
304 /// A record that cannot be serialized is reported and dropped: the
305 /// shutdown must not fail over its own receipt, and the reader treats
306 /// the record's absence as a state it names honestly.
307 pub fn record_outcome(&self, record: &crate::control::outcome::OutcomeRecord) {
308 match crate::control::outcome::render_entry(record) {
309 Ok(entry) => self.note.write_entry(&entry),
310 Err(error) => {
311 error!(
312 %error,
313 "could not write the shutdown outcome record into the death note; \
314 `aion server stop` will report the record as absent"
315 );
316 }
317 }
318 }
319}
320
321impl Drop for DeathNote {
322 fn drop(&mut self) {
323 self.armed.store(false, Ordering::SeqCst);
324 #[cfg(unix)]
325 self.signals_handle.close();
326 let reason = self.disarm_reason.as_deref().unwrap_or(
327 "run scope exited without an explicit disarm (an error return, or an unwind — \
328 see any PANIC entry directly above)",
329 );
330 self.note.write_entry(&format!("DISARMED {reason}"));
331 *BREADCRUMB_SLOT
332 .lock()
333 .unwrap_or_else(PoisonError::into_inner) = None;
334 info!(path = %self.note.path.display(), reason, "death note disarmed");
335 }
336}
337
338/// The note file plus its path, shared by the run scope, the panic hook, and
339/// the signal watcher thread.
340struct NoteFile {
341 path: PathBuf,
342 file: Mutex<File>,
343 /// This process's id, stamped onto EVERY entry. One note per process
344 /// (`ARMED_ONCE`), so one pid per writer — the frame is a property of the
345 /// file handle, not of each call site, which is what makes it impossible
346 /// for a new entry kind to be added without it.
347 pid: u32,
348}
349
350impl NoteFile {
351 /// Append one timestamped, pid-framed entry and force it to disk. A
352 /// poisoned lock is recovered and written through — the writer that
353 /// poisoned it was a panicking thread, which is precisely when this file
354 /// must still accept entries. A write or sync failure falls back to
355 /// stderr so the entry is never silently lost while the process can still
356 /// say anything at all.
357 fn write_entry(&self, entry: &str) {
358 let line = format!(
359 "{} pid={} {entry}\n",
360 chrono::Utc::now().to_rfc3339(),
361 self.pid
362 );
363 let mut file = self.file.lock().unwrap_or_else(PoisonError::into_inner);
364 let written = file
365 .write_all(line.as_bytes())
366 .and_then(|()| file.flush())
367 .and_then(|()| file.sync_all());
368 if let Err(io_error) = written {
369 eprintln!(
370 "death note write to `{}` failed ({io_error}); the entry was: {line}",
371 self.path.display()
372 );
373 }
374 }
375}
376
377/// Build the [`ServerError`] for an arming failure.
378fn death_note_error(message: impl Into<String>) -> ServerError {
379 ServerError::DeathNote {
380 message: message.into(),
381 }
382}
383
384/// Install the panic hook, chained IN FRONT of the previously installed hook
385/// so default stderr reporting (and anything a test harness installed) still
386/// runs after the note is on disk.
387fn install_panic_hook(note: Arc<NoteFile>, armed: Arc<AtomicBool>) {
388 let previous = std::panic::take_hook();
389 std::panic::set_hook(Box::new(move |panic_info: &PanicHookInfo<'_>| {
390 if armed.load(Ordering::SeqCst) {
391 note.write_entry(&panic_entry(panic_info));
392 }
393 previous(panic_info);
394 }));
395}
396
397/// Render a panic into one note entry: thread, location, payload, and the
398/// full backtrace (force-captured — by the time this runs, cost is moot).
399fn panic_entry(panic_info: &PanicHookInfo<'_>) -> String {
400 let thread = std::thread::current();
401 let thread_name = thread.name().unwrap_or("<unnamed>").to_owned();
402 let location = panic_info
403 .location()
404 .map_or_else(|| "<unknown location>".to_owned(), ToString::to_string);
405 let payload: &str = panic_info
406 .payload()
407 .downcast_ref::<&str>()
408 .copied()
409 .or_else(|| {
410 panic_info
411 .payload()
412 .downcast_ref::<String>()
413 .map(String::as_str)
414 })
415 .unwrap_or("<non-string panic payload>");
416 let backtrace = std::backtrace::Backtrace::force_capture();
417 format!(
418 "PANIC thread={thread_name} location={location} payload={payload} \
419 (a panic in a spawned task can be survivable; death by panic is this entry \
420 followed by a DISARMED line as the unwind leaves the run scope)\n{backtrace}"
421 )
422}
423
424/// The production fatal action: re-apply the signal's default disposition so
425/// the process terminates exactly as it would have without the watcher. If
426/// the default action somehow fails to terminate, that failure is itself
427/// noted and the process exits loudly with the conventional `128 + signal`
428/// code rather than continuing in an undefined disposition.
429#[cfg(unix)]
430fn terminate_with_default_action(note: Arc<NoteFile>) -> FatalAction {
431 Box::new(move |signal| {
432 if let Err(io_error) = signal_hook::low_level::emulate_default_handler(signal) {
433 note.write_entry(&format!(
434 "SIGNAL-DEFAULT-FAILED signal={} error={io_error}; exiting {} instead",
435 signal_label(signal),
436 128 + signal,
437 ));
438 std::process::exit(128 + signal);
439 }
440 })
441}
442
443/// Spawn the signal watcher thread over the catchable termination set.
444///
445/// `SIGTERM`/`SIGINT` entries are observations ONCE the run loop's graceful
446/// drain is watching (`drain_owns_termination`); before that — the whole boot
447/// window, which is minutes on a large store — they ABANDON THE BOOT, because
448/// registering this watcher masks the default action and nothing else is
449/// listening yet. `SIGHUP`/`SIGQUIT`/`SIGUSR1`/`SIGUSR2` had a default
450/// disposition of silent process death, so those are noted, synced, and then
451/// handed to `fatal_action`. Registration goes through `signal-hook`'s
452/// registry, which chains with tokio's own listeners rather than replacing
453/// them.
454#[cfg(unix)]
455fn spawn_signal_watcher(
456 note: Arc<NoteFile>,
457 armed: Arc<AtomicBool>,
458 drain_owns_termination: Arc<AtomicBool>,
459 fatal_action: FatalAction,
460) -> Result<signal_hook::iterator::Handle, ServerError> {
461 use signal_hook::consts::{SIGHUP, SIGINT, SIGQUIT, SIGTERM, SIGUSR1, SIGUSR2};
462
463 let mut signals =
464 signal_hook::iterator::Signals::new([SIGHUP, SIGINT, SIGQUIT, SIGTERM, SIGUSR1, SIGUSR2])
465 .map_err(|source| {
466 death_note_error(format!("could not register the signal watcher: {source}"))
467 })?;
468 let handle = signals.handle();
469 std::thread::Builder::new()
470 .name("aion-death-note".to_owned())
471 .spawn(move || {
472 for signal in &mut signals {
473 if !armed.load(Ordering::SeqCst) {
474 continue;
475 }
476 let label = signal_label(signal);
477 if signal == SIGTERM || signal == SIGINT {
478 if drain_owns_termination.load(Ordering::SeqCst) {
479 note.write_entry(&format!(
480 "SIGNAL {label} observed; the graceful drain owns the response"
481 ));
482 warn!(signal = label, "death note observed a termination signal");
483 continue;
484 }
485 // No drain is listening yet: this is the BOOT window, and
486 // registering this handler is what masked the default
487 // action. Answer it here rather than leaving the signal
488 // caught and unanswered.
489 note.write_entry(&format!(
490 "SIGNAL {label} received during boot; no listener is bound and \
491 nothing is draining, so the boot is abandoned"
492 ));
493 // Close the bracket HERE, before the default action ends
494 // the process. `Drop` never runs on this path, so without
495 // this the note would show an ARMED bracket that never
496 // closed — which every reader is entitled to read as the
497 // `kill -9` shape, and `aion server stop` duly reported
498 // exactly that about a stop the operator had just asked
499 // for. An exit this deliberate is owed a recorded reason.
500 //
501 // `armed` is deliberately NOT cleared: the default action
502 // ends the process on the next line, and clearing the flag
503 // would only silence entries from the microseconds in
504 // between — including a PANIC one, which is precisely what
505 // a reader would most want to see.
506 note.write_entry(&format!(
507 "DISARMED {label} received before the doors opened; the boot \
508 was abandoned with nothing serving and nothing draining"
509 ));
510 warn!(
511 signal = label,
512 "death note received a termination signal before the doors \
513 opened; abandoning the boot (nothing is serving and nothing \
514 is draining, so there is nothing a drain could do)"
515 );
516 fatal_action(signal);
517 } else {
518 note.write_entry(&format!(
519 "SIGNAL {label} received; terminating with the signal's default action"
520 ));
521 error!(
522 signal = label,
523 "death note recorded a fatal signal; applying its default action"
524 );
525 fatal_action(signal);
526 }
527 }
528 })
529 .map_err(|source| {
530 death_note_error(format!(
531 "could not spawn the signal watcher thread: {source}"
532 ))
533 })?;
534 Ok(handle)
535}
536
537/// Human-readable signal name (`SIGHUP`), falling back to the raw number for
538/// anything the platform table does not name.
539#[cfg(unix)]
540fn signal_label(signal: i32) -> String {
541 signal_hook::low_level::signal_name(signal)
542 .map_or_else(|| format!("signal {signal}"), ToOwned::to_owned)
543}
544
545#[cfg(test)]
546#[path = "death_note_tests.rs"]
547mod tests;