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

show macro backtrace with -Z flag #45545

Merged
merged 7 commits into from
Nov 21, 2017
Merged

Conversation

durka
Copy link
Contributor

@durka durka commented Oct 26, 2017

Fixes #39413 by adding a facility to restore the "old school" macro expansion backtraces (previously removed in 6186538).

The restored functionality is accessed through the flag -Z external-macro-backtrace. Errors showing the truncated backtraces will suggest this flag.

Example

Code:


a/src/lib.rs

#[macro_export]
macro_rules! a {
    () => { a!(@) };
    (@) => { a!(@@) };
    (@@) => {
        syntax error;
    }
}

b/src/main.rs

#[macro_use] extern crate a;

macro_rules! b {
    () => { b!(@) };
    (@) => { b!(@@) };
    (@@) => {
        syntax error;
    }
}

fn main() {
    a!();
    b!();
}




Running without env var (note: first error is from remote macro, second from local macro):

$ cargo +custom run
   Compiling b v0.1.0
error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  --> src/main.rs:12:5
   |
12 |     a!();
   |     ^^^^^
   |     |
   |     expected one of 8 possible tokens here
   |     unexpected token
   |
   = note: this error originates in a macro outside of the current crate (run with RUST_MACRO_BACKTRACE=1 for more info)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  --> src/main.rs:7:16
   |
7  |         syntax error;
   |               -^^^^^ unexpected token
   |               |
   |               expected one of 8 possible tokens here
...
13 |     b!();
   |     ----- in this macro invocation

error: aborting due to 2 previous errors

error: Could not compile `b`.

To learn more, run the command again with --verbose.
The output is the same as today, except for an addition to the note which aids discoverability of the new environment variable.




Running with env var:

$ RUST_MACRO_BACKTRACE=1 cargo +custom run
   Compiling b v0.1.0
error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> <a macros>:1:72
  |
1 | (  ) => { a ! ( @ ) } ; ( @ ) => { a ! ( @ @ ) } ; ( @ @ ) => { syntax error ;
  |                                                                       -^^^^^ unexpected token
  |                                                                       |
  |                                                                       expected one of 8 possible tokens here
src/main.rs:12:5: 12:10 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:11: 1:20 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:36: 1:47 note: in this expansion of a! (defined in <a macros>)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> src/main.rs:7:16
  |
7 |         syntax error;
  |               -^^^^^ unexpected token
  |               |
  |               expected one of 8 possible tokens here
src/main.rs:12:5: 12:10 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:11: 1:20 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:36: 1:47 note: in this expansion of a! (defined in <a macros>)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> src/main.rs:7:16
  |
7 |         syntax error;
  |               -^^^^^ unexpected token
  |               |
  |               expected one of 8 possible tokens here
src/main.rs:13:5: 13:10 note: in this expansion of b! (defined in src/main.rs)
src/main.rs:4:13: 4:18 note: in this expansion of b! (defined in src/main.rs)
src/main.rs:5:14: 5:20 note: in this expansion of b! (defined in src/main.rs)

error: aborting due to 2 previous errors

error: Could not compile `b`.

To learn more, run the command again with --verbose.

The output is hard to read, but better than nothing (and it's exactly what we used to have before the infamous fix_multispans_in_std_macros).




Wishlist:

  • Save the actual source of macros in crate metadata, not just AST, so the output can be improved
    • Hopefully this would allow line numbers in the trace as well
  • Show the actual macro invocations in the traces

r? @nrc

@kennytm kennytm added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Oct 26, 2017
@oli-obk
Copy link
Contributor

oli-obk commented Oct 26, 2017

Can you add a ui test?

@durka
Copy link
Contributor Author

durka commented Oct 26, 2017

Sure, though I expect the output to change as this facility is improved and modernized. In particular, the error for the non-local macro is emitted twice (once from <a macros> with the AST-ified formatting, and once from src/main.rs) and I wouldn't mind if one of those was "fixed" to show the top-level macro invocation.

@durka
Copy link
Contributor Author

durka commented Oct 27, 2017

Added test.

@kennytm
Copy link
Member

kennytm commented Oct 29, 2017

I'm not convinced that this should be an environment variable instead of a -Z option (a -Z option can be feature-gated, the env var cannot).

@durka
Copy link
Contributor Author

durka commented Oct 30, 2017

Well, we could just restrict the environment variable to only have an effect on nightly. (In general I think restricting useful tools for no reason is not helpful, especially since debugging macro expansion across compiler versions is a common occurrence, though I might feel differently if this were introducing new functionality instead of just restoring output that was removed.)

That being said, if -Z is the way to get this landed then I'll do it. Initially it seemed to me like a large amount of plumbing to add. I guess the way to go is:

  1. Add a debugging option to the session
  2. ??? <--- this is the plumbing I can't figure out, how is the error emitter supposed to find out about the session options?
  3. Add a macro_backtraces: bool flag to EmitterWriter and its constructor which is called here (but there is no Session at that point!)

@shepmaster
Copy link
Member

ping @rust-lang/compiler — we haven't heard from @nrc in over 6 days, would you mind assigning a new reviewer?

@shepmaster
Copy link
Member

Ok, @rust-lang/compiler — I'll roll a die for you:

r? @petrochenkov

@rust-highfive rust-highfive assigned petrochenkov and unassigned nrc Nov 11, 2017
@petrochenkov
Copy link
Contributor

@durka

??? <--- this is the plumbing I can't figure out, how is the error emitter supposed to find out about the session options?

See #45205 for an example.
An option is added into src/librustc/session/config.rs and then used through session.opts.debugging_opts.my_option.

@kennytm kennytm added S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Nov 12, 2017
@durka
Copy link
Contributor Author

durka commented Nov 15, 2017

@petrochenkov

So, the emitter seems to have no reference to any session or context. That's the problem. And there isn't a session to pass in when creating the EmitterWriter because run_compiler doesn't return one if it fails (see source links in my previous comment).

@durka
Copy link
Contributor Author

durka commented Nov 15, 2017

Actually I think that call to EmitterWriter::new that I pinpointed is the wrong one, but I'm not sure where I should be looking. Searching for other places they are constructed, some have a session available and some do not.

@petrochenkov
Copy link
Contributor

@durka
Unfortunately, I'm no more familiar with that infrastructure than you.

@durka durka changed the title show macro backtrace with env var [WIP] show macro backtrace with env var Nov 19, 2017
@durka
Copy link
Contributor Author

durka commented Nov 19, 2017

I found a way to do it, but it required making a DiagnosticBuilder field public and a small update to rustfmt (ping @nrc durka/rustfmt@626ef4f). Please review.

@durka durka changed the title [WIP] show macro backtrace with env var [WIP] show macro backtrace with -Z flag Nov 20, 2017
@durka durka changed the title [WIP] show macro backtrace with -Z flag show macro backtrace with -Z flag Nov 20, 2017
@@ -1226,6 +1247,30 @@ impl EmitterWriter {
}
}
}

fn render_macro_backtrace_old_school(&self,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

old_school isn't very helpful here - what distinguishes it from a normal backtrace? expanded or complete or something might be better

Copy link
Contributor Author

@durka durka Nov 20, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I just used the name from the commit I'm partially reverting. I think it looks a bit "old school" (it doesn't have fancy span notes or anything).

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@durka would you be against using the full span machinery for them or would you think it'd be too verbose?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The more spans the better, probably. I'm afraid I'm not too familiar with the new span hardware. What would it look like?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some changes will need to be made to the macro expansion machinery to avoid bogus spans (<a macros>:1:36: 1:47 note: in this expansion of a! (defined in <a macros>)), but I think it could be made to look something along the lines of:

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  -->  a/src/lib.rs:6:16
3  |     () => { a!(@) };
   |             ----- in this expansion of `a!` (#2)
4  |     (@) => { a!(@@) };
   |              ------ in this expansion of `a!` (#3)
5  |     (@@) => {
6  |         syntax error;
   |                ^^^^^ expected one of 8 possible tokens here
  ::: src/main.rs
   |
12 |     a!();
   |     ----- in this expansion of `a!` (#1)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  --> src/main.rs:7:16
   |
4  |     () => { b!(@) };
   |             ----- in this expansion of `b!` (#2)
5  |     (@) => { b!(@@) };
   |              ------ in this expansion of `b!` (#3)
6  |     (@@) => {
7  |         syntax error;
   |                ^^^^^ expected one of 8 possible tokens here
13 |     b!();
   |     ----- in this expansion of `b!` (#1)

error: aborting due to 2 previous errors

error: Could not compile `b`.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well that mockup looks really good to me! :)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@durka suggestion implemented in #46605. The output is not perfect as it is pointing at the pretty printed expanded macro code instead of the actual code, but it is close enough :)

@@ -1036,6 +1036,8 @@ options! {DebuggingOptions, DebuggingSetter, basic_debugging_options,
"run all passes except translation; no output"),
treat_err_as_bug: bool = (false, parse_bool, [TRACKED],
"treat all errors that occur as bugs"),
macro_backtrace: bool = (false, parse_bool, [UNTRACKED],
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

could you use full_macro_backtrace or something? The name is a bit confusing as is because we get a macro backtrace in any case.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure. Or maybe external_macro_backtrace since you do get a full one for local macros?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sure, works for me

cm: Option<Rc<CodeMapper>>)
-> Handler {
let emitter = Box::new(EmitterWriter::stderr(color_config, cm, false));
Handler::with_emitter(can_emit_warnings, treat_err_as_bug, emitter)
Handler::with_emitter(can_emit_warnings, treat_err_as_bug, macro_backtrace, emitter)
}

pub fn with_emitter(can_emit_warnings: bool,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you add another method rather than adding another bool flag to this one? That would be more self-documenting (bools tell the reader nothing), less susceptible to bugs (since it is easy enough to confuse the two bools here), and avoids a breaking change.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do you mean a new method like Handler::with_backtracing_emitter(...)? We also thought of always initializing the flag to false and providing a setter. But that's kind of a weird mixture of constructor flags and setters which seems like it ought to be refactored into a settings struct anyway.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe with_emitter_with_settings and take a settings struct to allow adding more flags in the future which are similarly detailed.

Copy link
Contributor Author

@durka durka Nov 20, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm calling it with_[tty_]emitter_and_flags and this should reduce the size of the patch / avoid breaking rustfmt. But we should still refactor users of with_emitter/with_tty_emitter and remove those at some point!

@durka
Copy link
Contributor Author

durka commented Nov 20, 2017

Addressed comments.

@kennytm kennytm added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. and removed S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author. labels Nov 20, 2017
@nrc
Copy link
Member

nrc commented Nov 21, 2017

@bors: r+

@bors
Copy link
Contributor

bors commented Nov 21, 2017

📌 Commit b34a7ff has been approved by nrc

@bors
Copy link
Contributor

bors commented Nov 21, 2017

⌛ Testing commit b34a7ff with merge bac7c53...

bors added a commit that referenced this pull request Nov 21, 2017
show macro backtrace with -Z flag

Fixes #39413 by adding a facility to restore the "old school" macro expansion backtraces (previously removed in 6186538).

The restored functionality is accessed through the flag `-Z external-macro-backtrace`. Errors showing the truncated backtraces will suggest this flag.

### Example

Code: <details>
`a/src/lib.rs`
```rust
#[macro_export]
macro_rules! a {
    () => { a!(@) };
    (@) => { a!(@@) };
    (@@) => {
        syntax error;
    }
}
```
`b/src/main.rs`
```rust
#[macro_use] extern crate a;

macro_rules! b {
    () => { b!(@) };
    (@) => { b!(@@) };
    (@@) => {
        syntax error;
    }
}

fn main() {
    a!();
    b!();
}
```
</details>

<br/><br/>
Running without env var (note: first error is from remote macro, second from local macro):

<details>

```
$ cargo +custom run
   Compiling b v0.1.0
error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  --> src/main.rs:12:5
   |
12 |     a!();
   |     ^^^^^
   |     |
   |     expected one of 8 possible tokens here
   |     unexpected token
   |
   = note: this error originates in a macro outside of the current crate (run with RUST_MACRO_BACKTRACE=1 for more info)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
  --> src/main.rs:7:16
   |
7  |         syntax error;
   |               -^^^^^ unexpected token
   |               |
   |               expected one of 8 possible tokens here
...
13 |     b!();
   |     ----- in this macro invocation

error: aborting due to 2 previous errors

error: Could not compile `b`.

To learn more, run the command again with --verbose.
```
</details>
The output is the same as today, except for an addition to the note which aids discoverability of the new environment variable.

<br/><br/>
Running _with_ env var:
<details>

```
$ RUST_MACRO_BACKTRACE=1 cargo +custom run
   Compiling b v0.1.0
error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> <a macros>:1:72
  |
1 | (  ) => { a ! ( @ ) } ; ( @ ) => { a ! ( @ @ ) } ; ( @ @ ) => { syntax error ;
  |                                                                       -^^^^^ unexpected token
  |                                                                       |
  |                                                                       expected one of 8 possible tokens here
src/main.rs:12:5: 12:10 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:11: 1:20 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:36: 1:47 note: in this expansion of a! (defined in <a macros>)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> src/main.rs:7:16
  |
7 |         syntax error;
  |               -^^^^^ unexpected token
  |               |
  |               expected one of 8 possible tokens here
src/main.rs:12:5: 12:10 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:11: 1:20 note: in this expansion of a! (defined in <a macros>)
<a macros>:1:36: 1:47 note: in this expansion of a! (defined in <a macros>)

error: expected one of `!`, `.`, `::`, `;`, `?`, `{`, `}`, or an operator, found `error`
 --> src/main.rs:7:16
  |
7 |         syntax error;
  |               -^^^^^ unexpected token
  |               |
  |               expected one of 8 possible tokens here
src/main.rs:13:5: 13:10 note: in this expansion of b! (defined in src/main.rs)
src/main.rs:4:13: 4:18 note: in this expansion of b! (defined in src/main.rs)
src/main.rs:5:14: 5:20 note: in this expansion of b! (defined in src/main.rs)

error: aborting due to 2 previous errors

error: Could not compile `b`.

To learn more, run the command again with --verbose.
```
</details>

The output is hard to read, but better than nothing (and it's exactly what we used to have before the infamous `fix_multispans_in_std_macros`).

<br/><br/>
Wishlist:

- Save the actual source of macros in crate metadata, not just AST, so the output can be improved
    - Hopefully this would allow line numbers in the trace as well
- Show the actual macro invocations in the traces

r? @nrc
@bors
Copy link
Contributor

bors commented Nov 21, 2017

☀️ Test successful - status-appveyor, status-travis
Approved by: nrc
Pushing bac7c53 to master...

@bors bors merged commit b34a7ff into rust-lang:master Nov 21, 2017
@kennytm kennytm mentioned this pull request Nov 21, 2017
@kennytm
Copy link
Member

kennytm commented Nov 21, 2017

@durka That (run with -Z external-macro-backtrace for more info) message is going to show up in beta and stable channel?

@durka
Copy link
Contributor Author

durka commented Nov 21, 2017 via email

@kennytm
Copy link
Member

kennytm commented Nov 21, 2017

@durka Perhaps add a channel check (use UnstableFeatures::from_environment().is_nightly_build() or plumb through sess.opts.unstable_features) and don't emit it at all when in beta/stable. But then we need to figure out what to do with the UI tests after entering beta...

@durka
Copy link
Contributor Author

durka commented Nov 21, 2017

It must be discoverable, that's the point of having a message. We've got users asking why there is nothing available on stable.

@durka
Copy link
Contributor Author

durka commented Nov 21, 2017

The message for const fn also says "in Nightly you can do XYZ" so there's precedent.

@kennytm
Copy link
Member

kennytm commented Nov 21, 2017

I'll file an issue for this. (Edit: #46167)

@RReverser
Copy link
Contributor

Just wanted to say thanks for this - upgraded to nightly and it immediately helped me to debug an annoying error inside of nom macro. Hopefully this becomes stable someday.

@cramertj
Copy link
Member

Is there a tracking issue for stabilizing this flag?

@durka
Copy link
Contributor Author

durka commented Mar 19, 2018

Let's make one.

@durka
Copy link
Contributor Author

durka commented Mar 19, 2018

In fact, should there be a tracking issue for every -Z flag?

@nikomatsakis
Copy link
Contributor

@durka I don't think so. Many of them have no particular path to stabilization.

@Aaron1011
Copy link
Member

Was a tracking issue ever filed?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-review Status: Awaiting review from the assignee but also interested parties.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

useless errors with macro in a separate crate