Thread panic: Invalid range for Time fractional part.

[will3942]

I have received this panic a few times after running on Rodio's master commit d93b1f3

From my tracing I believe this may be related to seeking (https://github.com/RustAudio/rodio/blob/master/src/decoder/symphonia.rs#L180-L212)

thread '<unnamed>' panicked at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/symphonia-core-0.5.4/src/units.rs:197:9:
Invalid range for Time fractional part.
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread '<unnamed>' panicked at core/src/panicking.rs:221:5:
panic in a function that cannot unwind
stack backtrace:
   0:        0x105c8d6e0 - std::backtrace_rs::backtrace::libunwind::trace::h6285d60e8a2c022a
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1:        0x105c8d6e0 - std::backtrace_rs::backtrace::trace_unsynchronized::h21fc036d4b8dd7fe
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:        0x105c8d6e0 - std::sys::backtrace::_print_fmt::h69654d1f9cd065f2
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/sys/backtrace.rs:66:9
   3:        0x105c8d6e0 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h7adefaad4a31afc0
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/sys/backtrace.rs:39:26
   4:        0x105cae87c - core::fmt::rt::Argument::fmt::h42151196bb7af094
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/fmt/rt.rs:177:76
   5:        0x105cae87c - core::fmt::write::h381c0b0ce6ab972a
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/fmt/mod.rs:1186:21
   6:        0x105c895cc - std::io::Write::write_fmt::h75af97148630d8d3
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/io/mod.rs:1839:15
   7:        0x105c8d594 - std::sys::backtrace::BacktraceLock::print::h8baf33e22611de71
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/sys/backtrace.rs:42:9
   8:        0x105c8e654 - std::panicking::default_hook::{{closure}}::h369c7295ef58c5b1
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/panicking.rs:268:22
   9:        0x105c8e498 - std::panicking::default_hook::h50746358288a9d6a
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/panicking.rs:295:9
  10:        0x105c8ee08 - std::panicking::rust_panic_with_hook::h7d795911432661cb
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/panicking.rs:801:13
  11:        0x105c8ea94 - std::panicking::begin_panic_handler::{{closure}}::h36f15310ecbde379
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/panicking.rs:667:13
  12:        0x105c8dba4 - std::sys::backtrace::__rust_end_short_backtrace::heed121414170e0c7
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/sys/backtrace.rs:170:18
  13:        0x105c8e774 - rust_begin_unwind
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/std/src/panicking.rs:665:5
  14:        0x105cf5828 - core::panicking::panic_nounwind_fmt::runtime::h5272f45982e012a1
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/panicking.rs:112:18
  15:        0x105cf5828 - core::panicking::panic_nounwind_fmt::h5d86a478a9d7437c
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/panicking.rs:122:5
  16:        0x105cf58a0 - core::panicking::panic_nounwind::he171ad52d328e60b
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/panicking.rs:221:5
  17:        0x105cf5a18 - core::panicking::panic_cannot_unwind::h2dd8cd735765e065
                               at /rustc/90b35a6239c3d8bdabc530a6a0816f7ff89a0aaf/library/core/src/panicking.rs:310:5
  18:        0x10555d7d4 - coreaudio::audio_unit::render_callback::input_proc::h141ae8fd5e747250
                               at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/coreaudio-rs-0.11.3/src/audio_unit/render_callback.rs:758:1
  19:        0x166d8e8dc - _DefaultOutputAUFactory
  20:        0x166e8d9dc - _AUNotQuiteSoSimpleTimeFactory
  21:        0x166d92c88 - _AUGenericOutputFactory
  22:        0x18d2e973c - <unknown>
  23:        0x18d2e6bf0 - <unknown>
  24:        0x18d465f2c - <unknown>
  25:        0x18aac6034 - __pthread_joiner_wake

[will3942]

More detailed trace:

thread '<unnamed>' panicked at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/symphonia-core-0.5.4/src/units.rs:197:9:
Invalid range for Time fractional part.
stack backtrace:
   0: std::panicking::begin_panic
             at /Users/willevans/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/std/src/panicking.rs:737:5
   1: symphonia_core::units::TimeBase::calc_timestamp
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/symphonia-core-0.5.4/src/units.rs:197:9
   2: <symphonia_bundle_mp3::demuxer::MpaReader as symphonia_core::formats::FormatReader>::seek
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/symphonia-bundle-mp3-0.5.4/src/demuxer.rs:239:21
   3: <rodio::decoder::symphonia::SymphoniaDecoder as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/decoder/symphonia.rs:197:24
   4: rodio::decoder::DecoderImpl<R>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/decoder/mod.rs:191:47
   5: <rodio::decoder::Decoder<R> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/decoder/mod.rs:444:9
   6: <alloc::boxed::Box<dyn rodio::source::Source+Item = S+core::marker::Send> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/mod.rs:688:17
   7: <rodio::source::position::TrackPosition<I> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/position.rs:149:22
   8: <rodio::source::channel_volume::ChannelVolume<I> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/channel_volume.rs:153:9
   9: <rodio::source::periodic::PeriodicAccess<I,F> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/periodic.rs:125:9
  10: <desktop::done_callback::DoneCallback<I> as rodio::source::Source>::try_seek
             at ./src/done_callback.rs:93:9
  11: <rodio::source::position::TrackPosition<I> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/position.rs:149:22
  12: <rodio::source::pausable::Pausable<I> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/pausable.rs:129:9
  13: <rodio::source::amplify::Amplify<I> as rodio::source::Source>::try_seek
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/amplify.rs:101:9
  14: desktop::single_source_sink::SeekOrder::attempt
             at ./src/single_source_sink.rs:131:15
  15: desktop::single_source_sink::SourceControl::new::{{closure}}
             at ./src/single_source_sink.rs:193:11
  16: <rodio::source::periodic::PeriodicAccess<I,F> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/periodic.rs:84:13
  17: <rodio::source::samples_converter::SamplesConverter<I,D> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/samples_converter.rs:57:9
  18: <rodio::source::done::Done<I> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/done.rs:57:20
  19: <rodio::source::uniform::Take<I> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/uniform.rs:180:17
  20: <rodio::conversions::sample_rate::SampleRateConverter<I> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/conversions/sample_rate.rs:132:20
  21: <rodio::conversions::channels::ChannelCountConverter<I> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/conversions/channels.rs:65:29
  22: <rodio::conversions::sample::DataConverter<I,O> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/conversions/sample.rs:44:9
  23: <rodio::source::uniform::UniformSourceIterator<I,D> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/source/uniform.rs:88:30
  24: <alloc::boxed::Box<I,A> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/alloc/src/boxed.rs:2388:9
  25: rodio::mixer::MixerSource<S>::sum_current_sources
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/mixer.rs:203:34
  26: <rodio::mixer::MixerSource<S> as core::iter::traits::iterator::Iterator>::next
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/mixer.rs:158:19
  27: rodio::stream::OutputStream::init_stream::{{closure}}::{{closure}}
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/stream.rs:338:44
  28: <core::slice::iter::IterMut<T> as core::iter::traits::iterator::Iterator>::for_each
             at /Users/willevans/.rustup/toolchains/stable-aarch64-apple-darwin/lib/rustlib/src/rust/library/core/src/slice/iter/macros.rs:254:21
  29: rodio::stream::OutputStream::init_stream::{{closure}}
             at /Users/willevans/.cargo/git/checkouts/rodio-6458f6e95b054746/d93b1f3/src/stream.rs:337:21
  30: cpal::traits::DeviceTrait::build_output_stream::{{closure}}
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/cpal-0.15.3/src/traits.rs:169:17
  31: cpal::host::coreaudio::macos::Device::build_output_stream_raw::{{closure}}
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/cpal-0.15.3/src/host/coreaudio/macos/mod.rs:708:13
  32: coreaudio::audio_unit::render_callback::<impl coreaudio::audio_unit::AudioUnit>::set_render_callback::{{closure}}
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/coreaudio-rs-0.11.3/src/audio_unit/render_callback.rs:502:19
  33: coreaudio::audio_unit::render_callback::input_proc
             at /Users/willevans/.cargo/registry/src/index.crates.io-6f17d22bba15001f/coreaudio-rs-0.11.3/src/audio_unit/render_callback.rs:768:9
  34: _DefaultOutputAUFactory
  35: _AUNotQuiteSoSimpleTimeFactory
  36: _AUGenericOutputFactory
  37: <unknown>
  38: <unknown>
  39: <unknown>
  40: __pthread_joiner_wake
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

[dvdsk]

Anyway you can reproduce this? If not try sprinkeling some dbg! around that area you linked, specifically the time might be useful. Once we get it reproducing we can try to adjust one of the symphonia examples to reproduce it. If that succeeds we know its an upstream symphonia issue and we can give their maintainer a good solid starting point for tackling it.

[will3942]

@dvdsk yes - reproducible test here:

#[test]
    fn test_overseek() {
        let asset = Path::new("assets/test-bad-seek").with_extension("mp3");
        let file = std::fs::File::open(asset).unwrap();
        let mut decoder = crate::Decoder::new(BufReader::new(file)).unwrap();

        let res = decoder.try_seek(Duration::from_secs_f32(357.485));

        assert!(res.is_ok(), "err: {res:?}");
    }

mp3 attached (as zip to allow upload)

test-bad-seek.mp3.zip

[will3942]

It seems like this is upstream as Rodio correctly trims the seek duration to the EOF but Symphonia throws at an EOF seek.

On v0.20.1 of Rodio I get the error "Err(SymphoniaDecoder(Refining(IoError(Custom { kind: UnexpectedEof, error: "end of stream" }))))" and the thread does not panic. Interestingly total_duration().as_millis() is also reported as "194294" rather than "190000" on master.

[will3942]

I believe there is also a bug in Rodio's seek where in skip_back_a_tiny_bit - if frac is passed in as 0.0 then it becomes 1.0001 which is outside of the 0.0 to 1.0 bounds that Symphonia defines here

[will3942]

I believe there is also a bug in Rodio's seek where in skip_back_a_tiny_bit - if frac is passed in as 0.0 then it becomes 1.0001 which is outside of the 0.0 to 1.0 bounds that Symphonia defines here

I've fixed this specific issue in this PR here - it was a sneaky issue where we subtracted a negative value rather than adding.

Edit - this actually fixes the whole issue. The issue was we were not handling durations that were whole numbers with no fractional component correctly. Will add a test to that PR that demonstrates this to avoid any regressions.

[dvdsk]

this got fixed in #697