1453658 - Intermittent ssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:749)

Status: RESOLVED FIXED

(Release Engineering :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ebalazs [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=173261090&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/FnkLwmPeTfyvC5dCZqJWBA/runs/0/artifacts/public/logs/live_backing.log

Comment 1

[Eliza Balazs [:ebalazs_]]

13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\ssl.py", line 683, in do_handshake
13:34:48     INFO -          self._sslobj.do_handshake()
13:34:48     INFO -      ssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:749)
13:34:48     INFO -      During handling of the above exception, another exception occurred:
13:34:48     INFO -      Traceback (most recent call last):
13:34:48     INFO -        File "c:\users\task_1523537049\py3venv\lib\site-packages\setuptools\package_index.py", line 747, in open_url
13:34:48     INFO -          return open_with_auth(url, self.opener)
13:34:48     INFO -        File "c:\users\task_1523537049\py3venv\lib\site-packages\setuptools\package_index.py", line 948, in _socket_timeout
13:34:48     INFO -          return func(*args, **kwargs)
13:34:48     INFO -        File "c:\users\task_1523537049\py3venv\lib\site-packages\setuptools\package_index.py", line 1067, in open_with_auth
13:34:48     INFO -          fp = opener(request)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 223, in urlopen
13:34:48     INFO -          return opener.open(url, data, timeout)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 526, in open
13:34:48     INFO -          response = self._open(req, data)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 544, in _open
13:34:48     INFO -          '_open', req)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 504, in _call_chain
13:34:48     INFO -          result = func(*args)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 1361, in https_open
13:34:48     INFO -          context=self._context, check_hostname=self._check_hostname)
13:34:48     INFO -        File "C:\Users\task_1523537049\build\python3.6\lib\urllib\request.py", line 1320, in do_open
13:34:48     INFO -          raise URLError(err)
13:34:48     INFO -      urllib.error.URLError: <urlopen error [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:749)>
13:34:48     INFO -      During handling of the above exception, another exception occurred:
13:34:48     INFO -      Traceback (most recent call last):

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

this is during mozharness pip install of packages, I am seeing this failure on try as well

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

this seems to be a perma fail issue for jobs run after 10am EDT.

:catlee, can you get someone to look into this?

Comment 4

[Eliza Balazs [:ebalazs_]]

Autoland and inbound trees are closed for this.

Comment 5

[Chris AtLee [:catlee]]

My guess is that this is due to pypi shutting down TLS1.0/1.1 on pypi.python.org. We shouldn't be downloading packages from there, but they do sneak into our dependencies in various ways.

I expect more problems like this to show up soon.

It looks like this particular issue is that brotlipy==0.6.0 depends on cffi==1.11.5, which tries to be downloaded from https://files.pythonhosted.org instead of our local package mirror.

Further down in the log it runs `pip install mitmproxy`, which manages to succeed.

Note that this doesn't seem to be fatal on its own. The failure that seems to cause the job to fail is further down in the log:

13:35:28     INFO - Return code: 0
13:35:28 CRITICAL - PERFHERDER_DATA was seen 0 times, expected 1.
13:35:28 CRITICAL - Error copying results C:\Users\task_1523537049\build\local.json to upload dir C:\Users\task_1523537049\build\blobber_upload_dir\perfherder-data.json
13:35:28     INFO - Running post-action listener: _package_coverage_data
13:35:28     INFO - Running post-action listener: _resource_record_post_action
13:35:28     INFO - [mozharness: 2018-04-12 13:35:28.799000Z] Finished run-tests step (failed)
13:35:28    FATAL - Uncaught exception: Traceback (most recent call last):
13:35:28    FATAL -   File "C:\Users\task_1523537049\mozharness\mozharness\base\script.py", line 2076, in run
13:35:28    FATAL -     self.run_action(action)
13:35:28    FATAL -   File "C:\Users\task_1523537049\mozharness\mozharness\base\script.py", line 2015, in run_action
13:35:28    FATAL -     self._possibly_run_method(method_name, error_if_missing=True)
13:35:28    FATAL -   File "C:\Users\task_1523537049\mozharness\mozharness\base\script.py", line 1955, in _possibly_run_method
13:35:28    FATAL -     return getattr(self, method_name)()
13:35:28    FATAL -   File "C:\Users\task_1523537049\mozharness\mozharness\mozilla\testing\talos.py", line 770, in run_tests
13:35:28    FATAL -     self._artifact_perf_data(dest)
13:35:28    FATAL -   File "C:\Users\task_1523537049\mozharness\mozharness\mozilla\testing\talos.py", line 665, in _artifact_perf_data
13:35:28    FATAL -     parser.update_worst_log_and_tbpl_levels(CRITICAL, TBPL_FAILURE)
13:35:28    FATAL - NameError: global name 'parser' is not defined
13:35:28    FATAL - Running post_fatal callback...
13:35:28    FATAL - Exiting -1

Comment 6

[Chris AtLee [:catlee]]

Also, this task seems to be running python 2.7.14, which has a recent SSL stack, and should be able to talk to modern pypi.

Comment 7

[Chris AtLee [:catlee]]

(In reply to Chris AtLee [:catlee] from comment #6)
> Also, this task seems to be running python 2.7.14, which has a recent SSL
> stack, and should be able to talk to modern pypi.

It looks like this task is fetching a zipped version of python 3.6.1 from tooltool, and then using that to execute the pip commands.

Comment 8

[Alex Gaynor [:Alex_Gaynor]]

This is not related to the TLS version changes on PyPI, this is a failure to verify the certificate.

Comment 9

[Jake Watkins [:dividehex]]

Has anyone verified the host has the Root/Intermediate CA cert of the newly issued pypi certificate?  If this is using the system CA files (which nearly never get updated on our side), it is possible the certificate issued from Digicert might be signed by Root CAs (and/or intermediate CAs) the host doesn't have.

Comment 10

[Phabricator Automation]

Attachment: Bug 1453658: Use pip options when install python3 modules.

Comment 11

[Phabricator Automation]

Attachment: Bug 1453658: [talos] Install cffi before trying to install mitmproxy dependencies.

Comment 12

[Phabricator Automation]

Comment on attachment 8967419 [details]
Bug 1453658: [talos] Install cffi before trying to install mitmproxy dependencies.

Ben Hearsum (:bhearsum) has approved the revision.

https://phabricator.services.mozilla.com/D925

Comment 13

[Phabricator Automation]

Comment on attachment 8967418 [details]
Bug 1453658: Use pip options when install python3 modules.

Ben Hearsum (:bhearsum) has approved the revision.

https://phabricator.services.mozilla.com/D924

Comment 14

[Chris AtLee [:catlee]]

(In reply to Jake Watkins [:dividehex] from comment #9)
> Has anyone verified the host has the Root/Intermediate CA cert of the newly
> issued pypi certificate?  If this is using the system CA files (which nearly
> never get updated on our side), it is possible the certificate issued from
> Digicert might be signed by Root CAs (and/or intermediate CAs) the host
> doesn't have.

From curl:
* Server certificate:
*  subject: C=US; ST=California; L=San Francisco; O=Fastly, Inc; CN=r.ssl.fastly.net
*  start date: Apr 12 01:06:12 2018 GMT
*  expire date: May  5 18:54:01 2018 GMT
*  subjectAltName: host "files.pythonhosted.org" matched cert's "*.pythonhosted.org"
*  issuer: C=BE; O=GlobalSign nv-sa; CN=GlobalSign CloudSSL CA - SHA256 - G3
*  SSL certificate verify ok.

Comment 15

[Joel Maher ( :jmaher ) (UTC -8)]

what are the next steps on this bug?

Comment 16

[Tom Prince [:tomprince]]

My understanding was that Aryx was going to landed it and then merge it around.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/mozilla-central/rev/ad1e2f797d20
Use pip options when install python3 modules; r=bhearsum
https://hg.mozilla.org/mozilla-central/rev/16b880957aa7
[talos] Install cffi before trying to install mitmproxy dependencies; r=bhearsum a=Aryx

Comment 18

[Intermittent Failures Robot]

115 failures in 175 pushes (0.657 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-inbound: 57
* autoland: 44
* mozilla-beta: 14

Platform breakdown:
* windows7-32: 62
* windows10-64: 53

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1453658&startday=2018-04-12&endday=2018-04-12&tree=trunk

Comment 19

[Intermittent Failures Robot]

114 failures in 792 pushes (0.144 failures/push) were associated with this bug in the last 7 days. 

This is the #10 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **   

Repository breakdown:
* mozilla-inbound: 56
* autoland: 44
* mozilla-beta: 14

Platform breakdown:
* windows7-32: 64
* windows10-64: 50

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1453658&startday=2018-04-09&endday=2018-04-15&tree=trunk

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/b36fb5458ecb
https://hg.mozilla.org/releases/mozilla-beta/rev/1cf6b6ff8bd2