Editable install: raise ImportError when rebuilding fails

[lesteve]

When using meson editable install, this can be very suprising that there is no obvious error when recompilation fails.

One use case I bumped into:

1. I modify a scikit-learn cython file and introduce a compilation error
2. I run my scikit-learn test pytest sklearn/.../test_bla.py that imports scikit-learn and should recompile when needed

What happens:
The test run so I thought everything was fine, but actually the recompilation failed and I did not notice because pytest captures the output. If I had done pytest -s and looked carefully at the output I may have noticed

What I would expect:
There is an explicit error that tells me that recompilation failed.

With the current change, the tests run fine locally but there may be a side-effect I have not thought of?

This is how the output currently looks:

❯ pytest sklearn/tests/test_isotonic.py   
meson-python: building scikit-learn: /home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja
[1/3] Compiling Cython source /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx
FAILED: sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c 
cython -M --fast-fail -3 '-X language_level=3' '-X boundscheck=False' '-X wraparound=False' '-X initializedcheck=False' '-X nonecheck=False' '-X cdivision=True' '-X profile=False' --include-dir /home/lesteve/dev/scikit-learn/build/cp312 /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx -o sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c

Error compiling Cython file:
------------------------------------------------------------
...
# Author: Nelle Varoquaux, Andrew Tulloch, Antony Lee

# Uses the pool adjacent violators algorithm (PAVA), with the
# enhancement of searching for the longest decreasing subsequence to
# pool at each step.
asdf
^
------------------------------------------------------------

/home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx:6:0: undeclared name not builtin: asdf
ninja: build stopped: subcommand failed.
ImportError while loading conftest '/home/lesteve/dev/scikit-learn/sklearn/conftest.py'.
../../micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py:309: in find_spec
    tree = self._rebuild()
../../micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py:340: in _rebuild
    subprocess.run(self._build_cmd, cwd=self._build_path, env=env, check=True)
../../micromamba/envs/scikit-learn-dev/lib/python3.12/subprocess.py:571: in run
    raise CalledProcessError(retcode, process.args,
E   subprocess.CalledProcessError: Command '['/home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja']' returned non-zero exit status 1.

I will look at adding a test once I get some feed-back that this is something that looks reasonable.

[dnicolodi]

Not raising an exception on failing to recompile is definitely not intended. I think it is a regression, actually. Most likely I missed this when reviewing the last patch that touched this code: I was sure that check=True is the default. However, I think that we should raise ImportError with a bit of a nicer exception message, instead of the exception raised by subprocess.run().

[lesteve]

Thanks for your feed-back, indeed an ImportError make sense, I'll try to do that with a human redable message and add the output of the failing command afterwards.

[lesteve]

This is what the error message looks like in my last commit:

❯ python -c 'import sklearn'
meson-python: building scikit-learn: /home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja
[1/3] Compiling Cython source /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx
FAILED: sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c 
cython -M --fast-fail -3 '-X language_level=3' '-X boundscheck=False' '-X wraparound=False' '-X initializedcheck=False' '-X nonecheck=False' '-X cdivision=True' '-X profile=False' --include-dir /home/lesteve/dev/scikit-learn/build/cp312 /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx -o sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c

Error compiling Cython file:
------------------------------------------------------------
...
# Author: Nelle Varoquaux, Andrew Tulloch, Antony Lee

# Uses the pool adjacent violators algorithm (PAVA), with the
# enhancement of searching for the longest decreasing subsequence to
# pool at each step.
error
^
------------------------------------------------------------

/home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx:6:0: undeclared name not builtin: error
ninja: build stopped: subcommand failed.
Traceback (most recent call last):
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 342, in _rebuild
    subprocess.run(self._build_cmd, cwd=self._build_path, env=env, check=True)
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja']' returned non-zero exit status 1.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 310, in find_spec
    tree = self._rebuild()
           ^^^^^^^^^^^^^^^
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 346, in _rebuild
    raise ImportError(
ImportError: Error in meson-python when building scikit-learn: /home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja
See above for more details

[lesteve]

The test is in a reasonable shape now I think.

Something a bit not so great, you see the compilation error only if you are in verbose editable mode, so I added a note about this in the ImportError ...

Not sure there is a straightforward way to improve the situation. It seems like you want both:

• the subprocess.run(recompile_command_list) to in streaming mode, i.e. capture_output=False, so that the compilation output is seen as it progresses. This is quite nice to have the feed-back something is happening live, rather than wait until the recompilation finishes (potentially a few minutes in scikit-learn) before you get the output
• the subprocess.run(recompile_command_list) to capture its output so that you can show the compilation error to the user it in the top-level ImportError

Maybe I miss something obvious but each time I have tried to do this in the past for both stdout and stderr, I ended up in tricky places. Maybe this is a new reason to have another stab at it.

The kind of tricky things I remember off the top of my head, read are blocking so you need to set file descriptors in non-blocking mode, or you miss part of the output when the process finish, or the stdout and stderr are intermingled or in an unexpected order, or somehow your CPU usage is quite high because you keep reading the process output and writing it to stdout/stderr.

For completeness, right now the error looks like this. First part is the meson editable verbose output, second part in the exception raised by meson-python.

meson-python: building scikit-learn: /home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja
[1/3] Compiling Cython source /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx
FAILED: sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c 
cython -M --fast-fail -3 '-X language_level=3' '-X boundscheck=False' '-X wraparound=False' '-X initializedcheck=False' '-X nonecheck=False' '-X cdivision=True' '-X profile=False' --include-dir /home/lesteve/dev/scikit-learn/build/cp312 /home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx -o sklearn/_isotonic.cpython-312-x86_64-linux-gnu.so.p/sklearn/_isotonic.pyx.c

Error compiling Cython file:
------------------------------------------------------------
...
# pool at each step.

import numpy as np
from cython cimport floating

error
^
------------------------------------------------------------

/home/lesteve/dev/scikit-learn/sklearn/_isotonic.pyx:10:0: undeclared name not builtin: error
ninja: build stopped: subcommand failed.
Traceback (most recent call last):
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 342, in _rebuild
    subprocess.run(self._build_cmd, cwd=self._build_path, env=env, check=True)
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja']' returned non-zero exit status 1.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 310, in find_spec
    tree = self._rebuild()
           ^^^^^^^^^^^^^^^
  File "/home/lesteve/micromamba/envs/scikit-learn-dev/lib/python3.12/site-packages/_scikit_learn_editable_loader.py", line 347, in _rebuild
    raise ImportError(
ImportError: Error in meson-python when building scikit-learn: /home/lesteve/micromamba/envs/scikit-learn-dev/bin/ninja
See above for more details (make sure to be in verbose editable mode, for example by setting MESONPY_EDITABLE_VERBOSE=1)

[lesteve]

Hi @dnicolodi let me know if you have any further inputs on this! Of course I completely understand if you have other higher-priority things on your plate, no worries.

I think this PR is already an improvement by making the exit code is non-zero when rebuilding fails. There is definitely some room for improvement, in particular the fact that the compilation error is only visible if MESONPY_EDITABLE_VERBOSE is set ...

Looking at the CI error they come from CirrusCI credit limits and don't seem to be related to this PR.

[dnicolodi]

I'm on holiday for a couple more weeks. I'll have a closer look when I'm back.

[dnicolodi]

I've squashed the commits, simplified the exception message, and rewritten the test to be more accurate. Please have a look.

[lesteve]

Thanks a lot, this looks fine to me!

I quite liked the fact that there was some guidance in the ImportError message about being in editable verbose mode to have more details about the compilation error, but I guess you found it a bit messy maybe?

To give more details: if the recompilation fails and I am not in editable verbose mode, the error with the current code in the PR is not very helpful. In case of error I do want to see the compilation error to figure out how to fix it.

Having said that, I am always in editable verbose mode (except when I forget to set it), because I want to see some output when recompilation happens rather than wait without any output and wondering what is happening. The context is mostly scikit-learn, when you switch between branches the recompilation can take very easily tens of seconds to a 1-2 minutes.

[dnicolodi]

I quite liked the fact that there was some guidance in the ImportError message about being in editable verbose mode to have more details about the compilation error, but I guess you found it a bit messy maybe?

To give more details: if the recompilation fails and I am not in editable verbose mode, the error with the current code in the PR is not very helpful. In case of error I do want to see the compilation error to figure out how to fix it.

I don't like error messages that try to be little tutorials. Editable builds are a developer oriented feature and I would expect users of this feature to have at least a basic understanding of how it works. How to get compilation process output is described prominently in our documentation. The wording of the error message was also messy, indeed.

But what is maybe more important is that it assumed that the exception message is displayed on the same output stream where the compilation error would be printed if editable wheel verbose mode is enabled. This is may not be true for a number of reasons. Python exceptions are printed on standard error, but ninja prints all its output on standard output, and the execution environment may be setup in such a way that the two are not displayed together. The python module may be imported into a web application and the developer observes the exception on a web framework error page. In these circumstances enabling verbose mode does nothing to show the compilation error to the developer. Having the exception message claim that enabling verbose mode will display the exception would be misleading.

[lesteve]

OK makes sense, thanks for the explanations!