Closed Bug 1240993 Opened 8 years ago Closed 7 years ago

Frequent Windows build failure Could not install python package: pip install --download-cache cache --timeout 120 request

Categories

(Release Engineering :: Applications: MozharnessCore, defect)

Product:
Release Engineering
Component:
Applications: MozharnessCore
Type:
defect
Priority:
Not set
Severity:
major

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: KWierso, Unassigned)

References

Details

(Keywords: intermittent-failure) 

I'm seeing these on inbound a bunch tonight. Not seeing it elsewhere, but other trees don't have recent pushes, so I don't know if it's something relengy that changed today or code that landed on inbound.

It's not permafail, but it's always failing the same way: https://treeherder.mozilla.org/logviewer.html#?job_id=20078413&repo=mozilla-inbound

 17:19:02     INFO -  'USERDOMAIN': 'B-2008-SPOT-125',
 17:19:02     INFO -  'USERNAME': 'cltbld',
 17:19:02     INFO -  'USERPROFILE': 'C:\\Users\\cltbld',
 17:19:02     INFO -  'VS100COMNTOOLS': 'c:\\Program Files (x86)\\Microsoft Visual Studio 10.0\\Common7\\Tools\\',
 17:19:02     INFO -  'VS110COMNTOOLS': 'C:\\Program Files (x86)\\Microsoft Visual Studio 11.0\\Common7\\Tools\\',
 17:19:02     INFO -  'VS120COMNTOOLS': 'C:\\Program Files (x86)\\Microsoft Visual Studio 12.0\\Common7\\Tools\\',
 17:19:02     INFO -  'WINDIR': 'C:\\Windows',
 17:19:02     INFO -  'WINDOWS_TRACING_FLAGS': '3',
 17:19:02     INFO -  'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log',
 17:19:02     INFO -  'WIX_351728_PATH': 'c:/mozilla-build/wix-351728',
 17:19:02     INFO -  '_': 'C:\\mozilla-build\\buildbotve\\Scripts\\python'}
 17:19:03     INFO -  c:\builds\moz2_slave\m-in-w64-000000000000000000000\build\venv\lib\site-packages\pip-8.0.0-py2.7.egg\pip\pep425tags.py:89: RuntimeWarning: Config variable 'Py_DEBUG' is unset, Python ABI tag may be incorrect
 17:19:03     INFO -    warn=(impl == 'cp')):
 17:19:03     INFO -  c:\builds\moz2_slave\m-in-w64-000000000000000000000\build\venv\lib\site-packages\pip-8.0.0-py2.7.egg\pip\pep425tags.py:93: RuntimeWarning: Config variable 'WITH_PYMALLOC' is unset, Python ABI tag may be incorrect
 17:19:03     INFO -    warn=(impl == 'cp')):
 17:19:03     INFO -  c:\builds\moz2_slave\m-in-w64-000000000000000000000\build\venv\lib\site-packages\pip-8.0.0-py2.7.egg\pip\pep425tags.py:99: RuntimeWarning: Config variable 'Py_UNICODE_SIZE' is unset, Python ABI tag may be incorrect
 17:19:03     INFO -    sys.version_info < (3, 3))) \
 17:19:03     INFO -  Usage:
 17:19:03     INFO -    pip install [options] <requirement specifier> [package-index-options] ...
 17:19:03     INFO -    pip install [options] -r <requirements file> [package-index-options] ...
 17:19:03     INFO -    pip install [options] [-e] <vcs project url> ...
 17:19:03     INFO -    pip install [options] [-e] <local project path> ...
 17:19:03     INFO -    pip install [options] <archive url/path> ...
 17:19:03     INFO -  no such option: --download-cache
 17:19:03  WARNING - Return code: 2
 17:19:03    FATAL - Could not install python package: c:\builds\moz2_slave\m-in-w64-000000000000000000000\build\venv\Scripts\pip install --download-cache c:\builds\moz2_slave\m-in-w64-000000000000000000000\build\venv\cache --timeout 120 requests==2.8.1 failed after 5 tries!
 17:19:03    FATAL - Running post_fatal callback...
 17:19:03    ERROR - setting return code to 2 because fatal was called
 17:19:03  WARNING - setting return code to 2
 17:19:03    FATAL - Exiting -1
 program finished with exit code -1


I've clobbered Windows builders on inbound to see if that clears things up or makes them worse.

Dustin pinged markco in #releng when I asked him about this, so Ccing them both as well.
So that's pip 8.0.0, which was just released today:
  https://pypi.python.org/pypi/pip
So really, two questions:

 1. why is pip being installed from upstream? We should be using pypi.pub.build.mozilla.org for python installs.. I'm guessing something in mozharness is failing here/

 2. what's wrong with pip-8.0.0?  It looks like the egg has binary extensions in it with a different ABI version??
And there's the failures on a new fx-team push. Closing trees.
6:29 PM <dustin> KWierso|afk: I'm guessing that's not actually an infra issue
6:29 PM <dustin> based on my comments
6:30 PM <KWierso|afk> dustin: kinda curious why it's not a permafail
6:30 PM <KWierso|afk> maybe the other builders haven't restarted lately to pick up some change?
6:30 PM <dustin> I bet the pip install is cached in the workdir
6:30 PM <dustin> so probably permafail post-clobber
Severity: normal → blocker
OOOOH. The actual issue is:
>  17:19:03     INFO -  no such option: --download-cache

They removed that from pip 8.0. The other warnings are spurious.
--download-cache was deprecated in pip 6.0, this was just the final removal of it. More info:
https://pip.pypa.io/en/stable/reference/pip_install/#caching
(In reply to Dustin J. Mitchell [:dustin] from comment #1)
>  1. why is pip being installed from upstream? We should be using
> pypi.pub.build.mozilla.org for python installs.. I'm guessing something in
> mozharness is failing here/

Going back to this one, though -- 8.0.0 shouldn't even be an issue for us..
Removing the argument doesn't seem to hurt anything.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f7f15afc84ca
ryan's try/patch seems to work indeed. If this is ok from releng side, can we deploy this as asap to resolve the general tree closure ?
Flags: needinfo?(dustin)
< philor> the try runs mean nothing, though, since none of them have been with pip 8, so don't just land it and reopen
We have at least one build with pip 8, so in that confidence, landed onto m-c to give it a shot.

The new caches are in the following folders (https://pip.pypa.io/en/latest/reference/pip_install/#caching):


Unix
    ~/.cache/pip and it respects the XDG_CACHE_HOME directory.
OS X
    ~/Library/Caches/pip.
Windows
    <CSIDL_LOCAL_APPDATA>\pip\Cache

If we fail again on other platforms, it could be due to permissions around writing to these caches.


https://archive.mozilla.org/pub/firefox/try-builds/ryanvm@gmail.com-f7f15afc84ca8958657f666b7e3a08b8400de845/try-win32/try-win32-bm78-try1-build1977.txt.gz
Michael, I assume this patch is also something you will be interested in for build/mozharness.
Flags: needinfo?(mshal)
Given that this is a mozharness issue, lets move the bug to the correct component.
Component: Buildduty → Mozharness
QA Contact: bugspam.Callek → jlund
Sorry, wanted to ni? Hal and not Michael.
Flags: needinfo?(mshal) → needinfo?(hwine)
Just to be clear, there are a few important things to ensure before this is closed:

 * All Python stuff is being downloaded from the Mozilla mirror, not pypi.python.org
   (without this we're vulnerable to surprise upgrades like this one, as well as pypi downtime, and we put a huge load on pypi)
   (this includes things initially installed by virtualenv.py, such as pip and setuptools)

 * Python packages are being cached somewhere on disk -- this cuts down the load and time substantially
   (It sounds like nigelb has verified this already, from comment 13)

 * Versions are specified in the source, rather than allowing "latest"
   that even if we upload something to our own mirror, we want to be able to control deployment via commits

These downloads are all performed *within* the build process, so this isn't something we can control at the system-configuration or docker-image level.
Flags: needinfo?(dustin)
(In reply to Dustin J. Mitchell [:dustin] from comment #18)
> Just to be clear, there are a few important things to ensure before this is
> closed:
> 
>  * All Python stuff is being downloaded from the Mozilla mirror, not
> pypi.python.org
>    (without this we're vulnerable to surprise upgrades like this one, as
> well as pypi downtime, and we put a huge load on pypi)
>    (this includes things initially installed by virtualenv.py, such as pip
> and setuptools)

This is actually tracked in Bug 1148087 -- which sadly was "past selves shooting future selves in the foot"
Depends on: 1148087
(In reply to Nigel Babu [:nigelb] from comment #13)
> We have at least one build with pip 8, so in that confidence, landed onto
> m-c to give it a shot.

Marking as "Major" only for now, to get it to stop alerting. (the tree-closure part is fixed).
Severity: blocker → major
(In reply to Justin Wood (:Callek) from comment #19)
> This is actually tracked in Bug 1148087 -- which sadly was "past selves
> shooting future selves in the foot"

Pulling things from PyPI isn't the number 1 issue here, unpinned dependencies are. From a reliability point of view, yes it's nice to use the internal mirror rather than PyPI, but both repeatability and security can be handled by pinning and using hashes (either peep, or with pip v8+ via the new --require-hashes feature).

IMO it would make sense to fix that first, and only then worry about switching everything to the internal mirror.
(In reply to Henrik Skupin (:whimboo) from comment #15)
> [Hal], I assume this patch is also something you will be interested in for
> build/mozharness.

Thanks for the thought, but probably not. mozharness has the ability to pin versions of pypi packages, and that feature is already used in apps still using the old repository.
Flags: needinfo?(hwine)
Note, the l10n nightlies still show the pip error traceback on https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&revision=2e50b83954e6&exclusion_profile=false&filter-job_group_symbol=L10n, which is nigelb's landing from comment 12.
Yes, but those are not-fatal. See comment 6. Your failures appear to be " 09:08:27 INFO - HTTPError: 400 Client Error: BAD REQUEST "
No, that's not-fatal :)

Your failures are the command timed out: 10800 seconds elapsed as a result of all those non-fatal failures talking to aus4-admin-dev, which is bug 1240141.
Though at some point we are going to have to do something about them, since that's merely the first time they were mentioned in this bug, and we'll inevitably get new bugs filed about them since Windows builds are notorious for not producing any useful failure output, and now every single one has those three lines highlighted, twice over if it got as far as uploading since we create another virtualenv there.
The upstream issue indicates that a fix is coming soon (making those warnings debug-only). Not sure what pip's release cadence is, though.
Dustin, any ideas here?
Flags: needinfo?(dustin)
Well, the bug isn't fixed yet, so that's probably why it's still happening.  I think comment 18 still applies.
Flags: needinfo?(dustin)
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.