Repository navigation
BUG: BLAS setup can silently fail and not be reported in show_config() #24200
Description
Describe the issue:
With 2.0.0dev0 wheel on scientific-python-nightly-wheels there is a big slowdown for @ / dot for us. First noticed a ~1.5x slowdown in MNE-Python CIs, then went through a bunch of stuff with @seberg on Discord (thanks for your patience!). Finally I think I created a minimal example:
$ python3 -m venv ~/python/virtualenvs/npbad
$ source ~/python/virtualenvs/npbad/bin/activate
$ pip install --default-timeout=60 --extra-index-url "https://pypi.anaconda.org/scientific-python-nightly-wheels/simple" "numpy==1.25.0rc1+218.g0e5a362fd"
$ pip list
Package Version
---------- ------------------------
numpy 1.25.0rc1+218.g0e5a362fd
pip 23.0.1
setuptools 66.1.1
$ which python
/home/larsoner/python/virtualenvs/npbad/bin/python
$ python -m timeit -s "import numpy as np; x = np.random.RandomState(0).randn(300, 10000)" "x @ x.T"
20 loops, best of 5: 18.6 msec per loop
$ pip install --default-timeout=60 --upgrade --extra-index-url "https://pypi.anaconda.org/scientific-python-nightly-wheels/simple" "numpy==2.0.0dev0"
$ python -m timeit -s "import numpy as np; x = np.random.RandomState(0).randn(300, 10000)" "x @ x.T"
1 loop, best of 5: 911 msec per loopTL;DR: 18.6ms on "1.25.0rc1" from just under a month ago, 911ms on latest 2.0.0dev0 on my machine.
I've tried to reproduce this on main on my machine as well by building myself by setting dispatches, using meson or not, etc. but have only ever managed to get the good/fast time.
Reproduce the code example:
AboveError message:
N/ARuntime information:
Above
Context for the issue:
Above
Activity
rgommers commentedon Jul 17, 2023
Thanks for the report @larsoner. That is probably simply expected right now, because SIMD support is incomplete in the Meson build. We can leave this open for a while, but I would recommend not investigating anything because looking at anything performance-related for a Meson vs. a distutils build isn't all that useful right now.
larsoner commentedon Jul 17, 2023
FWIW locally I built using the Meson and distutils backends and performance was the same. But maybe I didn't configure options properly to see the slowdown...
I also kind of expected this to just get sent over to OpenBLAS so didn't think the SIMD / dispatch stuff would matter. So I thought perhaps an OpenBLAS version changed between a month ago and now and that had performance problems.
rgommers commentedon Jul 17, 2023
Oh wait, I missed that this was ~50x or so. If you rebuilt and it's both that much slower, maybe the build is silently using
lapack_liteinstead of OpenBLAS? This seems like a lot.We do have a whole bunch of logic in
numpy/core/src/umath/matmul.c.src, so it's not always straightforward to determine that one is really library an optimized BLAS library.larsoner commentedon Jul 17, 2023
No it's the opposite rather -- locally I rebuilt using Meson and distutils with my own OpenBLAS that was the same each time (0.3.21 or something?), and it's just as fast as the 1.25.rc wheel from SPNW (no regression): the only problematic case seems to be the 2.0.0dev0 wheel.
Both the 1.25.rc (fast) and 2.0.0dev0 (slow) show that the OpenBLAS lib used is "OpenBLAS 0.3.23 with 1 thread" when I look using threadpoolctl on my machine (locally I limit it to 1 thread). But if something changed about how that was built or what version was actually used (despite being reported the same) in the last ~30 days that's a good candidate!
rgommers commentedon Jul 17, 2023
mattip commentedon Jul 17, 2023
How are you locally limiting OpenBLAS to one thread?
mattip commentedon Jul 17, 2023
Nevermind, this reproduces even when not limiting OpenBLAS to one thread
mattip commentedon Jul 17, 2023
As far as I can tell, both wheels use the same OpenBLAS
site-packages/numpy.libs/libopenblas64_p-r0-7a851222.3.23.soEach build in the scheduled wheel build log has artifacts. Perhaps someone could download them and find the point at which the slowdown started.
larsoner commentedon Jul 18, 2023
I can do it tomorrow morning EDT unless someone beats me to it (feel free!)
larsoner commentedon Jul 18, 2023
Okay clearly I must have meant tomorrow July 19th EDT :)
larsoner commentedon Jul 18, 2023
Actually it only took a couple of minutes to bisect using
cp311-manylinux_x86_64:__array_ufunc__works without any kwargs passed #24031 from seberg/array-ufunc-no-kwargs"-ftrapping-mathwith Clang on macOS in Meson build #24060 from rgommers/clang-floatingpoint-flags"Which I guess gets us this diff: https://github.com/numpy/numpy/compare/0e2af84..85385d6
larsoner commentedon Jul 18, 2023
... I am a bit worried about this meson check EDIT: potentially failing in the wheel build:
https://github.com/numpy/numpy/compare/0e2af84..85385d6#diff-d4017f02419a9799bc2d59ae04399d2c45b9855443bb4a5ff7544ff76b040258
It passing on my machine and failing in the wheel build (for some reason!) would be a possible explanation for the slowdown because
@might revert to a non-BLAS version...25 remaining items
rgommers commentedon Jul 23, 2023
Actually, I think I'll just clean it up straight away. I did a GitHub search and I don't find usage in the wild of the
numpy.linalg.lapack_litemodule. And since it's clearly broken and we're building the sources twice, let's just get rid of one of them. It's a 5 line diff to add the_ilp64attribute that we need for testing toumath_linalg.cpp.TST: fix running the test suite in builds without BLAS/LAPACK
rgommers commentedon Jul 23, 2023
Hmm, not entirely true unfortunately -
numpy/linalg/tests/test_linalg.pycontains a couple of test functions which uselapack_lite. And one of the two is forxerbla, which is a broken test - see #12472 (comment).TST: fix running the test suite in builds without BLAS/LAPACK
rgommers commentedon Jul 28, 2023
gh-24279 adds an
-Dallow-noblas=falsebuild switch.TST: fix running the test suite in builds without BLAS/LAPACK
rgommers commentedon Sep 27, 2023
This caught some issues, but is also tripping folks up. The most annoying consequence is when a package has a transitive build-time dependency on
numpy. That will start failing, it typically doesn't matter for building wheels, and it's very difficult to work around the problem because there's no good way to pass the-Dallow-noblas=falseto a transitive dependency.We'll be reverting to defaulting to
trueon the 1.26.x branch, and probably also inmainlater on.larsoner commentedon Sep 27, 2023
Could we make the default "True if env var NUMPY_ALLOW_NOBLAS is set and False otherwise"? Then these wheel builders or whoever can set this env var. Apologies if someone thought of this and discussed it already...
rgommers commentedon Sep 27, 2023
That is possible, and we may end up doing that in
mainperhaps. I'm not thrilled about it though, because environment variables are really bad for diagnostics. I got rid of all of them (we had lots of partially documented and untested ones floating around), and right now all of the build options can be found inmeson_options.txt, and the build log clearly shows any non-default values that were used. New environment variables bypass all that - it's like programming with globals.rgommers commentedon Oct 12, 2023
Update on this: for 1.26.1 we keep the value of
-Dallow-noblasasfalse, in order to get bug reports rather than silent fallbacks to slow code in case anything changed with the updated BLAS/LAPACK detection (see gh-24893). We've had a bunch of complaints about this (see the tracking issue gh-24703), but not so many that it's super urgent to switch the default back.rgommers commentedon Nov 3, 2023
I just opened #25063 to revert the default to
allow-noblas=true. That should land in 1.26.2 and 2.0.I decided against the environment variable for now, I really don't like it. The situation after gh-25063 will just go back to how it always was - with the difference that the warning about the slow fallback being used is much more prominent in the build log.
TST: fix running the test suite in builds without BLAS/LAPACK