fix: backtraces working out of the box (#5)

Cargo.toml

@@ -11,7 +11,6 @@ crate-type = ["cdylib", "rlib"]
 js-sys = "0.3"
 log = "0.4"
 fern = "0.6"
-# crate not yet published! TODO remove before merge
 screeps-arena-game-api = { git = "https://github.com/rustyscreeps/screeps-arena-game-api.git" }
 # screeps-arena-game-api = "0.1"
 # screeps-arena-game-api = { path = "../screeps-arena-game-api" }
@@ -22,7 +21,7 @@ web-sys = { version = "0.3", features = ["console"] }
 # logging them with `console.error`. This is great for development, but requires
 # all the `std::fmt` and `std::panicking` infrastructure, so isn't great for
 # code size when deploying.
-console_error_panic_hook = { version = "0.1.6", optional = true }
+# console_error_panic_hook = { version = "0.1.6", optional = true }
 
 [dev-dependencies]
 wasm-bindgen-test = "0.3"
@@ -31,9 +30,13 @@ wasm-bindgen-test = "0.3"
 panic = "abort"
 opt-level = 3
 lto = true
+debug = true
 
+# wasm pack has a significant impact on binary size but adds some seconds to the build
+# so it can be disabled
 [package.metadata.wasm-pack.profile.release]
-wasm-opt = ["-O4"]
+wasm-opt = ["-O4", "-g"]
+#wasm-opt = false
 
 [features]
 default = []

javascript/main.mjs

@@ -1,4 +1,43 @@
-import { initSync } from "./screeps-arena-starter-rust";
+import { initSync, wasm_loop } from "./screeps-arena-starter-rust";
 import wasm_bytes from "./screeps-arena-starter-rust_bg.wasm.bin";
 initSync(wasm_bytes);
 export * from "./screeps-arena-starter-rust";
+
+Error.stackTraceLimit = 100;
+
+// This provides the function `console.error` that wasm_bindgen sometimes expects to exist,
+// especially with type checks in debug mode. An alternative is to have this be `function () {}`
+// and let the exception handler log the thrown JS exceptions, but there is some additional
+// information that wasm_bindgen only passes here.
+//
+// There is nothing special about this function and it may also be used by any JS/Rust code as a convenience.
+function console_error() {
+    const processedArgs = Array.prototype.map.call(arguments, (arg) => {
+        if (arg instanceof Error) {
+            // On this version of Node, the `stack` property of errors contains
+            // the message as well.
+            return arg.stack;
+        } else {
+            return arg;
+        }
+    }).join(' ');
+    console.log("ERROR:", processedArgs);
+}
+
+function loop () {
+  // need to freshly override the fake console object each tick
+  console.error = console_error;
+  try {
+      wasm_loop();
+  } catch (error) {
+      console.error("caught exception:", error);
+      // we've already logged the more-descriptive stack trace from rust's panic_hook
+      // if for some reason (like wasm init problems) you're not getting output from that
+      // and need more information, uncomment the following:
+      // if (error.stack) {
+      //     console.error("stack trace:", error.stack);
+      // }
+  }
+}
+
+export { loop }

src/lib.rs

@@ -14,7 +14,7 @@ fn setup() {
 
 // add wasm_bindgen to any function you would like to expose for call from js
 // to use a reserved name as a function name, use `js_name`:
-#[wasm_bindgen(js_name = loop)]
+#[wasm_bindgen(js_name = wasm_loop)]
 pub fn tick() {
     let tick = game::utils::get_ticks();
 

src/logging.rs

@@ -1,8 +1,11 @@
+use crate::wasm_bindgen;
+use core::panic::PanicInfo;
 use js_sys::JsString;
-//use screeps::Game;
-use web_sys::console;
-
+use log::error;
 pub use log::LevelFilter::*;
+use std::fmt::Write;
+use std::panic;
+use web_sys::console;
 
 struct JsLog;
 
@@ -30,4 +33,55 @@ pub fn setup_logging(verbosity: log::LevelFilter) {
         .chain(Box::new(JsLog) as Box<dyn log::Log>)
         .apply()
         .expect("expected setup_logging to only ever be called once per instance");
+    panic::set_hook(Box::new(panic_hook));
+}
+
+fn panic_hook(info: &PanicInfo) {
+    // import JS Error API to get backtrace info (backtraces don't work in wasm)
+    // Node 8 does support this API: https://nodejs.org/docs/latest-v8.x/api/errors.html#errors_error_stack
+
+    #[wasm_bindgen]
+    extern "C" {
+        type Error;
+
+        #[wasm_bindgen(constructor)]
+        fn new() -> Error;
+
+        #[wasm_bindgen(structural, method, getter)]
+        fn stack(error: &Error) -> String;
+
+        #[wasm_bindgen(static_method_of = Error, setter, js_name = stackTraceLimit)]
+        fn stack_trace_limit(size: f32);
+    }
+
+    let mut fmt_error = String::new();
+    let _ = writeln!(fmt_error, "Backtrace from panic_hook");
+    let _ = writeln!(fmt_error, "{}", info);
+
+    // this could be controlled with an env var at compilation instead
+    const SHOW_BACKTRACE: bool = true;
+
+    if SHOW_BACKTRACE {
+        Error::stack_trace_limit(10000_f32);
+        let stack = Error::new().stack();
+        // Skip all frames before the special symbol `__rust_end_short_backtrace`
+        // and then skip that frame too.
+        // Note: sometimes wasm-opt seems to delete that symbol.
+        if stack.contains("__rust_end_short_backtrace") {
+            for line in stack
+                .lines()
+                .skip_while(|line| !line.contains("__rust_end_short_backtrace"))
+                .skip(1)
+            {
+                let _ = writeln!(fmt_error, "{}", line);
+            }
+        } else {
+            // If there was no `__rust_end_short_backtrace` symbol, use the whole stack
+            // but skip the first line, it just says Error.
+            let (_, stack) = stack.split_once('\n').unwrap();
+            let _ = writeln!(fmt_error, "{}", stack);
+        }
+    }
+
+    error!("{}", fmt_error);
 }