Colored stack traces - Githubissues

dev-ardi commented 3 months ago

Is it possible that we have better stack traces?

There is so much information on them, yet they are difficult to parse. This could be improved somewhat via coloring!:

See a typical backtrace, it's hard to find where the error happened:

called `Option::unwrap()` on a `None` value
stack backtrace:
   0: rust_begin_unwind
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/panicking.rs:72:14
   2: core::panicking::panic
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/panicking.rs:141:5
   3: core::option::unwrap_failed
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/option.rs:1984:5
   4: core::option::Option<T>::unwrap
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/option.rs:932:21
   5: alloc::collections::btree::navigate::<impl alloc::collections::btree::node::Handle<alloc::collections::btree::node::NodeRef<alloc::collections::btree::node::marker::Dying,K,V,alloc::collections::btree::node::marker::Leaf>,alloc::collections::btree::node::marker::Edge>>::deallocating_next_unchecked::{{closure}}
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/navigate.rs:601:48
   6: alloc::collections::btree::mem::replace
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/mem.rs:29:28
   7: alloc::collections::btree::navigate::<impl alloc::collections::btree::node::Handle<alloc::collections::btree::node::NodeRef<alloc::collections::btree::node::marker::Dying,K,V,alloc::collections::btree::node::marker::Leaf>,alloc::collections::btree::node::marker::Edge>>::deallocating_next_unchecked
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/navigate.rs:600:9
   8: alloc::collections::btree::navigate::LazyLeafRange<alloc::collections::btree::node::marker::Dying,K,V>::deallocating_next_unchecked
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/navigate.rs:200:24
   9: alloc::collections::btree::map::IntoIter<K,V,A>::dying_next
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/map.rs:1697:27
  10: <alloc::collections::btree::map::IntoIter<K,V,A> as core::ops::drop::Drop>::drop
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/map.rs:1677:30
  11: core::ptr::drop_in_place<alloc::collections::btree::map::IntoIter<alloc::string::String,serde_json::value::Value>>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  12: core::mem::drop
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/mem/mod.rs:938:24
  13: <alloc::collections::btree::map::BTreeMap<K,V,A> as core::ops::drop::Drop>::drop
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/alloc/src/collections/btree/map.rs:189:9
  14: core::ptr::drop_in_place<alloc::collections::btree::map::BTreeMap<alloc::string::String,serde_json::value::Value>>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  15: core::ptr::drop_in_place<serde_json::map::Map<alloc::string::String,serde_json::value::Value>>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  16: core::ptr::drop_in_place<emulator_rs::opts::MessageInner>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  17: core::ptr::drop_in_place<emulator_rs::opts::Message>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  18: core::ptr::drop_in_place<(alloc::string::String,emulator_rs::opts::Message)>
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/ptr/mod.rs:514:1
  19: emulator_rs::execution::recurse::{{closure}}
             at ./src/execution.rs:83:21
  20: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/future/future.rs:123:9
  21: emulator_rs::execution::route_output::{{closure}}::{{closure}}::{{closure}}
             at ./src/execution.rs:169:69
  22: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  23: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
  24: tokio::runtime::task::core::Core<T,S>::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  25: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  26: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/panic/unwind_safe.rs:272:9
  27: std::panicking::try::do_call
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panicking.rs:552:40
  28: __rust_try
  29: std::panicking::try
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panicking.rs:516:19
  30: std::panic::catch_unwind
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panic.rs:149:14
  31: tokio::runtime::task::harness::poll_future
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
  32: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
  33: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
  34: tokio::runtime::task::raw::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
  35: tokio::runtime::task::raw::RawTask::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
  36: tokio::runtime::task::LocalNotified<S>::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:427:9
  37: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:639:17
  38: tokio::runtime::coop::with_budget
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:107:5
  39: tokio::runtime::coop::budget
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/coop.rs:73:5
  40: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:575:9
  41: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:526:24
  42: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:491:21
  43: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/scoped.rs:40:9
  44: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:26
  45: std::thread::local::LocalKey<T>::try_with
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/thread/local.rs:286:12
  46: std::thread::local::LocalKey<T>::with
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/thread/local.rs:262:9
  47: tokio::runtime::context::set_scheduler
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context.rs:176:9
  48: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:486:9
  49: tokio::runtime::context::runtime::enter_runtime
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/context/runtime.rs:65:16
  50: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:478:5
  51: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/scheduler/multi_thread/worker.rs:447:45
  52: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/task.rs:42:21
  53: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:328:17
  54: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/loom/std/unsafe_cell.rs:16:9
  55: tokio::runtime::task::core::Core<T,S>::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/core.rs:317:13
  56: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:485:19
  57: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/core/src/panic/unwind_safe.rs:272:9
  58: std::panicking::try::do_call
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panicking.rs:552:40
  59: __rust_try
  60: std::panicking::try
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panicking.rs:516:19
  61: std::panic::catch_unwind
             at /rustc/becebb3158149a115cad8a402612e25436a7e37b/library/std/src/panic.rs:149:14
  62: tokio::runtime::task::harness::poll_future
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:473:18
  63: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:208:27
  64: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/harness.rs:153:15
  65: tokio::runtime::task::raw::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:271:5
  66: tokio::runtime::task::raw::RawTask::poll
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/raw.rs:201:18
  67: tokio::runtime::task::UnownedTask<S>::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/task/mod.rs:464:9
  68: tokio::runtime::blocking::pool::Task::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:159:9
  69: tokio::runtime::blocking::pool::Inner::run
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:513:17
  70: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/pool.rs:471:13
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
fish: Job 1, 'RUST_BACKTRACE=1 cargo run emul…' terminated by signal SIGILL (Illegal instruction)

Some example colors

Red for the actual error
gray for the panicking code (0-2) This is mostly noise so it makes sense to treat it differently
green for library code
blue for dependencies
white for user code. It must stand out

Also for the at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/task.rs:42:21 It's good to have the full path so I can jump into it and see what failed, but it's a good idea to highlight the important information: at /home/ardi/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.37.0/src/runtime/blocking/task.rs:42:21

saethlin commented 3 months ago

The first two bullets would be a good start:

Red for the actual error gray for the panicking code (0-2) This is mostly noise so it makes sense to treat it differently

The last 3 do not have a clear implementable definition:

green for library code blue for dependencies white for user code. It must stand out

dev-ardi commented 3 months ago

Couldn't we try some heuristics for the last three?

If the path contains crates.io it's a dependency
If one of the dirs of the path is rustc it's library code
etc

saethlin commented 3 months ago

A backtrace in the default release profile looks like this:

   0: rust_begin_unwind
   1: core::panicking::panic_fmt
   2: scratch::main

So that heuristic is implementable, but it falls apart in a default configuration which seems bad.

dev-ardi commented 3 months ago

Well yes, it will fail for release builds without debug symbols. We could suggest to enable symbols for a better backtrace. It would also be very helpful for tools with many, many stack trace messages like AddressSanitizer and ThreadSanitizer.

If we figure out better heuristics at some point we can improve the coloring then. Having a fallback to "not color anything" is no worse that what we have right now.

White is probably not the greatest for user code then, that should be reserved for unknown.

saethlin commented 3 months ago

It would also be very helpful for tools with many, many stack trace messages like AddressSanitizer and ThreadSanitizer.

No, it wouldn't. Those tools do their own backtrace printing that we do not maintain.

workingjubilee commented 3 months ago

People use white-background terminals. Using a foreground white is right out.

bjorn3 commented 3 months ago

Making the text bold/increased intensity (CSI 1 m) rather change the text color to bright white (CSI 97 m) should work fine when using a white background.

workingjubilee commented 3 months ago

Yes, that sounds fine.

workingjubilee commented 3 months ago

I mean, I'll still have to judge it by how it actually looks, but it sounds fine as-such.

c4rrao commented 2 months ago

Red for the actual error

I don't understand what actual error means. I'm think of it to be the first BacktraceFrame but I don't know if I'm getting it wrong. Can you be more detailed?

rust-lang / rust

Colored stack traces #124143