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

Make it possible to hide certain functions in MIRI_LOG output #3349

Open
RalfJung opened this issue Mar 3, 2024 · 0 comments
Open

Make it possible to hide certain functions in MIRI_LOG output #3349

RalfJung opened this issue Mar 3, 2024 · 0 comments
Labels
A-diagnostics errors and warnings emitted by miri C-enhancement Category: a PR with an enhancement or an issue tracking an accepted enhancement

Comments

@RalfJung
Copy link
Member

RalfJung commented Mar 3, 2024

MIRI_LOG output is excessively verbose. This is what a single call to is_null looks like:

│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step _0 = std::ptr::mut_ptr::<impl *mut T>::is_null::runtime_impl(move (_2.0: *mut u8)) -> [return: bb1, unwind continue]
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┐rustc_const_eval::interpret::eval_context::frame std::ptr::mut_ptr::<impl *mut T>::is_null::runtime_impl
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step // executing bb0
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step _3 = _1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step _2 = std::ptr::mut_ptr::<impl *mut u8>::addr(move _3) -> [return: bb1, unwind continue]
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┐rustc_const_eval::interpret::eval_context::frame std::ptr::mut_ptr::<impl *mut u8>::addr
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step // executing bb0
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step _3 = _1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step _2 = std::ptr::mut_ptr::<impl *mut T>::cast::<()>(move _3) -> [return: bb1, unwind continue]
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┐rustc_const_eval::interpret::eval_context::frame std::ptr::mut_ptr::<impl *mut u8>::cast::<()>
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step // executing bb0
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step StorageLive(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  0ms INFO rustc_const_eval::interpret::step _3 = _1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step _2 = move _3 as *mut U (PtrToPtr)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step _0 = _2
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step StorageDead(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step StorageDead(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::step return
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  1ms INFO rustc_const_eval::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  2ms INFO miri::machine Leaving std::ptr::mut_ptr::<impl *mut u8>::cast::<()>
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┘
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  3ms INFO miri::machine Continuing in std::ptr::mut_ptr::<impl *mut u8>::addr
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  3ms INFO rustc_const_eval::interpret::step // executing bb1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  3ms INFO rustc_const_eval::interpret::step StorageDead(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  4ms INFO rustc_const_eval::interpret::step _0 = move _2 as usize (Transmute)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  4ms INFO rustc_const_eval::interpret::step StorageDead(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  4ms INFO rustc_const_eval::interpret::step return
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  4ms INFO rustc_const_eval::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  4ms INFO miri::machine Leaving std::ptr::mut_ptr::<impl *mut u8>::addr
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┘
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  6ms INFO miri::machine Continuing in std::ptr::mut_ptr::<impl *mut T>::is_null::runtime_impl
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  6ms INFO rustc_const_eval::interpret::step // executing bb1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  6ms INFO rustc_const_eval::interpret::step StorageDead(_3)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  6ms INFO rustc_const_eval::interpret::step _0 = Eq(move _2, const 0_usize)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  6ms INFO rustc_const_eval::interpret::step StorageDead(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  7ms INFO rustc_const_eval::interpret::step return
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  7ms INFO rustc_const_eval::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  7ms INFO miri::machine Leaving std::ptr::mut_ptr::<impl *mut T>::is_null::runtime_impl
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─┘
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  9ms INFO miri::machine Continuing in std::ptr::mut_ptr::<impl *mut std::sys::locks::rwlock::queue::Node>::is_null
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─  9ms INFO rustc_const_eval::interpret::step // executing bb1
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─ 10ms INFO rustc_const_eval::interpret::step StorageDead(_2)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─ 10ms INFO rustc_const_eval::interpret::step return
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─ 10ms INFO rustc_const_eval::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ │ ├─ 10ms INFO miri::machine Leaving std::ptr::mut_ptr::<impl *mut std::sys::locks::rwlock::queue::Node>::is_null

There should be some way to not trace certain functions, or to only trace certain functions.

Maybe using tracing is the wrong approach to begin with... given our trouble with concurrency, maybe we need our own little ad-hoc logging thing.

@RalfJung RalfJung added C-enhancement Category: a PR with an enhancement or an issue tracking an accepted enhancement A-diagnostics errors and warnings emitted by miri labels May 3, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-diagnostics errors and warnings emitted by miri C-enhancement Category: a PR with an enhancement or an issue tracking an accepted enhancement
Projects
None yet
Development

No branches or pull requests

1 participant