Improve mod trap diagnostics

Co-authored-by: Codex <codex@openai.com>

crates/horizon-mods/src/runtime.rs

@@ -951,6 +951,7 @@ impl Mods {
     /// Calls `f` on every running mod whose hooks `wants`, with `fuel`.
     fn each(
         &mut self,
+        callback: &str,
         fuel: u64,
         wants: impl Fn(&Hooks) -> bool,
         mut f: impl FnMut(&mut Running) -> wasmtime::Result<()>,
@@ -961,18 +962,20 @@ impl Mods {
                 .as_ref()
                 .is_some_and(|r| wants(&r.hooks))
             {
-                self.call(i, fuel, &mut f);
+                self.call(i, callback, fuel, &mut f);
             }
         }
     }
     /// [`Mods::each`] over the client mods.
     fn each_client(
         &mut self,
+        callback: &str,
         fuel: u64,
         wants: impl Fn(&Registration) -> bool,
         mut f: impl FnMut(&ClientEvents, &mut Store<State>) -> wasmtime::Result<()>,
     ) {
         self.each(
+            callback,
             fuel,
             |h| h.client().is_some_and(&wants),
             |run| match &run.hooks {
@@ -984,11 +987,13 @@ impl Mods {
     /// [`Mods::each`] over the server mods.
     fn each_server(
         &mut self,
+        callback: &str,
         fuel: u64,
         wants: impl Fn(&ServerRegistration) -> bool,
         mut f: impl FnMut(&ServerEvents, &mut Store<State>) -> wasmtime::Result<()>,
     ) {
         self.each(
+            callback,
             fuel,
             |h| h.server().is_some_and(&wants),
             |run| match &run.hooks {
@@ -1002,6 +1007,7 @@ impl Mods {
     fn call<R>(
         &mut self,
         i: usize,
+        callback: &str,
         fuel: u64,
         f: impl FnOnce(&mut Running) -> wasmtime::Result<R>,
     ) -> Option<R> {
@@ -1029,7 +1035,11 @@ impl Mods {
             Ok(r) => Some(r),
             Err(e) => {
                 let reason = reason(&e);
-                log::warn!("Horizon: mod {} stopped: {reason}", run.store.data().id);
+                log::warn!(
+                    "Horizon: mod {} stopped in {callback} (fuel budget {fuel}, remaining {:?}): {reason}; error: {e:#}",
+                    run.store.data().id,
+                    run.store.get_fuel().ok(),
+                );
                 let name = run.store.data().name.clone();
                 self.out.push(Output::Stopped {
                     name,
@@ -1045,15 +1055,20 @@ impl Mods {
 
     /// A game tick.
     pub fn tick(&mut self, tick: u64) {
-        self.each_client(FUEL_TICK, |h| h.tick, |m, s| m.call_tick(s, tick));
+        self.each_client("tick", FUEL_TICK, |h| h.tick, |m, s| m.call_tick(s, tick));
     }
     /// A rendered frame, `seconds` after the last.
     pub fn frame(&mut self, seconds: f32) {
-        self.each_client(FUEL_FRAME, |h| h.frame, |m, s| m.call_frame(s, seconds));
+        self.each_client(
+            "frame",
+            FUEL_FRAME,
+            |h| h.frame,
+            |m, s| m.call_frame(s, seconds),
+        );
     }
     /// A chat line the player received, as plain text.
     pub fn chat(&mut self, text: &str) {
-        self.each_client(FUEL_EVENT, |h| h.chat, |m, s| m.call_chat(s, text));
+        self.each_client("chat", FUEL_EVENT, |h| h.chat, |m, s| m.call_chat(s, text));
     }
     /// Whether a running client mod owns `/name`.
     pub fn has_command(&self, name: &str) -> bool {
@@ -1073,7 +1088,7 @@ impl Mods {
         let Some(i) = self.command_owner(false, name) else {
             return false;
         };
-        let result = self.call(i, FUEL_EVENT, |run| match &run.hooks {
+        let result = self.call(i, "command", FUEL_EVENT, |run| match &run.hooks {
             Hooks::Client(m, _) => m
                 .horizon_mods_events()
                 .call_command(&mut run.store, name, args),
@@ -1100,11 +1115,17 @@ impl Mods {
 
     /// A server tick.
     pub fn server_tick(&mut self, tick: u64) {
-        self.each_server(FUEL_TICK, |h| h.tick, |m, s| m.call_tick(s, tick));
+        self.each_server(
+            "server tick",
+            FUEL_TICK,
+            |h| h.tick,
+            |m, s| m.call_tick(s, tick),
+        );
     }
     /// `player` joined the server (they are in the snapshot's players).
     pub fn player_joined(&mut self, player: &ServerPlayer) {
         self.each_server(
+            "player joined",
             FUEL_EVENT,
             |h| h.joins,
             |m, s| m.call_player_joined(s, player),
@@ -1113,6 +1134,7 @@ impl Mods {
     /// `player` left the server (they are no longer in the snapshot's players).
     pub fn player_left(&mut self, player: &ServerPlayer) {
         self.each_server(
+            "player left",
             FUEL_EVENT,
             |h| h.joins,
             |m, s| m.call_player_left(s, player),
@@ -1120,11 +1142,17 @@ impl Mods {
     }
     /// A chat message `player` sent, as plain text.
     pub fn player_chat(&mut self, player: &ServerPlayer, text: &str) {
-        self.each_server(FUEL_EVENT, |h| h.chat, |m, s| m.call_chat(s, player, text));
+        self.each_server(
+            "player chat",
+            FUEL_EVENT,
+            |h| h.chat,
+            |m, s| m.call_chat(s, player, text),
+        );
     }
     /// `player` broke `state` at `pos`.
     pub fn block_broken(&mut self, player: &ServerPlayer, pos: BlockPos, state: &str) {
         self.each_server(
+            "block broken",
             FUEL_EVENT,
             |h| h.blocks,
             |m, s| m.call_block_broken(s, player, pos, state),
@@ -1133,6 +1161,7 @@ impl Mods {
     /// `player` placed `state` at `pos`.
     pub fn block_placed(&mut self, player: &ServerPlayer, pos: BlockPos, state: &str) {
         self.each_server(
+            "block placed",
             FUEL_EVENT,
             |h| h.blocks,
             |m, s| m.call_block_placed(s, player, pos, state),
@@ -1173,7 +1202,7 @@ impl Mods {
                 return true;
             }
         };
-        let result = self.call(i, FUEL_EVENT, |run| match &run.hooks {
+        let result = self.call(i, "server command", FUEL_EVENT, |run| match &run.hooks {
             Hooks::Server(m, _) => m.horizon_mods_server_events().call_command(
                 &mut run.store,
                 player,
@@ -1824,7 +1853,7 @@ impl Mods {
             .and_then(|e| e.run.as_ref())
             .is_some_and(|r| r.ui.is_some());
         if has_ui {
-            self.call(i, FUEL_EVENT, |run| {
+            self.call(i, "UI event", FUEL_EVENT, |run| {
                 f(run.ui.as_ref().expect("checked above"), &mut run.store)
             });
         }
@@ -1915,7 +1944,7 @@ fn modified(path: &Path) -> Option<SystemTime> {
 /// A trap or error, as the player reads it.
 fn reason(e: &wasmtime::Error) -> String {
     match e.downcast_ref::<Trap>() {
-        Some(Trap::OutOfFuel) => "it took too long (an endless loop?)".into(),
+        Some(Trap::OutOfFuel) => "it exceeded its execution limit".into(),
         Some(Trap::UnreachableCodeReached) => "it crashed (a panic)".into(),
         Some(trap) => format!("it crashed: {trap}"),
         None => format!("{e:#}"),

crates/horizon-mods/tests/sandbox.rs

@@ -476,7 +476,7 @@ fn vanilla_commands_win() {
 #[test]
 fn a_misbehaving_mod_is_stopped_alone() {
     for (command, reason) in [
-        ("spin", "it took too long (an endless loop?)"),
+        ("spin", "it exceeded its execution limit"),
         ("panic", "it crashed (a panic)"),
         ("grow", "it crashed (a panic)"),
     ] {