Allow printing a trace of a run of the executor

Cargo.lock

@@ -2146,6 +2146,7 @@ version = "0.1.0"
 dependencies = [
  "anyhow",
  "async-task",
+ "backtrace",
  "bindgen",
  "block",
  "cc",

gpui/Cargo.toml

@@ -6,6 +6,7 @@ version = "0.1.0"
 
 [dependencies]
 async-task = "4.0.3"
+backtrace = "0.3"
 ctor = "0.1"
 etagere = "0.2"
 gpui_macros = { path = "../gpui_macros" }

gpui/src/executor.rs

@@ -1,10 +1,12 @@
 use anyhow::{anyhow, Result};
 use async_task::Runnable;
 pub use async_task::Task;
+use backtrace::{Backtrace, BacktraceFmt, BytesOrWideString};
 use parking_lot::Mutex;
 use rand::prelude::*;
 use smol::{channel, prelude::*, Executor};
 use std::{
+    fmt::{self, Debug},
     marker::PhantomData,
     mem,
     pin::Pin,
@@ -40,8 +42,8 @@ pub enum Background {
 struct DeterministicState {
     rng: StdRng,
     seed: u64,
-    scheduled: Vec<Runnable>,
+    scheduled: Vec<(Runnable, Backtrace)>,
-    spawned_from_foreground: Vec<Runnable>,
+    spawned_from_foreground: Vec<(Runnable, Backtrace)>,
     waker: Option<SyncSender<()>>,
 }
 
@@ -63,14 +65,16 @@ impl Deterministic {
         T: 'static,
         F: Future<Output = T> + 'static,
     {
+        let backtrace = Backtrace::new_unresolved();
         let scheduled_once = AtomicBool::new(false);
         let state = self.0.clone();
         let (runnable, task) = async_task::spawn_local(future, move |runnable| {
             let mut state = state.lock();
+            let backtrace = backtrace.clone();
             if scheduled_once.fetch_or(true, SeqCst) {
-                state.scheduled.push(runnable);
+                state.scheduled.push((runnable, backtrace));
             } else {
-                state.spawned_from_foreground.push(runnable);
+                state.spawned_from_foreground.push((runnable, backtrace));
             }
             if let Some(waker) = state.waker.as_ref() {
                 waker.send(()).ok();
@@ -85,10 +89,11 @@ impl Deterministic {
         T: 'static + Send,
         F: 'static + Send + Future<Output = T>,
     {
+        let backtrace = Backtrace::new_unresolved();
         let state = self.0.clone();
         let (runnable, task) = async_task::spawn(future, move |runnable| {
             let mut state = state.lock();
-            state.scheduled.push(runnable);
+            state.scheduled.push((runnable, backtrace.clone()));
             if let Some(waker) = state.waker.as_ref() {
                 waker.send(()).ok();
             }
@@ -113,6 +118,7 @@ impl Deterministic {
         })
         .detach();
 
+        let mut trace = Trace::default();
         loop {
             if let Ok(value) = output_rx.try_recv() {
                 state.lock().waker = None;
@@ -126,9 +132,13 @@ impl Deterministic {
                     .rng
                     .gen_range(0..state.scheduled.len() + state.spawned_from_foreground.len());
                 if ix < state.scheduled.len() {
-                    state.scheduled.remove(ix)
+                    let (_, backtrace) = &state.scheduled[ix];
+                    trace.record(&state, backtrace.clone());
+                    state.scheduled.remove(ix).0
                 } else {
-                    state.spawned_from_foreground.remove(0)
+                    let (_, backtrace) = &state.spawned_from_foreground[0];
+                    trace.record(&state, backtrace.clone());
+                    state.spawned_from_foreground.remove(0).0
                 }
             };
 
@@ -137,6 +147,129 @@ impl Deterministic {
     }
 }
 
+#[derive(Default)]
+struct Trace {
+    executed: Vec<Backtrace>,
+    scheduled: Vec<Vec<Backtrace>>,
+    spawned_from_foreground: Vec<Vec<Backtrace>>,
+}
+
+impl Trace {
+    fn record(&mut self, state: &DeterministicState, executed: Backtrace) {
+        self.scheduled.push(
+            state
+                .scheduled
+                .iter()
+                .map(|(_, backtrace)| backtrace.clone())
+                .collect(),
+        );
+        self.spawned_from_foreground.push(
+            state
+                .spawned_from_foreground
+                .iter()
+                .map(|(_, backtrace)| backtrace.clone())
+                .collect(),
+        );
+        self.executed.push(executed);
+    }
+
+    fn resolve(&mut self) {
+        for backtrace in &mut self.executed {
+            backtrace.resolve();
+        }
+
+        for backtraces in &mut self.scheduled {
+            for backtrace in backtraces {
+                backtrace.resolve();
+            }
+        }
+
+        for backtraces in &mut self.spawned_from_foreground {
+            for backtrace in backtraces {
+                backtrace.resolve();
+            }
+        }
+    }
+}
+
+impl Debug for Trace {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        struct FirstCwdFrameInBacktrace<'a>(&'a Backtrace);
+
+        impl<'a> Debug for FirstCwdFrameInBacktrace<'a> {
+            fn fmt(&self, f: &mut fmt::Formatter<'_>) -> std::fmt::Result {
+                let cwd = std::env::current_dir().unwrap();
+                let mut print_path = |fmt: &mut fmt::Formatter<'_>, path: BytesOrWideString<'_>| {
+                    fmt::Display::fmt(&path, fmt)
+                };
+                let mut fmt = BacktraceFmt::new(f, backtrace::PrintFmt::Full, &mut print_path);
+                for frame in self.0.frames() {
+                    let mut formatted_frame = fmt.frame();
+                    if frame
+                        .symbols()
+                        .iter()
+                        .any(|s| s.filename().map_or(false, |f| f.starts_with(&cwd)))
+                    {
+                        formatted_frame.backtrace_frame(frame)?;
+                        break;
+                    }
+                }
+                fmt.finish()
+            }
+        }
+
+        for ((backtrace, scheduled), spawned_from_foreground) in self
+            .executed
+            .iter()
+            .zip(&self.scheduled)
+            .zip(&self.spawned_from_foreground)
+        {
+            writeln!(f, "Scheduled")?;
+            for backtrace in scheduled {
+                writeln!(f, "- {:?}", FirstCwdFrameInBacktrace(backtrace))?;
+            }
+            if scheduled.is_empty() {
+                writeln!(f, "None")?;
+            }
+            writeln!(f, "==========")?;
+
+            writeln!(f, "Spawned from foreground")?;
+            for backtrace in spawned_from_foreground {
+                writeln!(f, "- {:?}", FirstCwdFrameInBacktrace(backtrace))?;
+            }
+            if spawned_from_foreground.is_empty() {
+                writeln!(f, "None")?;
+            }
+            writeln!(f, "==========")?;
+
+            writeln!(f, "Run: {:?}", FirstCwdFrameInBacktrace(backtrace))?;
+            writeln!(f, "+++++++++++++++++++")?;
+        }
+
+        Ok(())
+    }
+}
+
+impl Drop for Trace {
+    fn drop(&mut self) {
+        let trace_on_panic = if let Ok(trace_on_panic) = std::env::var("EXECUTOR_TRACE_ON_PANIC") {
+            trace_on_panic == "1" || trace_on_panic == "true"
+        } else {
+            false
+        };
+        let trace_always = if let Ok(trace_always) = std::env::var("EXECUTOR_TRACE_ALWAYS") {
+            trace_always == "1" || trace_always == "true"
+        } else {
+            false
+        };
+
+        if trace_always || (trace_on_panic && thread::panicking()) {
+            self.resolve();
+            dbg!(self);
+        }
+    }
+}
+
 impl Foreground {
     pub fn platform(dispatcher: Arc<dyn platform::Dispatcher>) -> Result<Self> {
         if dispatcher.is_main_thread() {