search

breakfastquay / rubberband

Official mirror of Rubber Band Library, an audio time-stretching and pitch-shifting library.
http://breakfastquay.com/rubberband/
GNU General Public License v2.0
561 stars 89 forks source link

Stretcher test times out on i686 (at least when CPU also supports x86_64) #87

Closed triallax closed 1 year ago

triallax commented 1 year ago

I'm working to bump rubberband in Void Linux's repos to 3.2.1, but I'm facing an issue where the "Stretcher" test times out on i686 on an x86_64 CPU. Compiling to and running the tests on x86_64 work fine. I've confirmed this on two separate laptops, and it also happens on GitHub's CI. I combed through the GitHub and Sourcehut issue trackers but failed to find any similar reports.

Here are the full xbps-src logs:

xbps-src logs ``` => xbps-src: updating repositories for host (i686)... [*] Updating repository `https://repo-default.voidlinux.org/current/bootstrap/i686-repodata' ... [*] Updating repository `https://repo-default.voidlinux.org/current/i686-repodata' ... [*] Updating repository `https://repo-default.voidlinux.org/current/nonfree/i686-repodata' ... [*] Updating repository `https://repo-default.voidlinux.org/current/debug/i686-repodata' ... => xbps-src: updating software in / masterdir... => xbps-src: cleaning up / masterdir... => rubberband-3.2.1_1: removing autodeps, please wait... => rubberband-3.2.1_1: building with [meson] for i686... [host] pkg-config-0.29.2_3: found (https://repo-default.voidlinux.org/current) [host] meson-1.1.0_1: found (https://repo-default.voidlinux.org/current) [check] boost-devel-1.82.0_1: found (https://repo-default.voidlinux.org/current) [target] ladspa-sdk-1.15_3: found (https://repo-default.voidlinux.org/current) [target] libsamplerate-devel-0.2.2_1: found (https://repo-default.voidlinux.org/current) [target] vamp-plugin-sdk-devel-2.10.0_1: found (https://repo-default.voidlinux.org/current) [target] fftw-devel-3.3.10_1: found (https://repo-default.voidlinux.org/current) [target] lv2-1.18.2_1: found (https://repo-default.voidlinux.org/current) [runtime] libvamp-plugin-sdk-2.10.0_1: found (https://repo-default.voidlinux.org/current) [runtime] libvamp-plugin-sdk-2.10.0_1: found (https://repo-default.voidlinux.org/current) [runtime] librubberband-3.2.1_1: not found (subpkg, ignored) => rubberband-3.2.1_1: installing host dependencies: pkg-config-0.29.2_3 meson-1.1.0_1 boost-devel-1.82.0_1 ... => rubberband-3.2.1_1: installing target dependencies: ladspa-sdk-1.15_3 libsamplerate-devel-0.2.2_1 vamp-plugin-sdk-devel-2.10.0_1 fftw-devel-3.3.10_1 lv2-1.18.2_1 ... => rubberband-3.2.1_1: running do-fetch hook: 00-distfiles ... => rubberband-3.2.1_1: running do-extract hook: 00-distfiles ... => rubberband-3.2.1_1: extracting distfile(s), please wait... => rubberband-3.2.1_1: running do_patch ... => rubberband-3.2.1_1: running do-patch hook: 00-patches ... => rubberband-3.2.1_1: running pre-configure hook: 00-gnu-configure-asneeded ... => rubberband-3.2.1_1: running pre-configure hook: 01-override-config ... => rubberband-3.2.1_1: running pre-configure hook: 02-script-wrapper ... => rubberband-3.2.1_1: running do_configure ... The Meson build system Version: 1.1.0 Source dir: /builddir/rubberband-3.2.1 Build dir: /builddir/rubberband-3.2.1/build Build type: native build Project name: Rubber Band Library Project version: 3.2.1 C compiler for the host machine: cc (gcc 12.2.0 "cc (GCC) 12.2.0") C linker for the host machine: cc ld.bfd 2.39 C++ compiler for the host machine: g++ (gcc 12.2.0 "g++ (GCC) 12.2.0") C++ linker for the host machine: g++ ld.bfd 2.39 Host machine cpu family: x86 Host machine cpu: i686 Found pkg-config: /usr/bin/pkg-config (0.29.2) Run-time dependency fftw3 found: YES 3.3.10 Did not find CMake 'cmake' Found CMake: NO Run-time dependency sleef found: NO (tried pkgconfig and cmake) Run-time dependency sleefdft found: NO (tried pkgconfig and cmake) Run-time dependency samplerate found: YES 0.2.2 Run-time dependency speexdsp found: NO (tried pkgconfig and cmake) Run-time dependency sndfile found: YES 1.2.0 Run-time dependency vamp-sdk found: YES 2.10 Run-time dependency Boost (found: unit_test_framework) found: YES 1.82.0 (/usr) Run-time dependency threads found: YES Has header "ladspa.h" : YES Has header "lv2.h" : YES Checking for function "sincos" : YES Compiler for language java for the build machine not found. Compiler for language java for the host machine not found. Message: For FFT: using built-in implementation Message: (to use FFTW instead, reconfigure with -Dfft=fftw) Message: For resampler: using built-in implementation Message: (to use libsamplerate instead, reconfigure with -Dresampler=libsamplerate) Message: Will build Rubber Band Library static library Message: Will build Rubber Band Library dynamic library Message: Not building Java Native Interface: Java compiler or archiver missing Message: Will build LADSPA plugin Message: Will build LV2 plugin Message: Will build Vamp plugin Message: Will build command-line utilities Message: Will build unit tests: use "meson test -C " to run them Build targets in project: 9 Rubber Band Library 3.2.1 Directories prefix : /usr bindir : bin libdir : lib32 datadir : share Configuration FFT : Built-in Resampler : Built-in Build type : Debug Architecture : x86 Build targets Static library : YES Name: rubberband Dynamic library : YES Name: rubberband JNI library : NO LADSPA plugin : YES Name: ladspa-rubberband LV2 plugin : YES Name: lv2-rubberband Vamp plugin : YES Name: vamp-rubberband Command-line utility (R2): YES Name: rubberband Command-line utility (R3): YES Name: rubberband-r3 Unit tests : YES Name: tests User defined options auto_features : auto bindir : /usr/bin buildtype : plain datadir : /usr/share includedir : /usr/include infodir : /usr/share/info libdir : /usr/lib32 libexecdir : /usr/libexec localedir : /usr/share/locale localstatedir : /var mandir : /usr/share/man prefix : /usr sbindir : /usr/bin sharedstatedir : /var/lib sysconfdir : /etc wrap_mode : nodownload b_lto : true b_ndebug : true b_staticpic : true tests : enabled Found ninja-1.11.1 at /usr/bin/ninja => rubberband-3.2.1_1: running pre-build hook: 02-script-wrapper ... => rubberband-3.2.1_1: running do_build ... ninja: Entering directory `build' [1/46] Compiling C++ object librubberband_objlib.a.p/src_rubberband-c.cpp.o [2/46] Compiling C++ object librubberband_objlib.a.p/src_RubberBandStretcher.cpp.o [3/46] Compiling C++ object librubberband_objlib.a.p/src_faster_AudioCurveCalculator.cpp.o [4/46] Compiling C++ object librubberband_objlib.a.p/src_faster_HighFrequencyAudioCurve.cpp.o [5/46] Compiling C++ object librubberband_objlib.a.p/src_faster_SilentAudioCurve.cpp.o [6/46] Compiling C++ object librubberband_objlib.a.p/src_faster_CompoundAudioCurve.cpp.o [7/46] Compiling C++ object librubberband_objlib.a.p/src_faster_PercussiveAudioCurve.cpp.o [8/46] Compiling C++ object librubberband_objlib.a.p/src_faster_StretcherChannelData.cpp.o [9/46] Compiling C++ object librubberband_objlib.a.p/src_faster_R2Stretcher.cpp.o [10/46] Compiling C++ object librubberband_objlib.a.p/src_common_Allocators.cpp.o [11/46] Compiling C++ object librubberband_objlib.a.p/src_faster_StretcherProcess.cpp.o [12/46] Compiling C++ object librubberband_objlib.a.p/src_common_FFT.cpp.o [13/46] Compiling C++ object librubberband_objlib.a.p/src_common_Log.cpp.o [14/46] Compiling C++ object librubberband_objlib.a.p/src_common_Profiler.cpp.o [15/46] Compiling C++ object librubberband_objlib.a.p/src_common_Resampler.cpp.o [16/46] Compiling C++ object librubberband_objlib.a.p/src_common_sysutils.cpp.o [17/46] Compiling C++ object librubberband_objlib.a.p/src_common_mathmisc.cpp.o [18/46] Compiling C++ object librubberband_objlib.a.p/src_common_StretchCalculator.cpp.o [19/46] Compiling C++ object librubberband_objlib.a.p/src_common_Thread.cpp.o [20/46] Compiling C++ object librubberband_objlib.a.p/src_common_BQResampler.cpp.o [21/46] Compiling C++ object ladspa-rubberband.so.p/ladspa-lv2_libmain-ladspa.cpp.o [22/46] Compiling C++ object librubberband_objlib.a.p/src_finer_R3Stretcher.cpp.o [23/46] Linking static target librubberband_objlib.a [24/46] Compiling C++ object lv2-rubberband.so.p/ladspa-lv2_libmain-lv2.cpp.o [25/46] Linking static target librubberband.a [26/46] Linking target librubberband.so.2.2.4 [27/46] Linking target ladspa-rubberband.so [28/46] Compiling C++ object vamp-rubberband.so.p/vamp_RubberBandVampPlugin.cpp.o [29/46] Compiling C++ object vamp-rubberband.so.p/vamp_libmain.cpp.o [30/46] Linking target lv2-rubberband.so [31/46] Compiling C++ object rubberband.p/main_main.cpp.o [32/46] Linking target vamp-rubberband.so [33/46] Compiling C++ object rubberband-r3.p/main_main.cpp.o [34/46] Linking target rubberband [35/46] Linking target rubberband-r3 [36/46] Compiling C++ object tests.p/src_test_TestAllocators.cpp.o [37/46] Compiling C++ object tests.p/src_test_TestResampler.cpp.o [38/46] Compiling C++ object tests.p/src_test_TestFFT.cpp.o [39/46] Compiling C++ object tests.p/src_test_TestVectorOpsComplex.cpp.o [40/46] Compiling C++ object tests.p/src_test_TestVectorOps.cpp.o [41/46] Compiling C++ object tests.p/src_test_TestSignalBits.cpp.o [42/46] Compiling C++ object tests.p/src_test_TestStretchCalculator.cpp.o [43/46] Compiling C++ object tests.p/src_test_TestStretcher.cpp.o [44/46] Compiling C++ object tests.p/src_test_TestBinClassifier.cpp.o [45/46] Compiling C++ object tests.p/src_test_test.cpp.o [46/46] Linking target tests => rubberband-3.2.1_1: running do_check ... ninja: Entering directory `build' [0/1] Running all tests. 1/8 Allocators OK 0.04s 2/8 VectorOps OK 0.04s 3/8 VectorOpsComplex OK 0.03s 4/8 SignalBits OK 0.03s 5/8 FFT OK 0.10s 6/8 StretchCalculator OK 0.03s 7/8 Resampler OK 0.29s Stretcher time out (After 30 seconds) 8/8 Stretcher TIMEOUT 30.04s killed by signal 15 SIGTERM >>> MALLOC_PERTURB_=58 /builddir/rubberband-3.2.1/build/tests --run_test=TestStretcher --log_level=message Summary of Failures: 8/8 Stretcher TIMEOUT 30.04s killed by signal 15 SIGTERM Ok: 7 Expected Fail: 0 Fail: 0 Unexpected Pass: 0 Skipped: 0 Timeout: 1 Full log written to /builddir/rubberband-3.2.1/build/meson-logs/testlog.txt FAILED: meson-internal__test /usr/bin/meson test --no-rebuild --print-errorlogs ninja: build stopped: subcommand failed. => ERROR: rubberband-3.2.1_1: do_check: '${make_check_pre} ${make_cmd} -C ${meson_builddir} ${makejobs} ${make_check_args} ${make_check_target}' exited with 1 => ERROR: in do_check() at common/build-style/meson.sh:141 ```

Any idea how to fix this? Feel free to ask me if you need any more details.

cannam commented 1 year ago

Thanks for the report!

Do you have the ability to run the tests in a debugger? The tests compile to a binary called tests in the build directory, so e.g.

$ gdb ./build/tests
GNU gdb (GDB) 13.1
Copyright (C) 2023 Free Software Foundation, Inc.
[etc]
(gdb) run

then wait 20 seconds, hit ^C to interrupt, and type where to get a backtrace.

It may be worth testing the current repo code as well, as there are a few changes since 3.2.1.

If none of this is practical to do, I could have a go at reproducing it in a container but I would need to have more directions about how to set up the proper environment on that distro. I don't have a 32-bit build environment on my current dev box and the tests pass (for me) on a true 32-bit machine.

triallax commented 1 year ago

Here's the full gdb session output:

gdb run for v3.2.1 tests ``` GNU gdb (GDB) 13.2 Copyright (C) 2023 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "i686-pc-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: . Find the GDB manual and other documentation resources online at: . For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from ./build/tests... (gdb) run Starting program: /builddir/rubberband-3.2.1/build/tests [Thread debugging using libthread_db enabled] Using host libthread_db library "/usr/lib32/libthread_db.so.1". Running 325 test cases... ^C Program received signal SIGINT, Interrupt. floorf64 () at ../sysdeps/i386/fpu/s_floor.S:20 20 ../sysdeps/i386/fpu/s_floor.S: No such file or directory. (gdb) where #0 floorf64 () at ../sysdeps/i386/fpu/s_floor.S:20 #1 0x56654c9b in RubberBand::BQResampler::reconstruct_one(RubberBand::BQResampler::state*) const () #2 0x5665e97b in RubberBand::BQResampler::resampleInterleaved(float*, int, float const*, int, double, bool) () #3 0x5664d2dd in RubberBand::R2Stretcher::processChunkForChannel(unsigned int, unsigned int, unsigned int, bool) () #4 0x566476f6 in RubberBand::R2Stretcher::process(float const* const*, unsigned int, bool) () #5 0x56612827 in TestStretcher::process_realtime(RubberBand::RubberBandStretcher&, std::vector > const&, int, int, bool) [clone .lto_priv.0] () #6 0x56660949 in TestStretcher::sinusoid_realtime(int, double, double, bool) [clone .constprop.0] () #7 0x5662325f in TestStretcher::sinusoid_slow_higher_realtime_faster_hcpitch_invoker() [clone .lto_priv.0] () #8 0xf7f42d90 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #9 0xf7f4104c in boost::execution_monitor::catch_signals(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #10 0xf7f410ee in boost::execution_monitor::execute(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #11 0xf7f411f5 in boost::execution_monitor::vexecute(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #12 0xf7f6b994 in boost::unit_test::unit_test_monitor_t::execute_and_translate(boost::function const&, unsigned long) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #13 0xf7f48813 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #14 0xf7f48bd9 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #15 0xf7f48bd9 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #16 0xf7f4a045 in boost::unit_test::framework::run(unsigned long, bool) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #17 0xf7f6a588 in boost::unit_test::unit_test_main(bool (*)(), int, char**) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #18 0x56569371 in main () ```

I tried with current master (82dab93ecf44c9b1203289c0118760b7331b2156), but no dice. Here's the gdb output for that run:

gdb run for master tests ``` GNU gdb (GDB) 13.2 Copyright (C) 2023 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "i686-pc-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: . Find the GDB manual and other documentation resources online at: . For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from ./build/tests... (gdb) run Starting program: /builddir/rubberband-3.2.1/build/tests [Thread debugging using libthread_db enabled] Using host libthread_db library "/usr/lib32/libthread_db.so.1". Running 333 test cases... ^C Program received signal SIGINT, Interrupt. 0x5665deca in RubberBand::BQResampler::reconstruct_one(RubberBand::BQResampler::state*) const () (gdb) where #0 0x5665deca in RubberBand::BQResampler::reconstruct_one(RubberBand::BQResampler::state*) const () #1 0x5666691b in RubberBand::BQResampler::resampleInterleaved(float*, int, float const*, int, double, bool) () #2 0x5664fe34 in RubberBand::R2Stretcher::processChunkForChannel(unsigned int, unsigned int, unsigned int, bool) () #3 0x56651984 in RubberBand::R2Stretcher::processOneChunk() () #4 0x56652cb7 in RubberBand::R2Stretcher::available() const () #5 0x566131cc in TestStretcher::process_realtime(RubberBand::RubberBandStretcher&, std::vector > const&, int, int, bool, bool) [clone .lto_priv.0] () #6 0x56667497 in TestStretcher::sinusoid_realtime(int, double, double, int, bool, bool) [clone .constprop.0] () #7 0x56623cd6 in TestStretcher::sinusoid_slow_higher_realtime_faster_hcpitch_invoker() [clone .lto_priv.0] () #8 0xf7f44d90 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #9 0xf7f4304c in boost::execution_monitor::catch_signals(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #10 0xf7f430ee in boost::execution_monitor::execute(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #11 0xf7f431f5 in boost::execution_monitor::vexecute(boost::function const&) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #12 0xf7f6d994 in boost::unit_test::unit_test_monitor_t::execute_and_translate(boost::function const&, unsigned long) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #13 0xf7f4a813 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #14 0xf7f4abd9 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #15 0xf7f4abd9 in ?? () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #16 0xf7f4c045 in boost::unit_test::framework::run(unsigned long, bool) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #17 0xf7f6c588 in boost::unit_test::unit_test_main(bool (*)(), int, char**) () from /usr/lib32/libboost_unit_test_framework.so.1.82.0 #18 0x565696f1 in main () ```

I'm not sure if this is related, but the ../sysdeps/i386/fpu/s_floor.S:20 thing in the v3.2.1 gdb output caught my attention, as we're running in an i686 environment, not i386. ¯\_(ツ)_/¯

snd1 commented 1 year ago

hi, i have the same problem with some more archs on debian, https://buildd.debian.org/status/package.php?p=rubberband

i increased the timeout with --timeout-multiplier 3 and then i got this error on i386: ../src/test/TestStretcher.cpp(951): error: in "TestStretcher/impulses_fast_samepitch_realtime_finer": check peak0 < int(ceil(200 * timeRatio)) has failed [100 >= 100] https://salsa.debian.org/multimedia-team/rubberband/-/jobs/4352360

cannam commented 1 year ago

Thanks for the further information. I've pushed something to address that last failure.

I initially jumped to the conclusion that the tests timing out meant that something had got totally stuck, so they would never complete at all. The fact that both gdb traces interrupted the same test seemed to support that.

But now I wonder about the simple explanation, i.e. that the tests are just too slow! These are quite intensive tests and they certainly run relatively slowly in 32-bit mode. I've reviewed this locally now in a 32-bit container, and while I haven't managed to reproduce a total hang, I have certainly been surprised by how much slower they are than in 64-bit mode on the same hardware. But note also that the choice of resampler makes a much bigger difference in 32-bit than 64-bit builds - configuring with -Dresampler=libsamplerate produces a much faster build than the defaults here and is probably a good idea for a platform package.

@mhmdanas if you run the tests directly (via build/tests as in the gdb case, not through Ninja) and just let them run, do they eventually complete? Perhaps using build/tests --log_level=all for maximum status reporting so you can see whether they ever totally stall.

triallax commented 1 year ago

@cannam I can support the hypothesis that the test is just too slow. A few days ago I tried what @snd1 did (using --timeout-multiplier 3), and in around 45 seconds the test did fail with what I recall to be a similar error to theirs, though I don't remember the details.

But note also that the choice of resampler makes a much bigger difference in 32-bit than 64-bit builds - configuring with -Dresampler=libsamplerate produces a much faster build than the defaults here and is probably a good idea for a platform package.

So, just to make sure I'm reading this correctly, it's probably a good idea to configure with -Dresampler=libsamplerate for ALL archs, right?

Edit: I just noticed that Void's build template for rubberband already installs libsamplerate and fftw as make dependencies, but since -Dresampler=libsamplerate and -Dfft=fftw aren't passed to meson in the template, rubberband is built with the built-in implementations instead. facepalm

Anyway, using libsamplerate causes the test to fail much faster, at 9.41s, which is progress I guess. I'll add https://github.com/breakfastquay/rubberband/commit/df596f472e3271ad64ab6c2968920e5e95c17080 as a patch to fix the test and be on my way. Thank you very much @cannam and @snd1.

triallax commented 1 year ago

configuring with -Dresampler=libsamplerate produces a much faster build than the defaults here and is probably a good idea for a platform package.

Also, shouldn't this be mentioned in the documentation somewhere?

cannam commented 1 year ago

So, just to make sure I'm reading this correctly, it's probably a good idea to configure with -Dresampler=libsamplerate for ALL archs, right?

That would generally not be a wrong thing to do - libsamplerate works well and is typically faster, if not always as much as this. There are actually some situations in which the built-in resampler can sound very slightly better, which is why libsamplerate is not always picked by default, and on 64-bit platforms the difference in performance is less, so the penalty for sticking with the built-in resampler is lower. But in general it should be a totally acceptable tradeoff to use libsamplerate and here there is clearly a big advantage to it.

Also, shouldn't this be mentioned in the documentation somewhere?

Yes, probably so. The docs say "If you are proposing to package Rubber Band for a Linux distribution, please select either the built-in FFT or FFTW, and either the built-in resampler or libsamplerate" - but the reason for this was more to suggest avoiding the other options than anything else. I should probably update that wording.

triallax commented 1 year ago

That would generally not be a wrong thing to do - libsamplerate works well and is typically faster, if not always as much as this. There are actually some situations in which the built-in resampler can sound very slightly better, which is why libsamplerate is not always picked by default, and on 64-bit platforms the difference in performance is less, so the penalty for sticking with the built-in resampler is lower. But in general it should be a totally acceptable tradeoff to use libsamplerate and here there is clearly a big advantage to it.

Hmm, so I assume it wouldn't be wrong to use libsamplerate on 32-bit platforms, and the built-in on 64-bit ones?

Yes, probably so. The docs say "If you are proposing to package Rubber Band for a Linux distribution, please select either the built-in FFT or FFTW, and either the built-in resampler or libsamplerate" - but the reason for this was more to suggest avoiding the other options than anything else. I should probably update that wording.

Sounds good to me.

cannam commented 1 year ago

Hmm, so I assume it wouldn't be wrong to use libsamplerate on 32-bit platforms, and the built-in on 64-bit ones?

That would also be fine I think.

triallax commented 1 year ago

This issue is fixed for my purposes, so I'm closing.