Open Bug 1751795 Opened 7 months ago Updated 3 months ago

Python-based linters cannot be installed, mozlog 6.0 requires mozterm, which is not installed.

Categories

(Firefox Build System :: Lint and Formatting, defect)

Desktop
All
defect

Tracking

(Not tracked)

People

(Reporter: Gijs, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: leave-open)

Attachments

(1 file)

CC'ing other folks who have seen this and folks who might know what's wrong...

Whenever I commit on macOS I see output like this:

mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of pylint
Try to install it manually with:
    $ pip install -U --require-hashes -r /abs/path/to/srcdir/tools/lint/python/pylint_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of codespell
Try to install it manually with:
    $ pip install -U --require-hashes -r /abs/path/to/srcdir/tools/lint/spell/codespell_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of black
Try to install it manually with:
    $ pip install -U --require-hashes -r /abs/path/to/srcdir/tools/lint/python/black_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install required version of rstcheck
Try to install it manually with:
    $ pip install -U --require-hashes -r /abs/path/to/srcdir/tools/lint/rst/requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of flake8
Try to install it manually with:
    $ pip install -U --require-hashes -r /abs/path/to/srcdir/tools/lint/python/flake8_requirements.txt
error: problem with lint setup, skipping android-api-lint, android-checkstyle, android-format, android-javadoc, android-lint, android-test, black, codespell, flake8, pylint, rst

This is getting annoying. Please can we make it go away. From the logging I think the linter is trying to install/update itself and is falling over in the process, but I don't know how to figure out more of it than that.

I tried to dig into this a little earlier today, 'cuz I wasn't sure that linting was working for me (it is, as far as I can tell, even with these warnings). When I tried to manually /path/to/virtualenv -m pip install /path/to/requirements.txt, they all succeeded. So my guess is that the virtual env manager is getting confused in some way.

NI to mhentges, since I think this is more to do with changes to mach and the virtual env management process.

Flags: needinfo?(mhentges)

I'm struggling to reproduce this - editing a .cpp file (I chose browser/components/about/AboutRedirector.cpp at random) and doing an hg commit didn't trigger the failure.

Do you know what specific Mach command is failing? Is it ./mach clang-format, or perhaps ./mach lint [with-some-other-args-perhaps]?
Let me know and I'll see if I can dig into this further 👍

Flags: needinfo?(mhentges) → needinfo?(gijskruitbosch+bugs)

(In reply to Mitchell Hentges [:mhentges] 🦀 from comment #3)

I'm struggling to reproduce this - editing a .cpp file (I chose browser/components/about/AboutRedirector.cpp at random) and doing an hg commit didn't trigger the failure.

Do you have the linter hooks set up? My .hg/hgrc in the repo has:

pretxncommit.lint = python:~/path/to/repo/tools/lint/hooks.py:hg

in the hooks section, and my userdir .hgrc has:

clang-format = /Users/gkruitbosch/.mozbuild/version-control-tools/hgext/clang-format
js-format = /Users/gkruitbosch/.mozbuild/version-control-tools/hgext/js-format

in the extensions section.

Do you know what specific Mach command is failing? Is it ./mach clang-format, or perhaps ./mach lint [with-some-other-args-perhaps]?

I'm not sure. I'm not executing mach commands myself, I assume this is from https://searchfox.org/mozilla-central/rev/7fb9750a14e99267a77328559c2fd022e360d99b/tools/lint/hooks.py#38 so I guess python3 /absolute/path/to/mach lint?

Let me know and I'll see if I can dig into this further 👍

Does that help? If not, is there some way I can gather more debug info myself?

Here's the complete output of me changing uriloader/exthandler/nsMIMEInfoImpl.cpp just now:

$ hg amend
Processing 1 file(s)...
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of pylint
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of codespell
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/spell/codespell_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install required version of rstcheck
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/rst/requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of flake8
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/python/flake8_requirements.txt
error: problem with lint setup, skipping android-api-lint, android-checkstyle, android-format, android-javadoc, android-lint, android-test, codespell, flake8, pylint, rst
✖ 0 problems (0 errors, 0 warnings, 0 fixed)
Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(mhentges)

Do you have the linter hooks set up? My .hg/hgrc in the repo has:

Hmm, I didn't have the linter hooks set up, I'll give that a shot tomorrow (just ending my day here today).
FWIW, I ran ./mach clang-format and ./mach lint locally, and both ran happily.

I'm not sure. I'm not executing mach commands myself

Can you try executing either of those (./mach clang-format, ./mach lint) and see if either fails? That would help in narrowing towards our root cause.

Flags: needinfo?(mhentges) → needinfo?(gijskruitbosch+bugs)

(In reply to Mitchell Hentges [:mhentges] 🦀 from comment #5)

Do you have the linter hooks set up? My .hg/hgrc in the repo has:

Hmm, I didn't have the linter hooks set up, I'll give that a shot tomorrow (just ending my day here today).
FWIW, I ran ./mach clang-format and ./mach lint locally, and both ran happily.

I'm not sure. I'm not executing mach commands myself

Can you try executing either of those (./mach clang-format, ./mach lint) and see if either fails? That would help in narrowing towards our root cause.

Reverting some of my changes to the file from comment #4 and then running mach lint produced the same result:

$ ./mach lint
warning: linting the entire repo takes a long time, using --outgoing and --workdir instead. If you want to lint the entire repo, run `./mach lint .`
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of pylint
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of codespell
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/spell/codespell_requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install required version of rstcheck
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/rst/requirements.txt
mozlog 6.0 requires mozterm, which is not installed.
Unable to install correct version of flake8
Try to install it manually with:
    $ pip install -U --require-hashes -r /path/to/srcdir/tools/lint/python/flake8_requirements.txt
error: problem with lint setup, skipping android-api-lint, android-checkstyle, android-format, android-javadoc, android-lint, android-test, codespell, flake8, pylint, rst
✖ 0 problems (0 errors, 0 warnings, 0 fixed)

(this is sort of confusing; the warning suggests it was going to lint the entire repo, but considering it finished within about 10-20 seconds at most, I don't think it did)

I realized we are hitting exception handlers for the subprocess calls and added a traceback there (ie at https://searchfox.org/mozilla-central/rev/7fb9750a14e99267a77328559c2fd022e360d99b/tools/lint/python/pylint.py#58 ). That produces:

Traceback (most recent call last):
  File "/path/to/srcdir/tools/lint/python/pylint.py", line 54, in setup
    virtualenv_manager.install_pip_requirements(
  File "/path/to/srcdir/python/mach/mach/site.py", line 580, in install_pip_requirements
    self._virtualenv.pip_check()
  File "/path/to/srcdir/python/mach/mach/site.py", line 782, in pip_check
    subprocess.check_call(
  File "/usr/local/Cellar/python@3.9/3.9.8/Frameworks/Python.framework/Versions/3.9/lib/python3.9/subprocess.py", line 373, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['/path/to/objdir/_virtualenvs/common/bin/python', '-m', 'pip', 'check']' returned non-zero exit status 1.

I then added --verbose to the pip install arguments in site.py, which produced:

Requirement already satisfied: astroid==2.8.5 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 7)) (2.8.5)
Requirement already satisfied: colorama==0.4.4 in ./third_party/python/colorama (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 11)) (0.4.4)
Requirement already satisfied: isort==5.10.1 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 15)) (5.10.1)
Requirement already satisfied: lazy-object-proxy==1.6.0 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 19)) (1.6.0)
Requirement already satisfied: mccabe==0.6.1 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 43)) (0.6.1)
Requirement already satisfied: platformdirs==2.4.0 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 47)) (2.4.0)
Requirement already satisfied: pylint==2.11.1 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 51)) (2.11.1)
Requirement already satisfied: toml==0.10.2 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 55)) (0.10.2)
Requirement already satisfied: typed-ast==1.4.3 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 59)) (1.4.3)
Collecting typing-extensions==3.10.0.2
  Using cached typing_extensions-3.10.0.2-py3-none-any.whl (26 kB)
Requirement already satisfied: wrapt==1.13.3 in /path/to/objdir/_virtualenvs/common/lib/python3.9/site-packages (from -r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 96)) (1.13.3)
Requirement already satisfied: setuptools>=20.0 in ./third_party/python/setuptools (from astroid==2.8.5->-r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 7)) (51.2.0)
Installing collected packages: typing-extensions
  Attempting uninstall: typing-extensions
    Found existing installation: typing-extensions 3.10.0.0
    Not uninstalling typing-extensions at /path/to/srcdir/third_party/python/typing_extensions, outside environment /path/to/objdir/_virtualenvs/common
    Can't uninstall 'typing-extensions'. No files were found to uninstall.
Successfully installed typing-extensions-3.10.0.2
mozlog 6.0 requires mozterm, which is not installed.

It's maybe worth noting that I happened to run ./mach clobber on this objdir earlier today for unrelated reasons, which I assume would have wiped /path/to/objdir/_virtualenvs, though perhaps not?

I don't actually know much anything about python package management, so at this point I'm not sure how to gather more debugging info, but hopefully this helps...

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(mhentges)

Actually, this looks weird:

(In reply to :Gijs (he/him) from comment #6)

Requirement already satisfied: setuptools>=20.0 in ./third_party/python/setuptools (from astroid==2.8.5->-r /path/to/srcdir/tools/lint/python/pylint_requirements.txt (line 7)) (51.2.0)
Installing collected packages: typing-extensions
  Attempting uninstall: typing-extensions
    Found existing installation: typing-extensions 3.10.0.0
    Not uninstalling typing-extensions at **/path/to/srcdir/**third_party/python/typing_extensions, outside environment /path/to/objdir/_virtualenvs/common
    Can't uninstall 'typing-extensions'. No files were found to uninstall.
Successfully installed typing-extensions-3.10.0.2

(emphasis mine)

This wasn't a typo in my finds/replace, this is actually pointing to my srcdir, and setuptools is pointing to ./ which is also the srcdir. That seems... odd? Isn't the venv meant to exist only in the objdir? (But I refer back to my "I don't know anything about this" statement earlier!)

Reverting some of my changes to the file from comment #4 and then running mach lint produced the same result:

Nice, that's good news that we've narrowed it down to ./mach lint, that helps.
Unfortunately, I'm still not able to repro on either my M1 or Intel-based Mac 🤔

(this is sort of confusing; the warning suggests it was going to lint the entire repo, but considering it finished within about 10-20 seconds at most, I don't think it did)

My best guess here is that perhaps it exited early due to the setup failures, hopefully :)

I realized we are hitting exception handlers for the subprocess calls and added a traceback there

Good call on this, and thanks for the command output. However, I'm guessing that there's two failures:

  1. Failure creating the lint virtualenv and installing necessary packages
  2. Failure on using the lint virtualenv because it's missing packages

Based on the error output provided, it looks like we're seeing the second failure, and I'm wondering if the "first failure" exists and prints information that will hint us towards the root cause.

It's maybe worth noting that I happened to run ./mach clobber on this objdir earlier today for unrelated reasons, which I assume would have wiped /path/to/objdir/_virtualenvs, though perhaps not?

I believe so too, though there may be "shenanigans" going on. You can try a rm -r [objdir-name] and then ./mach lint and see if it has more virtualenv-creation logging.

This wasn't a typo in my finds/replace, this is actually pointing to my srcdir, and setuptools is pointing to ./ which is also the srcdir. That seems... odd? Isn't the venv meant to exist only in the objdir? (But I refer back to my "I don't know anything about this" statement earlier!)

To support builds-without-internet-access, we vendor most pure-python dependencies. Then, when we create virtualenvs (say for installing linting tools, or python packages that include native code), we tell the virtualenvs to prioritize our vendored dependencies first (to avoid collisions between package versions of already-loaded-modules).


Based on the output so far, I have one theory starting to form:

  1. We've recently started verifying that our virtualenvs are compatible with vendored packages (rather than assuming they are, and failing at runtime). In general, we've added this restriction up-front: if a pip installed package isn't compatible, then we bail out early with an error.
  2. However, our in-tree lockfiles so far somtimes haven't been compatible with vendored dependencies, so we still pip install-ing them without restricting based on existing packages. (For comparison, see how install[_single]_pip_package() installs "with constraints", while install_pip_requirements() does an install and pip checks afterwards.
    • This is why there's the warning about "Attempt uninstall: typing-extensions": the pinned typing-extensions version in the linting lockfile doesn't match the typing-extensions version that's vendored.
  3. ... Something is going on with your specific environment not being able to formulate a virtualenv that installs necessary linting tools while being able to cooperate with vendored packages. Somehow, that's not reproducible on my machine, which surprises me.

I don't actually know much anything about python package management, so at this point I'm not sure how to gather more debugging info, but hopefully this helps...

Heh, I appreciate the modesty, and the information you've provided so far is really helpful, thanks!
I still need to "cross the bridge" to be able to either reproduce locally or understand the root cause, so I need a little more help from you:

  • If you're available for a ~15-30m Zoom meeting, let me know, so I can interactively see what's going on on your machine
  • Alternatively, try a rm -r [objdir-name], then share the full output of the next ./mach lint call
  • If that doesn't work, the full output^ of ./mach lint will hint me towards what pip process is having its output suppressed, at which point I'll open it up and we'll try again.
Flags: needinfo?(mhentges) → needinfo?(gijskruitbosch+bugs)

Mitch and I tried to repro this together this AM and will repeat this PM. I have a potentially related problem with testing which manifests as:

created virtual environment CPython3.9.10.final.0-64 in 23ms
  creator CPython3Posix(dest=/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test, clear=False, no_vcs_ignore=False, global=False)
  activators BashActivator,CShellActivator,FishActivator,PowerShellActivator,PythonActivator
Collecting pytest==4.6.6
  Using cached pytest-4.6.6-py2.py3-none-any.whl (230 kB)
Collecting wcwidth
  Using cached wcwidth-0.2.5-py2.py3-none-any.whl (30 kB)
Requirement already satisfied: packaging in ./third_party/python/packaging (from pytest==4.6.6) (21.0)
Requirement already satisfied: attrs>=17.4.0 in ./third_party/python/attrs (from pytest==4.6.6) (19.2.0)
Collecting pluggy<1.0,>=0.12
  Using cached pluggy-0.13.1-py2.py3-none-any.whl (18 kB)
Collecting atomicwrites>=1.0
  Using cached atomicwrites-1.4.0-py2.py3-none-any.whl (6.8 kB)
Collecting py>=1.5.0
  Using cached py-1.11.0-py2.py3-none-any.whl (98 kB)
Requirement already satisfied: six>=1.10.0 in ./third_party/python/six (from pytest==4.6.6) (1.13.0)
Collecting more-itertools>=4.0.0
  Using cached more_itertools-8.12.0-py3-none-any.whl (54 kB)
Requirement already satisfied: pyparsing>=2.0.2 in ./third_party/python/pyparsing (from packaging->pytest==4.6.6) (2.4.7)
Installing collected packages: wcwidth, py, pluggy, more-itertools, atomicwrites, pytest
Successfully installed atomicwrites-1.4.0 more-itertools-8.12.0 pluggy-0.13.1 py-1.11.0 pytest-4.6.6 wcwidth-0.2.5
 0:05.16 Setting retcode to 1 from /Users/nalexander/Mozilla/gecko/python/mozbuild/mozpack/test/test_packager_l10n.py
 0:05.49 /Users/nalexander/Mozilla/gecko/python/mozbuild/mozpack/test/test_packager_l10n.py
 0:05.49 Traceback (most recent call last):
 0:05.49   File "/Users/nalexander/Mozilla/gecko/python/mozbuild/mozpack/test/test_packager_l10n.py", line 155, in <module>
 0:05.49     mozunit.main()
 0:05.49   File "/Users/nalexander/Mozilla/gecko/config/mozunit/mozunit/mozunit.py", line 330, in main
 0:05.49     sys.exit(pytest.main(args))
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 63, in main
 0:05.49     config = _prepareconfig(args, plugins)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 206, in _prepareconfig
 0:05.49     return pluginmanager.hook.pytest_cmdline_parse(
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/hooks.py", line 286, in __call__
 0:05.49     return self._hookexec(self, self.get_hookimpls(), kwargs)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/manager.py", line 93, in _hookexec
 0:05.49     return self._inner_hookexec(hook, methods, kwargs)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/manager.py", line 84, in <lambda>
 0:05.49     self._inner_hookexec = lambda hook, methods, kwargs: hook.multicall(
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/callers.py", line 203, in _multicall
 0:05.49     gen.send(outcome)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/helpconfig.py", line 94, in pytest_cmdline_parse
 0:05.49     config = outcome.get_result()
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/callers.py", line 80, in get_result
 0:05.49     raise ex[1].with_traceback(ex[2])
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/callers.py", line 187, in _multicall
 0:05.49     res = hook_impl.function(*args)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 687, in pytest_cmdline_parse
 0:05.49     self.parse(args)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 895, in parse
 0:05.49     self._preparse(args, addopts=addopts)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 841, in _preparse
 0:05.49     self.pluginmanager.load_setuptools_entrypoints("pytest11")
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/manager.py", line 300, in load_setuptools_entrypoints
 0:05.49     self.register(plugin, name=ep.name)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/config/__init__.py", line 321, in register
 0:05.49     ret = super(PytestPluginManager, self).register(plugin, name)
 0:05.49   File "/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/pluggy/manager.py", line 104, in register
 0:05.49     raise ValueError(
 0:05.49 ValueError: Plugin already registered: mozlog=<module 'mozlog.pytest_mozlog.plugin' from '/Users/nalexander/Mozilla/gecko/testing/mozbase/mozlog/mozlog/pytest_mozlog/plugin.py'>
 0:05.49 {'4369755968': <_pytest.config.PytestPluginManager object at 0x104752f40>, 'pytestconfig': <_pytest.config.Config object at 0x105495f40>, 'mozlog.pytest_mozlog.plugin': <module 'mozlog.pytest_mozlog.plugin' from '/Users/nalexander/Mozilla/gecko/testing/mozbase/mozlog/mozlog/pytest_mozlog/plugin.py'>, 'mozunit.pytest_plugin': <module 'mozunit.pytest_plugin' from '/Users/nalexander/Mozilla/gecko/config/mozunit/mozunit/pytest_plugin.py'>, 'stepwise': None, 'pytest_stepwise': None, 'cacheprovider': None, 'pytest_cacheprovider': None, 'mark': <module '_pytest.mark' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/mark/__init__.py'>, 'main': <module '_pytest.main' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/main.py'>, 'runner': <module '_pytest.runner' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/runner.py'>, 'fixtures': <module '_pytest.fixtures' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/fixtures.py'>, 'helpconfig': <module '_pytest.helpconfig' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/helpconfig.py'>, 'python': <module '_pytest.python' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/python.py'>, 'terminal': <module '_pytest.terminal' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/terminal.py'>, 'debugging': <module '_pytest.debugging' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/debugging.py'>, 'unittest': <module '_pytest.unittest' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/unittest.py'>, 'capture': <module '_pytest.capture' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/capture.py'>, 'skipping': <module '_pytest.skipping' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/skipping.py'>, 'tmpdir': <module '_pytest.tmpdir' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/tmpdir.py'>, 'monkeypatch': <module '_pytest.monkeypatch' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/monkeypatch.py'>, 'recwarn': <module '_pytest.recwarn' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/recwarn.py'>, 'pastebin': <module '_pytest.pastebin' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/pastebin.py'>, 'nose': <module '_pytest.nose' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/nose.py'>, 'assertion': <module '_pytest.assertion' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/assertion/__init__.py'>, 'junitxml': <module '_pytest.junitxml' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/junitxml.py'>, 'resultlog': <module '_pytest.resultlog' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/resultlog.py'>, 'doctest': <module '_pytest.doctest' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/doctest.py'>, 'freeze_support': <module '_pytest.freeze_support' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/freeze_support.py'>, 'setuponly': <module '_pytest.setuponly' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/setuponly.py'>, 'setupplan': <module '_pytest.setupplan' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/setupplan.py'>, 'warnings': <module '_pytest.warnings' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/warnings.py'>, 'logging': <module '_pytest.logging' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/logging.py'>, 'reports': <module '_pytest.reports' from '/Users/nalexander/Mozilla/gecko/obj-x86_64-apple-darwin18.7.0/_virtualenvs/python-test/lib/python3.9/site-packages/_pytest/reports.py'>}
 0:05.49 TEST-UNEXPECTED-FAIL | No test output (missing mozunit.main() call?): /Users/nalexander/Mozilla/gecko/python/mozbuild/mozpack/test/test_packager_l10n.py
 0:05.49 Return code from mach python-test: 1
Test configuration changed. Regenerating backend.
No build detected, test metadata may be incomplete.
 0:02.67 
Overall Summary
===============

In addition to showing the pip check failure, also show:

  • The pip install --requirements ... output
  • The output of pip list -v
  • The path to the requirements.txt file and the affected site.

Additionally, in both places doing pip check
(post-install-requirements and when doing system-package compatibility
checking), move the pip check output to happen last, so that users
don't need to scroll to the top of the pip list wall of text to find
the reason for their command failure.

Attachment #9261135 - Attachment description: WIP: Bug 1751795: Log more information if `pip_install_requirements` fails → Bug 1751795: Log more information if `pip_install_requirements` fails
Assignee: nobody → mhentges
Status: NEW → ASSIGNED

Workaround:

This workaround is Linux-/macOS-specific. From the top of your checkout, do:

find testing/mozbase/ -name "*.egg-info" -type d -print0 | xargs -0 /bin/rm -r

If you're on Windows: remove extra <package-name>.egg-info directories that exist in your checkout that are ignored by your VCS. Check the output of hg status -i | grep .egg-info to find such ignored directories.

Explanation:

A python module is importable if its parent directory is in the Python sys.path.
For example, if python/mach/ is in the sys.path, then import mach will import the Python module at python/mach/mach/.
A python package (specifically: a "pip" package) is defined by the existence of a *.egg-info or *.dist-info directory. These info directories define the package's version, its dependency requirements, and so on. Importantly, pip discovers these packages based on what it finds in the sys.path.

The stream of events that led to this bug are:

  1. When Mach prepares its first-party modules (mach, mozversioncontrol, mozlog, etc) to be importable, it makes them available in its sys.path.
  2. When mozharness prepares its dependencies, it creates a virtualenv, then does pip install -e <first-party-module> for the modules that it needs. The specifics here are a little foggy for me.
  3. As part of the above, setup.py files were created for some modules to allow pip install -e on them. They define their dependencies, both first-party (such as mozlog -> mozterm) and third-party (mozlog -> six >= 1.13.0). These setup.py files are dubious in their correctness/up-to-date-ness.
  4. When pip install -e <module> occurs, a <module>.egg-info file is created beside the module in-tree.

So, I bet that this issue was encountered by:

  1. Attempt to run mozharness in-tree such that runs pip install -e <first-party-module> on at least mozlog
  2. Run ./mach lint
    1. Mach adds all necessary modules to its sys.path
    2. Mach runs pip check (such as after installing a requirements.txt file)
    3. pip detects mozlog as a package due to the mozlog.egg-info remnant left by mozharness
    4. pip checks mozlog's package dependencies: it defines mozterm, so pip begins looking for a mozterm package.
      • Note that pip isn't just checking that it can import mozterm, it's looking for mozterm package metadata. For some reason, in Nick (and I'm assuming Gijs') case, when mozharness runs, it doesn't do pip install -e for mozterm.
    5. mozterm doesn't have a mozterm.egg-info file, so pip doesn't detect it as a package. pip bails out since mozlog appears to be missing dependencies

The short-term solution is: people encountering this issue should purge their ignored .egg-info directories as described in the workaround.
The medium-term solution here is for me to chat with RelEng to see what the right move is here: ideally, mozharness shouldn't create .egg-info directories, and very likely shouldn't rely on the setup.py files that exist in-tree because they're generally out-of-date (Mach handles dependencies at the higher, per-virtualenv level, not the per-module level).


Most importantly: :gijs, does the workaround solve the issue for you?

The workaround fixed my similar problem on Windows 10 with ./mach try chooser failing with the same mozlog 6.0 requires mozterm, which is not installed error.

Apologies for the delay. Yes, the workaround fixes the issue for me.

(In reply to Mitchell Hentges [:mhentges] 🦀 from comment #11)

  1. Attempt to run mozharness in-tree such that runs pip install -e <first-party-module> on at least mozlog

I don't really use mozharness directly. I probably use other things that use it though - but I'm not sure what. Maybe mach test or its friends? mach mozregression? Is there some way of finding out what is tripping this? It sounds bad...

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(mhentges)

Oh, and should we not .hgignore those in-tree egg-info files if they're not meant to be there?

Oh, and should we not .hgignore those in-tree egg-info files if they're not meant to be there?

I'd like for that to be the solution as well, but that's dependent on mozharness not creating .egg-info files. So, discussion with RelEng is needed :)

Flags: needinfo?(mhentges)
Pushed by mhentges@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/fdcaa230d0e1
Log more information if `pip_install_requirements` fails r=ahal

The severity field is not set for this bug.
:ahal, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(ahal)

The medium-term solution here is for me to chat with RelEng to see what the right move is here

Chatted with :ahal, sounds like it should be OK if mozharness is tweaked to no longer create .egg-info directories in-tree.
It'll probably have to be modified to do sys.path shenanigans, just like Mach.

Severity: -- → S3
Flags: needinfo?(ahal)
Assignee: mhentges → nobody
Status: ASSIGNED → NEW
You need to log in before you can comment on or make changes to this bug.