-
Notifications
You must be signed in to change notification settings - Fork 12.8k
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
Improve backtrace formating while panicking. #38165
Conversation
Thanks for the pull request, and welcome! The Rust team is excited to review your changes, and you should hear from @brson (or someone else) soon. If any changes to this PR are deemed necessary, please add them as extra commits. This ensures that the reviewer can see what has changed since they last reviewed the code. Due to the way GitHub handles out-of-date commits, this should also make it reasonably obvious what issues have or haven't been addressed. Large or tricky changes may require several passes of review and changes. Please see the contribution instructions for more information. |
Any idea about how I could get access to the build root path? |
Result formatting with
and with
I plan to mask 1-8 and 12-16 with |
Those appear to be the same, did you copy the wrong thing in? |
For now they are nearly the same, except the address which is not printed with |
In fact, that may not be necessary. We can simply recognized the mangled form of |
e94d312
to
ebc1ce9
Compare
With
|
@@ -173,7 +178,7 @@ pub fn print(w: &mut Write, idx: isize, addr: *mut libc::c_void, | |||
for (i, &(file, line)) in fileline_buf[..fileline_count].iter().enumerate() { | |||
if file.is_null() { continue; } // just to be sure | |||
let file = unsafe { CStr::from_ptr(file).to_bytes() }; | |||
output_fileline(w, file, line, i == FILELINE_SIZE - 1)?; | |||
output_fileline(w, file, line, i == FILELINE_SIZE - 1, format)?; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I believe you should be able to accomplish item 4 in #37783 by doing something like
let mut print_line = if format == backtrace::PrintFormat::Short { false } else { true };
for (i, &(file, line)) in fileline_buf[..fileline_count].iter().enumerate() {
if file.is_null() { continue; } // just to be sure
let file = unsafe { CStr::from_ptr(file).to_bytes() };
if format == backtrace::PrintFormat::Short && !print_line {
let magic_str = "core::panicking::panic_fmt";
if file[..magic_str.len()] == magic_str.as_bytes() {
print_line = true
}
continue;
}
output_fileline(w, file, line, i == FILELINE_SIZE - 1, format)?;
}
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
No, this loop only prints the at file:line
lines.
It's getting better!
compared to
|
Added removal of path prefix. It prints
|
Can someone test on windows? |
5df66a1
to
1aa97b5
Compare
Updated first post. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for the PR! I like the look and feel of the new output.
Could most of the changes be moved to the common implementation of backtraces? I don't see many changes to the Windows side of things so it'd be helpful to just define all the skipping and such logic in one location rather than in multiple.
configure
Outdated
@@ -1877,6 +1877,8 @@ fi | |||
|
|||
msg | |||
copy_if_changed ${CFG_SRC_DIR}${INPUT_MAKEFILE} ./Makefile | |||
# Export CFG_BUILD_DIR for use in backtrace unwinding. | |||
sed -i -re 's/^(CFG_BUILD_DIR)/export \1/' config.tmp |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This seems sort of suspicious, how come this was necessary?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
See #38165 (comment)
src/libstd/sys_common/backtrace.rs
Outdated
} | ||
|
||
let val = match env::var_os("RUST_BACKTRACE") { | ||
Some(x) => if &x == "0" { 1 } else { 2 }, | ||
None => 1, | ||
Some(x) => if ["no", "0"].iter().any(|val| &x == *val) { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In the interest of being as conservative as possible here, could we leave this as just recognizing 0
?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed in ddfef15.
src/libstd/sys_common/backtrace.rs
Outdated
None | ||
} else if &x == "full" { | ||
Some(PrintFormat::Full) | ||
} else if ["short", "yes", "1"].iter().any(|val| &x == *val) { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Could this just be collapsed with the case below?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Are you sure? I find it cleaner with the "catch anything" separated.
src/libstd/sys_common/backtrace.rs
Outdated
@@ -25,45 +27,107 @@ pub const HEX_WIDTH: usize = 18; | |||
#[cfg(target_pointer_width = "32")] | |||
pub const HEX_WIDTH: usize = 10; | |||
|
|||
#[derive(Debug, Copy, Clone, Eq, PartialEq)] | |||
pub enum PrintFormat { | |||
Full = 2, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
These values seem to be quite subtle, could you be sure to comment as to their purpose here?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK. In fact, it controls if the unwinding should use the short or long backtrace format.
src/libstd/sys_common/backtrace.rs
Outdated
let mut already_printed = false; | ||
if format == PrintFormat::Short && file_path.is_absolute() { | ||
if let Ok(cwd) = env::current_dir() { | ||
let buildroot = Path::new(env!("CFG_BUILD_DIR")); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Could this use option_env
and handle the None
case to ensure that we can build the standard library separately if need be?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
See #38165 (comment)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed in 7780ef8
let file_path = Path::new(file); | ||
let mut already_printed = false; | ||
if format == PrintFormat::Short && file_path.is_absolute() { | ||
if let Ok(cwd) = env::current_dir() { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Most of this can still be printed even if this fails, right?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh yeah, right. Fixed in 5c08069
src/libstd/sys_common/backtrace.rs
Outdated
if format == PrintFormat::Short && file_path.is_absolute() { | ||
if let Ok(cwd) = env::current_dir() { | ||
let buildroot = Path::new(env!("CFG_BUILD_DIR")); | ||
let libpath = Path::new("/tmp/libpath"); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hm I'm curious where this path name came into effect?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It's a dummy value, because the library directory is defined at compilation of the crate, not of stdlib. I still have to find a way to get it.
if let Some(mangled_symbol_name) = resolve_symname(symaddr) { | ||
let magics_begin = [ | ||
"_ZN3std3sys3imp9backtrace7tracing3imp5write", | ||
"_ZN3std9panicking", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This logic seems like we'd want to do this across all platforms, right? Perhaps this could go into the common module?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Sure, that would just need a bit of refactoring.
The |
Is it possible to also have the appveyor build? It would help me supporting windows. |
@alexcrichton A solution for cleaner code reuse would be that the unwinding function calls a platform-dependent function that generates some sort of Vec, then prints it. Not sure if it's an option, though, since it would allocate while unwinding. |
The platform specific option could potentially return an iterator instead of a vec to avoid the allocation (through impl Trait, or just explicitly naming it). |
I thought about that, but it may be complicated since the system specific code gives a callback to a C library that's invoked for each frame. |
What I propose is to add the structs |
8e563c1
to
4447538
Compare
@alexcrichton I think I'm ready for a final review. I'm only on linux, so I was not able to test on windows and such. As I moved code around, there is probably at least some unused imports. |
// See libunwind:src/unwind/Backtrace.c for the return values. | ||
// No, there is no doc. | ||
let ret = match result_unwind { | ||
uw::_URC_END_OF_STACK => { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I may have missed it, but where did these changes come from? How come we're handling different return codes now?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
http://git.savannah.gnu.org/gitweb/?p=libunwind.git;a=blob;f=src/unwind/Backtrace.c;hb=bc8698fd7ed13a629a8ec3cb2a89bd74f9d8b5c0
_Unwind_Backtrace
only return some values.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Sure yeah I can imagine that this function returns a number of values, but we weren't checking any of them before, only for errors. What prompted the change in logic?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I thought it was better to handle error codes. Was I wrong?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh no that's fine, I'm just trying to understand why. Did this come up during testing? Was this just done on a whim? Have these code paths been executed? etc.
I'm wary of these sorts of changes because libunwind's cross-platform behavior is notoriously finnicky, so I just wanted to dig into what prompted this change. My guess is that it's fine to land as such, but I just want to make sure.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
No, I just found it strange to ignore the error case (https://github.com/rust-lang/rust/blob/master/src/libstd/panicking.rs#L349, I'm watching ^^)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hm I feel like we're still not getting to an answer to my question. The code you linked to ignores errors because it has nowhere to pass the errors to and the information is just advisory, so it's fine to just ignore errors.
My question is why did this change happen? Is it purely being proactive? Was it reactive to some problem?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
No, I added it for the reasons explained above, without detected problems
let addr = frame.AddrPC.Offset; | ||
if addr == frame.AddrReturn.Offset || addr == 0 || | ||
frame.AddrReturn.Offset == 0 { break } | ||
|
||
frames[i] = addr; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Below it printed addr - 1
, but that seems to have been lost here?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yeah, not sure why there is this -1
, but it was probably important XD
|
||
let name = if ret == c::TRUE { | ||
if ret == c::TRUE { | ||
let ptr = info.Name.as_ptr() as *const c_char; | ||
Some(CStr::from_ptr(ptr).to_bytes()) | ||
} else { | ||
None | ||
}; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This semicolon seems like it'd cause a compile failure? And the to_bytes
doesn't seem to match the &'static str
return type?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Coding without compiler is not a good idea
CStr::from_ptr(info.dli_sname).to_bytes() | ||
})) | ||
Some(unsafe { | ||
CStr::from_ptr(info.dli_sname).to_str().ok() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This type of Option<Option<&str>>
seems to disagree with the tyep on the return of the function?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oops, the "Some" shouldn't be there
fn _foreach_symbol_fileline<F>(symbol_addr: Frame, | ||
mut f: F, | ||
context: &BacktraceContext) -> io::Result<bool> | ||
where F: FnMut(&[u8], libc::c_int) -> io::Result<()> |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Stylistically we typically indent where clauses like these over one
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK
src/libstd/sys_common/backtrace.rs
Outdated
output(w, index, *frame, resolve_symname(*frame, &context), format)?; | ||
if foreach_symbol_fileline(*frame, |file, line| { | ||
output_fileline(w, file, line, format) | ||
}, &context)? { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The indentation here was a little confusing for me at first, perhaps the result of this could be bound to a let
?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
yes, you're right
src/libstd/sys_common/backtrace.rs
Outdated
} else if &x == "full" { | ||
Some(PrintFormat::Full) | ||
} else if ["short", "yes", "1"].iter().any(|val| &x == *val) { | ||
Some(PrintFormat::Short) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I believe we can just remove this, right? (always fall through below)
match cx.last_error { | ||
Some(err) => panic!("Fatal error while unwinding: {}", | ||
err), | ||
None => panic!("Fatal error while unwinding"), |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Er so to clarify, we definitely can't panic while producing a backtrace. This is called during a panic, which would be a recursive panic, which we don't want to abort on. If we do end up handling this then we need to punt the error upwards and let the caller deal with it.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ok
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
What do you suggest as return value?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oh a bool or a Result would be fine
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yeah, sure, now that there is no cx.next_error ^^
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In fact, if I replace it with a bool we will loose the io::Error on https://github.com/Yamakaky/rust/blob/better-backtrace/src/libstd/sys/windows/backtrace/mod.rs#L76. Is that what we want?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
An alternative would be to return the already-decoded frames on error. Are you OK with that?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
That's what I did, finally.
match print(cx.writer, cx.idx, ip, symaddr) { | ||
Ok(()) => {} | ||
Err(e) => { cx.last_error = Some(e); } | ||
if cx.last_error.is_some() { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think this field is no longer necessary, right? It was only used when we could generate an error during a backtrace by calling write!
, but with that no longer happening the body of this function is infallible.
} | ||
_ => Ok(()), | ||
_ => unreachable!("\"{:?}\" should not be triggered", | ||
result_unwind), |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Could this return an error?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I see a few possibilities:
- same handling than for
_URC_FATAL_PHASE1_ERROR
- above + print an error message
- create a new error type and return it using io::ErrorKind::Other
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Er sorry, what I mean is that this must not panic. It should return an error of some kind (Err(())
is fine) so the caller can deal with the failure.
📌 Commit 52bed53 has been approved by |
⌛ Testing commit 52bed53 with merge bea2b27... |
💔 Test failed - status-appveyor |
Both Travis and Appveyor failed.
Appveyor on the "classic" one (WTF, I tested this locally in this exact configuration)
Time to drop both |
I'm thinking: what if we captured a stacktrace juste before the main, then substract it to the backtrace on panic? That way, at least the bottom of the trace would be correct all the time. Maybe we could do the same for the top, in Not sure how it would play with inlining. |
src/test/run-pass/backtrace.rs
Outdated
assert!(!s.contains(symbol), | ||
"{} should be removed from the backtrace\n{}", | ||
symbol, s); | ||
} | ||
assert!(s.contains(" 0:"), "the frame number should start at 0"); | ||
|
||
// Only on linux for _start and __libc_start_main |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This one failed on Travis too.
9cfd356
to
6398b20
Compare
@Yamakaky |
@bors r+ |
📌 Commit 6398b20 has been approved by |
Improve backtrace formating while panicking. Fixes #37783. Done: - Fix alignment of file paths for better readability - `RUST_BACKTRACE=full` prints all the informations (current behaviour) - `RUST_BACKTRACE=(short|yes)` is the default and does: - Skip irrelevant frames at the beginning and the end - Remove function address - Remove the current directory from the absolute paths - Remove `::hfabe6541873` at the end of the symbols - `RUST_BACKTRACE=(0|no)` disables the backtrace. - `RUST_BACKTRACE=<everything else>` is equivalent to `short` for backward compatibility. - doc - More uniform printing across platforms. Removed, TODO in a new PR: - Remove path prefix for libraries and libstd Example of short backtrace: ```rust fn fail() { panic!(); } fn main() { let closure = || fail(); closure(); } ``` Short: ``` thread 'main' panicked at 'explicit panic', t.rs:2 Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace. stack backtrace: 0: t::fail at ./t.rs:2 1: t::main::{{closure}} at ./t.rs:6 2: t::main at ./t.rs:7 ``` Full: ``` thread 'main' panicked at 'This function never returns!', t.rs:2 stack backtrace: 0: 0x558ddf666478 - std::sys::imp::backtrace::tracing::imp::unwind_backtrace::hec84c9dd8389cc5d at /home/yamakaky/dev/rust/rust/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 1: 0x558ddf65d90e - std::sys_common::backtrace::_print::hfa25f8b31f4b4353 at /home/yamakaky/dev/rust/rust/src/libstd/sys_common/backtrace.rs:71 2: 0x558ddf65cb5e - std::sys_common::backtrace::print::h9b711e11ac3ba805 at /home/yamakaky/dev/rust/rust/src/libstd/sys_common/backtrace.rs:60 3: 0x558ddf66796e - std::panicking::default_hook::{{closure}}::h736d216e74748044 at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:355 4: 0x558ddf66743c - std::panicking::default_hook::h16baff397e46ea10 at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:371 5: 0x558ddf6682bc - std::panicking::rust_panic_with_hook::h6d5a9bb4eca42c80 at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:559 6: 0x558ddf64ea93 - std::panicking::begin_panic::h17dc549df2f10b99 at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:521 7: 0x558ddf64ec42 - t::diverges::he6bc43fc925905f5 at /tmp/p/t.rs:2 8: 0x558ddf64ec5a - t::main::h0ffc20356b8a69c0 at /tmp/p/t.rs:6 9: 0x558ddf6687f5 - core::ops::FnOnce::call_once::hce41f19c0db56f93 10: 0x558ddf667cde - std::panicking::try::do_call::hd4c8c97efb4291df at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:464 11: 0x558ddf698d77 - __rust_try 12: 0x558ddf698c57 - __rust_maybe_catch_panic at /home/yamakaky/dev/rust/rust/src/libpanic_unwind/lib.rs:98 13: 0x558ddf667adb - std::panicking::try::h2c56ed2a59ec1d12 at /home/yamakaky/dev/rust/rust/src/libstd/panicking.rs:440 14: 0x558ddf66cc9a - std::panic::catch_unwind::h390834e0251cc9af at /home/yamakaky/dev/rust/rust/src/libstd/panic.rs:361 15: 0x558ddf6809ee - std::rt::lang_start::hb73087428e233982 at /home/yamakaky/dev/rust/rust/src/libstd/rt.rs:57 16: 0x558ddf64ec92 - main 17: 0x7fecb869e290 - __libc_start_main 18: 0x558ddf64e8b9 - _start 19: 0x0 - <unknown> ```
☀️ Test successful - status-appveyor, status-travis |
\o/ |
Does this also affect the output of https://crates.io/crates/backtrace or should we file a separate issue in that repository? |
You should open an issue. |
Fixes #37783.
Done:
RUST_BACKTRACE=full
prints all the informations (current behaviour)RUST_BACKTRACE=(short|yes)
is the default and does:::hfabe6541873
at the end of the symbolsRUST_BACKTRACE=(0|no)
disables the backtrace.RUST_BACKTRACE=<everything else>
is equivalent toshort
forbackward compatibility.
Removed, TODO in a new PR:
Example of short backtrace:
Short:
Full: