Print a backtrace when query forcing fails. #91742

cjgillot · 2021-12-10T11:06:24Z

The aim of this PR is to help debugging incremental compilation bugs where query forcing panics.
For instance: #90682 #90697 #90715 #90739 #91401

These bugs happen when the dep-graph attempts to force a dep-node whose fingerprint does not correspond to an actual DefPathHash. PR #91741 attempts to hide this bug.

I still don't know how to reproduce these bugs, so I sadly could not test this debugging device.

rust-highfive · 2021-12-10T11:06:27Z

r? @estebank

(rust-highfive has picked a reviewer for you, use r? to override)

cjgillot · 2021-12-10T23:02:15Z

@bors try @rust-timer queue

rust-timer · 2021-12-10T23:02:16Z

Awaiting bors try build completion.

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

bors · 2021-12-10T23:02:31Z

⌛ Trying commit 72e15e4c1be2deb6b0f992c3d456845c65d2e268 with merge 2983d878369251d21927e651000a8ff8ec49de90...

bors · 2021-12-11T00:16:57Z

☀️ Try build successful - checks-actions
Build commit: 2983d878369251d21927e651000a8ff8ec49de90 (2983d878369251d21927e651000a8ff8ec49de90)

rust-timer · 2021-12-11T00:16:59Z

Queued 2983d878369251d21927e651000a8ff8ec49de90 with parent 0b42dea, future comparison URL.

rust-timer · 2021-12-11T01:49:04Z

Finished benchmarking commit (2983d878369251d21927e651000a8ff8ec49de90): comparison url.

Summary: This change led to very large relevant regressions 😿 in compiler performance.

Very large regression in instruction counts (up to 145.0% on incr-patched: dummy fn builds of unused-warnings)

If you disagree with this performance assessment, please file an issue in rust-lang/rustc-perf.

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 led to changes in compiler perf.

Next Steps: If you can justify the regressions found in this try perf run, please indicate this with @rustbot label: +perf-regression-triaged along with sufficient written justification. If you cannot justify the regressions please fix the regressions and do another perf run. If the next run shows neutral or positive results, the label will be automatically removed.

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

cjgillot · 2021-12-11T10:36:15Z

@bors try @rust-timer queue

rust-timer · 2021-12-11T10:36:17Z

Awaiting bors try build completion.

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

bors · 2021-12-11T10:36:24Z

⌛ Trying commit 65c3ca2e6b1bea9e1b648aebf878cf012efe5000 with merge 8bb5f28b3708053643baaeb7e07417b143f54496...

bors · 2021-12-11T12:13:04Z

☀️ Try build successful - checks-actions
Build commit: 8bb5f28b3708053643baaeb7e07417b143f54496 (8bb5f28b3708053643baaeb7e07417b143f54496)

rust-timer · 2021-12-11T12:13:06Z

Queued 8bb5f28b3708053643baaeb7e07417b143f54496 with parent 4a66a70, future comparison URL.

rust-timer · 2021-12-11T13:43:54Z

Finished benchmarking commit (8bb5f28b3708053643baaeb7e07417b143f54496): comparison url.

Summary: This change led to large relevant regressions 😿 in compiler performance.

Large regression in instruction counts (up to 4.1% on incr-unchanged builds of deep-vector)

If you disagree with this performance assessment, please file an issue in rust-lang/rustc-perf.

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 led to changes in compiler perf.

Next Steps: If you can justify the regressions found in this try perf run, please indicate this with @rustbot label: +perf-regression-triaged along with sufficient written justification. If you cannot justify the regressions please fix the regressions and do another perf run. If the next run shows neutral or positive results, the label will be automatically removed.

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

estebank · 2021-12-12T00:56:14Z

compiler/rustc_query_system/src/dep_graph/graph.rs

+            .map(|dep_node_index| (prev_index, dep_node_index));
+
+        // We succeeded, forego printing a backtrace.
+        std::mem::forget(_backtrace_print);


Isn't this a memory leak?

MarkingStack only contains three references, so forgetting it cannot create a memory leak. The backing memory of the SmallVec is correctly dropped since it's in a separate local. I'll add a comment.

estebank · 2021-12-13T17:28:53Z

r? rust-lang/compiler

Punting this on the team because I'm not as familiar with the intricacies of the query system and I'm not sure how far the implications of this change can be ^_^'

Given the perf impact it might make sense to put it behind an opt-in flag (maybe insta-stable so that we can mention it in the panic so that people can rerun and send us a report with the info? Ideally this would be always on if we can make the perf hit negligent.)

Mark-Simulacrum · 2021-12-13T18:48:19Z

compiler/rustc_query_system/src/dep_graph/graph.rs

+            .map(|dep_node_index| (prev_index, dep_node_index));
+
+        // We succeeded, forego printing a backtrace.
+        std::mem::forget(_backtrace_print);


A rough look at perf statistics suggests that the main cost is in allocations -- it might make sense to try replacing smallvec with just storing the top 8 or 16 or whatever indices, and stopping there? It's not storing the full stack, but not sure that's actually necessary either?

bors · 2023-02-23T12:36:06Z

⌛ Testing commit 870dd16 with merge 5a11a18d967fd55a839556407df0851878dca425...

bors · 2023-02-23T16:51:06Z

💥 Test timed out

rust-log-analyzer · 2023-02-23T17:07:21Z

A job failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)

WaffleLapkin · 2023-02-24T11:21:15Z

@bors r=estebank
(once CI is fixed the tree will be reopened and this will be merged)

bors · 2023-02-24T11:21:17Z

💡 This pull request was already approved, no need to approve it again.

This pull request previously failed. You should add more commits to fix the bug, or use retry to trigger a build again.

bors · 2023-02-24T11:21:18Z

📌 Commit 870dd16 has been approved by estebank

It is now in the queue for this repository.

bors · 2023-02-24T11:21:20Z

🌲 The tree is currently closed for pull requests below priority 100. This pull request will be tested once the tree is reopened.

bors · 2023-02-24T23:48:48Z

⌛ Testing commit 870dd16 with merge f0bc76a...

bors · 2023-02-25T02:39:55Z

☀️ Test successful - checks-actions
Approved by: estebank
Pushing f0bc76a to master...

rust-timer · 2023-02-25T03:57:23Z

Finished benchmarking commit (f0bc76a): comparison URL.

Overall result: ❌ regressions - ACTION NEEDED

Next Steps: If you can justify the regressions found in this perf run, please indicate this with @rustbot label: +perf-regression-triaged along with sufficient written justification. If you cannot justify the regressions please open an issue or create a new PR that fixes the regressions, add a comment linking to the newly created issue or PR, and then add the perf-regression-triaged label to this PR.

@rustbot label: +perf-regression
cc @rust-lang/wg-compiler-performance

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.3%	[0.2%, 0.7%]	65
Regressions ❌ (secondary)	0.5%	[0.2%, 2.3%]	14
Improvements ✅ (primary)	-	-	0
Improvements ✅ (secondary)	-	-	0
All ❌✅ (primary)	0.3%	[0.2%, 0.7%]	65

Max RSS (memory usage)

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

Cycles

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)	3.0%	[1.7%, 4.3%]	15
Improvements ✅ (primary)	-	-	0
Improvements ✅ (secondary)	-	-	0
All ❌✅ (primary)	-	-	0

pnkfelix · 2023-03-01T02:53:53Z

The compiler team anticipated fallout here, and the actual fallout seems to roughly match.

marking as triaged.

@rustbot label: +perf-regression-triaged

Optimize dep node backtrace and ignore fatal errors This attempts to optimize rust-lang#91742 while also passing through fatal errors. r? `@cjgillot`

Optimize dep node backtrace and ignore fatal errors This attempts to optimize rust-lang/rust#91742 while also passing through fatal errors. r? `@cjgillot`

rust-highfive assigned estebank Dec 10, 2021

rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Dec 10, 2021

cjgillot force-pushed the force-backtrace branch from 958e8af to 72e15e4 Compare December 10, 2021 12:32

rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Dec 10, 2021

rustbot added perf-regression Performance regression. and removed S-waiting-on-perf Status: Waiting on a perf run to be completed. labels Dec 11, 2021

rustbot added the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Dec 11, 2021

rustbot removed the S-waiting-on-perf Status: Waiting on a perf run to be completed. label Dec 11, 2021

estebank reviewed Dec 12, 2021

View reviewed changes

rust-highfive assigned wesleywiser and unassigned estebank Dec 13, 2021

Mark-Simulacrum assigned Mark-Simulacrum and unassigned wesleywiser Dec 13, 2021

Mark-Simulacrum reviewed Dec 13, 2021

View reviewed changes

bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Feb 22, 2023

bors added S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. and removed S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. labels Feb 23, 2023

bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Feb 24, 2023

bors added the merged-by-bors This PR was explicitly merged by bors. label Feb 25, 2023

bors merged commit f0bc76a into rust-lang:master Feb 25, 2023

rustbot added this to the 1.69.0 milestone Feb 25, 2023

cjgillot deleted the force-backtrace branch February 25, 2023 15:29

Zoxc mentioned this pull request Feb 27, 2023

Optimize dep node backtrace and ignore fatal errors #108524

Merged

rustbot added the perf-regression-triaged The performance regression has been triaged. label Mar 1, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Print a backtrace when query forcing fails. #91742

Print a backtrace when query forcing fails. #91742

cjgillot commented Dec 10, 2021

rust-highfive commented Dec 10, 2021

cjgillot commented Dec 10, 2021

rust-timer commented Dec 10, 2021

bors commented Dec 10, 2021

bors commented Dec 11, 2021

rust-timer commented Dec 11, 2021

rust-timer commented Dec 11, 2021

cjgillot commented Dec 11, 2021

rust-timer commented Dec 11, 2021

bors commented Dec 11, 2021

bors commented Dec 11, 2021

rust-timer commented Dec 11, 2021

rust-timer commented Dec 11, 2021

estebank Dec 12, 2021

cjgillot Dec 12, 2021

estebank commented Dec 13, 2021

Mark-Simulacrum Dec 13, 2021

bors commented Feb 23, 2023

bors commented Feb 23, 2023

rust-log-analyzer commented Feb 23, 2023

WaffleLapkin commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 25, 2023

rust-timer commented Feb 25, 2023

pnkfelix commented Mar 1, 2023

Print a backtrace when query forcing fails. #91742

Print a backtrace when query forcing fails. #91742

Conversation

cjgillot commented Dec 10, 2021

rust-highfive commented Dec 10, 2021

cjgillot commented Dec 10, 2021

rust-timer commented Dec 10, 2021

bors commented Dec 10, 2021

bors commented Dec 11, 2021

rust-timer commented Dec 11, 2021

rust-timer commented Dec 11, 2021

cjgillot commented Dec 11, 2021

rust-timer commented Dec 11, 2021

bors commented Dec 11, 2021

bors commented Dec 11, 2021

rust-timer commented Dec 11, 2021

rust-timer commented Dec 11, 2021

estebank Dec 12, 2021

Choose a reason for hiding this comment

cjgillot Dec 12, 2021

Choose a reason for hiding this comment

estebank commented Dec 13, 2021

Mark-Simulacrum Dec 13, 2021

Choose a reason for hiding this comment

bors commented Feb 23, 2023

bors commented Feb 23, 2023

rust-log-analyzer commented Feb 23, 2023

WaffleLapkin commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 24, 2023

bors commented Feb 25, 2023

rust-timer commented Feb 25, 2023

Overall result: ❌ regressions - ACTION NEEDED

Instruction count

Max RSS (memory usage)

Cycles

pnkfelix commented Mar 1, 2023