Missing backtrace frames on Windows

[Plecra]

Running the usage example on Windows, I get a slightly different output to the documentation:

May 15 15:45:37.897  INFO read_config:read_file{path="fake_file"}: Reading file
Error: 
   0: Unable to read config
   1: The system cannot find the file specified. (os error 2)

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ SPANTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━

   0: usage::read_file with path="fake_file"
      at examples\usage.rs:31
   1: usage::read_config
      at examples\usage.rs:37

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
                                ⋮ 3 frames hidden ⋮
   4: color_eyre::{{impl}}::default
      at C:\Users\tomSp\Documents\Programming\color-eyre\src\lib.rs:185
                                ⋮ 2 frames hidden ⋮
   7: usage::read_config
      at C:\Users\tomSp\Documents\Programming\color-eyre\examples\usage.rs:39
   8: usage::main
      at C:\Users\tomSp\Documents\Programming\color-eyre\examples\usage.rs:10
                                ⋮ 15 frames hidden ⋮

Suggestion: try using a file that exists next time

The read_file stack frame seems to be outright missing, giving no hint towards the line the actual error occurred. In my own code, I can't find a pattern between the stack frames that get left out, and it makes the message far less useful.

• rustc 1.43.1 (8d69840ab 2020-05-04)
• Windows 10 Version 1909 (18363.836)

[yaahc]

This looks like its probably a bug in color-backtrace though it could be an issue with our local filter. I'll add windows to the set of test platforms and add a test to verify the output for the usage.rs example, and once I've got that setup I should be able to open a PR upstream in color-backtrace to fix the issue there.

cc @athre0z

[athre0z]

In any case, I think we should definitely add an env var that just disables all frame filtering in color-backtrace, for cases where false detects happen and to ease debugging custom filters. I originally planned on adding that in our custom filter effort, however later forgot about it. I'll see if I can hack that together tomorrow.

[athre0z]

Figured I might as well do it right away, here you go:

https://github.com/athre0z/color-backtrace/commit/85b46b178d3a512d574bec587e1b8ad8c7882f56

I'll wrap this in a new release after we figured out whether there is an actual filtering bug in color-bt so I don't have to release twice within 24h.

[yaahc]

@athre0z sick

@Plecra can you try using a patch directive to swap to the github version of color-backtrace and dump a full version of the output so we can figure out where the filtering went wrong?

[patch.crates-io]
color-backtrace = { git = "https://github.com/athre0z/color-backtrace.git" }

Then disable the frame filtering with

RUST_BACKTRACE=1 COLORBT_SHOW_HIDDEN=1 cargo run --example usage

[athre0z]

Just realized: If this is a release (or otherwise non-O0 build, or the function has #[inline(always)]), another very possible option is that the read_file code has simply been inlined and thus doesn't have a stack frame that could be displayed, which would be expected behavior.

[Plecra]

@yaahc Here's the output for me: https://hastebin.com/ewokiyivin.rb. It doesn't look like it's a problem with color-backtrace, rather the frame wasn't included in the Backtrace in the first place. I filed the issue here because it came up while I was using the library, but there's probably a more appropriate place to ask about it.

I have simply been running the example in the repository with cargo run --example usage. I don't know any reason it'd be being optimized. That said, I couldn't reproduce the problem on my laptop - the usage output looks like it should, so it must be something else in my environment.

[yaahc]

That's wild. Well, I guess I'll setup the windows testing and then, assuming this doesn't come back for you or doesn't show up in the new CI, I'll close this issue.

[Plecra]

Ah, that was some poor wording on my part - I still have the issue on my PC, I just couldn't get anything similar running the test on my Windows laptop (same ver. of windows & rust)

[yaahc]

Oh, could it be different environment settings on the PC vs laptop? Maybe its using a different compiler version or has some RUSTFLAGS exported or something?

[athre0z]

Feel free to provide the binary with the frame not showing up so we can take a look at this on assembly level and determine whether the function has indeed been inlined. You can also mail it to the address on my profile if you don't want to post it publicly. Accompanying .pdb file would also have to be provided so I don't have to reverse through the code.

I'm pretty confident that this is just a codegen issue / the function doesn't have a stack frame for some reason and that we unfortunately won't be able to resolve this, but this way we can make absolutely sure.

[Plecra]

I had access to the computer again today, and it looks like the msvc 2015 version was the latest once I had installed, and rustc typically uses 2017. I'm installing the 2017 toolchain now to see if it fixes the issue

[yaahc]

Any further word on this issue?

[Plecra]

The problem isn't resolved using VS2019. Here's the output of cargo build --example usage -vv: https://pastebin.com/raw/LgfNW1En

And the binary: https://drive.google.com/file/d/1ErpB0bgW36uMQgyHUPFCluGLcVa7TLD8/view?usp=sharing

[athre0z]

While playing around with your binary on my Windows 10 VM, I noticed two different Windows specific issues:

• The VT100 escape sequences are not evaluated
  • Also, a lot of the unicode characters are broken
• When starting with

set RUST_BACKTRACE=full
set COLORBT_SHOW_HIDDEN=1
.\usage.exe

color-eyre panics while trying to print its stuff:

My VM is no-network and hasn't installed updates in a while -- is this specific to my somewhat old Win10 version or should we create issues for those two things?

[athre0z]

Back for more bad news:

read_file is in fact not inlined and has a proper stack frame. Assuming that the backtrace is properly captured inside the function, I really don't know why it wouldn't show up. It has a very boring and standard push ebp; mov ebp, esp stack frame and everything.

Edit: When cross-compiling the binary from macOS to Windows using

cross build --target x86_64-pc-windows-gnu --example usage

the frame shows up on Windows as expected. Pretty sure this is a backtrace-rs / backtrace-rs dep that does MSVC debug info based stacktraces issue. However, the VT100 issue persists. I suspect that color-eyre doesn't make the required API calls to enable terminal processing.

Edit 2: The panic with COLORBT_SHOW_HIDDEN=1 also doesn't happen in the x86_64-pc-windows-gnu build.

Edit 3:

Putting

#[cfg(target_os = "windows")]
{
    ansi_term::enable_ansi_support()?;
}

into the examples main function resolves the VT100 issue. I scrolled around in the color-eyre source and didn't find an obvious place to put it, so I'll leave this to Jane to decide where it should belong.

[yaahc]

assuming it's not expensive it's probably best to put it at the top of the report fn, if it's expensive then I can put it in the new panic hook install fn

[Plecra]

That's a shame. If there's anything I can tell you about my environment, I'd be happy to help - I don't really know where to start myself.

Since it seems to be isolated to my own computer, I don't think it's particularly important though. The dependency causing the issue will hopefully solve it in time.

[yaahc]

Eventually this crate will switch to using std::backtrace::Backtrace and I'd be extremely surprised if this issue isnt fixed by then, hopefully it doesn't show up too much on your PC in the mean time :(, I'll fix the VT100 issue at least before closing this issue.

[athre0z]

assuming it's not expensive it's probably best to put it at the top of the report fn, if it's expensive then I can put it in the new panic hook install fn

It's like 2-3 syscalls, should be pretty cheap. The report fn is only called when the lib prints an error right? In that case, that should be absolutely fine. If you want to make particularly sure, you could also just wrap it into an std::once.