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

Miri: avoid tracking current location three times #72879

Merged
merged 7 commits into from
Jun 15, 2020

Conversation

RalfJung
Copy link
Member

@RalfJung RalfJung commented Jun 1, 2020

Miri tracks the current instruction to execute in the call stack, but it also additionally has two TyCtxtAt that carry a Span that also tracks the current instruction. That is quite silly, so this PR uses TyCtxt instead, and then uses a method for computing the current span when a TyCtxtAt is needed. Having less redundant (semi-)global state seems like a good improvement to me. :D

To keep the ConstProp errors the same, I had to add the option to error_to_const_error to overwrite the span. Also for some reason this changes cycle errors a bit -- not sure if we are now better or worse as giving those queries the right span. (It is unfortunately quite easy to accidentally use DUMMY_SP by calling the query on a TyCtxt instead of a TyCtxtAt.)

r? @oli-obk @eddyb

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Jun 1, 2020
@rust-highfive
Copy link
Collaborator

The job mingw-check of your PR failed (pretty log, raw log). Through arcane magic we have determined that the following fragments from the build log may contain information about the problem.

Click to expand the log.
##[section]Starting: Linux mingw-check
##[section]Starting: Initialize job
Agent name: 'Azure Pipelines 3'
Agent machine name: 'fv-az578'
Current agent version: '2.169.1'
##[group]Operating System
16.04.6
LTS
LTS
##[endgroup]
##[group]Virtual Environment
Environment: ubuntu-16.04
Version: 20200517.1
Included Software: https://github.com/actions/virtual-environments/blob/ubuntu16/20200517.1/images/linux/Ubuntu1604-README.md
##[endgroup]
Agent running as: 'vsts'
Prepare build directory.
Set build variables.
Download all required tasks.
Download all required tasks.
Downloading task: Bash (3.163.2)
Checking job knob settings.
   Knob: AgentToolsDirectory = /opt/hostedtoolcache Source: ${AGENT_TOOLSDIRECTORY} 
   Knob: AgentPerflog = /home/vsts/perflog Source: ${VSTS_AGENT_PERFLOG} 
Start tracking orphan processes.
##[section]Finishing: Initialize job
##[section]Starting: Configure Job Name
==============================================================================
---
========================== Starting Command Output ===========================
[command]/bin/bash --noprofile --norc /home/vsts/work/_temp/f212c0ab-fed2-4226-a201-ce6af2ad773f.sh

##[section]Finishing: Disable git automatic line ending conversion
##[section]Starting: Checkout rust-lang/rust@refs/pull/72879/merge to s
Task         : Get sources
Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
Version      : 1.0.0
Author       : Microsoft
---
##[command]git remote add origin https://github.com/rust-lang/rust
##[command]git config gc.auto 0
##[command]git config --get-all http.https://github.com/rust-lang/rust.extraheader
##[command]git config --get-all http.proxy
##[command]git -c http.extraheader="AUTHORIZATION: basic ***" fetch --force --tags --prune --progress --no-recurse-submodules --depth=2 origin +refs/heads/*:refs/remotes/origin/* +refs/pull/72879/merge:refs/remotes/pull/72879/merge
---
 ---> 3adb0605cc65
Step 6/7 : ENV RUN_CHECK_WITH_PARALLEL_QUERIES 1
 ---> Using cache
 ---> 28dbc326cb7f
Step 7/7 : ENV SCRIPT python3 ../x.py test src/tools/expand-yaml-anchors &&            python3 ../x.py check --target=i686-pc-windows-gnu --host=i686-pc-windows-gnu &&            python3 ../x.py build --stage 0 src/tools/build-manifest &&            python3 ../x.py test --stage 0 src/tools/compiletest &&            python3 ../x.py test src/tools/tidy &&            python3 ../x.py doc --stage 0 src/libstd &&            /scripts/validate-toolstate.sh
 ---> 537a01811900
Successfully built 537a01811900
Successfully tagged rust-ci:latest
Built container sha256:537a018119009dc218456238dec90b5530050db1e2a1e166550c218003f6159d
---
    Checking rustc_feature v0.0.0 (/checkout/src/librustc_feature)
    Checking fmt_macros v0.0.0 (/checkout/src/libfmt_macros)
    Checking rustc_ast_pretty v0.0.0 (/checkout/src/librustc_ast_pretty)
    Checking rustc_hir v0.0.0 (/checkout/src/librustc_hir)
    Checking chalk-rust-ir v0.10.0
    Checking rustc_query_system v0.0.0 (/checkout/src/librustc_query_system)
    Checking chalk-solve v0.10.0
    Checking rustc_hir_pretty v0.0.0 (/checkout/src/librustc_hir_pretty)
    Checking rustc_parse v0.0.0 (/checkout/src/librustc_parse)
    Checking rustc_ast_lowering v0.0.0 (/checkout/src/librustc_ast_lowering)
---
configure: rust.codegen-units-std := 1
configure: rust.verify-llvm-ir  := True
configure: dist.missing-tools   := True
configure: rust.debug-assertions := True
configure: build.configure-args := ['--enable-sccache', '--disable-manage-submodu ...
configure: writing `config.toml` in current directory
configure: 
configure: run `python /checkout/x.py --help`
configure: 
---
Hugepagesize:       2048 kB
DirectMap4k:      143296 kB
DirectMap2M:     4050944 kB
DirectMap1G:     5242880 kB
+ python3 ../x.py test src/tools/expand-yaml-anchors
Ensuring the YAML anchors in the GitHub Actions config were expanded
Ensuring the YAML anchors in the GitHub Actions config were expanded
Building stage0 tool expand-yaml-anchors (x86_64-unknown-linux-gnu)
   Compiling unicode-xid v0.2.0
   Compiling syn v1.0.11
   Compiling linked-hash-map v0.5.2
   Compiling lazy_static v1.4.0
   Compiling lazy_static v1.4.0
   Compiling yaml-rust v0.4.3
   Compiling quote v1.0.2
   Compiling thiserror-impl v1.0.5
   Compiling thiserror v1.0.5
   Compiling yaml-merge-keys v0.4.0
   Compiling expand-yaml-anchors v0.1.0 (/checkout/src/tools/expand-yaml-anchors)
Build completed successfully in 0:00:26
+ python3 ../x.py check --target=i686-pc-windows-gnu --host=i686-pc-windows-gnu
    Finished dev [unoptimized] target(s) in 0.18s
Checking rustdoc artifacts (x86_64-unknown-linux-gnu -> i686-pc-windows-gnu)
---
    Checking rustc_feature v0.0.0 (/checkout/src/librustc_feature)
    Checking fmt_macros v0.0.0 (/checkout/src/libfmt_macros)
    Checking rustc_ast_pretty v0.0.0 (/checkout/src/librustc_ast_pretty)
    Checking rustc_hir v0.0.0 (/checkout/src/librustc_hir)
    Checking chalk-rust-ir v0.10.0
    Checking rustc_query_system v0.0.0 (/checkout/src/librustc_query_system)
    Checking chalk-solve v0.10.0
    Checking rustc_hir_pretty v0.0.0 (/checkout/src/librustc_hir_pretty)
    Checking rustc_parse v0.0.0 (/checkout/src/librustc_parse)
    Checking rustc_ast_lowering v0.0.0 (/checkout/src/librustc_ast_lowering)
---
-                            "erroneous constant used",
-                            lint_root,
-                            Some(c.span),
-                        );
+                        err.report_as_lint(tcx, "erroneous constant used", lint_root, Some(c.span));
                     } else {
                         err.report_as_error(tcx, "erroneous constant used");
                     }
Running `"/checkout/obj/build/x86_64-unknown-linux-gnu/stage0/bin/rustfmt" "--config-path" "/checkout" "--edition" "2018" "--unstable-features" "--skip-children" "--check" "/checkout/src/librustc_mir/transform/const_prop.rs"` failed.
If you're running `tidy`, try again with `--bless`. Or, if you just want to format code, run `./x.py fmt` instead.
Build completed unsuccessfully in 0:00:36
== clock drift check ==
  local time: Mon Jun  1 09:44:01 UTC 2020
  network time: Mon, 01 Jun 2020 09:44:01 GMT
  network time: Mon, 01 Jun 2020 09:44:01 GMT
== end clock drift check ==

##[error]Bash exited with code '1'.
##[section]Finishing: Run build
##[section]Starting: Checkout rust-lang/rust@refs/pull/72879/merge to s
Task         : Get sources
Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
Version      : 1.0.0
Author       : Microsoft
Author       : Microsoft
Help         : [More Information](https://go.microsoft.com/fwlink/?LinkId=798199)
==============================================================================
Cleaning any cached credential from repository: rust-lang/rust (GitHub)
##[section]Finishing: Checkout rust-lang/rust@refs/pull/72879/merge to s
Cleaning up task key
Start cleaning up orphan processes.
Terminate orphan process: pid (3535) (python)
##[section]Finishing: Finalize Job

I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact @rust-lang/infra. (Feature Requests)

@oli-obk
Copy link
Contributor

oli-obk commented Jun 2, 2020

I did this for a few reasons:

  1. No accidental forgetting to use TyCtxtAt for queries, giving us better query cycle errors. This is not tested on CI, so you won't see if we regressed that
  2. Kinda hoping for more usage of TyCtxtAt in other APIs, improving query cycle errors further
  3. More precise errors (you regressed a bunch of errors to much more general spans).
  4. ecx.tcx is used a lot, I wanted using it to be as cheap as possible.

I'd prefer working on 2. than doing this PR

@RalfJung
Copy link
Member Author

RalfJung commented Jun 3, 2020

I very strongly dislike having redundant mutable state. TyCtxAt feels to me like it is made for situations where you'd otherwise anyway have to track a Span separately. That is not the case here. Redundancy in mutable state is just a recipe for screwups as the state becomes inconsistent.

For 1, I think a better solution is to not provide the query methods on TyCtxt, and instead make people write tcx.at_dummy().query() or so.

For 4, the version with a span is not actually used that often. This PR overall makes code nicer as we stop having a lot of random self.tcx.tcx or *self.tcx all over the place.
Let's see if this has any perf impact.
@bors try @rust-timer queue

@rust-timer
Copy link
Collaborator

Awaiting bors try build completion

@bors
Copy link
Contributor

bors commented Jun 3, 2020

⌛ Trying commit b5bd4af967a2489941fe4ee9a622c02ee762fcd7 with merge 2b703712231b2c5d8bf99c98ff8596b3a46d539d...

@oli-obk
Copy link
Contributor

oli-obk commented Jun 3, 2020

I think a better solution is to not provide the query methods on TyCtxt, and instead make people write tcx.at_dummy().query() or so.

oh I like that.

I'm not really worried about perf, but could you look into the regressed spans?

|
LL | n = if n % 2 == 0 { n/2 } else { 3*n + 1 };
| ^^^^^^^^^^ exceeded interpreter step limit (see `#[const_eval_limit]`)
| ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ exceeded interpreter step limit (see `#[const_eval_limit]`)
Copy link
Contributor

Choose a reason for hiding this comment

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

This one's ok, the previous span didn't really give the user any additional info.

| |__-
LL | / const X: usize = {
LL | | let mut x = 0;
LL | | while x != 1000 {
Copy link
Contributor

Choose a reason for hiding this comment

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

Although when looking at the multi-line variant, I guess we should figure out how to make things point at the while instead of the entire while expression

@RalfJung
Copy link
Member Author

RalfJung commented Jun 3, 2020

I'm not really worried about perf, but could you look into the regressed spans?

Any hints for where to start? I am not even sure if these errors are better or worse than before.

My best guess is... maybe const_prop is doing something weird? Does it even have a stack frame to fetch the Location from? But then it doesn't follow function calls so it shouldn't have cycle errors, or should it?

I think a better solution is to not provide the query methods on TyCtxt, and instead make people write tcx.at_dummy().query() or so.

oh I like that.

:)

It's a big change though to do this for all queries, I don't think I'll be able to push this through. I could try doing it for a few queries that Miri needs, though. And anyway I figure this requires MCP so I'd first have to read up on the bureaucracy involved in that.^^

@oli-obk
Copy link
Contributor

oli-obk commented Jun 3, 2020

I don't think I'll be able to push this through. I could try doing it for a few queries that Miri needs, though. And anyway I figure this requires MCP so I'd first have to read up on the bureaucracy involved in that.^^

Oh I wasn't suggesting you do this, or it being done fast. Don't worry about it. I just want a path forward to exist, and you gave me one.

@bors
Copy link
Contributor

bors commented Jun 3, 2020

☀️ Try build successful - checks-azure
Build commit: 2b703712231b2c5d8bf99c98ff8596b3a46d539d (2b703712231b2c5d8bf99c98ff8596b3a46d539d)

@rust-timer
Copy link
Collaborator

Queued 2b703712231b2c5d8bf99c98ff8596b3a46d539d with parent 680a4b2, future comparison URL.

@rust-timer
Copy link
Collaborator

Finished benchmarking try commit 2b703712231b2c5d8bf99c98ff8596b3a46d539d, comparison URL.

@oli-obk

This comment has been minimized.

@RalfJung

This comment has been minimized.

@RalfJung
Copy link
Member Author

RalfJung commented Jun 4, 2020

Perf shows up to 3.5% regression in ctfe-stress-4. That's concerning.

@oli-obk
Copy link
Contributor

oli-obk commented Jun 8, 2020

The problem is that the span may now be computed many times, since we need the span before invoking a query instead of just handling it at query failure time.

Maybe we should just use the base span for queries? The little bit of help we get from having the query use the current statement's span is likely not worth it.

@RalfJung
Copy link
Member Author

RalfJung commented Jun 8, 2020

Maybe we should just use the base span for queries? The little bit of help we get from having the query use the current statement's span is likely not worth it.

Sure, makes sense.

@RalfJung
Copy link
Member Author

Okay, this should fix most of the perf impact. It doesn't actually change output for any of our tests...

@bors try @rust-timer queue

@rust-timer
Copy link
Collaborator

Awaiting bors try build completion

@bors
Copy link
Contributor

bors commented Jun 11, 2020

⌛ Trying commit b34637db75c75bf22d201a78d1c16ebc04495f82 with merge 90b1db045a8b817d21633edf1974a53db4622000...

@RalfJung
Copy link
Member Author

@oli-obk I eliminated those two calls to cur_span, each in a separate commit so you can see the test fallout.
@bors try @rust-timer queue

@rust-timer
Copy link
Collaborator

Awaiting bors try build completion

@bors
Copy link
Contributor

bors commented Jun 13, 2020

⌛ Trying commit c6512fd with merge 731149c25b195069cebc2629cea9bb0023470cee...

@bors
Copy link
Contributor

bors commented Jun 13, 2020

☀️ Try build successful - checks-azure
Build commit: 731149c25b195069cebc2629cea9bb0023470cee (731149c25b195069cebc2629cea9bb0023470cee)

@rust-timer
Copy link
Collaborator

Queued 731149c25b195069cebc2629cea9bb0023470cee with parent 1fb612b, future comparison URL.

@rust-timer
Copy link
Collaborator

Finished benchmarking try commit (731149c25b195069cebc2629cea9bb0023470cee): comparison url.

@RalfJung
Copy link
Member Author

I don't get it, how can it still be slowing down anything when we only do extra work in case of errors... but at least only the stress test is >1% this time (and 1.1% on a stress test is not a lot).

@Mark-Simulacrum
Copy link
Member

FWIW here are min/max instruction counts, across 3 runs on the 3 consecutive parent commits of the try build plus the try build itself, for the ctfe-stress-4 benchmark on that last try build.

To me, it looks like the increase in instruction counts isn't noise -- at least on the check-full benchmark, the previous results never went above 35328476078 whereas the try build came back at 35463018519.

commit profile cache min max
7c78a5f check full 35066309116 35328443982
f4fbb93 check full 35116992434 35328476078
1fb612b check full 35066307854 35328453364
731149c check full 35463018519 35725139289
7c78a5f check incr-full 51518942754 51781361474
f4fbb93 check incr-full 51519607402 51786058020
1fb612b check incr-full 51518962369 51781451729
731149c check incr-full 51915651189 52182760277
7c78a5f check incr-unchanged 4861217909 4863982451
f4fbb93 check incr-unchanged 4861215229 4863977552
1fb612b check incr-unchanged 4861215174 4863983736
731149c check incr-unchanged 4861215718 4863982296
7c78a5f debug full 35305507288 35567863908
f4fbb93 debug full 35356218690 35567822880
1fb612b debug full 35305497192 35567845577
731149c debug full 35702233063 35964524738
7c78a5f debug incr-full 51759633718 52021809140
f4fbb93 debug incr-full 51759993115 52021838728
1fb612b debug incr-full 51759309209 52021846642
731149c debug incr-full 52166510753 52418543282
7c78a5f debug incr-unchanged 4875529962 4879808936
f4fbb93 debug incr-unchanged 4875526486 4879819749
1fb612b debug incr-unchanged 4875526149 4879800136
731149c debug incr-unchanged 4875523566 4879797176
7c78a5f opt full 35514990754 35766300381
f4fbb93 opt full 35565727117 35766295616
1fb612b opt full 35515044051 35766377897
731149c opt full 35895418254 36146694087
7c78a5f opt incr-full 51820771281 52072446788
f4fbb93 opt incr-full 51821156195 52083684988
1fb612b opt incr-full 51820507355 52072763256
731149c opt incr-full 52211352684 52452919751
7c78a5f opt incr-unchanged 4875648758 4879968575
f4fbb93 opt incr-unchanged 4875653144 4879946311
1fb612b opt incr-unchanged 4875649275 4879953253
731149c opt incr-unchanged 4875651022 4879952210

For mostly my own future reference, generated this using:

select substring(artifact.name, 0, 8) as commit, pstat_series.profile, pstat_series.cache, min(pstat.value), max(pstat.value) from pstat join pstat_series on series = pstat_series.id join artifact on aid = artifact.id where crate = 'ctfe-stress-4' and (artifact.name LIKE '731149c2%' or artifact.name LIKE '1fb612bd%' or artifact.name LIKE 'f4fbb93113aa4f0a%' or artifact.name LIKE '7c78a5f97de0%') and statistic = 'instructions:u' group by (profile, cache, artifact.id) order by (profile, cache, artifact.date);

@Mark-Simulacrum
Copy link
Member

My guess is that we could likely track down the exact cause of the increased instruction counts by locally comparing two builds with cachegrind. I might actually suspect that the increased counts are coming from larger TyCtxt being copied around, but that might be spurious. OTOH, Span is another 64 bits so that's another instruction presumably every time we create or copy TyCtxt, and this PR introduces more TyCtxtAt than we had previously I think.

But this is just a theory of course :)

@RalfJung
Copy link
Member Author

this PR introduces more TyCtxtAt than we had previously I think.

No, this PR means TyCtxtAt is used less often.

Unless you mean this PR means we construct TyCtxtAt more often from its constituent parts, which is true. I suppose I could merge the root_span and tcx to a TyCtxtAt to test of that reduces the overhead.

@RalfJung
Copy link
Member Author

@bors try @rust-timer queue

@rust-timer
Copy link
Collaborator

Awaiting bors try build completion

@bors
Copy link
Contributor

bors commented Jun 14, 2020

⌛ Trying commit 2210abe with merge 70469937ac3dc60160860773f6fc701f61e60ca7...

@bors
Copy link
Contributor

bors commented Jun 14, 2020

☀️ Try build successful - checks-azure
Build commit: 70469937ac3dc60160860773f6fc701f61e60ca7 (70469937ac3dc60160860773f6fc701f61e60ca7)

@rust-timer
Copy link
Collaborator

Queued 70469937ac3dc60160860773f6fc701f61e60ca7 with parent 10326d8, future comparison URL.

@rust-timer
Copy link
Collaborator

Finished benchmarking try commit (70469937ac3dc60160860773f6fc701f61e60ca7): comparison url.

@RalfJung
Copy link
Member Author

RalfJung commented Jun 15, 2020

Yes, this seems to mostly fix the regressions. :) I wouldn't have thought that tcx.at is so expensive...

@oli-obk
Copy link
Contributor

oli-obk commented Jun 15, 2020

@bors r+

@bors
Copy link
Contributor

bors commented Jun 15, 2020

📌 Commit 2210abe has been approved by oli-obk

@bors 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-author Status: This is awaiting some action (such as code changes or more information) from the author. labels Jun 15, 2020
bors added a commit to rust-lang-ci/rust that referenced this pull request Jun 15, 2020
Rollup of 10 pull requests

Successful merges:

 - rust-lang#72707 (Use min_specialization in the remaining rustc crates)
 - rust-lang#72740 (On recursive ADT, provide indirection structured suggestion)
 - rust-lang#72879 (Miri: avoid tracking current location three times)
 - rust-lang#72938 (Stabilize Option::zip)
 - rust-lang#73086 (Rename "cyclone" to "apple-a7" per changes in upstream LLVM)
 - rust-lang#73104 (Example about explicit mutex dropping)
 - rust-lang#73139 (Add methods to go from a nul-terminated Vec<u8> to a CString)
 - rust-lang#73296 (Remove vestigial CI job msvc-aux.)
 - rust-lang#73304 (Revert heterogeneous SocketAddr PartialEq impls)
 - rust-lang#73331 (extend network support for HermitCore)

Failed merges:

r? @ghost
@bors bors merged commit f9c8a67 into rust-lang:master Jun 15, 2020
@RalfJung RalfJung deleted the miri-tctx-at branch June 15, 2020 17:08
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants