Stack overflow on audio change

[mathstuf]

Not sure what's up here (backtrace below). I don't see repeating pointer values in the first few pages, so not obviously a refcycle. But, you can see that we're way deep in a call stack here. The Arc::drop_slow is the set of frames seen over and over.

#53678 0x00005642f4b1d23b in alloc::sync::Arc<T>::drop_slow (self=0x5642f52a9870) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:739
#53679 0x00005642f4b1dfd6 in <alloc::sync::Arc<T> as core::ops::drop::Drop>::drop (self=0x5642f52a9870) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:1249
#53680 0x00005642f4b27c0e in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53681 0x00005642f4b27ebe in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53682 0x00005642f4b29a79 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53683 0x00005642f4b28bce in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53684 0x00005642f4b28212 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53685 0x00005642f4b1d23b in alloc::sync::Arc<T>::drop_slow (self=0x5642f51bcee0) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:739
#53686 0x00005642f4b1dfd6 in <alloc::sync::Arc<T> as core::ops::drop::Drop>::drop (self=0x5642f51bcee0) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:1249
#53687 0x00005642f4b27c0e in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53688 0x00005642f4b27ebe in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53689 0x00005642f4b29a79 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53690 0x00005642f4b28bce in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53691 0x00005642f4b28212 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53692 0x00005642f4b1d23b in alloc::sync::Arc<T>::drop_slow (self=0x5642f539d668) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:739
#53693 0x00005642f4b1dfd6 in <alloc::sync::Arc<T> as core::ops::drop::Drop>::drop (self=0x5642f539d668) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/sync.rs:1249
#53694 0x00005642f4b27c0e in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53695 0x00005642f4b2a2b1 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53696 0x00005642f4b2b0da in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53697 0x00005642f4b29a11 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53698 0x00005642f4b29761 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53699 0x00005642f4b27ed1 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53700 0x00005642f4b2a851 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53701 0x00005642f4b28021 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53702 0x00005642f4b27ea1 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53703 0x00005642f4b291f1 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53704 0x00005642f4b748d8 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53705 0x00005642f4b2ab55 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53706 0x00005642f4b2a111 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53707 0x00005642f4b2a901 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53708 0x00005642f4b27e01 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53709 0x00005642f4b29d51 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53710 0x00005642f4b28a59 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53711 0x00005642f4b2b261 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53712 0x00005642f4b748d8 in core::ptr::drop_in_place () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ptr/mod.rs:174
#53713 0x00005642f4b7657d in <rodio::dynamic_mixer::DynamicMixer<S> as core::iter::traits::iterator::Iterator>::next (self=0x5642f523ba00) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/rodio-0.11.0/src/dynamic_mixer.rs:133
#53714 0x00005642f4b7072d in rodio::engine::audio_callback (engine=0x7f9499cceaf8, stream_id=..., buffer=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/rodio-0.11.0/src/engine.rs:95
#53715 0x00005642f4b71319 in <rodio::engine::play_raw::ENGINE as core::ops::deref::Deref>::deref::__static_ref_initialize::{{closure}}::{{closure}} (stream_id=..., buffer=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/rodio-0.11.0/src/engine.rs:42
#53716 0x00005642f4b6cd36 in <cpal::platform::platform_impl::EventLoop as cpal::traits::EventLoopTrait>::run::{{closure}} (id=..., result=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/cpal-0.11.0/src/platform/mod.rs:350
#53717 0x00005642f4b80ef7 in cpal::host::alsa::EventLoop::run_inner (self=0x5642f523b430, callback=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/cpal-0.11.0/src/host/alsa/mod.rs:702
#53718 0x00005642f4b6c5c8 in cpal::host::alsa::EventLoop::run (self=0x5642f523b430, callback=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/cpal-0.11.0/src/host/alsa/mod.rs:567
#53719 0x00005642f4b6ca11 in <cpal::host::alsa::EventLoop as cpal::traits::EventLoopTrait>::run (self=0x5642f523b430, callback=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/cpal-0.11.0/src/host/alsa/mod.rs:135
#53720 0x00005642f4b6cc35 in <cpal::platform::platform_impl::EventLoop as cpal::traits::EventLoopTrait>::run (self=0x5642f523b430, callback=...) at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/cpal-0.11.0/src/platform/mod.rs:348
#53721 0x00005642f4b713a9 in <rodio::engine::play_raw::ENGINE as core::ops::deref::Deref>::deref::__static_ref_initialize::{{closure}} () at /home/boeckb/.cargo/registry/src/github.com-1ecc6299db9ec823/rodio-0.11.0/src/engine.rs:40
#53722 0x00005642f4b6a3ce in std::sys_common::backtrace::__rust_begin_short_backtrace (f=...) at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/sys_common/backtrace.rs:129
#53723 0x00005642f4b7764f in std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}} () at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/thread/mod.rs:475
#53724 0x00005642f4b71464 in <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once (self=..., _args=()) at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/panic.rs:318
#53725 0x00005642f4b7780b in std::panicking::try::do_call (data=0x7f9499ccec18 " \264#\365BV\000") at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/panicking.rs:305
#53726 0x00005642f4ce3b77 in __rust_maybe_catch_panic ()
#53727 0x00005642f4b7773b in std::panicking::try (f=...) at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/panicking.rs:281
#53728 0x00005642f4b714c4 in std::panic::catch_unwind (f=...) at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/panic.rs:394
#53729 0x00005642f4b7745a in std::thread::Builder::spawn_unchecked::{{closure}} () at /builddir/build/BUILD/rustc-1.42.0-src/src/libstd/thread/mod.rs:474
#53730 0x00005642f4b742b4 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at /builddir/build/BUILD/rustc-1.42.0-src/src/libcore/ops/function.rs:232
#53731 0x00005642f4cd79ff in <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once ()
#53732 0x00005642f4ce3140 in std::sys::unix::thread::Thread::new::thread_start ()
#53733 0x00007f949aba14e2 in start_thread () from /lib64/libpthread.so.0
#53734 0x00007f949aab66d3 in clone () from /lib64/libc.so.6

The bottom of the stack is interesting as well:

#0  0x00007f949a9f1625 in raise () from /lib64/libc.so.6
#1  0x00007f949a9da8d9 in abort () from /lib64/libc.so.6
#2  0x00005642f4ce3687 in std::sys::unix::abort_internal ()
#3  0x00005642f4ce03a5 in std::sys_common::util::abort ()
#4  0x00005642f4ce2ac0 in std::sys::unix::stack_overflow::imp::signal_handler ()
#5  <signal handler called>
#6  0x00007f949aa3e332 in _int_free () from /lib64/libc.so.6
#7  0x00007f949aa408bc in free_check () from /lib64/libc.so.6
#8  0x00005642f4bddc43 in alloc::alloc::dealloc (ptr=0x5642f60a3700 "\333\377\247\374\265\377\241\373\322\377+\373\017\000", layout=...) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/alloc.rs:103
#9  0x00005642f4bdda2a in <alloc::alloc::Global as core::alloc::Alloc>::dealloc (self=0x5642f60a0778, ptr=..., layout=...) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/alloc.rs:174
#10 0x00005642f4c06c43 in alloc::raw_vec::RawVec<T,A>::dealloc_buffer (self=0x5642f60a0778) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/raw_vec.rs:709
#11 0x00005642f4c105df in <alloc::raw_vec::RawVec<T,A> as core::ops::drop::Drop>::drop (self=0x5642f60a0778) at /builddir/build/BUILD/rustc-1.42.0-src/src/liballoc/raw_vec.rs:719

That free_check makes me wonder if MALLOC_CHECK_=3 is involved here, but that only signals bugs elsewhere.

[mathstuf]

Oh, and the thread that crashes is:

thread 'rodio audio processing' has overflowed its stack

[mathstuf]

And unsetting MALLOC_CHECK_=3 doesn't help.

[mathstuf]

release builds are fine though. A lot of those stack frames are likely just inlined there.

[mathstuf]

Just happened with a release build as well.

[gridbugs]

Hi @mathstuf. I think I have a fix for this, but lack a reliable way to trigger the problem. Do you happen to know a way to reliably trigger it?

[mathstuf]

I've been seeing it with this app: https://github.com/mathstuf/music-rater

It's basically just a Pausable<Repeat<Decoder<BufReader<Box<Cursor<Vec>>>>>> that loops. If I let that go for "too long", switching to the next file ends up crashing.

[gridbugs]

Can you try running with this branch https://github.com/stevebob/rodio/tree/fix-frame-drop-stack-overflow and see the problem keeps happening?

[mathstuf]

Looks good so far (I'm back on the debug build since it happened much more easily there). I'll let you know tomorrow (as there seemed to be a hint of chance).

[mathstuf]

@stevebob So after quite a few instances of going through the actions when the crash would happen, I feel that patch fixes the problem. Thanks!

[est31]

#285 has been merged