Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Compatibility with color-backtrace in 0.1.3 #828

Closed
QuadnucYard opened this issue Aug 1, 2024 · 9 comments
Closed

Compatibility with color-backtrace in 0.1.3 #828

QuadnucYard opened this issue Aug 1, 2024 · 9 comments
Labels
bug c: core Core components

Comments

@QuadnucYard
Copy link

I just run this code:

color_backtrace::install();
panic!("Just panic");

It will print unexpected panic information after normal information.

It seems alright in 0.1.1 with the output below, despite an issue with unwind:

(Output from color_backtrace omitted)
19: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
20: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
21: BaseThreadInitThunk
    at <unknown source file>
22: RtlUserThreadStart
    at <unknown source file>
The application panicked (crashed).
Message:  panic in a function that cannot unwind
Location: library\core\src\panicking.rs:221
......
21: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
22: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
23: BaseThreadInitThunk
    at <unknown source file>
24: RtlUserThreadStart
    at <unknown source file>
thread caused non-unwinding panic. aborting.

But on more unexpected stack backtrace from panic (no panic info available) occurs in 0.1.2 and 0.1.3 as below

The application panicked (crashed).
Message:  Just panic
(Output from color_backtrace omitted)
24: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
25: ZN6embree13TaskScheduler12startThreadsEv
    at <unknown source file>
26: BaseThreadInitThunk
    at <unknown source file>
27: RtlUserThreadStart
    at <unknown source file>
thread '<unnamed>' panicked at E:\Program\rust\.cargo\registry\src\rsproxy.cn-0dccff568467c15b\godot-core-0.1.3\src\private.rs:361:39:
no panic info available
stack backtrace:
   0:     0x7fff82fbf82d - std::backtrace_rs::backtrace::dbghelp64::trace
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\..\..\backtrace\src\backtrace\dbghelp64.rs:91
   1:     0x7fff82fbf82d - std::backtrace_rs::backtrace::trace_unsynchronized
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\..\..\backtrace\src\backtrace\mod.rs:66
   2:     0x7fff82fbf82d - std::sys::backtrace::_print_fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:68
   3:     0x7fff82fbf82d - std::sys::backtrace::impl$0::print::impl$0::fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:41
   4:     0x7fff82fd3ca9 - core::fmt::rt::Argument::fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\fmt\rt.rs:173   
   5:     0x7fff82fd3ca9 - core::fmt::write
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\fmt\mod.rs:1182 
   6:     0x7fff82fbdb21 - std::io::Write::write_fmt<std::sys::pal::windows::stdio::Stderr>
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\io\mod.rs:1827   
   7:     0x7fff82fc1537 - std::panicking::default_hook::closure$1
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:269 
   8:     0x7fff82fc1129 - std::panicking::default_hook
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:296 
   9:     0x7fff82fc1cab - alloc::boxed::impl$50::call
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\alloc\src\boxed.rs:2163  
  10:     0x7fff82fc1cab - std::panicking::rust_panic_with_hook
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:808 
  11:     0x7fff82fc1ab6 - std::panicking::begin_panic_handler::closure$0
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:674 
  12:     0x7fff82fbff1f - std::sys::backtrace::__rust_end_short_backtrace<std::panicking::begin_panic_handler::closure_env$0,never$>
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:172
  13:     0x7fff82fc1696 - std::panicking::begin_panic_handler
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:665 
  14:     0x7fff82fde474 - core::panicking::panic_fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:74 
  15:     0x7fff82fde43c - core::panicking::panic_display
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:264  16:     0x7fff82fde43c - core::option::expect_failed
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\option.rs:2030  
  17:     0x7fff8270f36b - godot_core::private::handle_panic_with_print<godot_core::private::handle_ptrcall_panic::closure_env$0<my_project::scene_tree::impl$13::__virtual_call::virtual_fn::closure_env$0,tuple$<> >,my_project::scene_tree::impl$13::__virtual_call::virtual_fn::c
                               at E:\Program\rust\.cargo\registry\src\rsproxy.cn-0dccff568467c15b\godot-core-0.1.3\src\private.rs:361
  18:     0x7fff826a13b1 - godot_core::private::handle_ptrcall_panic<my_project::scene_tree::impl$13::__virtual_call::virtual_fn::closure_env$0,tuple$<> >
                               at E:\Program\rust\.cargo\registry\src\rsproxy.cn-0dccff568467c15b\godot-core-0.1.3\src\private.rs:295
  19:     0x7fff8274e067 - my_project::scene_tree::impl$13::__virtual_call::virtual_fn
                               at E:\Project\my-project\rust\crates\my-project\src\scene_tree.rs:42
  20:     0x7ff6a468fff7 - ZN6embree13TaskScheduler12startThreadsEv
  21:     0x7ff6a28f75cd - <unknown>
  22:     0x7ff6a6f2da73 - ZN6embree13TaskScheduler12startThreadsEv
  23:     0x7ff6a28712ee - <unknown>
  24:     0x7ff6a28713e6 - <unknown>
  25:     0x7fffde727374 - BaseThreadInitThunk
  26:     0x7fffde95cc91 - RtlUserThreadStart
thread '<unnamed>' panicked at library\core\src\panicking.rs:221:5:
panic in a function that cannot unwind
stack backtrace:
   0:     0x7fff82fbf82d - std::backtrace_rs::backtrace::dbghelp64::trace
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\..\..\backtrace\src\backtrace\dbghelp64.rs:91
   1:     0x7fff82fbf82d - std::backtrace_rs::backtrace::trace_unsynchronized
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\..\..\backtrace\src\backtrace\mod.rs:66
   2:     0x7fff82fbf82d - std::sys::backtrace::_print_fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:68
   3:     0x7fff82fbf82d - std::sys::backtrace::impl$0::print::impl$0::fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:41
   4:     0x7fff82fd3ca9 - core::fmt::rt::Argument::fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\fmt\rt.rs:173   
   5:     0x7fff82fd3ca9 - core::fmt::write
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\fmt\mod.rs:1182 
   6:     0x7fff82fbdb21 - std::io::Write::write_fmt<std::sys::pal::windows::stdio::Stderr>
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\io\mod.rs:1827   
   7:     0x7fff82fc1537 - std::panicking::default_hook::closure$1
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:269 
   8:     0x7fff82fc1129 - std::panicking::default_hook
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:296 
   9:     0x7fff82fc1cab - alloc::boxed::impl$50::call
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\alloc\src\boxed.rs:2163
  10:     0x7fff82fc1cab - std::panicking::rust_panic_with_hook
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:808 
  11:     0x7fff82fc1a7f - std::panicking::begin_panic_handler::closure$0
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:667 
  12:     0x7fff82fbff1f - std::sys::backtrace::__rust_end_short_backtrace<std::panicking::begin_panic_handler::closure_env$0,never$>
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\sys\backtrace.rs:172
  13:     0x7fff82fc1696 - std::panicking::begin_panic_handler
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\std\src\panicking.rs:665 
  14:     0x7fff82fde4bd - core::panicking::panic_nounwind_fmt::runtime
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:112  15:     0x7fff82fde4bd - core::panicking::panic_nounwind_fmt
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:122  16:     0x7fff82fde563 - core::panicking::panic_nounwind
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:221  17:     0x7fff82fde6bb - core::panicking::panic_cannot_unwind
                               at /rustc/7120fdac7a6e55a5e4b606256042890b36067052/library\core\src\panicking.rs:309  18:     0x7fff8274e096 - my_project::scene_tree::impl$13::__virtual_call::virtual_fn
                               at E:\Project\my-project\rust\crates\my-project\src\scene_tree.rs:42
  19:     0x7fffb4dd1060 - <unknown>
  20:     0x7fffb4dd4d38 - is_exception_typeof
  21:     0x7fffde9b1c96 - RtlCaptureContext2
  22:     0x7fff8274e067 - my_project::scene_tree::impl$13::__virtual_call::virtual_fn
                               at E:\Project\my-project\rust\crates\my-project\src\scene_tree.rs:42
  23:     0x7ff6a468fff7 - ZN6embree13TaskScheduler12startThreadsEv
  24:     0x7ff6a28f75cd - <unknown>
  25:     0x7ff6a6f2da73 - ZN6embree13TaskScheduler12startThreadsEv
  26:     0x7ff6a28712ee - <unknown>
  27:     0x7ff6a28713e6 - <unknown>
  28:     0x7fffde727374 - BaseThreadInitThunk
  29:     0x7fffde95cc91 - RtlUserThreadStart
thread caused non-unwinding panic. aborting.

If I do not use color_backtrace, only a simple piece of information is given (v0.1.3).
And no backtrace is printed.

ERROR: godot-rust function call failed: ......
    Reason: [panic]  Just panic
   at: godot_core::private::report_call_error (E:\Program\rust\.cargo\registry\src\rsproxy.cn-0dccff568467c15b\godot-core-0.1.3\src\private.rs:313)

Rust version: rustc 1.82.0-nightly (7120fdac7 2024-07-25).
color-backtrace=0.6.1
Run with RUST_BACKTRACE=full.

So is this a bug, or does it require additional setting up panic handling? Thank you for your response!

@Bromeon
Copy link
Member

Bromeon commented Aug 1, 2024

Thanks for reporting!

According to your stacktrace, it happens in this line:

let info = guard.as_ref().expect("no panic info available");

So the PanicInfo that's usually provided in a panic hook seems to be None (absent). I don't know how color_backtrace interferes with the panic system, here you'd need to help me to see what we need to consider.

Worst case we could just print "no panic info" instead of .expect(), but it would be nice to go to the bottom of this 🤔

@Bromeon Bromeon added bug c: core Core components labels Aug 1, 2024
@QuadnucYard
Copy link
Author

QuadnucYard commented Aug 2, 2024

Besides, my previous tests triggered a panic in the initialize of SceneTree.
If the panic occurs elsewhere (during process), only ERROR: ... with the panic information will be printed out (no backtrace), even if with color-backtrace installed.

Such panic cannot be caught by the debugger either, which is terrible for debugging.

@QuadnucYard
Copy link
Author

It seems that color-backtrace just set a new panic hook but not take the previous one, so it is the only panic handler.
It employs backtrace library to collect backtrace frames, which should do nothing with panic.

let prev_hook = std::panic::take_hook();

This hook is taken when runing process, so no backtrace is printed. But why initialize appears differently?

eprintln!("panic occurred, but can't get location information");

I didn't see this eprintln take effect. So the new hook doesn't work in initialize?

@QuadnucYard
Copy link
Author

QuadnucYard commented Aug 2, 2024

I hope to get a pretty backtrace (from color-backtrace, printed to stdout) during debugging.
It needn't to be printed to godot debugger, considering:

  • Color support. Output from godot_print always has a single color (red if ERROR).
  • Duplication. Output from godot_print is also printed to stdout, just a poor replica.

But when released, I just need to collect plain backtrace as crash logs.

I take the following code from gdnative. It somehow works well in 0.1.1 (or earlier?), and I can see the crash from godot logs.

fn init_panic_hook() {
    let old_hook = std::panic::take_hook();
    std::panic::set_hook(Box::new(move |panic_info| {
        let loc_string;
        if let Some(location) = panic_info.location() {
            loc_string = format!("file '{}' at line {}", location.file(), location.line());
        } else {
            loc_string = "unknown location".to_owned()
        }

        let error_message;
        if let Some(s) = panic_info.payload().downcast_ref::<&str>() {
            error_message = format!("[RUST] {loc_string}: panic occurred: {s:?}");
        } else if let Some(s) = panic_info.payload().downcast_ref::<String>() {
            error_message = format!("[RUST] {loc_string}: panic occurred: {s:?}");
        } else {
            error_message = format!("[RUST] {loc_string}: unknown panic occurred");
        }
        godot_error!("{}", error_message);

        if let Ok(str) = format_backtrace_string() {
            godot_print!("{str}");
        }

        (*(old_hook.as_ref()))(panic_info);
    }));
}

fn format_backtrace_string() -> Result<String, std::io::Error> {
    use backtrace::Backtrace;
    use color_backtrace::{termcolor::NoColor, BacktracePrinter};

    let mut out = NoColor::new(vec![]);
    BacktracePrinter::new().print_trace(&Backtrace::new(), &mut out)?;
    Ok(String::from_utf8(out.into_inner()).unwrap())
}

@Bromeon
Copy link
Member

Bromeon commented Aug 2, 2024

Besides, my previous tests triggered a panic in the initialize of SceneTree. If the panic occurs elsewhere (during process), only ERROR: ... with the panic information will be printed out (no backtrace), even if with color-backtrace installed.

Such panic cannot be caught by the debugger either, which is terrible for debugging.

This probably falls under #411. Fully agree that we should look for ways to trigger the debugger.


It seems that color-backtrace just set a new panic hook but not take the previous one, so it is the only panic handler.
It employs backtrace library to collect backtrace frames, which should do nothing with panic.

Hm, independently of this issue in gdext, do you think that's something worth reporting to color-backtrace?


This hook is taken when runing process, so no backtrace is printed. But why initialize appears differently?

Good question, do you think this should be unified somehow?


I take the following code from gdnative. It somehow works well in 0.1.1 (or earlier?), and I can see the crash from godot logs.

The main takeaway here seems to be calling the previous hook, right?

Btw, you seem to have quite a concrete idea how to improve panic handling. Would you be interested in helping out with a pull request? 🙂

@QuadnucYard
Copy link
Author

@Bromeon I'm glad to offer some help, but sorry I don't have much experience with Rust (especially runtime) and I'm not familiar with foundations of gdext yet...

@Bromeon
Copy link
Member

Bromeon commented Aug 2, 2024

Let us know if we can help somehow. Our Discord community is also quite friendly in case you need some onboarding 🙂

If not, that's also fair, just keep in mind that I'm currently addressing many foundational parts for v0.2, and likely won't get around looking into very specific integrations (like color-backtrace or #832) for several months 😉

@QuadnucYard
Copy link
Author

Oh, I further noticed that my color-backtrace is unexpectedly stripped sometime.

In a panic triggered by a custom callable (used to connect to a pressed signal), my panic handle is gone. Only a large number of bare stack frames (but no [ERROR]) are printed, as if I haven't set a panic hook.

So the only [ERROR] output I saw before may be because there is only that panic handle left.

@Bromeon
Copy link
Member

Bromeon commented Sep 16, 2024

@QuadnucYard note that in the meantime, we disabled panic hooks in Release mode (#889). So it might be that Release mode already has the issue solved.

Other than that, do you plan to investigate this? I don't see any concrete actionables on gdext side, as it's not even clear whether it's color-backtrace or gdext misbehaving. If not, I would probably close this.

@Bromeon Bromeon closed this as not planned Won't fix, can't repro, duplicate, stale Sep 24, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug c: core Core components
Projects
None yet
Development

No branches or pull requests

2 participants