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

stacked-borrows very slow #1647

Closed
PSeitz opened this issue Dec 10, 2020 · 8 comments
Closed

stacked-borrows very slow #1647

PSeitz opened this issue Dec 10, 2020 · 8 comments

Comments

@PSeitz
Copy link

PSeitz commented Dec 10, 2020

Miri seems to hang in an endlessloop in a test case in my project:

https://github.com/PSeitz/lz4_flex
cargo miri test test_minimum_compression_ratio

...
│ │ ├─1643ms  INFO rustc_mir::interpret::step // executing bb9
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageDead(_28)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageDead(_27)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageDead(_23)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageDead(_22)
│ │ ├─1656ms  INFO rustc_mir::interpret::step switchInt(_21) -> [false: bb10, otherwise: bb11]
│ │ ├─1656ms  INFO rustc_mir::interpret::step // executing bb10
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_60)
│ │ ├─1656ms  INFO rustc_mir::interpret::step _60 = _11
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_61)
│ │ ├─1656ms  INFO rustc_mir::interpret::step _61 = _11
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_62)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_63)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_64)
│ │ ├─1656ms  INFO rustc_mir::interpret::step _64 = _11
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_65)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_66)
│ │ ├─1656ms  INFO rustc_mir::interpret::step StorageLive(_67)
│ │ ├─1656ms  INFO rustc_mir::interpret::step _67 = &(*_1)
│ │ ├─1656ms  INFO rustc_mir::interpret::step Retag(_67)
│ │ ├─1656ms  INFO rustc_mir::interpret::step _66 = core::slice::<impl [u8]>::len(move _67) -> bb20
│ │ ├┐rustc_mir::interpret::eval_context::frame std::str::pattern::TwoWaySearcher::new
│ │ │└┐rustc_mir::interpret::eval_context::frame core::slice::<impl [u8]>::len
│ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _1)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_2)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_3)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step _3 = &raw const (*_1)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([raw] _3)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step (_2.0: *const [T]) = move _3
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageDead(_3)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step _0 = ((_2.2: std::ptr::FatPtr<T>).1: usize)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageDead(_2)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step return
│ │ │ ├─0ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │┌┘rustc_mir::interpret::eval_context::frame core::slice::<impl [u8]>::len
│ │ ├┘rustc_mir::interpret::eval_context::frame std::str::pattern::TwoWaySearcher::new
│ │ ├─1657ms  INFO rustc_mir::interpret::step // executing bb20
│ │ ├─1657ms  INFO rustc_mir::interpret::step StorageDead(_67)
│ │ ├─1657ms  INFO rustc_mir::interpret::step StorageLive(_68)
│ │ ├─1657ms  INFO rustc_mir::interpret::step _68 = _11
│ │ ├─1657ms  INFO rustc_mir::interpret::step _69 = CheckedSub(_66, _68)
│ │ ├─1657ms  INFO rustc_mir::interpret::step assert(!move (_69.1: bool), "attempt to compute `{} - {}`, which would overflow", move _66, move _68) -> bb21
│ │ ├─1657ms  INFO rustc_mir::interpret::step // executing bb21
│ │ ├─1657ms  INFO rustc_mir::interpret::step _65 = move (_69.0: usize)
│ │ ├─1657ms  INFO rustc_mir::interpret::step StorageDead(_68)
│ │ ├─1657ms  INFO rustc_mir::interpret::step StorageDead(_66)
│ │ ├─1657ms  INFO rustc_mir::interpret::step _63 = std::cmp::max::<usize>(move _64, move _65) -> bb22
│ │ ├┐rustc_mir::interpret::eval_context::frame std::str::pattern::TwoWaySearcher::new
│ │ │└┐rustc_mir::interpret::eval_context::frame std::cmp::max::<usize>
│ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _1)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _2)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_3)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step _3 = move _1
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_3)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_4)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step _4 = move _2
│ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_4)
│ │ │ ├─0ms  INFO rustc_mir::interpret::step _0 = <T as std::cmp::Ord>::max(move _3, move _4) -> [return: bb1, unwind: bb2]
│ │ │ ├┐rustc_mir::interpret::eval_context::frame std::cmp::max::<usize>
│ │ │ │└┐rustc_mir::interpret::eval_context::frame <usize as std::cmp::Ord>::max
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _1)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _2)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_3)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _3 = move _1
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_3)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_4)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _4 = move _2
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_4)
│ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _0 = std::cmp::max_by::<Self, for<'r, 's> fn(&'r Self, &'s Self) -> std::cmp::Ordering {<Self as std::cmp::Ord>::cmp}>(move _3, move _4, <Self as std::cmp::Ord>::cmp) -> [return: bb1, unwind: bb2]
│ │ │ │ ├┐rustc_mir::interpret::eval_context::frame <usize as std::cmp::Ord>::max
│ │ │ │ │└┐rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _1)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _2)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _3)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _13 = const false
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _12 = const false
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _13 = const true
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _12 = const true
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_4)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_5)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _5 = move _3
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_5)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_6)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_7)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_8)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _8 = &_1
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_8)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _7 = &(*_8)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_7)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_9)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_10)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _10 = &_2
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_10)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _9 = &(*_10)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag(_9)
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step (_6.0: &T) = move _7
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step (_6.1: &T) = move _9
│ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _4 = <F as std::ops::FnOnce<(&T, &T)>>::call_once(move _5, move _6) -> [return: bb1, unwind: bb10]
│ │ │ │ │ ├┐rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ │ │└┐rustc_mir::interpret::eval_context::frame <for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp} as std::ops::FnOnce<(&usize, &usize)>>::call_once - shim(for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp})
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _0 = move _1(move (_2.0: &usize), move (_2.1: &usize)) -> bb1
│ │ │ │ │ │ ├┐rustc_mir::interpret::eval_context::frame <for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp} as std::ops::FnOnce<(&usize, &usize)>>::call_once - shim(for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp})
│ │ │ │ │ │ │└┐rustc_mir::interpret::eval_context::frame std::cmp::impls::<impl std::cmp::Ord for usize>::cmp
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _1)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step Retag([fn entry] _2)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_3)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_4)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _4 = (*_1)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageLive(_5)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _5 = (*_2)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step _3 = Lt(move _4, move _5)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageDead(_5)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageDead(_4)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step switchInt(_3) -> [false: bb1, otherwise: bb2]
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb2
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step discriminant(_0) = 0
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step goto -> bb6
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb6
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step StorageDead(_3)
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step return
│ │ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │ │┌┘rustc_mir::interpret::eval_context::frame std::cmp::impls::<impl std::cmp::Ord for usize>::cmp
│ │ │ │ │ │ ├┘rustc_mir::interpret::eval_context::frame <for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp} as std::ops::FnOnce<(&usize, &usize)>>::call_once - shim(for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp})
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb1
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step return
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │┌┘rustc_mir::interpret::eval_context::frame <for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp} as std::ops::FnOnce<(&usize, &usize)>>::call_once - shim(for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp})
│ │ │ │ │ ├┘rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step // executing bb1
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step StorageDead(_9)
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step StorageDead(_7)
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step StorageDead(_6)
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step StorageDead(_5)
│ │ │ │ │ ├─1ms  INFO rustc_mir::interpret::step _11 = discriminant(_4)
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step switchInt(move _11) -> [-1_isize: bb4, 0_isize: bb4, 1_isize: bb2, otherwise: bb3]
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step // executing bb4
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step _12 = const false
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step _0 = move _2
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step Retag(_0)
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step goto -> bb5
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step // executing bb5
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step StorageDead(_10)
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step StorageDead(_8)
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step StorageDead(_4)
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step switchInt(_12) -> [false: bb6, otherwise: bb13]
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step // executing bb6
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step switchInt(_13) -> [false: bb7, otherwise: bb14]
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step // executing bb14
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step drop(_1) -> [return: bb7, unwind: bb9]
│ │ │ │ │ ├┐rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ │ │└┐rustc_mir::interpret::eval_context::frame std::intrinsics::drop_in_place::<usize> - shim(None)
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step // executing bb0
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::step return
│ │ │ │ │ │ ├─0ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │ │┌┘rustc_mir::interpret::eval_context::frame std::intrinsics::drop_in_place::<usize> - shim(None)
│ │ │ │ │ ├┘rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step // executing bb7
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::step return
│ │ │ │ │ ├─2ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │ │ │┌┘rustc_mir::interpret::eval_context::frame std::cmp::max_by::<usize, for<'r, 's> fn(&'r usize, &'s usize) -> std::cmp::Ordering {<usize as std::cmp::Ord>::cmp}>
│ │ │ │ ├┘rustc_mir::interpret::eval_context::frame <usize as std::cmp::Ord>::max
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::step // executing bb1
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::step Retag(_0)
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::step StorageDead(_4)
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::step StorageDead(_3)
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::step return
│ │ │ │ ├─3ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │ │┌┘rustc_mir::interpret::eval_context::frame <usize as std::cmp::Ord>::max
│ │ │ ├┘rustc_mir::interpret::eval_context::frame std::cmp::max::<usize>
│ │ │ ├─3ms  INFO rustc_mir::interpret::step // executing bb1
│ │ │ ├─3ms  INFO rustc_mir::interpret::step Retag(_0)
│ │ │ ├─3ms  INFO rustc_mir::interpret::step StorageDead(_4)
│ │ │ ├─3ms  INFO rustc_mir::interpret::step StorageDead(_3)
│ │ │ ├─3ms  INFO rustc_mir::interpret::step return
│ │ │ ├─3ms  INFO rustc_mir::interpret::eval_context popping stack frame (returning from function)
│ │ │┌┘rustc_mir::interpret::eval_context::frame std::cmp::max::<usize>
│ │ ├┘rustc_mir::interpret::eval_context::frame std::str::pattern::TwoWaySearcher::new
│ │ ├─1661ms  INFO rustc_mir::interpret::step // executing bb22      <--------------------------- same as beginning?
│ │ ├─1661ms  INFO rustc_mir::interpret::step StorageDead(_65)
│ │ ├─1661ms  INFO rustc_mir::interpret::step StorageDead(_64)
│ │ ├─1661ms  INFO rustc_mir::interpret::step _70 = CheckedAdd(_63, const 1_usize)
│ │ ├─1661ms  INFO rustc_mir::interpret::step assert(!move (_70.1: bool), "attempt to compute `{} + {}`, which would overflow", move _63, const 1_usize) -> bb23
│ │ ├─1661ms  INFO rustc_mir::interpret::step // executing bb23
│ │ ├─1661ms  INFO rustc_mir::interpret::step _62 = move (_70.0: usize)
│ │ ├─1661ms  INFO rustc_mir::interpret::step StorageDead(_63)
│ │ ├─1661ms  INFO rustc_mir::interpret::step StorageLive(_71)
│ │ ├─1661ms  INFO rustc_mir::interpret::step StorageLive(_72)
│ │ ├─1661ms  INFO rustc_mir::interpret::step _72 = &(*_1)
│ │ ├─1662ms  INFO rustc_mir::interpret::step Retag(_72)
│ │ ├─1662ms  INFO rustc_mir::interpret::step _71 = std::str::pattern::TwoWaySearcher::byteset_create(move _72) -> bb24
...
@bjorn3
Copy link
Member

bjorn3 commented Dec 10, 2020

It is much more likely that miri is just extremely slow. How long does it take in debug mode when running without miri?

@PSeitz
Copy link
Author

PSeitz commented Dec 11, 2020

The test is quite fast, around 3ms. I let run Miri for about 30Minutes before cancelling.

@RalfJung
Copy link
Member

Is there any concurrency involved? This could be a case of #1388.

@PSeitz
Copy link
Author

PSeitz commented Dec 11, 2020

I saw that issue, but here is no concurrency involved. There is not much happening, just a compress and decompress in around 1000Lines.

@oli-obk
Copy link
Contributor

oli-obk commented Dec 11, 2020

can you do some println debugging by printing the progress of your program via stdout and check this way where the operations differ between host execution and miri interpretation? Maybe keep printing an increasing index whenever the algorithm consumes another input byte?

@PSeitz PSeitz changed the title Miri in endless loop Miri very slow Dec 11, 2020
@PSeitz
Copy link
Author

PSeitz commented Dec 11, 2020

Okay it seems, it is just getting slower and slower. I just saw it also eats slowly all my memory, after 30 minutes it is at 7GB.
Is this the expected behaviour? Looks like some datastructures need some improvement.

55 took 34.7547ms
77 took 8.5469ms
85 took 122.1346ms
145 took 119.6924ms
177 took 125.09ms
196 took 32.8803ms
...
1915 took 1674.229ms           
1935 took 1686.6371ms          
1942 took 1657.0463ms          
1947 took 1627.8635ms          
1951 took 1606.6062ms          
1955 took 1627.4969999999998ms 
1970 took 1636.5376ms          
1975 took 1690.1798ms          
1979 took 6.84s                
1990 took 13.40s               
....

3855 took 19.07s
3866 took 40.23s
3885 took 8.81s
3892 took 19.47s
3901 took 6.25s
3909 took 22.29s
3919 took 6.32s
3925 took 21.96s
3939 took 37.42s
3958 took 27.44s

@PSeitz PSeitz changed the title Miri very slow stacked-borrows very slow Dec 11, 2020
@PSeitz
Copy link
Author

PSeitz commented Dec 11, 2020

It is related to the stacked borrows check.
With "-Zmiri-disable-stacked-borrows" it does not degrade in performance

@oli-obk
Copy link
Contributor

oli-obk commented Dec 11, 2020

Ah, yes, unfortunately this is a known issue: #1367

I'll close this issue then, thanks for analyzing it.

@oli-obk oli-obk closed this as completed Dec 11, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants