rust icon indicating copy to clipboard operation
rust copied to clipboard

debuginfo: Stabilize `-Z debug-macros`, `-Z collapse-macro-debuginfo` and `#[collapse_debuginfo]`

Open petrochenkov opened this issue 1 year ago • 30 comments

-Z debug-macros is "stabilized" by enabling it by default and removing.

-Z collapse-macro-debuginfo is stabilized as -C collapse-macro-debuginfo. It now supports all typical boolean values (parse_opt_bool) in addition to just yes/no.

Default value of collapse_debuginfo was changed from false to external (i.e. collapsed if external, not collapsed if local) - https://github.com/rust-lang/rust/issues/100758#issuecomment-1935815625 describes some debugging scenarios that motivate this default as reasonable. #[collapse_debuginfo] attribute without a value is no longer supported to avoid guessing the default.

Stabilization report: https://github.com/rust-lang/rust/pull/120845#issuecomment-1939145242

Closes https://github.com/rust-lang/rust/issues/100758 Closes https://github.com/rust-lang/rust/issues/41743 Closes https://github.com/rust-lang/rust/issues/39153

petrochenkov avatar Feb 09 '24 16:02 petrochenkov

r? @oli-obk

rustbot has assigned @oli-obk. They will have a look at your PR within the next two weeks and either review your PR or reassign to another reviewer.

Use r? to explicitly pick a reviewer

rustbot avatar Feb 09 '24 16:02 rustbot

Some changes occurred in compiler/rustc_codegen_cranelift

cc @bjorn3

The Miri subtree was changed

cc @rust-lang/miri

rustbot avatar Feb 09 '24 16:02 rustbot

cc @davidtwco @azhogin

petrochenkov avatar Feb 09 '24 16:02 petrochenkov

The job x86_64-gnu-tools failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)
GITHUB_ENV=/home/runner/work/_temp/_runner_file_commands/set_env_648162b5-5fdf-4b42-b285-405270da3946
GITHUB_EVENT_NAME=pull_request
GITHUB_EVENT_PATH=/home/runner/work/_temp/_github_workflow/event.json
GITHUB_GRAPHQL_URL=https://api.github.com/graphql
GITHUB_HEAD_REF=debmac
GITHUB_JOB=pr
GITHUB_PATH=/home/runner/work/_temp/_runner_file_commands/add_path_648162b5-5fdf-4b42-b285-405270da3946
GITHUB_REF=refs/pull/120845/merge
GITHUB_REF_NAME=120845/merge
GITHUB_REF_PROTECTED=false
---
   0: tests failed

FAILED TEST: tests/pass/backtrace/backtrace-api-v0.rs

command: MIRI_ENV_VAR_TEST="0" MIRI_TEMP="/tmp" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/miri" "--error-format=json" "-Dwarnings" "-Dunused" "-Ainternal_features" "-Zui-testing" "--target" "x86_64-unknown-linux-gnu" "--out-dir" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2-tools/ui/tests/pass/backtrace" "tests/pass/backtrace/backtrace-api-v0.rs" "--edition" "2021"
Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
Run with RUST_BACKTRACE=full to include source snippets.

Caused by:
  process didn't exit successfully: `/checkout/obj/build/x86_64-unknown-linux-gnu/stage2-tools/x86_64-unknown-linux-gnu/release/deps/compiletest-168e46bc52860114 --quiet` (exit status: 1)


error: actual output differed from expected
Execute `./miri test --bless` to update `tests/pass/backtrace/backtrace-api-v0.stdout` to the actual output
+++ <stdout output>
 $DIR/backtrace-api-v0.rs:24:14 (func_d)
-$DIR/backtrace-api-v0.rs:20:5 (func_c)
+$DIR/backtrace-api-v0.rs:14:9 (func_c)
---
/checkout/library/std/src/panicking.rs:554:40 (std::panicking::r#try::do_call::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>)
/checkout/library/std/src/panicking.rs:518:19 (std::panicking::r#try::<i32, &dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe>)
/checkout/library/std/src/panic.rs:142:14 (std::panic::catch_unwind::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>)
/checkout/library/std/src/rt.rs:148:48 (std::rt::lang_start_internal::{closure#2})
/checkout/library/std/src/panicking.rs:554:40 (std::panicking::r#try::do_call::<{closure@std::rt::lang_start_internal::{closure#2}}, isize>)
/checkout/library/std/src/panicking.rs:518:19 (std::panicking::r#try::<isize, {closure@std::rt::lang_start_internal::{closure#2}}>)
/checkout/library/std/src/panic.rs:142:14 (std::panic::catch_unwind::<{closure@std::rt::lang_start_internal::{closure#2}}, isize>)
/checkout/library/std/src/rt.rs:165:17 (std::rt::lang_start::<()>)

full stdout:
tests/pass/backtrace/backtrace-api-v0.rs:24:14 (func_d)
---



FAILED TEST: tests/pass/backtrace/backtrace-api-v1.rs
command: MIRI_ENV_VAR_TEST="0" MIRI_TEMP="/tmp" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/miri" "--error-format=json" "-Dwarnings" "-Dunused" "-Ainternal_features" "-Zui-testing" "--target" "x86_64-unknown-linux-gnu" "--out-dir" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2-tools/ui/tests/pass/backtrace" "tests/pass/backtrace/backtrace-api-v1.rs" "--edition" "2021"
error: actual output differed from expected
error: actual output differed from expected
Execute `./miri test --bless` to update `tests/pass/backtrace/backtrace-api-v1.stdout` to the actual output
+++ <stdout output>
 $DIR/backtrace-api-v1.rs:27:9 (func_d)
-$DIR/backtrace-api-v1.rs:20:5 (func_c)
+$DIR/backtrace-api-v1.rs:14:9 (func_c)
---
/checkout/library/std/src/panicking.rs:554:40 (std::panicking::r#try::do_call::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>)
/checkout/library/std/src/panicking.rs:518:19 (std::panicking::r#try::<i32, &dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe>)
/checkout/library/std/src/panic.rs:142:14 (std::panic::catch_unwind::<&dyn std::ops::Fn() -> i32 + std::marker::Sync + std::panic::RefUnwindSafe, i32>)
/checkout/library/std/src/rt.rs:148:48 (std::rt::lang_start_internal::{closure#2})
/checkout/library/std/src/panicking.rs:554:40 (std::panicking::r#try::do_call::<{closure@std::rt::lang_start_internal::{closure#2}}, isize>)
/checkout/library/std/src/panicking.rs:518:19 (std::panicking::r#try::<isize, {closure@std::rt::lang_start_internal::{closure#2}}>)
/checkout/library/std/src/panic.rs:142:14 (std::panic::catch_unwind::<{closure@std::rt::lang_start_internal::{closure#2}}, isize>)
/checkout/library/std/src/rt.rs:165:17 (std::rt::lang_start::<()>)

full stdout:
tests/pass/backtrace/backtrace-api-v1.rs:27:9 (func_d)

rust-log-analyzer avatar Feb 09 '24 16:02 rust-log-analyzer

I haven't thoroughly reviewed the changes here but this seems sensible to me at first glance.

davidtwco avatar Feb 12 '24 11:02 davidtwco

I removed one fast path optimization for simplicity, so let's also run benchmarks. @bors try @rust-timer queue

petrochenkov avatar Feb 12 '24 12:02 petrochenkov

Awaiting bors try build completion.

@rustbot label: +S-waiting-on-perf

rust-timer avatar Feb 12 '24 12:02 rust-timer

:hourglass: Trying commit 78ee1bc3b018604291a62bdb75ebea1e7d78a74d with merge 575a7f35a80ab18d54b08775b7bd6cc50ee4e338...

bors avatar Feb 12 '24 12:02 bors

:sunny: Try build successful - checks-actions Build commit: 575a7f35a80ab18d54b08775b7bd6cc50ee4e338 (575a7f35a80ab18d54b08775b7bd6cc50ee4e338)

bors avatar Feb 12 '24 14:02 bors

Queued 575a7f35a80ab18d54b08775b7bd6cc50ee4e338 with parent b17491c8f6d555386104dfd82004c01bfef09c95, future comparison URL. There are currently 0 preceding artifacts in the queue. It will probably take at least ~1.2 hours until the benchmark run finishes.

rust-timer avatar Feb 12 '24 14:02 rust-timer

Finished benchmarking commit (575a7f35a80ab18d54b08775b7bd6cc50ee4e338): comparison URL.

Overall result: ❌✅ regressions and improvements - no action needed

Benchmarking this pull request likely means that it is perf-sensitive, so we're automatically marking it as not fit for rolling up. While you can manually mark this PR as fit for rollup, we strongly recommend not doing so since this PR may lead to changes in compiler perf.

@bors rollup=never @rustbot label: -S-waiting-on-perf -perf-regression

Instruction count

This is a highly reliable metric that was used to determine the overall result at the top of this comment.

mean range count
Regressions ❌
(primary)
0.4% [0.4%, 0.4%] 1
Regressions ❌
(secondary)
- - 0
Improvements ✅
(primary)
- - 0
Improvements ✅
(secondary)
-0.6% [-0.7%, -0.5%] 2
All ❌✅ (primary) 0.4% [0.4%, 0.4%] 1

Max RSS (memory usage)

Results

This is a less reliable metric that may be of interest but was not used to determine the overall result at the top of this comment.

mean range count
Regressions ❌
(primary)
- - 0
Regressions ❌
(secondary)
- - 0
Improvements ✅
(primary)
-2.4% [-2.4%, -2.4%] 1
Improvements ✅
(secondary)
-2.8% [-3.2%, -2.3%] 7
All ❌✅ (primary) -2.4% [-2.4%, -2.4%] 1

Cycles

This benchmark run did not return any relevant results for this metric.

Binary size

Results

This is a less reliable metric that may be of interest but was not used to determine the overall result at the top of this comment.

mean range count
Regressions ❌
(primary)
0.0% [0.0%, 0.1%] 40
Regressions ❌
(secondary)
0.0% [0.0%, 0.1%] 6
Improvements ✅
(primary)
- - 0
Improvements ✅
(secondary)
- - 0
All ❌✅ (primary) 0.0% [0.0%, 0.1%] 40

Bootstrap: 663.718s -> 664.389s (0.10%) Artifact size: 308.26 MiB -> 308.31 MiB (0.01%)

rust-timer avatar Feb 12 '24 15:02 rust-timer

Perf changes are noise. @bors rollup=maybe

petrochenkov avatar Feb 12 '24 16:02 petrochenkov

Stabilization Report

Before this PR all spans coming from macro definitions were by default collapsed to a single span representing the macro's call site when generating debuginfo. The option -Z debug-macros changed that behavior and preserved all spans in debuginfo without collapsing.

With this PR the -Z debug-macros option is removed and the defaults are partially swapped. By default spans are preserved without collapsing, giving more detailed information during debugging, but only for macros coming from the current crate. For macros from other crates the spans are still collapsed to a single call site span, this way we don't jump to code of println! and other macros from the standard library.

Attributes #[collapse_debuginfo(yes/no/external)] and command line options -C collapse-macro-debuginfo=yes/no/external (replace -Z debug-macros) provide more fine-grained control over collapsing debuginfo spans to call site, when the defaults are insufficient.

History

https://github.com/rust-lang/rust/issues/41743 identified the problem with detailed debuginfo spans for macros not being available on stable channel.

https://github.com/rust-lang/rfcs/pull/2117 and https://github.com/rust-lang/compiler-team/issues/386 provided the solution for undesirable jumping to sources of println! and friends when detailed spans are enabled. https://github.com/rust-lang/rust/pull/99556 implemented that solution in July 2022.

https://github.com/rust-lang/rust/pull/118903 added detailed tests for the feature and fixed some issues with nested macro calls in December 2023. https://github.com/rust-lang/rust/pull/119828 added some more fine grained options to the #[collapse_debuginfo] attribute, and added a command line flag -C collapse-macro-debuginfo for overriding both defaults and attributes as well in January 2024.

Design

https://github.com/rust-lang/compiler-team/issues/386 gives motivation for not collapsing macros in debuginfo in general, but collapsing some macros in particular.

Comments in https://github.com/rust-lang/rust/issues/100758#issuecomment-1934051974 and below describe some possible debugging scenarios, and make a choice for the default collapsing behavior implemented in this PR.

Tests

  • tests/debuginfo/collapse-debuginfo*
  • tests/debuginfo/skip_second_statement*
  • tests/debuginfo/lexical-scope-with-macro.rs

Documentation

src/doc/rustc/src/codegen-options/index.md in this PR and https://github.com/rust-lang/reference/pull/1468 in the reference.

petrochenkov avatar Feb 12 '24 16:02 petrochenkov

@rfcbot fcp merge

petrochenkov avatar Feb 12 '24 16:02 petrochenkov

Team member @petrochenkov has proposed to merge this. The next step is review by the rest of the tagged team members:

  • [x] @Aaron1011
  • [x] @cjgillot
  • [x] @compiler-errors
  • [x] @davidtwco
  • [x] @eddyb
  • [x] @estebank
  • [x] @jackh726
  • [x] @lcnr
  • [x] @matthewjasper
  • [x] @michaelwoerister
  • [x] @nagisa
  • [x] @oli-obk
  • [x] @petrochenkov
  • [x] @pnkfelix
  • [ ] @wesleywiser

No concerns currently listed.

Once a majority of reviewers approve (and at most 2 approvals are outstanding), this will enter its final comment period. If you spot a major issue that hasn't been raised at any point in this process, please speak up!

cc @rust-lang/lang-advisors: FCP proposed for lang, please feel free to register concerns. See this document for info about what commands tagged team members can give me.

rfcbot avatar Feb 12 '24 16:02 rfcbot

My only (soft) concern is that collapse-macro-debuginfo has not sat for very long (and I guess the no/external/yes options are also fairly new, but I'm less concerned about that). Is it really useful and necessary? What would be the harm of stabilizing #[collapse_debuginfo] and removing -Z debug-macros without stabilizing -Z collapse-macro-debuginfo?

Also curious how often these features actually get used, but that doesn't need to block this at all since it does obviously seem useful.

jackh726 avatar Feb 14 '24 13:02 jackh726

Could it be better to change cmd/attr table (unspecified + unspecified = if-ext) instead of changing default attribute to external? cmd_attr_table

azhogin avatar Feb 15 '24 10:02 azhogin

@jackh726

My only (soft) concern is that collapse-macro-debuginfo has not sat for very long (and I guess the no/external/yes options are also fairly new, but I'm less concerned about that).

-C collapse-macro-debuginfo is basically a rename of -Z debug-macros, with a different default and more fine-grained options, so it's not entirely new.

Is it really useful and necessary? What would be the harm of stabilizing #[collapse_debuginfo] and removing -Z debug-macros without stabilizing -Z collapse-macro-debuginfo?

Like -Z debug-macros, the -Z collapse-macro-debuginfo command line flag helps to enable more (or less) debuginfo for code that you cannot edit to add the #[collapse_debuginfo] attributes. I tried to list some possible debugging scenarios in https://github.com/rust-lang/rust/issues/100758#issuecomment-1935815625.

I suspect that it's actually more important to stabilize the flag, than the attributes, because the flag can resolve any issues with a specific debugging session, while the attributes are more about setting defaults (and are not very likely to be widely adopted by third-party macro authors).

petrochenkov avatar Feb 15 '24 13:02 petrochenkov

@azhogin

Could it be better to change cmd/attr table (unspecified + unspecified = if-ext) instead of changing default attribute to external? cmd_attr_table

The end result is the same, no? I think the actual implementation in fn get_collapse_debuginfo is still working as you are explaining.

petrochenkov avatar Feb 15 '24 13:02 petrochenkov

:umbrella: The latest upstream changes (presumably #121370) made this pull request unmergeable. Please resolve the merge conflicts.

bors avatar Feb 22 '24 19:02 bors

switching review flag to waiting on Vadim for a rebase (then feel free to request a review when it's good)

@rustbot author

apiraino avatar Mar 07 '24 11:03 apiraino

I've rebased, but this still needs an approval from at least 2 compiler team members (ping @estebank @matthewjasper @pnkfelix @wesleywiser).

petrochenkov avatar Mar 07 '24 13:03 petrochenkov

Has the lang team approved the new attribute?

ehuss avatar Mar 07 '24 14:03 ehuss

@ehuss No, should it? The attribute only has effect on details of produced binaries, but not on anything else in the language.

petrochenkov avatar Mar 07 '24 14:03 petrochenkov

It has been the policy as long as I'm aware that the lang team is responsible for attributes. For example, they recently approved the debugger_visualizer attribute. I would not expect them to have any concerns here, but I think we should keep with the precedent unless there is an explicit decision by them to change it.

ehuss avatar Mar 07 '24 14:03 ehuss

Okay, I've lang nominated this PR.

petrochenkov avatar Mar 07 '24 14:03 petrochenkov

:bell: This is now entering its final comment period, as per the review above. :bell:

rfcbot avatar Mar 07 '24 17:03 rfcbot

For macros from other crates the spans are still collapsed to a single call site span, this way we don't jump to code of println! and other macros from the standard library.

@petrochenkov would it make sense to make --verbose imply the current behavior of -Zdebug-macros for foreign macros? (not necessarily as part of this PR).

estebank avatar Mar 07 '24 17:03 estebank

For macros from other crates the spans are still collapsed to a single call site span, this way we don't jump to code of println! and other macros from the standard library.

@petrochenkov would it make sense to make --verbose imply the current behavior of -Zdebug-macros for foreign macros? (not necessarily as part of this PR).

I feel like this would be quite unintuitive, I expect --verbose to give me more output, but not necessarily change what is produced.

davidtwco avatar Mar 11 '24 10:03 davidtwco

Looking at the existing uses of opts.verbose it indeed affects the debugging output of the compiler itself, rather than debuginfo in the produced binaries.

petrochenkov avatar Mar 11 '24 15:03 petrochenkov