1050016 - bouncer.prod failing in both Web QA and ci.mozilla.org environments

Status: RESOLVED WONTFIX

(Webtools :: Bouncer, defect)

Description

[Stephen Donner [:stephend] Not actively reading bugmail]

Sorry, I don't know if this is an *actual* bouncer failure, but this needs investigation.  And, it should be noted that this is not just Web QA's bouncer.prod tests (which sometimes have transient issues due to network/firewall-traversal), but it's also affecting ci.mozilla.org's Webdev/IT/Webops job, too:

https://ci.mozilla.org/job/bouncer.prod/90474/console

17:54:15 Started by user Stephen Donner
17:54:15 [EnvInject] - Loading node environment variables.
17:54:15 Building on master in workspace /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace
17:54:15 Wiping out workspace first.
17:54:15 Cloning the remote Git repository
17:54:15 Cloning repository git://gitmirror.mozilla.org/mozilla/bouncer-tests
17:54:15  > git init /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace
17:54:15 Fetching upstream changes from git://gitmirror.mozilla.org/mozilla/bouncer-tests
17:54:15  > git --version
17:54:15  > git fetch --tags --progress git://gitmirror.mozilla.org/mozilla/bouncer-tests +refs/heads/*:refs/remotes/origin/*
17:54:15  > git config remote.origin.url git://gitmirror.mozilla.org/mozilla/bouncer-tests
17:54:15  > git config remote.origin.fetch +refs/heads/*:refs/remotes/origin/*
17:54:15  > git config remote.origin.url git://gitmirror.mozilla.org/mozilla/bouncer-tests
17:54:15 Fetching upstream changes from git://gitmirror.mozilla.org/mozilla/bouncer-tests
17:54:15  > git fetch --tags --progress git://gitmirror.mozilla.org/mozilla/bouncer-tests +refs/heads/*:refs/remotes/origin/*
17:54:15  > git rev-parse origin/master^{commit}
17:54:15 Checking out Revision 192f78375ac10eb180cbb32784d91e2b6e46da12 (origin/master)
17:54:15  > git config core.sparsecheckout
17:54:15  > git checkout -f 192f78375ac10eb180cbb32784d91e2b6e46da12
17:54:15  > git rev-list 192f78375ac10eb180cbb32784d91e2b6e46da12
17:54:15  > git tag -a -f -m Jenkins Build #51597 jenkins-bouncer.prod-51597
17:54:15 [EnvInject] - Executing scripts and injecting environment variables after the SCM step.
17:54:15 [EnvInject] - Injecting as environment variables the properties content 
17:54:15 PATH=${WORKSPACE}/.env/bin:/usr/bin:/bin:/usr/sbin:/sbin
17:54:15 
17:54:15 [EnvInject] - Variables injected successfully.
17:54:15 [workspace] $ /bin/sh -xe /var/folders/4l/gs6245j554z8tbdgvcb4chy800007v/T/hudson859710804372162470.sh
17:54:15 + virtualenv .env
17:54:15 New python executable in .env/bin/python
17:54:15 Installing Setuptools..............................................................................................................................................................................................................................done.
17:54:16 Installing Pip.....................................................................................................................................................................................................................................................................................................................................done.
17:54:16 [workspace] $ /bin/sh -xe /var/folders/4l/gs6245j554z8tbdgvcb4chy800007v/T/hudson6246661587833892977.sh
17:54:16 + pip install -Ur requirements.txt
17:54:30 Downloading/unpacking py==1.4.14 (from -r requirements.txt (line 4))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fp%2Fpy%2Fpy-1.4.14.tar.gz
17:54:30   Running setup.py egg_info for package py
17:54:30     
17:54:30 Downloading/unpacking pytest==2.3.5 (from -r requirements.txt (line 5))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fp%2Fpytest%2Fpytest-2.3.5.tar.gz
17:54:30   Running setup.py egg_info for package pytest
17:54:30     
17:54:30 Downloading/unpacking pytest-xdist==1.8 (from -r requirements.txt (line 6))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fp%2Fpytest-xdist%2Fpytest-xdist-1.8.zip
17:54:30   Running setup.py egg_info for package pytest-xdist
17:54:30     
17:54:30     no previously-included directories found matching '.hg'
17:54:30 Downloading/unpacking unittestzero (from -r requirements.txt (line 7))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2FU%2FUnittestZero%2FUnittestZero-0.2.0.tar.gz
17:54:30   Running setup.py egg_info for package unittestzero
17:54:30     
17:54:30 Downloading/unpacking requests==0.11.2 (from -r requirements.txt (line 8))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fr%2Frequests%2Frequests-0.11.2.tar.gz
17:54:30   Running setup.py egg_info for package requests
17:54:30     
17:54:30 Downloading/unpacking beautifulsoup4==4.0.4 (from -r requirements.txt (line 9))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fb%2Fbeautifulsoup4%2Fbeautifulsoup4-4.0.4.tar.gz
17:54:30   Running setup.py egg_info for package beautifulsoup4
17:54:30     
17:54:30 Downloading/unpacking execnet>=1.0.8 (from pytest-xdist==1.8->-r requirements.txt (line 6))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fe%2Fexecnet%2Fexecnet-1.2.0.tar.gz
17:54:30   Running setup.py egg_info for package execnet
17:54:30     
17:54:30     warning: no files found matching 'conftest.py'
17:54:30 Downloading/unpacking certifi>=0.0.7 (from requests==0.11.2->-r requirements.txt (line 8))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fc%2Fcertifi%2Fcertifi-14.05.14.tar.gz
17:54:30   Running setup.py egg_info for package certifi
17:54:30     
17:54:30 Downloading/unpacking chardet>=1.0.0 (from requests==0.11.2->-r requirements.txt (line 8))
17:54:30   Using download cache from /Users/Shared/Jenkins/.pip_download_cache/https%3A%2F%2Fpypi.python.org%2Fpackages%2Fsource%2Fc%2Fchardet%2Fchardet-2.2.1.tar.gz
17:54:30   Running setup.py egg_info for package chardet
17:54:30     
17:54:30     warning: no files found matching 'COPYING'
17:54:30 Installing collected packages: py, pytest, pytest-xdist, unittestzero, requests, beautifulsoup4, execnet, certifi, chardet
17:54:30   Running setup.py install for py
17:54:30     
17:54:30   Running setup.py install for pytest
17:54:30     
17:54:30     Installing py.test script to /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/.env/bin
17:54:30     Installing py.test-2.7 script to /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/.env/bin
17:54:30   Running setup.py install for pytest-xdist
17:54:30     
17:54:30     no previously-included directories found matching '.hg'
17:54:30   Running setup.py install for unittestzero
17:54:30     
17:54:30   Running setup.py install for requests
17:54:30     
17:54:30   Running setup.py install for beautifulsoup4
17:54:30     
17:54:30   Running setup.py install for execnet
17:54:30     
17:54:30     warning: no files found matching 'conftest.py'
17:54:30   Running setup.py install for certifi
17:54:30     
17:54:30   Running setup.py install for chardet
17:54:30     
17:54:30     warning: no files found matching 'COPYING'
17:54:30     Installing chardetect script to /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/.env/bin
17:54:30 Successfully installed py pytest pytest-xdist unittestzero requests beautifulsoup4 execnet certifi chardet
17:54:30 Cleaning up...
17:54:30 [workspace] $ /bin/sh -xe /var/folders/4l/gs6245j554z8tbdgvcb4chy800007v/T/hudson1033916651335035997.sh
17:54:30 + py.test -n 4 tests/test_redirects.py --baseurl=http://download.mozilla.org --junitxml=results.xml
17:54:31 ============================= test session starts ==============================
17:54:31 platform darwin -- Python 2.7.5 -- pytest-2.3.5
17:54:31 plugins: xdist
17:54:31 gw0 I / gw1 I / gw2 I / gw3 I
17:54:39 gw0 [278] / gw1 [278] / gw2 [278] / gw3 [278]
17:54:39 
17:54:39 scheduling tests via LoadScheduling
17:54:39 ...................................................................................................................................................................................................................................................................................F.F
17:54:44 =================================== FAILURES ===================================
17:54:44 _________ TestRedirects.test_stub_installer_redirect_for_en_us_and_win _________
17:54:44 [gw0] darwin -- Python 2.7.5 /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/.env/bin/python
17:54:44 self = <tests.test_redirects.TestRedirects instance at 0x1086db320>
17:54:44 base_url = 'http://download.mozilla.org', product = 'firefox-stub'
17:54:44 
17:54:44     @pytest.mark.xfail(
17:54:44         "config.getvalue('base_url') == 'http://download.allizom.org'"
17:54:44     )
17:54:44     def test_stub_installer_redirect_for_en_us_and_win(self, base_url, product):
17:54:44         param = {
17:54:44             'product': product,
17:54:44             'lang': 'en-US',
17:54:44             'os': 'win'
17:54:44         }
17:54:44     
17:54:44         response = self._head_request(base_url, params=param)
17:54:44     
17:54:44         parsed_url = urlparse(response.url)
17:54:44     
17:54:44         Assert.equal(
17:54:44             response.status_code,
17:54:44             requests.codes.ok,
17:54:44             'Redirect failed with HTTP status %s. \n %s' %
17:54:44             (response.status_code, self.response_info_failure_message(
17:54:44                 base_url,
17:54:44                 param,
17:54:44                 response))
17:54:44         )
17:54:44         Assert.equal(
17:54:44             parsed_url.scheme,
17:54:44             'https',
17:54:44             'Failed by redirected to incorrect scheme %s. \n %s' %
17:54:44             (parsed_url.scheme, self.response_info_failure_message(
17:54:44                 base_url,
17:54:44                 param,
17:54:44                 response))
17:54:44         )
17:54:44         Assert.equal(
17:54:44             parsed_url.netloc,
17:54:44             'download-installer.cdn.mozilla.net',
17:54:44             'Failed by redirected to incorrect host %s. \n %s' %
17:54:44             (parsed_url.netloc, self.response_info_failure_message(
17:54:44                 base_url,
17:54:44                 param,
17:54:44 >               response))
17:54:44         )
17:54:44 
17:54:44 tests/test_redirects.py:151: 
17:54:44 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
17:54:44 
17:54:44 self = <class 'unittestzero.Assert'>, first = u'ftp.mozilla.org'
17:54:44 second = 'download-installer.cdn.mozilla.net'
17:54:44 msg = u"Failed by redirected to incorrect host ftp.mozilla.org. \n Failed on http://...irefox%20Setup%20Stub%2031.0.exe\n X-Backend-Server: ftp8.dmz.scl3.mozilla.com"
17:54:44 
17:54:44     @classmethod
17:54:44     def equal(self, first, second, msg=None):
17:54:44         """
17:54:44             Asserts that 2 elements are the same
17:54:44     
17:54:44             :Args:
17:54:44              - First object to be tested
17:54:44              - Second object to be tested
17:54:44              - Message that will be printed if it fails
17:54:44             """
17:54:44 >       assert first == second, msg
17:54:44 E       AssertionError: Failed by redirected to incorrect host ftp.mozilla.org. 
17:54:44 E        Failed on http://download.mozilla.org 
17:54:44 E       Using {'lang': 'en-US', 'product': 'firefox-stub', 'os': 'win'}.
17:54:44 E        Response URL: https://ftp.mozilla.org/pub/mozilla.org/firefox/releases/31.0/win32/en-US/Firefox%20Setup%20Stub%2031.0.exe
17:54:44 E        X-Backend-Server: ftp8.dmz.scl3.mozilla.com
17:54:44 
17:54:44 .env/lib/python2.7/site-packages/unittestzero.py:55: AssertionError
17:54:44 _______ TestRedirects.test_redirect_for_firefox_aliases[product_alias3] ________
17:54:44 [gw0] darwin -- Python 2.7.5 /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/.env/bin/python
17:54:44 self = <tests.test_redirects.TestRedirects instance at 0x108607908>
17:54:44 base_url = 'http://download.mozilla.org'
17:54:44 product_alias = {'lang': 'en-US', 'product_name': 'firefox-beta-stub'}
17:54:44 
17:54:44     @pytest.mark.parametrize('product_alias', [
17:54:44         {'product_name': 'firefox-beta-latest', 'lang': 'en-US'},
17:54:44         {'product_name': 'firefox-latest-euballot', 'lang': 'en-GB'},
17:54:44         {'product_name': 'firefox-latest', 'lang': 'en-US'},
17:54:44         {'product_name': 'firefox-beta-stub', 'lang': 'en-US'},
17:54:44         {'product_name': 'firefox-nightly-latest', 'lang': 'en-US'},
17:54:44     ])
17:54:44     def test_redirect_for_firefox_aliases(self, base_url, product_alias):
17:54:44     
17:54:44         if product_alias == {
17:54:44             'product_name': 'firefox-latest',
17:54:44             'lang': 'en-US'
17:54:44         } and base_url == 'http://download.allizom.org':
17:54:44             pytest.xfail(
17:54:44                 reason='https://bugzilla.mozilla.org/show_bug.cgi?id=813968 - '
17:54:44                 'Alias returns 404')
17:54:44     
17:54:44         if product_alias == {
17:54:44             'product_name': 'firefox-nightly-latest',
17:54:44             'lang': 'en-US'
17:54:44         } and base_url == 'http://download.allizom.org':
17:54:44             pytest.xfail(
17:54:44                 reason='https://github.com/mozilla/bouncer-tests/issues/46'
17:54:44                 'Alias returns 404')
17:54:44     
17:54:44         param = {
17:54:44             'product': product_alias['product_name'],
17:54:44             'os': 'win',
17:54:44             'lang': product_alias['lang']
17:54:44         }
17:54:44     
17:54:44         response = self._head_request(base_url, params=param)
17:54:44     
17:54:44         parsed_url = urlparse(response.url)
17:54:44     
17:54:44         if not (
17:54:44             product_alias['product_name'] == 'firefox-latest-euballot' and
17:54:44             "download.allizom.org" in base_url
17:54:44         ):
17:54:44             url_scheme = 'http'
17:54:44             if product_alias['product_name'] == 'firefox-beta-stub':
17:54:44                 url_scheme = 'https'
17:54:44             Assert.equal(
17:54:44                 response.status_code,
17:54:44                 requests.codes.ok,
17:54:44                 'Redirect failed with HTTP status %s. \n %s' %
17:54:44                 (response.status_code, self.response_info_failure_message(
17:54:44                     base_url,
17:54:44                     param,
17:54:44                     response))
17:54:44             )
17:54:44             Assert.equal(
17:54:44                 parsed_url.scheme,
17:54:44                 url_scheme,
17:54:44                 'Failed by redirected to incorrect scheme %s. \n %s' %
17:54:44                 (parsed_url.scheme, self.response_info_failure_message(
17:54:44                     base_url,
17:54:44                     param,
17:54:44                     response))
17:54:44             )
17:54:44             Assert.true(
17:54:44                 parsed_url.netloc.endswith(
17:54:44                     ('download.cdn.mozilla.net', 'edgecastcdn.net',
17:54:44                         'download-installer.cdn.mozilla.net')
17:54:44                 ),
17:54:44                 'Failed by redirected to incorrect host %s. \n %s' %
17:54:44                 (parsed_url.netloc, self.response_info_failure_message(
17:54:44                     base_url,
17:54:44                     param,
17:54:44 >                   response))
17:54:44             )
17:54:44 
17:54:44 tests/test_redirects.py:223: 
17:54:44 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
17:54:44 
17:54:44 self = <class 'unittestzero.Assert'>, first = False
17:54:44 msg = u"Failed by redirected to incorrect host ftp.mozilla.org. \n Failed on http://...efox%20Setup%20Stub%2032.0b4.exe\n X-Backend-Server: ftp3.dmz.scl3.mozilla.com"
17:54:44 
17:54:44     @classmethod
17:54:44     def true(self, first, msg=None):
17:54:44         """
17:54:44             Asserts that what is given is equal to True
17:54:44     
17:54:44             :Args:
17:54:44              - First object to be tested
17:54:44              - Message that will be printed if it fails
17:54:44             """
17:54:44     
17:54:44 >       assert bool(first) is True, msg
17:54:44 E       AssertionError: Failed by redirected to incorrect host ftp.mozilla.org. 
17:54:44 E        Failed on http://download.mozilla.org 
17:54:44 E       Using {'lang': 'en-US', 'product': 'firefox-beta-stub', 'os': 'win'}.
17:54:44 E        Response URL: https://ftp.mozilla.org/pub/mozilla.org/firefox/releases/32.0b4/win32/en-US/Firefox%20Setup%20Stub%2032.0b4.exe
17:54:44 E        X-Backend-Server: ftp3.dmz.scl3.mozilla.com
17:54:44 
17:54:44 .env/lib/python2.7/site-packages/unittestzero.py:79: AssertionError
17:54:44  generated xml file: /Users/Shared/Jenkins/Home/jobs/bouncer.prod/workspace/results.xml 
17:54:44 ==================== 2 failed, 276 passed in 13.07 seconds =====================
17:54:44 Build step 'Execute shell' marked build as failure
17:54:44 Archiving artifacts
17:54:44 Recording test results
17:54:44 Sending e-mails to: [e-mail]
17:54:44 Finished: FAILURE

Comment 1

[Nick Thomas [:nthomas] (UTC+12)]

Might be fallout from bug 829192, adding gozer to CC.

Can't reproduce right now though:

$ curl -sIL "http://download.mozilla.org/?product=firefox-stub&os=win&lang=en-US" | egrep '^(HTTP|Location)'
HTTP/1.1 302 Found
Location: https://download-installer.cdn.mozilla.net/pub/firefox/releases/31.0/win32/en-US/Firefox%20Setup%20Stub%2031.0.exe
HTTP/1.1 200 OK

$ curl -sIL "http://download.mozilla.org/?product=firefox-beta-stub&os=win&lang=en-US" | egrep '^(HTTP|Location)'
HTTP/1.1 302 Found
Location: https://download-installer.cdn.mozilla.net/pub/firefox/releases/32.0b4/win32/en-US/Firefox%20Setup%20Stub%2032.0b4.exe
HTTP/1.1 200 OK

Comment 2

[Stephen Donner [:stephend] Not actively reading bugmail]

Attachment: Screen Shot 2014-08-06 at 6.32.05 PM.png

Comment 3

[Nick Thomas [:nthomas] (UTC+12)]

Assuming https://nagios.mozilla.org/sentry/ is still good to look at after bug 829192, there are some issues polling download-installer.cdn.mozilla.net. Pretty close to the same time jenkins was finding issues (it's fine now, lowering severity).

Specifically,
 http://download-installer.cdn.mozilla.net/pub was disabled between 00:05 and 00:15 UTC
 https://download-installer.cdn.mozilla.net/pub was disabled between 00:15 and 00:20, and 00:35 and 00:55

The failing logs all have this message at the end
*** https://download-installer.cdn.mozilla.net/pub took longer than 6 minutes to execute file checks ... assuming host is overloaded and pulling it out.
That leaves only https://ftp.m.o to serve stub installers and other products marked ssl-only.

gozer, we've had issues with highwinds taking that long but didn't tend to get it for download-installer.cdn.mozilla.net when sentry was in SCL3. Which CDN do we get from PHX1 ? I'm getting edgecast when I try from another box there.

Comment 4

[Philippe M. Chiasson (:gozer)]

(In reply to Nick Thomas [:nthomas] from comment #3)
> [...]
>
> gozer, we've had issues with highwinds taking that long but didn't tend to
> get it for download-installer.cdn.mozilla.net when sentry was in SCL3. Which
> CDN do we get from PHX1 ? I'm getting edgecast when I try from another box
> there.

Currently getting edgecast from both new and old system.

Comment 5

[Robert Helmer [:rhelmer]]

We saw this happen earlier today on stage and it cleared without intervention too - I noticed that ftp.m.o was set up on stage as a valid mirror, and from my reading of https://github.com/mozilla/tuxedo/blob/master/bouncer/php/functions.php#L12 that means that it will occasionally be picked, because rating is treated as a weighted probability.

Comment 6

[Philippe M. Chiasson (:gozer)]

Disabled PHX1 in Dynect for the next few hours, to see if that makes the issue vanish.

Comment 7

[Philippe M. Chiasson (:gozer)]

Re-Enabled PHX1, this didn't change anything.

Upon looking further, the problem seems not to be getting a response from download.m.o, but rather following the redirect it sends to http://download-installer.cdn.mozilla.net/

Therefore, pointing the finger at EdgeCast having issues on its own or reaching cdn-origin

Comment 8

[Philippe M. Chiasson (:gozer)]

More failures overnight:

bouncer.prod #91765 (broken since this build)
08/11/2014 08:31 AM

bouncer.prod #91730 (broken since this build)
08/11/2014 05:36 AM

bouncer.prod #91715 (broken since this build)
08/11/2014 04:21 AM

Comment 9

[Philippe M. Chiasson (:gozer)]

Closing for now, looks like EdgeCast is not experiencing these issues anymore...