Closed Bug 792010 Opened 13 years ago Closed 13 years ago

balrog client getting ISE 500 error on mac

Categories

(Release Engineering :: General, defect)

Product:
Release Engineering
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: bhearsum, Assigned: bhearsum)

References

Details

Attachments

(2 files)

detect state where platform exists but not locales, log it
1.31 KB, patch
rail
: review+
bhearsum
: checked-in+
Details | Diff | Splinter Review
resolve alias' before altering anything
10.23 KB, patch
rail
: review+
nthomas
: review+
bhearsum
: checked-in+
Details | Diff | Splinter Review
Haven't been able to dig up the server logs yet: retry: Calling <function run_with_timeout at 0x10052dc80> with args: (['python', '/builds/slave/m-cen-osx64-ntly/tools/scripts/updates/balrog-client.py', '--build-properties', 'buildprops_balrog.json', '--api-root', 'https://aus4-admin-dev.allizom.org', '--verbose', '--credentials-file', 'BuildSlaves.py'], 1260, None, None, False, True), kwargs: {}, attempt #1 Executing: ['python', '/builds/slave/m-cen-osx64-ntly/tools/scripts/updates/balrog-client.py', '--build-properties', 'buildprops_balrog.json', '--api-root', 'https://aus4-admin-dev.allizom.org', '--verbose', '--credentials-file', 'BuildSlaves.py'] Balrog request to https://aus4-admin-dev.allizom.org/releases/Firefox-mozilla-central-nightly-20120917030530 Data sent: None Starting new HTTPS connection (1): aus4-admin-dev.allizom.org "HEAD /releases/Firefox-mozilla-central-nightly-20120917030530 HTTP/1.1" 404 0 Caught HTTPError: Balrog request to https://aus4-admin-dev.allizom.org/csrf_token Data sent: None Starting new HTTPS connection (2): aus4-admin-dev.allizom.org "HEAD /csrf_token HTTP/1.1" 200 0 Got CSRF Token: 20120917044713##28ec7f9a8b0a4d96720e6762baae1fe36c17b3b7 Balrog request to https://aus4-admin-dev.allizom.org/releases/Firefox-mozilla-central-nightly-20120917030530/builds/Darwin_x86-gcc3-u-i386-x86_64/en-US Data sent: {'csrf_token': '20120917044713##28ec7f9a8b0a4d96720e6762baae1fe36c17b3b7', 'product': 'Firefox', 'version': '18.0a1', 'data': '{"buildID": "20120917030530", "appv": "18.0a1", "partial": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-17-03-05-30-mozilla-central/firefox-18.0a1.en-US.mac.partial.20120916030607-20120917030530.mar", "hashValue": "e863fc8a9c3cdc8ee61cc01eb9ccaf5e9a3f0ae1299d2dc05ba9766e0bb8446be2a0193fa25d0f80c91b7323b1baa893238bca8a4f5c00b5ee2ad3f8dcb9c394", "from": "Firefox-mozilla-central-nightly-20120916030607", "filesize": "2279024"}, "complete": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-17-03-05-30-mozilla-central/firefox-18.0a1.en-US.mac.complete.mar", "hashValue": "2c5e17a339a7e7c4dd6db0229b4eeda6adf686f38c24b4b686a5c2971652514e976005f5ac8d89b20975c290db04bf5cda4dc39c6f6f7402d3371deee6488a6e", "from": "*", "filesize": "44857108"}, "extv": "18.0a1"}', 'copyTo': '["Firefox-mozilla-central-nightly-latest"]'} Starting new HTTPS connection (3): aus4-admin-dev.allizom.org "PUT /releases/Firefox-mozilla-central-nightly-20120917030530/builds/Darwin_x86-gcc3-u-i386-x86_64/en-US HTTP/1.1" 500 541 Caught HTTPError: <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN"> <html><head> <title>500 Internal Server Error</title> </head><body> <h1>Internal Server Error</h1> <p>The server encountered an internal error or misconfiguration and was unable to complete your request.</p> <p>Please contact the server administrator, webmaster@mozilla.com and inform them of the time the error occurred, and anything you might have done that may have caused the error.</p> <p>More information about this error may be available in the server error log.</p> </body></html> Traceback (most recent call last): File "/builds/slave/m-cen-osx64-ntly/tools/scripts/updates/balrog-client.py", line 36, in <module> runner.run() File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/balrog/client/cli.py", line 80, in run buildData=data, copyTo=copyTo) File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/balrog/client/api.py", line 121, in update_build url_template_vars=url_template_vars) File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/balrog/client/api.py", line 93, in request return self.do_request(url, data, method, url_template_vars) File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/balrog/client/api.py", line 101, in do_request verify=self.verify, auth=self.auth) File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/vendor/requests-0.10.8/requests/sessions.py", line 203, in request r.send(prefetch=prefetch) File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/vendor/requests-0.10.8/requests/models.py", line 585, in send self.response.raise_for_status() File "/builds/slave/m-cen-osx64-ntly/tools/lib/python/vendor/requests-0.10.8/requests/models.py", line 816, in raise_for_status raise http_error requests.exceptions.HTTPError: 500 Server Error
Assignee: nobody → bhearsum
Found this in the server logs: 2012-09-18 06:33:52,373 - auslib.admin.base.handle_exception#1021: Exception on /releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR [PUT] Traceback (most recent call last): File "/usr/lib/python2.6/site-packages/flask/app.py", line 1292, in wsgi_app response = self.full_dispatch_request() File "/usr/lib/python2.6/site-packages/flask/app.py", line 1062, in full_dispatch_request rv = self.handle_user_exception(e) File "/usr/lib/python2.6/site-packages/flask/app.py", line 1060, in full_dispatch_request rv = self.dispatch_request() File "/usr/lib/python2.6/site-packages/flask/app.py", line 1047, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/usr/lib/python2.6/site-packages/flask/views.py", line 56, in view return self.dispatch_request(*args, **kwargs) File "/usr/lib/python2.6/site-packages/flask/views.py", line 112, in dispatch_request return meth(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 46, in put return self._put(*args, transaction=trans, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 46, in put return self._put(*args, transaction=trans, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 13, in decorated return f(*args, changed_by=username, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 29, in decorated return f(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 147, in _put return changeRelease(release, changed_by, transaction, exists, commit, self.log) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 107, in changeRelease commitCallback(rel, product, version, incomingData, releaseInfo['data'], old_data_version) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 145, in commit return retry(db.releases.addLocaleToRelease, kwargs=dict(name=rel, platform=platform, locale=locale, data=localeData, old_data_version=old_data_version, changed_by=changed_by, transaction=transaction)) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/util/retry.py", line 12, in retry return upstream_retry(*a, **kw) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/vendor/lib/python/mozilla_buildtools/retry.py", line 27, in retry return action(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/db.py", line 789, in addLocaleToRelease transaction=transaction) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/db.py", line 386, in update return self._prepareUpdate(transaction, where, what, changed_by, old_data_version) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/db.py", line 360, in _prepareUpdate raise OutdatedDataError("Failed to update row, old_data_version doesn't match current data_version") OutdatedDataError: Failed to update row, old_data_version doesn't match current data_version 2012-09-18 06:33:52,376 - auslib.admin.base.isa#21: Caught ISE 500 error. 2012-09-18 06:33:52,377 - auslib.admin.base.isa#22: Balrog version is: 0.1.4 2012-09-18 06:33:52,377 - auslib.admin.base.isa#23: Request path is: /releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR 2012-09-18 06:33:52,378 - auslib.admin.base.isa#24: Request environment is: {'AUTH_TYPE': 'Basic', 'HTTP_AUTHORIZATION': 'Basic c3RhZ2UtZmZ4YmxkOkJsZEcwZA==', 'mod_wsgi.listener_port': '81', 'AUTHENTICATE_MAIL': 'stage-ffxbld', 'HTTP_SSLCLIENTCERTSTATUS': 'NoClientCert', 'SERVER_SOFTWARE': 'Apache', 'SCRIPT_NAME': '', 'mod_wsgi.handler_script': '', 'SERVER_SIGNATURE': '', 'REQUEST_METHOD': 'PUT', 'PATH_INFO': '/releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR', 'SERVER_PROTOCOL': 'HTTP/1.1', 'QUERY_STRING': '', 'HTTP_SSLSESSIONID': 'AB719DE21D9885710E5FCDCC557717B73B5DE1E74F6586B7F4AD1B4775B02048', 'CONTENT_LENGTH': '1235', 'HTTP_USER_AGENT': 'python-requests/0.10.8', 'HTTP_COOKIE': 'session="IdxFcv2Rpp1QEq7tjPCdoQn32xE=?csrf=UydiZjEzNGFiZGMzNjE0MzM0N2NmNmQ4YmIzMmNjN2UyMTEwMGE0YjJiJwpwMQou"', 'SERVER_NAME': 'aus4-admin-dev.allizom.org', 'REMOTE_ADDR': '10.8.33.241', 'mod_wsgi.request_handler': 'wsgi-script', 'wsgi.url_scheme': 'https', 'HTTP_SSLCLIENTCIPHER': 'SSL_RSA_WITH_RC4_128_SHA, version=TLSv1, bits=128', 'PATH_TRANSLATED': '/data/www/aus4-admin-dev.allizom.org/aus4-admin/admin.wsgi/releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR', 'SERVER_PORT': '80', 'wsgi.multiprocess': True, 'mod_wsgi.input_chunked': '0', 'SERVER_ADDR': '10.8.33.19', 'DOCUMENT_ROOT': '/data/www/aus4-admin-dev.allizom.org/', 'mod_wsgi.process_group': 'aus4-admin', 'werkzeug.request': <Request 'https://aus4-admin-dev.allizom.org/releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR' [PUT]>, 'SCRIPT_FILENAME': '/data/www/aus4-admin-dev.allizom.org/aus4-admin/admin.wsgi', 'SERVER_ADMIN': 'webmaster@mozilla.com', 'wsgi.input': <mod_wsgi.Input object at 0xb3135390>, 'REMOTE_USER': 'stage-ffxbld', 'HTTP_HOST': 'aus4-admin-dev.allizom.org', 'HTTPS': 'on', 'wsgi.multithread': True, 'mod_wsgi.callable_object': 'application', 'REQUEST_URI': '/releases/Thunderbird-comm-aurora-nightly-20120918042014/builds/Darwin_x86-gcc3-u-i386-x86_64/pt-BR', 'HTTP_ACCEPT': '*/*', 'wsgi.version': (1, 1), 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <mod_wsgi.Log object at 0xb3135480>, 'REMOTE_PORT': '38066', 'mod_wsgi.listener_host': '', 'mod_wsgi.version': (3, 2), 'CONTENT_TYPE': 'application/x-www-form-urlencoded', 'mod_wsgi.application_group': 'aus4-admin-dev.allizom.org|', 'mod_wsgi.script_reloading': '1', 'wsgi.file_wrapper': <built-in method file_wrapper of mod_wsgi.Adapter object at 0xb3333a40>, 'HTTP_X_CLUSTER_CLIENT_IP': '63.245.214.82', 'HTTP_ACCEPT_ENCODING': 'identity, deflate, compress, gzip'} 2012-09-18 06:33:52,380 - auslib.admin.base.isa#25: Request headers are: Authorization: Basic c3RhZ2UtZmZ4YmxkOkJsZEcwZA==^M Sslclientcertstatus: NoClientCert^M Sslsessionid: AB719DE21D9885710E5FCDCC557717B73B5DE1E74F6586B7F4AD1B4775B02048^M Content-Length: 1235^M User-Agent: python-requests/0.10.8^M Cookie: session="IdxFcv2Rpp1QEq7tjPCdoQn32xE=?csrf=UydiZjEzNGFiZGMzNjE0MzM0N2NmNmQ4YmIzMmNjN2UyMTEwMGE0YjJiJwpwMQou"^M Sslclientcipher: SSL_RSA_WITH_RC4_128_SHA, version=TLSv1, bits=128^M Host: aus4-admin-dev.allizom.org^M Accept: */*^M Content-Type: application/x-www-form-urlencoded^M X-Cluster-Client-Ip: 63.245.214.82^M Accept-Encoding: identity, deflate, compress, gzip^M ^M
Digging through a bit more, I find this interesting. The first time we sent a request we don't include data_version: Data sent: {'csrf_token': '20120919045401##0048ab7ed122e61fdc652d3641597f3eb578031b', 'product': 'Firefox', 'version': '18.0a1', 'data': '{"buildID": "20120919030602", "appv": "18.0a1", "partial": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.partial.20120918030553-20120919030602.mar", "hashValue": "d854d7fed65605c1b24f280d76ed7ede3d9c86b266e83324c8bd89a6bc1d9c16bc39484769f08842b0bd8ec167d01fff67ff48b22c00173c2cef74fac56309f6", "from": "Firefox-mozilla-central-nightly-20120918030553", "filesize": "3869674"}, "complete": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.complete.mar", "hashValue": "2f27284eceff35aa81d66981413c5646566259eebf81a3afa3de6a6472ef7969877ba1424e761d962ba8f0429e634e0e104d4141f9c16c071a9006c74cd11647", "from": "*", "filesize": "44877325"}, "extv": "18.0a1"}', 'copyTo': '["Firefox-mozilla-central-nightly-latest"]'} The subsequent times we do, and it increases each time: Data sent: {'product': 'Firefox', 'csrf_token': '20120919045404##8fcef1a34eb1f2467fa90a018fdbe8a5d6658b9b', 'data_version': '2', 'copyTo': '["Firefox-mozilla-central-nightly-latest"]', 'version': '18.0a1', 'data': '{"buildID": "20120919030602", "appv": "18.0a1", "partial": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.partial.20120918030553-20120919030602.mar", "hashValue": "d854d7fed65605c1b24f280d76ed7ede3d9c86b266e83324c8bd89a6bc1d9c16bc39484769f08842b0bd8ec167d01fff67ff48b22c00173c2cef74fac56309f6", "from": "Firefox-mozilla-central-nightly-20120918030553", "filesize": "3869674"}, "complete": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.complete.mar", "hashValue": "2f27284eceff35aa81d66981413c5646566259eebf81a3afa3de6a6472ef7969877ba1424e761d962ba8f0429e634e0e104d4141f9c16c071a9006c74cd11647", "from": "*", "filesize": "44877325"}, "extv": "18.0a1"}'} Data sent: {'product': 'Firefox', 'csrf_token': '20120919045407##155bf3aa6b2ac6ac6e2a1f50332c3186e898da86', 'data_version': '3', 'copyTo': '["Firefox-mozilla-central-nightly-latest"]', 'version': '18.0a1', 'data': '{"buildID": "20120919030602", "appv": "18.0a1", "partial": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.partial.20120918030553-20120919030602.mar", "hashValue": "d854d7fed65605c1b24f280d76ed7ede3d9c86b266e83324c8bd89a6bc1d9c16bc39484769f08842b0bd8ec167d01fff67ff48b22c00173c2cef74fac56309f6", "from": "Firefox-mozilla-central-nightly-20120918030553", "filesize": "3869674"}, "complete": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-03-06-02-mozilla-central/firefox-18.0a1.en-US.mac.complete.mar", "hashValue": "2f27284eceff35aa81d66981413c5646566259eebf81a3afa3de6a6472ef7969877ba1424e761d962ba8f0429e634e0e104d4141f9c16c071a9006c74cd11647", "from": "*", "filesize": "44877325"}, "extv": "18.0a1"}'} The root of the problem here might be that we're not sending it in the first place?
This problem actually seems to be intermittent, there's examples of submissions working fine, too: retry: Calling <function run_with_timeout at 0x10052dc08> with args: (['python', '/builds/slave/m-aurora-osx64-l10n-ntly/tools/scripts/updates/balrog-client.py', '--build-properties', 'buildprops_balrog.json', '--api-root', 'https://aus4-admin-dev.allizom.org', '--verbose', '--credentials-file', 'BuildSlaves.py'], 1260, None, None, False, True), kwargs: {}, attempt #1 Executing: ['python', '/builds/slave/m-aurora-osx64-l10n-ntly/tools/scripts/updates/balrog-client.py', '--build-properties', 'buildprops_balrog.json', '--api-root', 'https://aus4-admin-dev.allizom.org', '--verbose', '--credentials-file', 'BuildSlaves.py'] Balrog request to https://aus4-admin-dev.allizom.org/releases/Firefox-mozilla-aurora-nightly-20120919042010 Data sent: None Starting new HTTPS connection (1): aus4-admin-dev.allizom.org "HEAD /releases/Firefox-mozilla-aurora-nightly-20120919042010 HTTP/1.1" 200 0 Got CSRF Token: 20120919060519##1ce671259e260aba9224b1ca3536ef2ca8f59bb3 Balrog request to https://aus4-admin-dev.allizom.org/releases/Firefox-mozilla-aurora-nightly-20120919042010/builds/Darwin_x86-gcc3-u-i386-x86_64/zh-TW Data sent: {'product': 'Firefox', 'csrf_token': '20120919060519##1ce671259e260aba9224b1ca3536ef2ca8f59bb3', 'data_version': '20', 'copyTo': '["Firefox-mozilla-aurora-nightly-latest"]', 'version': '17.0a2', 'data': '{"buildID": "20120919042010", "appv": "17.0a2", "partial": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-04-20-10-mozilla-aurora-l10n/firefox-17.0a2.zh-TW.mac.partial.20120918042011-20120919042010.mar", "hashValue": "3a7bf9f77d9cd7483c9f9b9d1e267e42c66bdc8f5c9ec05b694cf472c0c8da484c3600d459e32c465e0983c0ce889a0bf48f8ac62a45cedb5f9664b2b48c6f47", "from": "Firefox-mozilla-aurora-nightly-20120918042011", "filesize": "1195806"}, "complete": {"fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-19-04-20-10-mozilla-aurora-l10n/firefox-17.0a2.zh-TW.mac.complete.mar", "hashValue": "66a5b67a7f3c545acf3398fa13d92ee92ee6bf9bd4ba888fa715b0a1c8c392f07b6ca427af6a99f4d0d095c2447e120098c33abe6b910e2bfae2782f6207877d", "from": "*", "filesize": "44760024"}, "extv": "17.0a2"}'} Starting new HTTPS connection (2): aus4-admin-dev.allizom.org "PUT /releases/Firefox-mozilla-aurora-nightly-20120919042010/builds/Darwin_x86-gcc3-u-i386-x86_64/zh-TW HTTP/1.1" 201 24 program finished with exit code 0 This part is interesting too: This log shows the Balrog client giving up after 5 attempts: https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012-09-19-03-06-02-mozilla-central/mozilla-central-macosx64-nightly-bm32-build1-build27.txt.gz However, the release it was submitting to (Firefox-mozilla-central-nightly-20120919030602) has data for Mac en-US (https://aus4-admin-dev.allizom.org/releases/Firefox-mozilla-central-nightly-20120919030602/data) But the -latest blob doesn't. In fact, the latest blob only has recent data for the Linux build I submitted today as part of testing bug 792009. -latest is listed in "copyTo" rather than the URL, so it seems like there's something busted in the logic that's handling copyTo...
OK, so this definitely isn't related to not sending data_version in the initial request -- that was just because i was looking at en-US. There's locales hitting this bug too, which send data_version in the initial attempt and still get a 500 error (eg https://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012-09-19-03-06-02-mozilla-central-l10n/mozilla-central-macosx64-l10n-nightly-th-bm13-build1-build959.txt.gz)
What's more confusing is that one blob is getting updated but not the other.....the server is supposed to roll back whenever an error happens. The log is confusing on this matter. There's this: 2012-09-19 06:13:48,528 - mozilla_buildtools.retry.retry#33: retry: Giving up on <bound method Releases.addLocaleToRelease of <auslib.db.Releases object at 0xb413750c>> 2012-09-19 06:13:48,529 - AUSTransaction.__exit__#64: exc is: None And then immediately after: 2012-09-19 06:13:48,534 - auslib.admin.base.handle_exception#1021: Exception on /releases/Thunderbird-comm-aurora-nightly-20120919042002/builds/Darwin_x86-gcc3-u-i386-x86_64/nb-NO [PUT] followed by a traceback. So somehow the transaction isn't seeing it, but it's still getting raised? That doesn't make any sense =\.
I think I found the root exception: 2012-09-19 04:24:02,947 - auslib.admin.base.handle_exception#1021: Exception on /releases/Firefox-mozilla-central-nightly-20120919030602/builds/Darwin_x86-gcc3-u-i386-x86_64/en-US [PUT] Traceback (most recent call last): File "/usr/lib/python2.6/site-packages/flask/app.py", line 1292, in wsgi_app response = self.full_dispatch_request() File "/usr/lib/python2.6/site-packages/flask/app.py", line 1062, in full_dispatch_request rv = self.handle_user_exception(e) File "/usr/lib/python2.6/site-packages/flask/app.py", line 1060, in full_dispatch_request rv = self.dispatch_request() File "/usr/lib/python2.6/site-packages/flask/app.py", line 1047, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/usr/lib/python2.6/site-packages/flask/views.py", line 56, in view return self.dispatch_request(*args, **kwargs) File "/usr/lib/python2.6/site-packages/flask/views.py", line 112, in dispatch_request return meth(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 46, in put return self._put(*args, transaction=trans, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 46, in put return self._put(*args, transaction=trans, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 13, in decorated return f(*args, changed_by=username, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/base.py", line 29, in decorated return f(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 147, in _put return changeRelease(release, changed_by, transaction, exists, commit, self.log) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 107, in changeRelease commitCallback(rel, product, version, incomingData, releaseInfo['data'], old_data_version) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/admin/views/releases.py", line 145, in commit return retry(db.releases.addLocaleToRelease, kwargs=dict(name=rel, platform=platform, locale=locale, data=localeData, old_data_version=old_data_version, changed_by=changed_by, transaction=transaction)) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/util/retry.py", line 12, in retry return upstream_retry(*a, **kw) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/vendor/lib/python/mozilla_buildtools/retry.py", line 27, in retry return action(*args, **kwargs) File "/data/www/aus4-admin-dev.allizom.org/aus4-admin/auslib/db.py", line 783, in addLocaleToRelease releaseBlob['platforms'][platform]['locales'][locale] = data KeyError: 'locales'
I'm not sure where else to go with this bug right now, but I'm hoping this patch will glean some additional information. I see tons of the "KeyError: 'locales'" since Sept 15th, when the log problem was fixed, so I do believe this is related. In addition to the extra logging I've also had it fix up the state of the platform in the small hope that it will fix this issue. Even if it does, I'd like to try and figure out what the root of the problem was.
Attachment #662661 - Flags: review?(rail)
Attachment #662661 - Flags: review?(rail) → review+
Attachment #662661 - Flags: checked-in+
So, I forgot to reload apache after landing the patch last night. I reloaded this morning and re-ran the failed mac balrog client from this morning, and it managed to submit data fine. So, the little fix I put seems to have worked. We also got this new log message: 2012-09-20 09:58:06,107 - Releases.addLocaleToRelease#783: WEIRD: platform Darwin_x86-gcc3-u-i386-x86_64 exists in Firefox-mozilla-central-nightly-latest blob, but has no locales. Current platform blob is: {'alias': 'Darwin_x86_64-gcc3'} In the blob, we have: "Darwin_x86-gcc3-u-i386-x86_64": { "alias": "Darwin_x86_64-gcc3", "locales": { "en-US": { "buildID": "20120920030543", "appv": "18.0a1", "partial": { "fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-20-03-05-43-mozilla-central/firefox-18.0a1.en-US.mac.partial.20120919030602-20120920030543.mar", "from": "Firefox-mozilla-central-nightly-20120919030602", "hashValue": "eb38567db913eb7ad006ba50fa444d70c205fec60df67db477817a569ef522374ba46aa428550ccdbc46b6ff9aa19f195fa923b29a0b1e936700746727ca6443", "filesize": "4505806" }, "complete": { "fileUrl": "http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2012/09/2012-09-20-03-05-43-mozilla-central/firefox-18.0a1.en-US.mac.complete.mar", "from": "*", "hashValue": "a71b5a775afeef889b9e958f3232ff40f596cc5be261cf781437e33ffe554047e6e2444e86a1b45f4fa3f895144b87a059d672a5db27e6780c33e21e46ef6eee", "filesize": "44852187" }, "extv": "18.0a1" } } }, and the Darwin_x86_64-gcc3 platform has *all* the locales (albeit, old updates for them). So I think the issue here is that the -latest blob still has all the data in Darwin_x86_64-gcc3. That platform was removed in bug 775236, so now we're submitting data to Darwin_x86-gcc3-u-i386-x86_64 instead, which existed but only had an alias set. I think the fix for this is pretty simple: Resolve alias' when making changes to a platform. Right now, any locale information you put into a platform will be ignored, because we resolve alias' before pulling data out of a blob (https://github.com/mozilla/balrog/blob/master/auslib/AUS.py#L118). Therefore, any data we put into such a platform is pointless and probably confusing. While we don't have a facility for enforcing it right now, it seems to me that alias + locales in the same platform is an invalid state. We need to make sure we have a way to gracefully transition when update platforms disappear, too. Taking this one as an example, here's what I think should've been done: * Delete the existing "Darwin_x86-gcc3-u-i386-x86_64" from the blob (which only had the "alias" at the time). * Rename "Darwin_x86_64-gcc3" to "Darwin_x86-gcc3-u-i386-x86_64". * Repoint "Darwin_x86_64-gcc3-u-i386_x86_64" at "Darwin_x86-gcc3-u-i386-x86_64". Because the backend Balrog code would be resolving alias' before updating platforms, we wouldn't even have had failed requests if we didn't do this right away.
This bug is rather long and winding, but latter half of comment #8 should provide a good summary. This patch implements what's talked about there, and also fixes some tests in test_db.py (we had two 'TestReleasesSchemaV1' objects, which caused all the tests from the first one not to be run).
Attachment #663077 - Flags: review?(rail)
Attachment #663077 - Flags: review?(nthomas)
I had to manually edit the -latest blob to make Mac work again. Darwin_x86-gcc3-u-i386-x86_64 was still aliased to Darwin_x86_64. I removed that, and removed the Darwin_x86_64 platform completely.
Comment on attachment 663077 [details] [diff] [review] resolve alias' before altering anything lgtm
Attachment #663077 - Flags: review?(rail) → review+
Attachment #663077 - Flags: review?(nthomas) → review+
Comment on attachment 663077 [details] [diff] [review] resolve alias' before altering anything https://jenkins.mozilla.org/job/Balrog/104/
Attachment #663077 - Flags: checked-in+
Will double check tomorrow to be sure updates are still submitting successfully, but we should be all done here.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Product: mozilla.org → Release Engineering
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: