mozilla / cubeb-coreaudio-rs

The audio backend of Firefox on Mac OS X.
ISC License
25 stars 10 forks source link

Hi assertion when running `sh run_device_tests.sh` #61

Open ChunMinChang opened 4 years ago

ChunMinChang commented 4 years ago

The assertion is hit when running sh run_device_tests.sh

Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/.cargo/registry/src/github.com-1ecc6299db9ec823/cubeb-sys-0.6.2/libcubeb/src/cubeb_resampler_internal.h, line 257.
warning: unused variable: `frames_written`
   --> src/backend/mod.rs:659:17
    |
659 |             let frames_written = stm.frames_written.load(Ordering::SeqCst);
    |                 ^^^^^^^^^^^^^^ help: consider prefixing with an underscore: `_frames_written`
    |
    = note: `#[warn(unused_variables)]` on by default

    Finished test [unoptimized + debuginfo] target(s) in 0.03s
     Running target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290

running 1 test
Device change callback. data @ 0x7fc48b000400
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/.cargo/registry/src/github.com-1ecc6299db9ec823/cubeb-sys-0.6.2/libcubeb/src/cubeb_resampler_internal.h, line 257.
error: test failed, to rerun pass '--lib'
padenot commented 4 years ago

It passes all the time here, what is your configuration? I have blackhole installed and that's about it, I'm on 10.15.

padenot commented 4 years ago

It also passes with my Focusrite Scarlett 6i6 first gen, aggregate, non aggregate, tweaking the various input and output sample-rates, etc. Can you repro this?

ChunMinChang commented 4 years ago

I cannot reproduce it today. Weird

I used builtin mic and speaker and soundflower. I am also on 10.15.

Rust version is rustc 1.43.0-nightly (2c462a2f7 2020-02-20)

ChunMinChang commented 4 years ago

I got some after running sh run_device_tests.sh many time, with built-in mic, on MacBook Pro 15 2017, in current branch ef5f58b

running 1 test
Device change callback. data @ 0x7fb990603560
test backend::tests::device_change::test_destroy_output_stream_after_unplugging_a_default_output_device ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 184 filtered out

    Finished test [unoptimized + debuginfo] target(s) in 0.03s
     Running target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290

running 1 test
Device change callback. data @ 0x7ff7d600b970
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/.cargo/registry/src/github.com-1ecc6299db9ec823/cubeb-sys-0.6.2/libcubeb/src/cubeb_resampler_internal.h, line 257.
error: test failed, to rerun pass '--lib'

Caused by:
  process didn't exit successfully: `/Users/cchang/Work/cubeb-coreaudio-rs/target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290 test_destroy_duplex_stream_after_unplugging_a_nondefault_input_device --ignored --nocapture` (signal: 6, SIGABRT: process abort signal)
    Finished test [unoptimized + debuginfo] target(s) in 0.03s
     Running target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290

running 1 test
Device change callback. data @ 0x7fb608a000b0
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/.cargo/registry/src/github.com-1ecc6299db9ec823/cubeb-sys-0.6.2/libcubeb/src/cubeb_resampler_internal.h, line 257.
error: test failed, to rerun pass '--lib'

Caused by:
  process didn't exit successfully: `/Users/cchang/Work/cubeb-coreaudio-rs/target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290 test_destroy_duplex_stream_after_unplugging_a_default_input_device --ignored --nocapture` (signal: 6, SIGABRT: process abort signal)
    Finished test [unoptimized + debuginfo] target(s) in 0.03s
     Running target/debug/deps/cubeb_coreaudio-0fc83ebf572ae290

running 1 test
Device change callback. data @ 0x7ffad5b0fdd0
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/.cargo/registry/src/github.com-1ecc6299db9ec823/cubeb-sys-0.6.2/libcubeb/src/cubeb_resampler_internal.h, line 257.
error: test failed, to rerun pass '--lib'
ChunMinChang commented 4 years ago

I printed the output_frame_count, out_len, and in_len when hitting that assertion.

output_frame_count: 558
in_len: 136
out_len: 148
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/Work/cubeb-rs/cubeb-sys/libcubeb/src/cubeb_resampler_internal.h, line 261.
error: test failed, to rerun pass '--lib'

when running test_destroy_output_stream_after_unplugging_a_default_output_device.

All the test_destroy_* or test_reinit_* can randomly cause this crash.

Full log for test_destroy_output_stream_after_unplugging_a_default_output_device

running 1 test
Device change callback. data @ 0x7ffc60300060
test backend::tests::device_change::test_destroy_output_stream_after_unplugging_a_default_output_device ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 184 filtered out

warning: unnecessary parentheses around assigned value
  --> /Users/cchang/Work/cubeb-rs/cubeb-sys/src/device.rs:30:5
   |
30 |     (CUBEB_DEVICE_FMT_S16LE | CUBEB_DEVICE_FMT_S16BE);
   |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ help: remove these parentheses
   |
   = note: `#[warn(unused_parens)]` on by default

warning: unnecessary parentheses around assigned value
  --> /Users/cchang/Work/cubeb-rs/cubeb-sys/src/device.rs:32:5
   |
32 |     (CUBEB_DEVICE_FMT_F32LE | CUBEB_DEVICE_FMT_F32BE);
   |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ help: remove these parentheses

warning: unnecessary parentheses around assigned value
  --> /Users/cchang/Work/cubeb-rs/cubeb-sys/src/device.rs:34:5
   |
34 |     (CUBEB_DEVICE_FMT_S16_MASK | CUBEB_DEVICE_FMT_F32_MASK);
   |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ help: remove these parentheses

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/device.rs:21:1
   |
21 |   /// Architecture specific sample type.
   |   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
22 | / bitflags! {
23 | |     pub struct DeviceFormat: ffi::cubeb_device_fmt {
24 | |         const S16LE = ffi::CUBEB_DEVICE_FMT_S16LE;
25 | |         const S16BE = ffi::CUBEB_DEVICE_FMT_S16BE;
...  |
28 | |     }
29 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = note: `#[warn(unused_doc_comments)]` on by default
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/device.rs:31:1
   |
31 | / /// Channel type for a `cubeb_stream`. Depending on the backend and platform
32 | | /// used, this can control inter-stream interruption, ducking, and volume
33 | | /// control.
   | |____________^
34 | / bitflags! {
35 | |     pub struct DevicePref: ffi::cubeb_device_pref {
36 | |         const NONE = ffi::CUBEB_DEVICE_PREF_NONE;
37 | |         const MULTIMEDIA = ffi::CUBEB_DEVICE_PREF_MULTIMEDIA;
...  |
41 | |     }
42 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/device.rs:44:1
   |
44 | / /// Whether a particular device is an input device (e.g. a microphone), or an
45 | | /// output device (e.g. headphones).
   | |____________________________________^
46 | / bitflags! {
47 | |     pub struct DeviceType: ffi::cubeb_device_type {
48 | |         const UNKNOWN = ffi::CUBEB_DEVICE_TYPE_UNKNOWN as _;
49 | |         const INPUT = ffi::CUBEB_DEVICE_TYPE_INPUT as _;
50 | |         const OUTPUT = ffi::CUBEB_DEVICE_TYPE_OUTPUT as _;
51 | |     }
52 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/device.rs:58:1
   |
58 |   /// Audio device description
   |   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
59 | / ffi_type_heap! {
60 | |     type CType = ffi::cubeb_device;
61 | |     #[derive(Debug)]
62 | |     pub struct Device;
63 | |     pub struct DeviceRef;
64 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
   --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/device.rs:94:1
    |
94  | / /// This structure holds the characteristics of an input or output
95  | | /// audio device. It is obtained using `enumerate_devices`, which
96  | | /// returns these structures via `device_collection` and must be
97  | | /// destroyed via `device_collection_destroy`.
    | |______________________________________________^
98  | / ffi_type_stack! {
99  | |     type CType = ffi::cubeb_device_info;
100 | |     pub struct DeviceInfo;
101 | |     pub struct DeviceInfoRef;
102 | | }
    | |_- rustdoc does not generate documentation for macro expansions
    |
    = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/stream.rs:48:1
   |
48 |   /// Miscellaneous stream preferences.
   |   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
49 | / bitflags! {
50 | |     pub struct StreamPrefs: ffi::cubeb_stream_prefs {
51 | |         const NONE = ffi::CUBEB_STREAM_PREF_NONE;
52 | |         const LOOPBACK = ffi::CUBEB_STREAM_PREF_LOOPBACK;
...  |
55 | |     }
56 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: unused doc comment
  --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/stream.rs:58:1
   |
58 |   /// Stream format initialization parameters.
   |   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
59 | / ffi_type_stack!{
60 | |     type CType = ffi::cubeb_stream_params;
61 | |     #[derive(Debug)]
62 | |     pub struct StreamParams;
63 | |     pub struct StreamParamsRef;
64 | | }
   | |_- rustdoc does not generate documentation for macro expansions
   |
   = help: to document an item produced by a macro, the macro must produce the documentation as part of its expansion

warning: use of deprecated item 'std::error::Error::description': use the Display impl or to_string()
   --> /Users/cchang/Work/cubeb-rs/cubeb-core/src/error.rs:104:30
    |
104 |         write!(f, "{}", self.description())
    |                              ^^^^^^^^^^^
    |
    = note: `#[warn(deprecated)]` on by default

    Finished test [unoptimized + debuginfo] target(s) in 0.05s
     Running target/debug/deps/cubeb_coreaudio-0d933446de2ad732

running 1 test
output_frame_count: 553
in_len: 512
out_len: 553
output_frame_count: 558
in_len: 520
out_len: 558
output_frame_count: 557
in_len: 524
out_len: 557
output_frame_count: 557
in_len: 528
out_len: 557
output_frame_count: 558
in_len: 532
out_len: 558
output_frame_count: 557
in_len: 536
out_len: 557
output_frame_count: 557
in_len: 540
out_len: 557
output_frame_count: 557
in_len: 544
out_len: 557
output_frame_count: 558
in_len: 548
out_len: 558
output_frame_count: 557
in_len: 552
out_len: 557
output_frame_count: 557
in_len: 556
out_len: 557
output_frame_count: 558
in_len: 560
out_len: 558
output_frame_count: 557
in_len: 564
out_len: 557
output_frame_count: 557
in_len: 568
out_len: 557
output_frame_count: 557
in_len: 572
out_len: 557
output_frame_count: 558
in_len: 576
out_len: 558
output_frame_count: 557
in_len: 580
out_len: 557
output_frame_count: 557
in_len: 584
out_len: 557
output_frame_count: 558
in_len: 588
out_len: 558
output_frame_count: 557
in_len: 592
out_len: 557
output_frame_count: 557
in_len: 596
out_len: 557
output_frame_count: 557
in_len: 600
out_len: 557
output_frame_count: 558
in_len: 604
out_len: 558
output_frame_count: 557
in_len: 608
out_len: 557
output_frame_count: 557
in_len: 612
out_len: 557
output_frame_count: 557
in_len: 616
out_len: 557
output_frame_count: 558
in_len: 620
out_len: 558
output_frame_count: 557
in_len: 624
out_len: 557
output_frame_count: 557
in_len: 628
out_len: 557
output_frame_count: 558
in_len: 632
out_len: 558
output_frame_count: 557
in_len: 636
out_len: 557
output_frame_count: 557
in_len: 640
out_len: 557
Device change callback. data @ 0x7fce8a50ff70
output_frame_count: 557
in_len: 644
out_len: 557
output_frame_count: 558
in_len: 136
out_len: 148
Assertion failed: (out_len == output_frame_count), function output, file /Users/cchang/Work/cubeb-rs/cubeb-sys/libcubeb/src/cubeb_resampler_internal.h, line 261.
error: test failed, to rerun pass '--lib'

Caused by:
  process didn't exit successfully: `/Users/cchang/Work/cubeb-coreaudio-rs/target/debug/deps/cubeb_coreaudio-0d933446de2ad732 test_destroy_duplex_stream_after_unplugging_a_nondefault_input_device --ignored --nocapture` (signal: 6, SIGABRT: process abort signal)

The diff to print the log is here:

diff --git a/src/cubeb_resampler_internal.h b/src/cubeb_resampler_internal.h
index fb69992..f687268 100644
--- a/src/cubeb_resampler_internal.h
+++ b/src/cubeb_resampler_internal.h
@@ -8,6 +8,7 @@
 #if !defined(CUBEB_RESAMPLER_INTERNAL)
 #define CUBEB_RESAMPLER_INTERNAL

+#include <cstdio>
 #include <cmath>
 #include <cassert>
 #include <algorithm>
@@ -248,12 +249,15 @@ public:
       resampling_out_buffer.reserve(frames_to_samples(output_frame_count));
     }

+    fprintf(stderr, "output_frame_count: %zu\n", output_frame_count);
     uint32_t in_len = samples_to_frames(resampling_in_buffer.length());
+    fprintf(stderr, "in_len: %d\n", in_len);
     uint32_t out_len = output_frame_count;

     speex_resample(resampling_in_buffer.data(), &in_len,
                    resampling_out_buffer.data(), &out_len);

+     fprintf(stderr, "out_len: %d\n", out_len);
     assert(out_len == output_frame_count);

     /* This shifts back any unresampled samples to the beginning of the input
ChunMinChang commented 4 years ago

All the test_destroy_* or test_reinit_* can randomly cause this crash.

Those tests are based on test_unplug_a_device_on_an_active_stream. It will create an aggregate device to simulate plugging a device and use it as the active device for a cubeb stream, then destroy it to simulate unplugging a device, while the stream is still running. So the device-reset and strea-reinit should happen in between.

padenot commented 4 years ago

I see. We get the device callback before that, so we should be able to prevent this.