BackendUnavailable traceback with 19.0

[swt2c]

Environment

• pip version: 19.0
• Python version: 3.6.5
• OS: AWS Linux

Description
pip tracebacks with a BackendUnavailable Exception when running 'pip install -r requirements.txt'. Reverting to 18.1 avoids this problem.

Expected behavior
pip installs successfully

How to Reproduce
Run pip install -r requirements.txt.

Output

  2019-01-22 22:44:30,483 ERROR    Error installing dependencies: Command '/opt/python/run/venv/bin/pip install -r /opt/python/ondeck/app/requirements.txt' returned non-zero exit status 2
  Traceback (most recent call last):
    File "/opt/elasticbeanstalk/hooks/appdeploy/pre/03deploy.py", line 22, in main
      install_dependencies()
    File "/opt/elasticbeanstalk/hooks/appdeploy/pre/03deploy.py", line 18, in install_dependencies
      check_call('%s install -r %s' % (os.path.join(APP_VIRTUAL_ENV, 'bin', 'pip'), requirements_file), shell=True)
    File "/usr/lib64/python2.7/subprocess.py", line 190, in check_call
      raise CalledProcessError(retcode, cmd)
  CalledProcessError: Command '/opt/python/run/venv/bin/pip install -r /opt/python/ondeck/app/requirements.txt' returned non-zero exit status 2 (ElasticBeanstalk::ExternalInvocationError)
caused by: Collecting amqp==2.3.2 (from -r /opt/python/ondeck/app/requirements.txt (line 1))
    Downloading https://files.pythonhosted.org/packages/ca/0a/95f9fb2dd71578cb5629261230cb5b8b278c7cce908bca55af8030faceba/amqp-2.3.2.tar.gz (105kB)
  Collecting awsebcli==3.14.9 (from -r /opt/python/ondeck/app/requirements.txt (line 2))
    Downloading https://files.pythonhosted.org/packages/61/f5/68c4ca2ae2b31659d93b0a12356089c13d41e727175d96d5aa17109e53d2/awsebcli-3.14.9.tar.gz (228kB)
  Collecting billiard==3.5.0.4 (from -r /opt/python/ondeck/app/requirements.txt (line 3))
    Downloading https://files.pythonhosted.org/packages/87/ac/9b3cc065557ad5769d0626fd5dba0ad1cb40e3a72fe6acd3d081b4ad864e/billiard-3.5.0.4.tar.gz (150kB)
  Collecting blessed==1.15.0 (from -r /opt/python/ondeck/app/requirements.txt (line 4))
    Downloading https://files.pythonhosted.org/packages/51/c7/3af3ec267387d4a900a9e8f9a03a6c9068fb3c606c77bf2dd4558e1ea248/blessed-1.15.0.tar.gz (83kB)
  Collecting boto3==1.9.16 (from -r /opt/python/ondeck/app/requirements.txt (line 5))
    Downloading https://files.pythonhosted.org/packages/4b/ca/277c5253e393806fb6c98e3c6beef09c714cb41548e0ffa98624b709a2dc/boto3-1.9.16.tar.gz (93kB)
  Collecting botocore==1.12.76 (from -r /opt/python/ondeck/app/requirements.txt (line 6))
    Downloading https://files.pythonhosted.org/packages/a4/3c/7024ae28a82007c30a0390c98614fd2de3da61824b284edd8ee74a4f5311/botocore-1.12.76.tar.gz (5.4MB)
  Collecting cached-property==1.5.1 (from -r /opt/python/ondeck/app/requirements.txt (line 7))
    Downloading https://files.pythonhosted.org/packages/57/8e/0698e10350a57d46b3bcfe8eff1d4181642fd1724073336079cb13c5cf7f/cached-property-1.5.1.tar.gz
  Collecting celery==4.2.1 (from -r /opt/python/ondeck/app/requirements.txt (line 8))
    Downloading https://files.pythonhosted.org/packages/1e/6e/b30be7e43bab0311a695dd2576b3bf4528af4fd7c98f382e1b4029d5fc6a/celery-4.2.1.tar.gz (1.4MB)
  Collecting cement==2.8.2 (from -r /opt/python/ondeck/app/requirements.txt (line 9))
    Downloading https://files.pythonhosted.org/packages/70/60/608f0b8975f4ee7deaaaa7052210d095e0b96e7cd3becdeede9bd13674a1/cement-2.8.2.tar.gz (165kB)
  Collecting certifi==2018.11.29 (from -r /opt/python/ondeck/app/requirements.txt (line 10))
    Downloading https://files.pythonhosted.org/packages/55/54/3ce77783acba5979ce16674fc98b1920d00b01d337cfaaf5db22543505ed/certifi-2018.11.29.tar.gz (153kB)
  Collecting chardet==3.0.4 (from -r /opt/python/ondeck/app/requirements.txt (line 11))
    Downloading https://files.pythonhosted.org/packages/fc/bb/a5768c230f9ddb03acc9ef3f0d4a3cf93462473795d18e9535498c8f929d/chardet-3.0.4.tar.gz (1.9MB)
  Collecting colorama==0.3.9 (from -r /opt/python/ondeck/app/requirements.txt (line 12))
    Downloading https://files.pythonhosted.org/packages/e6/76/257b53926889e2835355d74fec73d82662100135293e17d382e2b74d1669/colorama-0.3.9.tar.gz
  Collecting Django==2.1.2 (from -r /opt/python/ondeck/app/requirements.txt (line 13))
    Downloading https://files.pythonhosted.org/packages/8b/03/4c74d3712919613f2c611e6689522df507a2753a92049009661a81b4b72f/Django-2.1.2.tar.gz (8.6MB)
  Collecting django-braces==1.13.0 (from -r /opt/python/ondeck/app/requirements.txt (line 14))
    Downloading https://files.pythonhosted.org/packages/03/e1/6ccb8b0bd6774327a80cce36e6e172de2efeeb45d4eb89e063177206abb2/django-braces-1.13.0.tar.gz (41kB)
  Collecting django-celery-beat==1.3.0 (from -r /opt/python/ondeck/app/requirements.txt (line 15))
    Downloading https://files.pythonhosted.org/packages/d6/8e/1c60693499a95649b8796785ef61dcd996d53758ad24d69d2da792f4a878/django-celery-beat-1.3.0.tar.gz (73kB)
  Collecting django-celery-results==1.0.4 (from -r /opt/python/ondeck/app/requirements.txt (line 16))
    Downloading https://files.pythonhosted.org/packages/28/ca/e4f4a7f78f89dfef491e33fd19824f380234920261aed0a14609678a98ae/django_celery_results-1.0.4.tar.gz (56kB)
  Collecting django-cors-headers==2.4.0 (from -r /opt/python/ondeck/app/requirements.txt (line 17))
    Downloading https://files.pythonhosted.org/packages/44/6d/1c036dd5280e4a0fa5e7fb09be38ce7da19c2698604096560af36ec49b1d/django-cors-headers-2.4.0.tar.gz
  Collecting django-crispy-forms==1.7.2 (from -r /opt/python/ondeck/app/requirements.txt (line 18))
    Downloading https://files.pythonhosted.org/packages/be/ff/225a8ebc3c81705135b64185e395cfc11915fb17105956b0bf2e0c9410ca/django-crispy-forms-1.7.2.tar.gz (53kB)
  Collecting django-extensions==2.1.3 (from -r /opt/python/ondeck/app/requirements.txt (line 19))
    Downloading https://files.pythonhosted.org/packages/26/35/113a74e58ab6b7e424f01955d11f4666d957fe2978a72fc719caa78f10d8/django-extensions-2.1.3.tar.gz (482kB)
  Collecting django-timezone-field==3.0 (from -r /opt/python/ondeck/app/requirements.txt (line 20))
    Downloading https://files.pythonhosted.org/packages/c8/79/429d35e54818332721a47dd2681138840aea7f77f2df0f30b5fed907d10f/django-timezone-field-3.0.tar.gz
  Collecting djangorestframework==3.8.2 (from -r /opt/python/ondeck/app/requirements.txt (line 21))
    Downloading https://files.pythonhosted.org/packages/c4/c0/a0d5a5872fb97c9210fb932116b2bf11f7b159239b00d514f5357b9cf11f/djangorestframework-3.8.2.tar.gz (795kB)
  Collecting docker==3.6.0 (from -r /opt/python/ondeck/app/requirements.txt (line 22))
    Downloading https://files.pythonhosted.org/packages/cc/9c/50ec68951d10fc341b650a2f5a6ed3925f7e4adc245113acfe64eb61f46a/docker-3.6.0.tar.gz (180kB)
  Collecting docker-compose==1.23.2 (from -r /opt/python/ondeck/app/requirements.txt (line 23))
    Downloading https://files.pythonhosted.org/packages/3d/03/c7803cbbb1dd89f85409929e9e53b4c58466449139b15a18898515499407/docker-compose-1.23.2.tar.gz (253kB)
  Collecting docker-pycreds==0.4.0 (from -r /opt/python/ondeck/app/requirements.txt (line 24))
    Downloading https://files.pythonhosted.org/packages/c5/e6/d1f6c00b7221e2d7c4b470132c931325c8b22c51ca62417e300f5ce16009/docker-pycreds-0.4.0.tar.gz
  Collecting dockerpty==0.4.1 (from -r /opt/python/ondeck/app/requirements.txt (line 25))
    Downloading https://files.pythonhosted.org/packages/8d/ee/e9ecce4c32204a6738e0a5d5883d3413794d7498fe8b06f44becc028d3ba/dockerpty-0.4.1.tar.gz
  Collecting docopt==0.6.2 (from -r /opt/python/ondeck/app/requirements.txt (line 26))
    Downloading https://files.pythonhosted.org/packages/a2/55/8f8cab2afd404cf578136ef2cc5dfb50baa1761b68c9da1fb1e4eed343c9/docopt-0.6.2.tar.gz
  Collecting docutils==0.14 (from -r /opt/python/ondeck/app/requirements.txt (line 27))
    Downloading https://files.pythonhosted.org/packages/84/f4/5771e41fdf52aabebbadecc9381d11dea0fa34e4759b4071244fa094804c/docutils-0.14.tar.gz (1.7MB)
  Collecting ecdsa==0.13 (from -r /opt/python/ondeck/app/requirements.txt (line 28))
    Downloading https://files.pythonhosted.org/packages/f9/e5/99ebb176e47f150ac115ffeda5fedb6a3dbb3c00c74a59fd84ddf12f5857/ecdsa-0.13.tar.gz (55kB)
  Collecting envs==1.2.6 (from -r /opt/python/ondeck/app/requirements.txt (line 29))
    Downloading https://files.pythonhosted.org/packages/34/f5/5277e967127581e5a63dca21dd42b43ab5d21ddd03cad0459649ee3c210a/envs-1.2.6.tar.gz
  Collecting et-xmlfile==1.0.1 (from -r /opt/python/ondeck/app/requirements.txt (line 30))
    Downloading https://files.pythonhosted.org/packages/22/28/a99c42aea746e18382ad9fb36f64c1c1f04216f41797f2f0fa567da11388/et_xmlfile-1.0.1.tar.gz
  Collecting future==0.17.1 (from -r /opt/python/ondeck/app/requirements.txt (line 31))
    Downloading https://files.pythonhosted.org/packages/90/52/e20466b85000a181e1e144fd8305caf2cf475e2f9674e797b222f8105f5f/future-0.17.1.tar.gz (829kB)
  Collecting idna==2.7 (from -r /opt/python/ondeck/app/requirements.txt (line 32))
    Downloading https://files.pythonhosted.org/packages/65/c4/80f97e9c9628f3cac9b98bfca0402ede54e0563b56482e3e6e45c43c4935/idna-2.7.tar.gz (172kB)
  Collecting jdcal==1.4 (from -r /opt/python/ondeck/app/requirements.txt (line 33))
    Downloading https://files.pythonhosted.org/packages/3b/d5/181cab9a39dbe8060bd073acae2518e0378e66ff7509c4c6db0881d58e01/jdcal-1.4.tar.gz
  Collecting jmespath==0.9.3 (from -r /opt/python/ondeck/app/requirements.txt (line 34))
    Downloading https://files.pythonhosted.org/packages/e5/21/795b7549397735e911b032f255cff5fb0de58f96da794274660bca4f58ef/jmespath-0.9.3.tar.gz
  Collecting jsonschema==2.6.0 (from -r /opt/python/ondeck/app/requirements.txt (line 35))
    Downloading https://files.pythonhosted.org/packages/58/b9/171dbb07e18c6346090a37f03c7e74410a1a56123f847efed59af260a298/jsonschema-2.6.0.tar.gz (53kB)
  Collecting kombu==4.2.1 (from -r /opt/python/ondeck/app/requirements.txt (line 36))
    Downloading https://files.pythonhosted.org/packages/39/9f/556b988833abede4a80dbd18b2bdf4e8ff4486dd482ed45da961347e8ed2/kombu-4.2.1.tar.gz (423kB)
  Collecting mysqlclient==1.3.13 (from -r /opt/python/ondeck/app/requirements.txt (line 37))
    Downloading https://files.pythonhosted.org/packages/ec/fd/83329b9d3e14f7344d1cb31f128e6dbba70c5975c9e57896815dbb1988ad/mysqlclient-1.3.13.tar.gz (90kB)
  Collecting openpyxl==2.5.12 (from -r /opt/python/ondeck/app/requirements.txt (line 38))
    Downloading https://files.pythonhosted.org/packages/08/8a/509eb6f58672288da9a5884e1cc7e90819bc8dbef501161c4b40a6a4e46b/openpyxl-2.5.12.tar.gz (173kB)
  Collecting pathspec==0.5.5 (from -r /opt/python/ondeck/app/requirements.txt (line 39))
    Downloading https://files.pythonhosted.org/packages/9f/fb/5a901a3b1eeebf83af6da74ecca69d7daf5189e450f0f4cccf9c19132651/pathspec-0.5.5.tar.gz
  Collecting pycryptodome==3.3.1 (from -r /opt/python/ondeck/app/requirements.txt (line 40))
    Downloading https://files.pythonhosted.org/packages/d2/50/6e4f3b4a77a430639feb6e37f5514fd537f011c0c8ce698f40731d4066b1/pycryptodome-3.3.1.tar.gz (3.1MB)
  Collecting pycurl==7.43.0.1 (from -r /opt/python/ondeck/app/requirements.txt (line 41))
    Downloading https://files.pythonhosted.org/packages/77/d9/d272b38e6e25d2686e22f6058820298dadead69340b1c57ff84c87ef81f0/pycurl-7.43.0.1.tar.gz (195kB)
  Collecting pygraphviz==1.5 (from -r /opt/python/ondeck/app/requirements.txt (line 42))
    Downloading https://files.pythonhosted.org/packages/7e/b1/d6d849ddaf6f11036f9980d433f383d4c13d1ebcfc3cd09bc845bda7e433/pygraphviz-1.5.zip (117kB)
  Collecting PyJWT==1.6.4 (from -r /opt/python/ondeck/app/requirements.txt (line 43))
    Downloading https://files.pythonhosted.org/packages/00/5e/b358c9bb24421e6155799d995b4aa3aa3307ffc7ecae4ad9d29fd7e07a73/PyJWT-1.6.4.tar.gz (41kB)
  Collecting python-crontab==2.3.5 (from -r /opt/python/ondeck/app/requirements.txt (line 44))
    Downloading https://files.pythonhosted.org/packages/66/88/4f443440230dd28158bac16dcccd8c9834cee55845bf83e85550d2e389ac/python-crontab-2.3.5.tar.gz (44kB)
  Collecting python-dateutil==2.7.5 (from -r /opt/python/ondeck/app/requirements.txt (line 45))
    Downloading https://files.pythonhosted.org/packages/0e/01/68747933e8d12263d41ce08119620d9a7e5eb72c876a3442257f74490da0/python-dateutil-2.7.5.tar.gz (316kB)
    Installing build dependencies: started
    Installing build dependencies: finished with status 'done'
    Getting requirements to build wheel: started
    Getting requirements to build wheel: finished with status 'done'
  /opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/req/req_file.py:184: UserWarning: Disabling all use of wheels due to the use of --build-options / --global-options / --install-options.
    cmdoptions.check_install_build_global(options, opts)
  Exception:
  Traceback (most recent call last):
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/cli/base_command.py", line 176, in main
      status = self.run(options, args)
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/commands/install.py", line 315, in run
      resolver.resolve(requirement_set)
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/resolve.py", line 131, in resolve
      self._resolve_one(requirement_set, req)
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/resolve.py", line 294, in _resolve_one
      abstract_dist = self._get_abstract_dist_for(req_to_install)
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/resolve.py", line 242, in _get_abstract_dist_for
      self.require_hashes
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/operations/prepare.py", line 349, in prepare_linked_requirement
      abstract_dist.prep_for_dist(finder, self.build_isolation)
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_internal/operations/prepare.py", line 149, in prep_for_dist
      reqs = self.req.pep517_backend.get_requires_for_build_wheel()
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_vendor/pep517/wrappers.py", line 71, in get_requires_for_build_wheel
      'config_settings': config_settings
    File "/opt/python/run/venv/local/lib/python3.6/site-packages/pip/_vendor/pep517/wrappers.py", line 162, in _call_hook
      raise BackendUnavailable
  pip._vendor.pep517.wrappers.BackendUnavailable

[pfmoore]

Can you please:

1. Post your requirements.txt
2. Create a minimal example reproducing this issue that only tries to install a single project (I don't know how many projects are in your requirements file, but it will be easier to debug the issue if we only have to look at a single project).
3. Post the failing project's pyproject.toml file.

I suspect the issue is that the failing project is not specifying the backend in its build-system.requires entry, but we'd need to see the details to confirm that.

[swt2c]

Here's my requirements.txt. I will work on a minimal reproducer, but I've not been having any luck on reproducing this outside of AWS Elastic Beanstalk's deployment process. I'll keep trying.

requirements.txt

[pfmoore]

Thanks - but yeah, we'll need something smaller. Also, if it's not reproducible outside AWS, it's going to be difficult for us to diagnose or offer any suggestions :-(

[swt2c]

I reduced the requirements.txt down to the following:

pycurl==7.43.0.1 --global-option="--with-nss"
-e git+https://github.com/capless/warrant@ae17d17d9888b9218a8facf6f6ad0bf4adae9a12#egg=warrant

Both are required, though. If you remove either, the problem goes away. I can reproduce it reliably on AWS Linux now but not on Ubuntu.

[pfmoore]

OK, neither of those projects use pyproject.toml, so I guess the next question is what version of setuptools is installed in your build environment? Also, can you run your install with the -vvv option to get maximum debug output and report that output here?

[swt2c]

setuptools is at 28.8.0. Here is the debug output.

pip_log.txt

[pfmoore]

OK, from the log pip is installing setuptools 40.6.3. So that's OK. But then the backend is failing with BackendUnavailable, which is the result of an ImportError when trying to import the backend. Unfortunately, the details of the ImportError are masked, so what you'll need to do is to patch your copy of pip to show the error.

In pip/_vendor/pep517/_in_process.py there's a section of code (lines 29-40) as follows:

def _build_backend():
    """Find and load the build backend"""
    ep = os.environ['PEP517_BUILD_BACKEND']
    mod_path, _, obj_path = ep.partition(':')
    try:
        obj = import_module(mod_path)
    except ImportError:
        raise BackendUnavailable
    if obj_path:
        for path_part in obj_path.split('.'):
            obj = getattr(obj, path_part)
    return obj

If you can delete the lines

    except ImportError:
        raise BackendUnavailable

your test should fail with an ImportError, and hopefully the traceback will provide a better clue as to what's going on.

Let me know the output and we'll see what that tells us.

[swt2c]

  Traceback (most recent call last):
    File "/home/ec2-user/foxty/local/lib/python3.6/dist-packages/pip/_vendor/pep517/_in_process.py", line 204, in <module>
      main()
    File "/home/ec2-user/foxty/local/lib/python3.6/dist-packages/pip/_vendor/pep517/_in_process.py", line 194, in main
      json_out['return_val'] = hook(**hook_input['kwargs'])
    File "/home/ec2-user/foxty/local/lib/python3.6/dist-packages/pip/_vendor/pep517/_in_process.py", line 45, in get_requires_for_build_wheel
      backend = _build_backend()
    File "/home/ec2-user/foxty/local/lib/python3.6/dist-packages/pip/_vendor/pep517/_in_process.py", line 33, in _build_backend
      obj = import_module(mod_path)
    File "/home/ec2-user/foxty/lib64/python3.6/importlib/__init__.py", line 126, in import_module
      return _bootstrap._gcd_import(name[level:], package, level)
    File "<frozen importlib._bootstrap>", line 994, in _gcd_import
    File "<frozen importlib._bootstrap>", line 971, in _find_and_load
    File "<frozen importlib._bootstrap>", line 953, in _find_and_load_unlocked
  ModuleNotFoundError: No module named 'setuptools.build_meta'

[pfmoore]

OK, so it looks like somehow either pip didn't install setuptools 40.6.3 in the build environment, in spite of what the log seems to say, or pip is somehow seeing the ancient setuptools 28.8.0 from the system. But I don't know why either of those would be the case.

Do you have command line access to the system? If so, I'd suggest doing something like inserting a call to os.system("bash") at the start of _build_backend() and manually inspecting the build environment. Maybe that will give some indication.

[swt2c]

That doesn't seem to work. bash seems to exit right away when run from within pip (is perhaps pip closing stdin or something?). It does work when I run it in a standalone script though.

[jaraco]

In pypa/setuptools#1644, the setuptools project itself has encountered this issue, although it seems only to happen on Python 2.7.