Aborting Panic on Jack host

[voidentente]

The default host on linux/dragonfly/freebsd/netbsd is alsa, but cpal also supports Jack. I wrote a little non-portable snippet that prefers jack if available, otherwise falls back to alsa. I've noticed that this results in an abort in kira when there is another process actively using alsa as host (this doesn't happen if the alsa client isn't sending anything though).

1. This aborts because it seems like the error callback passed to cpal can't unwind.
2. This panics because kira is writing errors into the ringbuffer faster than it pops them.
3. This errors because..? I don't know why. But it's probably StreamError::BackendSpecific, because it doesn't seem like kira handles this anywhere.

System

Arch Linux 6.13.1-arch2-1 pipewire 1:1.2.7-1 pipewire-audio 1:1.2.7-1 pipewire-alsa 1:1.2.7-1 pipewire-jack 1:1.2.7-1 pipewire-pulse 1:1.2.7-1 libpipewire 1:1.2.7-1

Reproducing?

fn main() {
    let host = cpal::host_from_id(cpal::HostId::Jack)
        .or_else(|_| cpal::host_from_id(cpal::HostId::Alsa))
        .unwrap();

    let device = host.default_output_device().unwrap();

    let _manager = AudioManager::<CpalBackend>::new(AudioManagerSettings {
        backend_settings: CpalBackendSettings {
            device: Some(device),
            ..Default::default()
        },
        ..Default::default()
    })
    .unwrap();

    thread::park();
}

Backtrace

thread '<unnamed>' panicked at /home/void/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/kira-0.10.3/src/backend/cpal/desktop/stream_manager.rs:152:22:
Stream error producer is full: Full(_)
stack backtrace:
   0:     0x5beaf8fd9ada - std::backtrace_rs::backtrace::libunwind::trace::ha054d7d4d7c78f06
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1:     0x5beaf8fd9ada - std::backtrace_rs::backtrace::trace_unsynchronized::h0dcb8ce11b23df94
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x5beaf8fd9ada - std::sys::backtrace::_print_fmt::hc630bcce9ccafe22
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:66:9
   3:     0x5beaf8fd9ada - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h47acb3ed35954013
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:39:26
   4:     0x5beaf9007763 - core::fmt::rt::Argument::fmt::h33093396512801af
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/fmt/rt.rs:177:76
   5:     0x5beaf9007763 - core::fmt::write::hf827e6afcc4ed99d
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/fmt/mod.rs:1437:21
   6:     0x5beaf8fd48d3 - std::io::Write::write_fmt::hf657bb22b5b09692
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/io/mod.rs:1887:15
   7:     0x5beaf8fd9922 - std::sys::backtrace::BacktraceLock::print::hda8908c817bf1aaa
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:42:9
   8:     0x5beaf8fdaaad - std::panicking::default_hook::{{closure}}::haede8f1849825240
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:284:22
   9:     0x5beaf8fda8f2 - std::panicking::default_hook::h848ae320493ee288
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:311:9
  10:     0x5beaf8fdb1f7 - std::panicking::rust_panic_with_hook::h008fcd15d56969f8
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:817:13
  11:     0x5beaf8fdaf7a - std::panicking::begin_panic_handler::{{closure}}::hccd4b0c0f87cc87f
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:690:13
  12:     0x5beaf8fd9fb9 - std::sys::backtrace::__rust_end_short_backtrace::h6b39b495cc66f143
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:168:18
  13:     0x5beaf8fdac0d - rust_begin_unwind
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:681:5
  14:     0x5beaf9004b20 - core::panicking::panic_fmt::h8bcb5214e28c3910
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/panicking.rs:75:14
  15:     0x5beaf9004ff6 - core::result::unwrap_failed::h679dd58ae42e4e7e
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/result.rs:1699:5
  16:     0x5beaf8a45f3f - core::result::Result<T,E>::expect::h399a1a3cc323c910
                               at /home/void/.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/result.rs:1061:23
  17:     0x5beaf8a49758 - kira::backend::cpal::desktop::stream_manager::StreamManager::start_stream::{{closure}}::hb5b9daeef5d2db8f
                               at /home/void/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/kira-0.10.3/src/backend/cpal/desktop/stream_manager.rs:150:5
  18:     0x5beaf8c4871f - <cpal::host::jack::stream::LocalProcessHandler as jack::client::callbacks::ProcessHandler>::buffer_size::hb4807d52ca2571d8
                               at /home/void/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/cpal-0.15.3/src/host/jack/stream.rs:391:17
  19:     0x5beaf8a2ad87 - jack::client::callbacks::buffer_size::h273275bf11c4b7be
                               at /home/void/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/jack-0.11.4/src/client/callbacks.rs:192:5
  20:     0x74e26e258580 - <unknown>
  21:     0x74e26df75f35 - <unknown>
  22:     0x74e26df78246 - <unknown>
  23:     0x74e26e1ffce7 - <unknown>
  24:     0x74e275c0970a - <unknown>
  25:     0x74e275c8daac - <unknown>
  26:                0x0 - <unknown>
thread '<unnamed>' panicked at library/core/src/panicking.rs:218:5:
panic in a function that cannot unwind
stack backtrace:
   0:     0x5beaf8fd9ada - std::backtrace_rs::backtrace::libunwind::trace::ha054d7d4d7c78f06
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/../../backtrace/src/backtrace/libunwind.rs:116:5
   1:     0x5beaf8fd9ada - std::backtrace_rs::backtrace::trace_unsynchronized::h0dcb8ce11b23df94
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x5beaf8fd9ada - std::sys::backtrace::_print_fmt::hc630bcce9ccafe22
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:66:9
   3:     0x5beaf8fd9ada - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h47acb3ed35954013
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:39:26
   4:     0x5beaf9007763 - core::fmt::rt::Argument::fmt::h33093396512801af
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/fmt/rt.rs:177:76
   5:     0x5beaf9007763 - core::fmt::write::hf827e6afcc4ed99d
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/fmt/mod.rs:1437:21
   6:     0x5beaf8fd48d3 - std::io::Write::write_fmt::hf657bb22b5b09692
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/io/mod.rs:1887:15
   7:     0x5beaf8fd9922 - std::sys::backtrace::BacktraceLock::print::hda8908c817bf1aaa
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:42:9
   8:     0x5beaf8fdaaad - std::panicking::default_hook::{{closure}}::haede8f1849825240
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:284:22
   9:     0x5beaf8fda8f2 - std::panicking::default_hook::h848ae320493ee288
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:311:9
  10:     0x5beaf8fdb1f7 - std::panicking::rust_panic_with_hook::h008fcd15d56969f8
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:817:13
  11:     0x5beaf8fdaf46 - std::panicking::begin_panic_handler::{{closure}}::hccd4b0c0f87cc87f
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:683:13
  12:     0x5beaf8fd9fb9 - std::sys::backtrace::__rust_end_short_backtrace::h6b39b495cc66f143
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/sys/backtrace.rs:168:18
  13:     0x5beaf8fdac0d - rust_begin_unwind
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/std/src/panicking.rs:681:5
  14:     0x5beaf9004b5d - core::panicking::panic_nounwind_fmt::runtime::hc261c02c3edb084b
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/panicking.rs:117:22
  15:     0x5beaf9004b5d - core::panicking::panic_nounwind_fmt::hbd6bdebf7750f466
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/intrinsics/mod.rs:3840:9
  16:     0x5beaf9004bf2 - core::panicking::panic_nounwind::hb19072faf800ff95
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/panicking.rs:218:5
  17:     0x5beaf9004db6 - core::panicking::panic_cannot_unwind::h834c768af1ccaedc
                               at /rustc/c26db435bf8aee2efc397aab50f3a21eb351d6e5/library/core/src/panicking.rs:307:5
  18:     0x5beaf8a2ad66 - jack::client::callbacks::buffer_size::h273275bf11c4b7be
                               at /home/void/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/jack-0.11.4/src/client/callbacks.rs:186:1
  19:     0x74e26e258580 - <unknown>
  20:     0x74e26df75f35 - <unknown>
  21:     0x74e26df78246 - <unknown>
  22:     0x74e26e1ffce7 - <unknown>
  23:     0x74e275c0970a - <unknown>
  24:     0x74e275c8daac - <unknown>
  25:                0x0 - <unknown>
thread caused non-unwinding panic. aborting.
Aborted (core dumped)

[voidentente]

I've forked kira and added a good old println to the error callback, it seems we get

A backend-specific error has occurred: buffer size changed to: 2048
A backend-specific error has occurred: buffer size changed to: 1024
A backend-specific error has occurred: buffer size changed to: 2048

in quick succession. That overflows the ringbuffer and aborts.

[tesselode]

I wrote that code with the assumption that a stream would stop after one error. What a fool I was!

Would it make sense to add a pop_error function to CpalBackend? The user should be able to see these somehow, even if they're not really errors, like the buffer size changing.

[voidentente]

Okay, so right now, Kira aborts if there's more than one error within 500 milliseconds, which is the poll interval of the stream manager.

Would it make sense to add a pop_error function to CpalBackend? The user should be able to see these somehow, even if they're not really errors, like the buffer size changing.

The question of adding a pop_error method would be a question of interface, when the underlying problem is one of transport. We need to get the errors out of the callback without panicking... what Kira does with it with from there is a different question.

IMO, apart from the "brute force approach" of simply giving the rb a higher capacity and the "quick fix" approach of simply discarding BackendSpecificError at the callback site, the only technically correct approach would be to change the channel to be growable, since the error rate is unpredictable. If it needs to allocate, so be it, we don't want to discard errors. That'd not be a problem on the stream manager side, but the error callback side could be a concern. HOWEVER, the error callback SHOULD be cold.

[voidentente]

BTW, I'd be available for a PR once a solution is settled on

[tesselode]

What do you mean by "the error callback should be cold"?

I'd be down to add a growable ringbuffer type if you can find a way to not allocate on the audio thread. Otherwise, I think it'll suffice to increase the ringbuffer size to 128 or so. If you're getting more than 128 errors every 500ms, something's horribly wrong and you should probably deal with the first 128 errors before worrying about the rest of them.

Go ahead and implement whatever solution you think is best! I'm not super opinionated on this because I haven't dealt with many errors from cpal.

[voidentente]

What do you mean by "the error callback should be cold"?

By that I mean it shouldn't be called often during "normal" operation, so it's not absolutely vital to have the error callback be lock-free and allocation-free.

So there's two options: Bounded transport (with any capacity) and any errors that don't fit are discarded (optionally with an atomic counter to track how many have been discarded), OR an unbounded transport with the risk of incurring stuttering at high error rates.

Edit: I'd personally prefer an unbounded channel, simply out of correctness. Should this in the future turn out to be problematic, this can always be reconsidered.

[voidentente]

PR open at #123, would be happy if you could take a look @tesselode