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

Better pretty printing for const raw pointers #65859

Closed
wants to merge 10 commits into from

Conversation

iwikal
Copy link

@iwikal iwikal commented Oct 27, 2019

closes #65349, hopefully.

@rust-highfive
Copy link
Collaborator

Thanks for the pull request, and welcome! The Rust team is excited to review your changes, and you should hear from @cramertj (or someone else) soon.

If any changes to this PR are deemed necessary, please add them as extra commits. This ensures that the reviewer can see what has changed since they last reviewed the code. Due to the way GitHub handles out-of-date commits, this should also make it reasonably obvious what issues have or haven't been addressed. Large or tricky changes may require several passes of review and changes.

Please see the contribution instructions for more information.

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Oct 27, 2019
@cramertj
Copy link
Member

I don't know who would be a great reviewer for this, but I don't know that it's me. I personally find the output with this change pretty intimidating in terms of length-- I don't know how often the full leading-zeros pointer value will be helpful. I guess I don't have a particularly better suggestion to offer, though. cc @estebank in case they have any ideas, and @RalfJung who might have thoughts about direct display of pointers coming from const contexts.

@bors r+

@bors
Copy link
Contributor

bors commented Oct 28, 2019

📌 Commit 6a6ed12 has been approved by cramertj

@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-review Status: Awaiting review from the assignee but also interested parties. labels Oct 28, 2019
@estebank
Copy link
Contributor

There are some hacks we could pursue to only highlight the parts of the hex value that differ, but it'd be a big hack for a fairly uncommonly used feature.

Centril added a commit to Centril/rust that referenced this pull request Oct 29, 2019
…mertj

Better pretty printing for const raw pointers

closes rust-lang#65349, hopefully.
Centril added a commit to Centril/rust that referenced this pull request Oct 29, 2019
…mertj

Better pretty printing for const raw pointers

closes rust-lang#65349, hopefully.
@Centril
Copy link
Contributor

Centril commented Oct 29, 2019

Failed in #65917 (comment), @bors r-

@bors bors 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-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. labels Oct 29, 2019
@rust-highfive
Copy link
Collaborator

The job x86_64-gnu-llvm-6.0 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.
2019-11-04T23:11:20.5834024Z ##[command]git remote add origin https://github.com/rust-lang/rust
2019-11-04T23:11:21.3199665Z ##[command]git config gc.auto 0
2019-11-04T23:11:21.3206817Z ##[command]git config --get-all http.https://github.com/rust-lang/rust.extraheader
2019-11-04T23:11:21.3210648Z ##[command]git config --get-all http.proxy
2019-11-04T23:11:21.3216189Z ##[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/65859/merge:refs/remotes/pull/65859/merge
---
2019-11-05T00:10:34.6408649Z .................................................................................................... 1600/9276
2019-11-05T00:10:40.3773772Z .................................................................................................... 1700/9276
2019-11-05T00:10:52.8371845Z ...............................................................i...............i.................... 1800/9276
2019-11-05T00:11:00.1321609Z .................................................................................................... 1900/9276
2019-11-05T00:11:15.3586385Z .....................................................iiiii.......................................... 2000/9276
2019-11-05T00:11:26.0730375Z .................................................................................................... 2200/9276
2019-11-05T00:11:28.6100650Z .................................................................................................... 2300/9276
2019-11-05T00:11:32.0236708Z .................................................................................................... 2400/9276
2019-11-05T00:11:55.2415568Z .................................................................................................... 2500/9276
2019-11-05T00:11:55.2415568Z .................................................................................................... 2500/9276
2019-11-05T00:11:58.0407352Z .................................................................................................... 2600/9276
2019-11-05T00:12:05.5719469Z .................................................................................................... 2700/9276
2019-11-05T00:12:14.3258487Z .....................i.............................................................................. 2800/9276
2019-11-05T00:12:23.2145477Z .................................................................................................... 2900/9276
2019-11-05T00:12:27.6964216Z ....................i............................................................................... 3000/9276
2019-11-05T00:12:36.3814978Z .................................................................................................... 3100/9276
2019-11-05T00:12:41.9549771Z .................................................................................................... 3200/9276
2019-11-05T00:12:50.7323995Z ..ii................................................................................................ 3300/9276
2019-11-05T00:13:07.4617027Z ...............................................................................................i.... 3500/9276
2019-11-05T00:13:14.8701476Z ..........................................i......................................................... 3600/9276
2019-11-05T00:13:21.4854852Z .................................................................................................... 3700/9276
2019-11-05T00:13:27.8426310Z .................................................................................................... 3800/9276
---
2019-11-05T00:14:48.6658312Z .....................................................i...............i.............................. 4800/9276
2019-11-05T00:14:57.6856733Z .................................................................................................... 4900/9276
2019-11-05T00:15:06.5166581Z .................................................................................................... 5000/9276
2019-11-05T00:15:12.7478410Z .................................................................................................... 5100/9276
2019-11-05T00:15:23.4110510Z ......................................................ii.ii...........i............................. 5200/9276
2019-11-05T00:15:33.4487898Z .................................................................................................... 5400/9276
2019-11-05T00:15:43.6578104Z .................................................................................................... 5500/9276
2019-11-05T00:15:51.1923360Z ...........................i........................................................................ 5600/9276
2019-11-05T00:15:57.6167107Z .................................................................................................... 5700/9276
2019-11-05T00:15:57.6167107Z .................................................................................................... 5700/9276
2019-11-05T00:16:09.8200396Z .................................................................................................... 5800/9276
2019-11-05T00:16:21.7669120Z ............ii...i..ii...........i.................................................................. 5900/9276
2019-11-05T00:16:42.5104192Z .................................................................................................... 6100/9276
2019-11-05T00:16:48.9994057Z .................................................................................................... 6200/9276
2019-11-05T00:16:48.9994057Z .................................................................................................... 6200/9276
2019-11-05T00:17:03.0536413Z ...............................i..ii................................................................ 6300/9276
2019-11-05T00:17:23.7234993Z ..................................................................................................i. 6500/9276
2019-11-05T00:17:26.0915557Z .................................................................................................... 6600/9276
2019-11-05T00:17:28.3367467Z ............................................................................i....................... 6700/9276
2019-11-05T00:17:31.2121760Z .................................................................................................... 6800/9276
---
2019-11-05T00:22:46.6909811Z running 62 tests
2019-11-05T00:22:52.0095984Z ..F......F...F..F.............................................
2019-11-05T00:22:52.0097277Z failures:
2019-11-05T00:22:52.0097469Z 
2019-11-05T00:22:52.0101949Z ---- [mir-opt] mir-opt/byte_slice.rs stdout ----
2019-11-05T00:22:52.0102595Z thread '[mir-opt] mir-opt/byte_slice.rs' panicked at 'Did not find expected line, error: ran out of mir dump to match against
2019-11-05T00:22:52.0102810Z Expected Line: "_1 = const b\"foo\";"
2019-11-05T00:22:52.0102965Z Test Name: rustc.main.EraseRegions.after.mir
2019-11-05T00:22:52.0103289Z ... (elided)
2019-11-05T00:22:52.0103425Z ... (elided)
2019-11-05T00:22:52.0103425Z ... (elided)
2019-11-05T00:22:52.0103581Z _1 = const b"foo";
2019-11-05T00:22:52.0103717Z ... (elided)
2019-11-05T00:22:52.0103881Z _2 = [const 5u8, const 120u8];
2019-11-05T00:22:52.0104024Z ... (elided)
2019-11-05T00:22:52.0104621Z Actual:
2019-11-05T00:22:52.0105148Z fn  main() -> () {
2019-11-05T00:22:52.0105349Z     let mut _0: ();
2019-11-05T00:22:52.0105493Z     let _1: &[u8; 3];
2019-11-05T00:22:52.0105653Z     scope 1 {
2019-11-05T00:22:52.0105795Z         let _2: [u8; 2];
2019-11-05T00:22:52.0105931Z         scope 2 {
2019-11-05T00:22:52.0107735Z     }
2019-11-05T00:22:52.0107959Z     bb0: {
2019-11-05T00:22:52.0108326Z         StorageLive(_1);
2019-11-05T00:22:52.0108326Z         StorageLive(_1);
2019-11-05T00:22:52.0108488Z         _1 = const {pointer} : &[u8; 3];
2019-11-05T00:22:52.0108628Z         StorageLive(_2);
2019-11-05T00:22:52.0108785Z         _2 = [const 5u8, const 120u8];
2019-11-05T00:22:52.0109330Z         StorageDead(_2);
2019-11-05T00:22:52.0109489Z         StorageDead(_1);
2019-11-05T00:22:52.0109624Z         return;
2019-11-05T00:22:52.0109758Z     }
2019-11-05T00:22:52.0109758Z     }
2019-11-05T00:22:52.0110377Z }', src/tools/compiletest/src/runtest.rs:3299:13
2019-11-05T00:22:52.0110611Z note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
2019-11-05T00:22:52.0110741Z 
2019-11-05T00:22:52.0111199Z ---- [mir-opt] mir-opt/const_prop/const_prop_fails_gracefully.rs stdout ----
2019-11-05T00:22:52.0111718Z thread '[mir-opt] mir-opt/const_prop/const_prop_fails_gracefully.rs' panicked at 'Did not find expected line, error: ran out of mir dump to match against
2019-11-05T00:22:52.0113167Z Expected Line: "     _4 = const Scalar(AllocId(1).0x0) : &i32;"
2019-11-05T00:22:52.0113231Z Test Name: rustc.main.ConstProp.after.mir
2019-11-05T00:22:52.0113341Z ... (elided)
2019-11-05T00:22:52.0113384Z  bb0: {
2019-11-05T00:22:52.0113457Z ... (elided)
2019-11-05T00:22:52.0113457Z ... (elided)
2019-11-05T00:22:52.0113505Z      _4 = const Scalar(AllocId(1).0x0) : &i32;
2019-11-05T00:22:52.0113554Z      _3 = const Scalar(AllocId(1).0x0) : &i32;
2019-11-05T00:22:52.0113621Z      _2 = const Scalar(AllocId(1).0x0) : *const i32;
2019-11-05T00:22:52.0113676Z ... (elided)
2019-11-05T00:22:52.0113721Z      _1 = move _2 as usize (Misc);
2019-11-05T00:22:52.0113766Z ... (elided)
2019-11-05T00:22:52.0113825Z      _6 = _1;
2019-11-05T00:22:52.0114174Z      _5 = const read(move _6) -> bb1;
2019-11-05T00:22:52.0114285Z Actual:
2019-11-05T00:22:52.0114511Z fn  main() -> () {
2019-11-05T00:22:52.0114559Z     let mut _0: ();
2019-11-05T00:22:52.0114620Z     let _1: usize;
2019-11-05T00:22:52.0114620Z     let _1: usize;
2019-11-05T00:22:52.0114666Z     let mut _2: *const i32;
2019-11-05T00:22:52.0114711Z     let mut _3: &i32;
2019-11-05T00:22:52.0114754Z     let mut _4: &i32;
2019-11-05T00:22:52.0114816Z     let _5: ();
2019-11-05T00:22:52.0114859Z     let mut _6: usize;
2019-11-05T00:22:52.0114911Z     scope 1 {
2019-11-05T00:22:52.0115013Z     bb0: {
2019-11-05T00:22:52.0115055Z         StorageLive(_1);
2019-11-05T00:22:52.0115100Z         StorageLive(_2);
2019-11-05T00:22:52.0115160Z         StorageLive(_3);
2019-11-05T00:22:52.0115160Z         StorageLive(_3);
2019-11-05T00:22:52.0115210Z         StorageLive(_4);
2019-11-05T00:22:52.0115255Z         _4 = const {pointer} : &i32;
2019-11-05T00:22:52.0115319Z         _3 = const {pointer} : &i32;
2019-11-05T00:22:52.0115368Z         _2 = const Scalar(AllocId(1).0x0) : *const i32;
2019-11-05T00:22:52.0115416Z         StorageDead(_3);
2019-11-05T00:22:52.0115478Z         _1 = move _2 as usize (Misc);
2019-11-05T00:22:52.0115524Z         StorageDead(_2);
2019-11-05T00:22:52.0115568Z         StorageDead(_4);
2019-11-05T00:22:52.0115611Z         StorageLive(_5);
2019-11-05T00:22:52.0115670Z         StorageLive(_6);
2019-11-05T00:22:52.0115715Z         _6 = _1;
2019-11-05T00:22:52.0115979Z         _5 = const read(move _6) -> bb1;
2019-11-05T00:22:52.0116095Z     bb1: {
2019-11-05T00:22:52.0116138Z         StorageDead(_6);
2019-11-05T00:22:52.0116198Z         StorageDead(_5);
2019-11-05T00:22:52.0116242Z         _0 = ();
2019-11-05T00:22:52.0116242Z         _0 = ();
2019-11-05T00:22:52.0116285Z         StorageDead(_1);
2019-11-05T00:22:52.0116328Z         return;
2019-11-05T00:22:52.0116393Z     }
2019-11-05T00:22:52.0116436Z     bb2 (cleanup): {
2019-11-05T00:22:52.0116479Z         resume;
2019-11-05T00:22:52.0116799Z }', src/tools/compiletest/src/runtest.rs:3299:13
2019-11-05T00:22:52.0116834Z 
2019-11-05T00:22:52.0117094Z ---- [mir-opt] mir-opt/const_prop/ref_deref.rs stdout ----
2019-11-05T00:22:52.0117094Z ---- [mir-opt] mir-opt/const_prop/ref_deref.rs stdout ----
2019-11-05T00:22:52.0117449Z thread '[mir-opt] mir-opt/const_prop/ref_deref.rs' panicked at 'Did not find expected line, error: ran out of mir dump to match against
2019-11-05T00:22:52.0117508Z Expected Line: "    _2 = const Scalar(AllocId(0).0x0) : &i32;"
2019-11-05T00:22:52.0117558Z Test Name: rustc.main.ConstProp.after.mir
2019-11-05T00:22:52.0117791Z ... (elided)
2019-11-05T00:22:52.0117833Z bb0: {
2019-11-05T00:22:52.0117891Z ... (elided)
2019-11-05T00:22:52.0117891Z ... (elided)
2019-11-05T00:22:52.0117939Z     _2 = const Scalar(AllocId(0).0x0) : &i32;
2019-11-05T00:22:52.0117985Z     _1 = const 4i32;
2019-11-05T00:22:52.0118028Z ... (elided)
2019-11-05T00:22:52.0118194Z Actual:
2019-11-05T00:22:52.0118451Z fn  main() -> () {
2019-11-05T00:22:52.0118516Z     let mut _0: ();
2019-11-05T00:22:52.0118559Z     let _1: i32;
2019-11-05T00:22:52.0118559Z     let _1: i32;
2019-11-05T00:22:52.0118603Z     let mut _2: &i32;
2019-11-05T00:22:52.0118645Z     let _3: i32;
2019-11-05T00:22:52.0118705Z     bb0: {
2019-11-05T00:22:52.0118746Z         StorageLive(_1);
2019-11-05T00:22:52.0118790Z         StorageLive(_2);
2019-11-05T00:22:52.0118852Z         _2 = const {pointer} : &i32;
2019-11-05T00:22:52.0118899Z         _1 = const 4i32;
2019-11-05T00:22:52.0118943Z         StorageDead(_2);
2019-11-05T00:22:52.0119002Z         StorageDead(_1);
2019-11-05T00:22:52.0119098Z         return;
2019-11-05T00:22:52.0119139Z     }
2019-11-05T00:22:52.0119139Z     }
2019-11-05T00:22:52.0119197Z     bb1 (cleanup): {
2019-11-05T00:22:52.0119241Z         resume;
2019-11-05T00:22:52.0119565Z }', src/tools/compiletest/src/runtest.rs:3299:13
2019-11-05T00:22:52.0119610Z 
2019-11-05T00:22:52.0119872Z ---- [mir-opt] mir-opt/const_prop/slice_len.rs stdout ----
2019-11-05T00:22:52.0119872Z ---- [mir-opt] mir-opt/const_prop/slice_len.rs stdout ----
2019-11-05T00:22:52.0120207Z thread '[mir-opt] mir-opt/const_prop/slice_len.rs' panicked at 'Did not find expected line, error: ran out of mir dump to match against
2019-11-05T00:22:52.0120286Z Expected Line: "     _4 = const Scalar(AllocId(0).0x0) : &[u32; 3];"
2019-11-05T00:22:52.0120336Z Test Name: rustc.main.ConstProp.after.mir
2019-11-05T00:22:52.0120440Z ... (elided)
2019-11-05T00:22:52.0120482Z  bb0: {
2019-11-05T00:22:52.0120524Z ... (elided)
2019-11-05T00:22:52.0120524Z ... (elided)
2019-11-05T00:22:52.0120586Z      _4 = const Scalar(AllocId(0).0x0) : &[u32; 3];
2019-11-05T00:22:52.0120636Z      _3 = const Scalar(AllocId(0).0x0) : &[u32; 3];
2019-11-05T00:22:52.0120694Z      _2 = move _3 as &[u32] (Pointer(Unsize));
2019-11-05T00:22:52.0120739Z ... (elided)
2019-11-05T00:22:52.0120843Z      _7 = const 3usize;
2019-11-05T00:22:52.0120894Z      _8 = const true;
2019-11-05T00:22:52.0120894Z      _8 = const true;
2019-11-05T00:22:52.0121214Z      assert(const true, "index out of bounds: the len is move _7 but the index is _6") -> bb1;
2019-11-05T00:22:52.0121309Z  bb1: {
2019-11-05T00:22:52.0121372Z      _1 = const 2u32;
2019-11-05T00:22:52.0121414Z ... (elided)
2019-11-05T00:22:52.0121456Z      return;
2019-11-05T00:22:52.0121456Z      return;
2019-11-05T00:22:52.0121496Z  }
2019-11-05T00:22:52.0121554Z Actual:
2019-11-05T00:22:52.0121596Z | User Type Annotations
2019-11-05T00:22:52.0121974Z | 0: Canonical { max_universe: U0, variables: [CanonicalVarInfo { kind: Region(U0) }], value: Ty(&[u32]) } at /checkout/src/test/mir-opt/const_prop/slice_len.rs:2:5: 2:30
2019-11-05T00:22:52.0122271Z fn  main() -> () {
2019-11-05T00:22:52.0122329Z     let mut _0: ();
2019-11-05T00:22:52.0122390Z     let _1: u32;
2019-11-05T00:22:52.0122435Z     let mut _2: &[u32];
2019-11-05T00:22:52.0122435Z     let mut _2: &[u32];
2019-11-05T00:22:52.0122480Z     let mut _3: &[u32; 3];
2019-11-05T00:22:52.0122526Z     let mut _4: &[u32; 3];
2019-11-05T00:22:52.0122596Z     let _5: [u32; 3];
2019-11-05T00:22:52.0122640Z     let _6: usize;
2019-11-05T00:22:52.0122683Z     let mut _7: usize;
2019-11-05T00:22:52.0122743Z     let mut _8: bool;
2019-11-05T00:22:52.0122786Z     bb0: {
2019-11-05T00:22:52.0122830Z         StorageLive(_1);
2019-11-05T00:22:52.0122890Z         StorageLive(_2);
2019-11-05T00:22:52.0122935Z         StorageLive(_3);
2019-11-05T00:22:52.0122978Z         StorageLive(_4);
2019-11-05T00:22:52.0123024Z         _4 = const {pointer} : &[u32; 3];
2019-11-05T00:22:52.0123091Z         _3 = const {pointer} : &[u32; 3];
2019-11-05T00:22:52.0123140Z         _2 = move _3 as &[u32] (Pointer(Unsize));
2019-11-05T00:22:52.0123186Z         StorageDead(_3);
2019-11-05T00:22:52.0123248Z         StorageLive(_6);
2019-11-05T00:22:52.0123429Z         _7 = const 3usize;
2019-11-05T00:22:52.0123491Z         _8 = const true;
2019-11-05T00:22:52.0123491Z         _8 = const true;
2019-11-05T00:22:52.0123891Z         assert(const true, "index out of bounds: the len is move _7 but the index is _6") -> bb1;
2019-11-05T00:22:52.0123993Z     bb1: {
2019-11-05T00:22:52.0124053Z         _1 = const 2u32;
2019-11-05T00:22:52.0124097Z         StorageDead(_6);
2019-11-05T00:22:52.0124140Z         StorageDead(_4);
2019-11-05T00:22:52.0124140Z         StorageDead(_4);
2019-11-05T00:22:52.0124201Z         StorageDead(_2);
2019-11-05T00:22:52.0124244Z         StorageDead(_1);
2019-11-05T00:22:52.0124287Z         _0 = ();
2019-11-05T00:22:52.0124346Z         return;
2019-11-05T00:22:52.0124388Z     }
2019-11-05T00:22:52.0124429Z     bb2 (cleanup): {
2019-11-05T00:22:52.0124472Z         resume;
2019-11-05T00:22:52.0124807Z }', src/tools/compiletest/src/runtest.rs:3299:13
2019-11-05T00:22:52.0124852Z 
2019-11-05T00:22:52.0124880Z 
2019-11-05T00:22:52.0124941Z failures:
---
2019-11-05T00:22:52.0126338Z 
2019-11-05T00:22:52.0126621Z thread 'main' panicked at 'Some tests failed', src/tools/compiletest/src/main.rs:537:22
2019-11-05T00:22:52.0126658Z 
2019-11-05T00:22:52.0126685Z 
2019-11-05T00:22:52.0128171Z command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-tools-bin/compiletest" "--compile-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib" "--run-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/x86_64-unknown-linux-gnu/lib" "--rustc-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/rustc" "--src-base" "/checkout/src/test/mir-opt" "--build-base" "/checkout/obj/build/x86_64-unknown-linux-gnu/test/mir-opt" "--stage-id" "stage2-x86_64-unknown-linux-gnu" "--mode" "mir-opt" "--target" "x86_64-unknown-linux-gnu" "--host" "x86_64-unknown-linux-gnu" "--llvm-filecheck" "/usr/lib/llvm-6.0/bin/FileCheck" "--host-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--target-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--docck-python" "/usr/bin/python2.7" "--lldb-python" "/usr/bin/python2.7" "--gdb" "/usr/bin/gdb" "--quiet" "--llvm-version" "6.0.0\n" "--system-llvm" "--cc" "" "--cxx" "" "--cflags" "" "--llvm-components" "" "--llvm-cxxflags" "" "--adb-path" "adb" "--adb-test-dir" "/data/tmp/work" "--android-cross-path" "" "--color" "always"
2019-11-05T00:22:52.0128916Z 
2019-11-05T00:22:52.0128967Z 
2019-11-05T00:22:52.0129015Z failed to run: /checkout/obj/build/bootstrap/debug/bootstrap test
2019-11-05T00:22:52.0129075Z Build completed unsuccessfully in 1:04:47
2019-11-05T00:22:52.0129075Z Build completed unsuccessfully in 1:04:47
2019-11-05T00:22:52.0161063Z == clock drift check ==
2019-11-05T00:22:52.0180287Z   local time: Tue Nov  5 00:22:52 UTC 2019
2019-11-05T00:22:52.2847482Z   network time: Tue, 05 Nov 2019 00:22:52 GMT
2019-11-05T00:22:52.2847597Z == end clock drift check ==
2019-11-05T00:22:56.6504176Z 
2019-11-05T00:22:56.6621308Z ##[error]Bash exited with code '1'.
2019-11-05T00:22:56.6679464Z ##[section]Starting: Checkout
2019-11-05T00:22:56.6681489Z ==============================================================================
2019-11-05T00:22:56.6681542Z Task         : Get sources
2019-11-05T00:22:56.6681613Z Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.

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 @TimNN. (Feature Requests)

@JohnCSimon
Copy link
Member

Ping from triage:
@iwikal - can you please address the build failure?
cc: @RalfJung @Centril

@iwikal
Copy link
Author

iwikal commented Nov 11, 2019

I'm stuck. I can't figure out how to debug the mir-opt tests. This is the part that has me mystified:

2019-11-05T00:22:52.0115255Z         _4 = const {pointer} : &i32;
2019-11-05T00:22:52.0115319Z         _3 = const {pointer} : &i32;
2019-11-05T00:22:52.0115368Z         _2 = const Scalar(AllocId(1).0x0) : *const i32;

That _2 looks like it's being printed by the fallback match arm, but it's not. It comes from somewhere else and I don't know where to begin to look. Also I can't figure out how to invoke the compiler exactly like the test does, so that I can debug properly. I tried to use dump-mir and ripgrep through the resulting mir_dump directory, but there is nothing in there that looks like the expected or the actual output from the test.

@rust-highfive
Copy link
Collaborator

The job x86_64-gnu-llvm-6.0 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.
2019-11-11T21:05:00.2040078Z ##[command]git remote add origin https://github.com/rust-lang/rust
2019-11-11T21:05:00.2225297Z ##[command]git config gc.auto 0
2019-11-11T21:05:00.9303442Z ##[command]git config --get-all http.https://github.com/rust-lang/rust.extraheader
2019-11-11T21:05:00.9320561Z ##[command]git config --get-all http.proxy
2019-11-11T21:05:00.9323854Z ##[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/65859/merge:refs/remotes/pull/65859/merge
---
2019-11-11T22:05:57.0087754Z .................................................................................................... 1500/9229
2019-11-11T22:06:03.1035891Z .................................................................................................... 1600/9229
2019-11-11T22:06:12.2950087Z .................................................................................................... 1700/9229
2019-11-11T22:06:21.1312841Z ...i................................................................................................ 1800/9229
2019-11-11T22:06:28.2593764Z .......................................................................................iiiii........ 1900/9229
2019-11-11T22:06:50.4914271Z .................................................................................................... 2100/9229
2019-11-11T22:06:53.0575468Z .................................................................................................... 2200/9229
2019-11-11T22:06:55.6801567Z .................................................................................................... 2300/9229
2019-11-11T22:07:05.6445308Z .................................................................................................... 2400/9229
---
2019-11-11T22:10:03.6613207Z ...................................................................................i...............i 4700/9229
2019-11-11T22:10:10.7567748Z .................................................................................................... 4800/9229
2019-11-11T22:10:19.9602803Z .................................................................................................... 4900/9229
2019-11-11T22:10:25.3359013Z .................................................................................................... 5000/9229
2019-11-11T22:10:36.9139541Z ......................................................................................ii.ii......... 5100/9229
2019-11-11T22:10:40.8246056Z ..i................................................................................................. 5200/9229
2019-11-11T22:10:54.1709246Z .................................................................................................... 5400/9229
2019-11-11T22:11:03.0018928Z ....................................................................i............................... 5500/9229
2019-11-11T22:11:10.5142342Z .................................................................................................... 5600/9229
2019-11-11T22:11:18.2571418Z .................................................................................................... 5700/9229
2019-11-11T22:11:18.2571418Z .................................................................................................... 5700/9229
2019-11-11T22:11:27.6189014Z .....................................................ii...i..ii...........i......................... 5800/9229
2019-11-11T22:11:50.7459272Z .................................................................................................... 6000/9229
2019-11-11T22:11:59.3781250Z .................................................................................................... 6100/9229
2019-11-11T22:11:59.3781250Z .................................................................................................... 6100/9229
2019-11-11T22:12:05.6400155Z ........................................................................i..ii....................... 6200/9229
2019-11-11T22:12:35.5458682Z .................................................................................................... 6400/9229
2019-11-11T22:12:37.8775758Z ........................................i........................................................... 6500/9229
2019-11-11T22:12:40.1937694Z .................................................................................................... 6600/9229
2019-11-11T22:12:42.6044125Z ........................i........................................................................... 6700/9229
---
2019-11-11T22:17:57.0215967Z running 64 tests
2019-11-11T22:18:02.7160135Z .........F......................................................
2019-11-11T22:18:02.7162067Z failures:
2019-11-11T22:18:02.7165294Z 
2019-11-11T22:18:02.7166358Z ---- [mir-opt] mir-opt/const_prop/const_prop_fails_gracefully.rs stdout ----
2019-11-11T22:18:02.7167089Z [ERROR compiletest::runtest] None
2019-11-11T22:18:02.7167943Z thread '[mir-opt] mir-opt/const_prop/const_prop_fails_gracefully.rs' panicked at 'Did not find expected line, error: Mismatch in lines
2019-11-11T22:18:02.7168189Z Current block: None
2019-11-11T22:18:02.7168335Z Actual Line: "        _2 = const Scalar(AllocId(1).0x0) : *const i32;"
2019-11-11T22:18:02.7168472Z Expected Line: "     _2 = const {pointer} : *const i32;"
2019-11-11T22:18:02.7168621Z Test Name: rustc.main.ConstProp.after.mir
2019-11-11T22:18:02.7169097Z ... (elided)
2019-11-11T22:18:02.7169242Z  bb0: {
2019-11-11T22:18:02.7169383Z ... (elided)
2019-11-11T22:18:02.7169383Z ... (elided)
2019-11-11T22:18:02.7169507Z      _4 = const {pointer} : &i32;
2019-11-11T22:18:02.7169651Z      _3 = const {pointer} : &i32;
2019-11-11T22:18:02.7169873Z      _2 = const {pointer} : *const i32;
2019-11-11T22:18:02.7170025Z ... (elided)
2019-11-11T22:18:02.7170151Z      _1 = move _2 as usize (Misc);
2019-11-11T22:18:02.7170272Z ... (elided)
2019-11-11T22:18:02.7170412Z      _6 = _1;
2019-11-11T22:18:02.7172143Z      _5 = const read(move _6) -> bb1;
2019-11-11T22:18:02.7172555Z Actual:
2019-11-11T22:18:02.7173551Z fn  main() -> () {
2019-11-11T22:18:02.7173816Z     let mut _0: ();
2019-11-11T22:18:02.7174219Z     let _1: usize;
2019-11-11T22:18:02.7174219Z     let _1: usize;
2019-11-11T22:18:02.7174366Z     let mut _2: *const i32;
2019-11-11T22:18:02.7174500Z     let mut _3: &i32;
2019-11-11T22:18:02.7174648Z     let mut _4: &i32;
2019-11-11T22:18:02.7175107Z     let _5: ();
2019-11-11T22:18:02.7175243Z     let mut _6: usize;
2019-11-11T22:18:02.7175392Z     scope 1 {
2019-11-11T22:18:02.7175839Z     bb0: {
2019-11-11T22:18:02.7176003Z         StorageLive(_1);
2019-11-11T22:18:02.7176126Z         StorageLive(_2);
2019-11-11T22:18:02.7176248Z         StorageLive(_3);
2019-11-11T22:18:02.7176248Z         StorageLive(_3);
2019-11-11T22:18:02.7176509Z         StorageLive(_4);
2019-11-11T22:18:02.7176712Z         _4 = const {pointer} : &i32;
2019-11-11T22:18:02.7176842Z         _3 = const {pointer} : &i32;
2019-11-11T22:18:02.7177107Z         _2 = const Scalar(AllocId(1).0x0) : *const i32;
2019-11-11T22:18:02.7177240Z         StorageDead(_3);
2019-11-11T22:18:02.7177383Z         _1 = move _2 as usize (Misc);
2019-11-11T22:18:02.7177515Z         StorageDead(_2);
2019-11-11T22:18:02.7177641Z         StorageDead(_4);
2019-11-11T22:18:02.7177780Z         StorageLive(_5);
2019-11-11T22:18:02.7177910Z         StorageLive(_6);
2019-11-11T22:18:02.7178037Z         _6 = _1;
2019-11-11T22:18:02.7178519Z         _5 = const read(move _6) -> bb1;
2019-11-11T22:18:02.7178840Z     bb1: {
2019-11-11T22:18:02.7178981Z         StorageDead(_6);
2019-11-11T22:18:02.7179113Z         StorageDead(_5);
2019-11-11T22:18:02.7179240Z         _0 = ();
2019-11-11T22:18:02.7179240Z         _0 = ();
2019-11-11T22:18:02.7179514Z         StorageDead(_1);
2019-11-11T22:18:02.7179652Z         return;
2019-11-11T22:18:02.7179782Z     }
2019-11-11T22:18:02.7179928Z     bb2 (cleanup): {
2019-11-11T22:18:02.7180061Z         resume;
2019-11-11T22:18:02.7180587Z }', src/tools/compiletest/src/runtest.rs:3308:13
2019-11-11T22:18:02.7180782Z note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace.
2019-11-11T22:18:02.7180907Z 
2019-11-11T22:18:02.7181041Z 
---
2019-11-11T22:18:02.7182598Z 
2019-11-11T22:18:02.7184090Z thread 'main' panicked at 'Some tests failed', src/tools/compiletest/src/main.rs:537:22
2019-11-11T22:18:02.7184930Z 
2019-11-11T22:18:02.7185215Z 
2019-11-11T22:18:02.7187169Z command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-tools-bin/compiletest" "--compile-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib" "--run-lib-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/lib/rustlib/x86_64-unknown-linux-gnu/lib" "--rustc-path" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage2/bin/rustc" "--src-base" "/checkout/src/test/mir-opt" "--build-base" "/checkout/obj/build/x86_64-unknown-linux-gnu/test/mir-opt" "--stage-id" "stage2-x86_64-unknown-linux-gnu" "--mode" "mir-opt" "--target" "x86_64-unknown-linux-gnu" "--host" "x86_64-unknown-linux-gnu" "--llvm-filecheck" "/usr/lib/llvm-6.0/bin/FileCheck" "--host-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--target-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/checkout/obj/build/x86_64-unknown-linux-gnu/native/rust-test-helpers" "--docck-python" "/usr/bin/python2.7" "--lldb-python" "/usr/bin/python2.7" "--gdb" "/usr/bin/gdb" "--quiet" "--llvm-version" "6.0.0\n" "--system-llvm" "--cc" "" "--cxx" "" "--cflags" "" "--llvm-components" "" "--llvm-cxxflags" "" "--adb-path" "adb" "--adb-test-dir" "/data/tmp/work" "--android-cross-path" "" "--color" "always"
2019-11-11T22:18:02.7187920Z 
2019-11-11T22:18:02.7188078Z 
2019-11-11T22:18:02.7189761Z failed to run: /checkout/obj/build/bootstrap/debug/bootstrap test
2019-11-11T22:18:02.7189949Z Build completed unsuccessfully in 1:06:32
2019-11-11T22:18:02.7189949Z Build completed unsuccessfully in 1:06:32
2019-11-11T22:18:02.7258884Z == clock drift check ==
2019-11-11T22:18:02.7276876Z   local time: Mon Nov 11 22:18:02 UTC 2019
2019-11-11T22:18:02.8907720Z   network time: Mon, 11 Nov 2019 22:18:02 GMT
2019-11-11T22:18:02.8912019Z == end clock drift check ==
2019-11-11T22:18:06.8087422Z 
2019-11-11T22:18:06.8188240Z ##[error]Bash exited with code '1'.
2019-11-11T22:18:06.8237010Z ##[section]Starting: Checkout
2019-11-11T22:18:06.8238875Z ==============================================================================
2019-11-11T22:18:06.8238923Z Task         : Get sources
2019-11-11T22:18:06.8238979Z Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.

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 @TimNN. (Feature Requests)

@RalfJung
Copy link
Member

That _2 looks like it's being printed by the fallback match arm, but it's not. It comes from somewhere else and I don't know where to begin to look.

The output itself is generated by Scalar's Debug implementation:

impl<Tag: fmt::Debug, Id: fmt::Debug> fmt::Debug for Scalar<Tag, Id> {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
match self {
Scalar::Ptr(ptr) =>
write!(f, "{:?}", ptr),
&Scalar::Raw { data, size } => {
Scalar::check_data(data, size);
if size == 0 {
write!(f, "<ZST>")
} else {
// Format as hex number wide enough to fit any value of the given `size`.
// So data=20, size=1 will be "0x14", but with size=4 it'll be "0x00000014".
write!(f, "0x{:>0width$x}", data, width=(size*2) as usize)
}
}
}
}
}

which calls Pointer's Debug:

impl<Tag: fmt::Debug, Id: fmt::Debug> fmt::Debug for Pointer<Tag, Id> {
default fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
write!(f, "{:?}.{:#x}[{:?}]", self.alloc_id, self.offset.bytes(), self.tag)
}
}

However, these should never end up being user-visible, they should be used only for Miri debugging (Miri has lots of trace! to figure out what is happening inside the engine).

p!(write("{:?} : ", ct.val), print(ct.ty))
}
// fallback
p!(write("{:?} : ", ct.val), print(ct.ty))
Copy link
Member

Choose a reason for hiding this comment

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

Ah, here you are using the Debug implementation of ConstValue. That's likely not what we want, it is called Debug for a reason. ;)

Copy link
Author

Choose a reason for hiding this comment

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

This is no different from the old fallback. I simply moved the block that tries to print slices and strings to happen before the big match statement, so that the new const ref arm we just added doesn't override strings and slices.

Copy link
Member

Choose a reason for hiding this comment

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

True. This was already bad before. I pointed this out because it might be related to your comment at #65859 (comment).

if you don't want to fix this in this PR, feel free to open an issue. We shouldn't use Debug for regular output such as error messages, IMO.

Copy link
Author

@iwikal iwikal Nov 15, 2019

Choose a reason for hiding this comment

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

I pointed this out because it might be related to your comment at #65859 (comment).

That's what I thought as well, but this is not the code path that causes that particular line in the mir-opt output. It comes from somewhere else, perhaps within miri itself. I don't feel confident making a decision about the fallback case, since I don't know what it affects, so I'll open an issue instead.

And since it won't be user facing, should I just bless this output and be done with it?

Copy link
Member

@RalfJung RalfJung Nov 15, 2019

Choose a reason for hiding this comment

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

Why is it not user-facing? Isn't this here used for the type mismatch errors that the PR updates?

I think I am confused about which change you are worried about. If this PR makes mir-opt fail, then please either fix that or update the mir-opt tests so that we can see in the diff what the changes are.

Copy link
Author

Choose a reason for hiding this comment

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

_4 = const {pointer} : &i32;
_3 = const {pointer} : &i32;
_2 = const Scalar(AllocId(1).0x0) : *const i32;

I saw this in the actual output from src/tests/mir-opt/const_prop/const_prop_fails_gracefully.rs, and thought I had introduced a bug, because a *const i32 should be covered by my changes, and be represented as {pointer} : *const i32.
So I updated the expected output to be this:

_4 = const {pointer} : &i32;
_3 = const {pointer} : &i32;
_2 = const {pointer} : *const i32;

And started trying to get that to happen. But if it's not critical that mir dumps are pretty, I will happily abandon that work. I've solved the merge conflicts and pushed a blessing.

@bors
Copy link
Contributor

bors commented Nov 14, 2019

☔ The latest upstream changes (presumably #66233) made this pull request unmergeable. Please resolve the merge conflicts.

@iwikal
Copy link
Author

iwikal commented Nov 16, 2019

I tried to add the or_patterns flag, but it says it's an incomplete feature and refuses to compile.

@varkor varkor added the F-const_generics `#![feature(const_generics)]` label Nov 16, 2019
(ConstValue::Scalar(_), ty::RawPtr(_)) => p!(write("{{pointer}}")),
(ConstValue::Scalar(value), ty::Ref(..)) |
(ConstValue::Scalar(value), ty::RawPtr(_)) => {
match value {
Copy link
Member

Choose a reason for hiding this comment

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

So this is a "fallback" case now, right? We already have a big case for references above. Unfortunately it is not immediately clear what distinguishes these cases.

Could you add some comments both at the if let ty::Ref above and at the match arm here describing why we do the matches we do in the order they are, and which various cases of references each conditional covers?

Copy link
Author

Choose a reason for hiding this comment

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

I don't know the history of that big if let ty::Ref statement or why it looks the way it does internally, so I don't feel comfortable documenting it. But I added a comment specifying that it needs to happen before the general case.

Copy link
Member

Choose a reason for hiding this comment

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

From what I can see, the point of that is to print the content of the slice/array when possible for types &[u8], [u8; N] and &str. Do you agree? If yes, please write that. Right now you only mention &str but that is not the only type handled here.

The fallback then is that for all other references and raw pointers, we just print the pointer value, not the thing it points to.

Comment on lines +27 to 28
// _3 = const {pointer} : &i32;
// _2 = const Value(Scalar(AllocId(1).0x0)) : *const i32;
Copy link
Member

@RalfJung RalfJung Nov 16, 2019

Choose a reason for hiding this comment

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

This is weirdly inconsistent between references and raw pointers. To be fair, it was also inconsistent before, but now the inconsistency is stronger.

Also @oli-obk @wesleywiser could you check these -Zdump-mir changes. This is a regression in terms of information content but I am not sure if anyone cares.

Copy link
Contributor

Choose a reason for hiding this comment

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

Mir dumps should probably dump the content of referenced allocations, like it dumps promoteds. Without showing alloc IDs this would be impossible to figure out though. I think mir dumps should keep dumping alloc ids

Copy link
Author

Choose a reason for hiding this comment

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

This is where I got stuck. I still haven't been able to chase down where this Debug print comes from. Maybe we should open another issue?

Copy link
Member

Choose a reason for hiding this comment

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

You are stuck trying to find out where the old printing for references came from, or the new one, or the one for raw pointers?

Copy link
Author

@iwikal iwikal Nov 16, 2019

Choose a reason for hiding this comment

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

The one for raw pointers. But with @oli-obk's comment in mind, maybe the opposite fix is more appropriate, replacing the new pretty printed references with a more verbose format? Either way it seems out of scope of this PR to me.

Copy link
Member

Choose a reason for hiding this comment

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

Well the PR changes behavior in an undesirable way when printing references, that part is in scope.

What is being debug-printed here is a ConstKind, I think. You could try removing the Debug impl for that and see where compilation fails.

Copy link
Author

Choose a reason for hiding this comment

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

Good idea, thanks!

| ^^^^^^^^^^^^^^ expected `$PREFIX0000000a : &()`, found `{pointer} : &()`
|
= note: expected type `Const<$PREFIX0000000a : &()>`
found type `Const<{pointer} : &()>`
Copy link
Member

Choose a reason for hiding this comment

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

FWIW, on current nightly this prints

   = note: expected type `Const<Scalar(0x000000000000000a) : &()>`
              found type `Const<Scalar(AllocId(9).0x0) : &()>`

So, yeah, the new output is much better. :D

It seems like right now the code is shared between printing this error and printing the mir-dump, and that is likely not what we want?

@iwikal
Copy link
Author

iwikal commented Nov 18, 2019

Sadly I have to admit this task is rising above my level of skill and familiarity with this codebase quicker than I can keep up with. Maybe I'll revisit this once I'm ready, if noone else has picked it up by then.

@bors
Copy link
Contributor

bors commented Nov 21, 2019

☔ The latest upstream changes (presumably #66389) made this pull request unmergeable. Please resolve the merge conflicts.

@JohnCSimon
Copy link
Member

Triage:
@iwikal - sorry to hear that. I'm going to close this PR now, but feel free to open it up again when you're ready.
Thank you!

@JohnCSimon JohnCSimon closed this Nov 29, 2019
@varkor
Copy link
Member

varkor commented Jan 6, 2020

@iwikal: if you wanted to pick this back up, and wanted more detailed advice about the parts you're finding tricky, feel free to ping me on Discord or Zulip!

@jyn514 jyn514 added S-blocked Status: Blocked on something else such as an RFC or other implementation work. and removed S-blocked-closed labels Mar 10, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
F-const_generics `#![feature(const_generics)]` S-blocked Status: Blocked on something else such as an RFC or other implementation work. S-waiting-on-author Status: This is awaiting some action (such as code changes or more information) from the author.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Improve pretty printing of const raw pointers