Closed Bug 1338530 Opened 8 years ago Closed 8 years ago

Push is failing on "Error 500: Internal Server Error", however the review request appears to have worked in Review Board

Categories

(MozReview Graveyard :: General, defect, P1)

Product:
MozReview Graveyard
Component:
General
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: Sylvestre, Assigned: gps)

References

Details

Trying to push on https://reviewboard.mozilla.org/r/111104/ , I am getting the following error: abort: HTTP Error 500: Internal Server Error Full log: $ hg push --debug --traceback -r 341749::tip review automatically setting Bugzilla API Key auth https://reviewboard-hg.mozilla.org pushing to https://reviewboard-hg.mozilla.org/autoreview using https://reviewboard-hg.mozilla.org/autoreview sending capabilities command using auth.autobmoapikey0.* for authentication searching for appropriate review repository sending listreviewrepos command using auth.autobmoapikey0.* for authentication redirecting push to https://reviewboard-hg.mozilla.org/gecko sending capabilities command using auth.autobmoapikey0.* for authentication capabilities: streamreqs=generaldelta,revlogv1 changegroupsubset bundle2=HG20%0Achangegroup%3D01%2C02%0Adigests%3Dmd5%2Csha1%2Csha512%0Aerror%3Dabort%2Cunsupportedcontent%2Cpushraced%2Cpushkey%0Ahgtagsfnodes%0Alistkeys%0Apushkey%0Aremote-changegroup%3Dhttp%2Chttps unbundlehash pullreviews batch mozreviewrequires=bzapikeys,commitid,jsonproto,listreviewdata,listreviewrepos,proto1 httpheader=1024 lookup pushlog pushkey known unbundle=HG10GZ,HG10BZ,HG10UN branchmap getbundle mozreview=publish,publishhttp,pullreviews,pushreview,submithttp reviewboard query 1; heads sending batch command using auth.autobmoapikey0.* for authentication searching for changes all local heads known remotely preparing listkeys for "phases" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "phases": 1485391 bytes preparing listkeys for "namespaces" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "namespaces": 37 bytes checking for updated bookmarks preparing listkeys for "bookmarks" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "bookmarks": 3901 bytes no changes found preparing listkeys for "phases" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "phases": 1485391 bytes try to push obsolete markers to remote preparing listkeys for "namespaces" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "namespaces": 37 bytes submitting 37 changesets for review using auth.autobmoapikey0.* for authentication using auth.autobmoapikey0.* for authentication http auth: user sledru@mozilla.com, password **************************************** using auth.autobmoapikey0.* for authentication Traceback (most recent call last): File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 205, in _runcatchfunc return _dispatch(req) File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 901, in _dispatch cmdpats, cmdoptions) File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 650, in runcommand ret = _runcommand(ui, options, cmd, d) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/hgext/pager.py", line 160, in pagecmd return orig(ui, options, cmd, cmdfunc) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/hgext/color.py", line 521, in colorcmd return orig(ui_, opts, cmd, cmdfunc) File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 909, in _runcommand return cmdfunc() File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 898, in <lambda> d = lambda: util.checksignature(func)(ui, *args, **cmdoptions) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/firefoxtree/__init__.py", line 491, in pushcommand return orig(ui, repo, dest=dest, **opts) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 178, in pushcommand return orig(ui, repo, *args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/hgext/mq.py", line 3540, in mqcommand return orig(ui, repo, *args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/home/sylvestre/dev/mozilla/evolve/hgext/evolve.py", line 732, in warnobserrors ret = orig(ui, repo, *args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1039, in check return func(*args, **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/commands.py", line 6043, in push opargs=opts.get('opargs')) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/firefoxtree/__init__.py", line 294, in push **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 255, in wrappedpush newbranch=False, **kwargs) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 304, in wrappedpush **kwargs) File "/usr/lib/python2.7/dist-packages/mercurial/extensions.py", line 220, in closure return func(*(args + a), **kw) File "/home/sylvestre/dev/mozilla/evolve/hgext/evolve.py", line 755, in push return orig(repo, *args, **opts) File "/usr/lib/python2.7/dist-packages/mercurial/exchange.py", line 482, in push pushop.trmanager.close() File "/usr/lib/python2.7/dist-packages/mercurial/exchange.py", line 1163, in close self._tr.close() File "/usr/lib/python2.7/dist-packages/mercurial/transaction.py", line 43, in _active return func(self, *args, **kwds) File "/usr/lib/python2.7/dist-packages/mercurial/transaction.py", line 490, in close self._postclosecallback[cat](self) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 473, in ontrclose doreview(pushop.repo, pushop.ui, pushop.remote, pushop.reviewnodes) File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 582, in doreview httpcommand='mozreviewsubmitseries') File "/home/sylvestre/.mozbuild/version-control-tools/hgext/reviewboard/client.py", line 112, in calljsoncommand fh = remote.urlopener.open(request) File "/usr/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/lib/python2.7/urllib2.py", line 467, in error result = self._call_chain(*args) File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/lib/python2.7/urllib2.py", line 909, in http_error_401 url, req, headers) File "/usr/lib/python2.7/dist-packages/mercurial/url.py", line 414, in http_error_auth_reqed self, auth_header, host, req, headers) File "/usr/lib/python2.7/urllib2.py", line 887, in http_error_auth_reqed return self.retry_http_basic_auth(host, req, realm) File "/usr/lib/python2.7/dist-packages/mercurial/url.py", line 425, in retry_http_basic_auth return self.parent.open(req) File "/usr/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/lib/python2.7/urllib2.py", line 473, in error return self._call_chain(*args) File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/lib/python2.7/urllib2.py", line 556, in http_error_default raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) HTTPError: HTTP Error 500: Internal Server Error abort: HTTP Error 500: Internal Server Error
Assignee: nobody → pzalewa
A clean push: automatically setting Bugzilla API Key auth https://reviewboard-hg.mozilla.org pushing to https://reviewboard-hg.mozilla.org/autoreview using https://reviewboard-hg.mozilla.org/autoreview sending capabilities command using auth.autobmoapikey0.* for authentication searching for appropriate review repository sending listreviewrepos command using auth.autobmoapikey0.* for authentication redirecting push to https://reviewboard-hg.mozilla.org/gecko sending capabilities command using auth.autobmoapikey0.* for authentication capabilities: streamreqs=generaldelta,revlogv1 changegroupsubset bundle2=HG20%0Achangegroup%3D01%2C02%0Adigests%3Dmd5%2Csha1%2Csha512%0Aerror%3Dabort%2Cunsupportedcontent%2Cpushraced%2Cpushkey%0Ahgtagsfnodes%0Alistkeys%0Apushkey%0Aremote-changegroup%3Dhttp%2Chttps unbundlehash pullreviews batch mozreviewrequires=bzapikeys,commitid,jsonproto,listreviewdata,listreviewrepos,proto1 httpheader=1024 lookup pushlog pushkey known unbundle=HG10GZ,HG10BZ,HG10UN branchmap getbundle mozreview=publish,publishhttp,pullreviews,pushreview,submithttp reviewboard query 1; heads sending batch command using auth.autobmoapikey0.* for authentication searching for changes 1 total queries preparing listkeys for "phases" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "phases": 1491712 bytes preparing listkeys for "namespaces" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "namespaces": 37 bytes checking for updated bookmarks preparing listkeys for "bookmarks" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "bookmarks": 3961 bytes 1 changesets found list of changesets: 89068534a77e32ffd36bfccbb03b39cd18d8dc81 bundle2-output-bundle: "HG20", 2 parts total bundle2-output-part: "replycaps" 172 bytes payload bundle2-output-part: "changegroup" (params: 1 mandatory) streamed payload sending unbundle command sending 1006 bytes using auth.autobmoapikey0.* for authentication using auth.autobmoapikey0.* for authentication http auth: user sledru@mozilla.com, password **************************************** using auth.autobmoapikey0.* for authentication bundle2-input-bundle: with-transaction bundle2-input-part: "reply:changegroup" (advisory) (params: 0 advisory) supported bundle2-input-part: "output" (advisory) (params: 0 advisory) supported bundle2-input-part: total payload size 125 remote: adding changesets remote: adding manifests remote: adding file changes remote: added 1 changesets with 1 changes to 1 files remote: recorded push in pushlog bundle2-input-part: "output" (advisory) supported bundle2-input-part: total payload size 216 bundle2-input-bundle: 2 parts total preparing listkeys for "phases" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "phases": 1491712 bytes try to push obsolete markers to remote preparing listkeys for "namespaces" sending listkeys command using auth.autobmoapikey0.* for authentication received listkey for "namespaces": 37 bytes submitting 1 changesets for review using auth.autobmoapikey0.* for authentication changeset: 341826:89068534a77e summary: Bug 1339027 - remove useless declaration in VideoDecoderManagerParent.cpp d?dvander review: https://reviewboard.mozilla.org/r/112034 (draft) review id: bz://1339027/Sylvestre review url: https://reviewboard.mozilla.org/r/112032 (draft) (review requests lack reviewers; visit review url to assign reviewers) publish these review requests now (Yn)? Y using auth.autobmoapikey0.* for authentication (published review request 112032)
had a quick chat with sylvestre and looked at the logs. looks like the size of this review is causing issues. the review push was processed server-side long after sylverstre's client reported http/500, and resulted in a draft banner in the ui. publishing from the ui took a while. looks like there's a very short timeout in the client somewhere, and a lack of caching of bug state during publishing. --- review push log 2017-02-14 13:40:56,285 - INFO - - Login attempt (apikey) for user sledru@mozilla.com: 2017-02-14 13:40:56,631 - INFO - - Login successful (apikey) for user sledru@mozilla.com: 2017-02-14 13:40:56,640 - INFO - - processing BatchReviewRequest for sylvestre 2017-02-14 13:40:56,655 - INFO - - processing batch submission bz://1338086/Sylvestre to gecko with 37 commits 2017-02-14 13:40:56,660 - INFO - - using squashed review request 111104 2017-02-14 13:40:56,660 - INFO - - bz://1338086/Sylvestre: generating squashed diffset for 111104 2017-02-14 13:40:57,350 - INFO - - bz://1338086/Sylvestre: updated squashed diffset for 111104 2017-02-14 13:40:57,354 - INFO - - bz://1338086/Sylvestre: 37 previous commits; 0 discard on publish; 0 unpublished 2017-02-14 13:40:57,354 - INFO - - bz://1338086/Sylvestre: 0/37 commits mapped exactly 2017-02-14 13:40:57,354 - INFO - - bz://1338086/Sylvestre: 0/37 mapped exactly or to precursors 2017-02-14 13:40:57,442 - INFO - - bz://1338086/Sylvestre: commit ID 2OsdUdGgL9O for 00598ef365c7e35cc97d49f759bddee6f27a590d found in review request 111128 2017-02-14 13:40:58,407 - INFO - - importing Bugzilla users from query "dolske": dolske@mozilla.com 2017-02-14 13:40:59,358 - INFO - - bz://1338086/Sylvestre: commit ID Bp1M9LW77Ia for a1d180f6eda3aa885e4f2dbddb0365e266f544e9 found in review request 111126 2017-02-14 13:41:00,749 - INFO - - importing Bugzilla users from query "jimm": jimmyw22@gmail.com, jmathies@mozilla.com 2017-02-14 13:41:01,746 - INFO - - bz://1338086/Sylvestre: commit ID H9zZd19V4Ww for 117d6d5b624c3d9a07bdef5c29f542144d78cdb7 found in review request 111122 2017-02-14 13:41:03,129 - INFO - - importing Bugzilla users from query "nical": nical.bugzilla@gmail.com 2017-02-14 13:41:04,190 - INFO - - bz://1338086/Sylvestre: commit ID IA3oVcvzTQw for 7992f165aee775bcb941c885c43a06cd1e38c81d found in review request 111120 2017-02-14 13:41:05,284 - INFO - - importing Bugzilla users from query "jya": jyavenard@mozilla.com 2017-02-14 13:41:06,301 - INFO - - bz://1338086/Sylvestre: commit ID FaKW6Sb721i for 913aed9a605ea01196386460dbb8d82727d7207c found in review request 111118 2017-02-14 13:41:07,288 - INFO - - importing Bugzilla users from query "cpearce": cpearce@mozilla.com 2017-02-14 13:41:08,319 - INFO - - bz://1338086/Sylvestre: commit ID Fyx3eryjsgQ for 16a1e3e0a4707f573aecdc59d94f7ab71dab5399 found in review request 111116 2017-02-14 13:41:09,449 - INFO - - importing Bugzilla users from query "baku": amarchesini@mozilla.com 2017-02-14 13:41:10,365 - INFO - - bz://1338086/Sylvestre: commit ID EWXDsio2aBh for dc81b6621b2a767b82b3ffa131464067cb80fa6e found in review request 111114 2017-02-14 13:41:10,723 - INFO - - bz://1338086/Sylvestre: commit ID GOhpMjzT0m0 for 157d33d9aa50c4d2ba290ba82e75922ae6bc44de found in review request 111112 2017-02-14 13:41:11,100 - INFO - - bz://1338086/Sylvestre: commit ID CxMopblOFVp for 58bdd27a8ca9b6ad7d28aca10ea0b8b25f689a54 found in review request 111108 2017-02-14 13:41:12,052 - INFO - - importing Bugzilla users from query "fitzgen": nfitzgerald@mozilla.com 2017-02-14 13:41:12,980 - INFO - - bz://1338086/Sylvestre: commit ID 7ZVqMkXZ5vj for 8bc79cf31e3631c860b27eaae7b9f06e86c7e953 found in review request 111106 2017-02-14 13:41:14,047 - INFO - - importing Bugzilla users from query "davidb": david@larlet.fr, dbolter@mozilla.com, mozilla@davidbienvenu.org 2017-02-14 13:41:15,030 - INFO - - bz://1338086/Sylvestre: commit ID 8qUQk8w0QSk for 8d88a3ebf3696d423907c8545c647e93fa914f2c found in review request 111130 2017-02-14 13:41:15,994 - INFO - - importing Bugzilla users from query "dholbert": dholbert@mozilla.com 2017-02-14 13:41:16,958 - INFO - - bz://1338086/Sylvestre: commit ID AjL8H7aHLkm for dcd0587d4fae753be7320fd1284aedefedd84beb found in review request 111176 2017-02-14 13:41:17,914 - INFO - - importing Bugzilla users from query "mstange": mstange@themasta.com 2017-02-14 13:41:18,930 - INFO - - bz://1338086/Sylvestre: commit ID HvmyxEwsnrg for 9e65773e5573bbe17fe2e23f150fd4a1f2edbf8a found in review request 111174 2017-02-14 13:41:19,873 - INFO - - importing Bugzilla users from query "froydnj": nfroyd@mozilla.com 2017-02-14 13:41:20,785 - INFO - - bz://1338086/Sylvestre: commit ID 33kF2DJl0Mi for 1879217b22c04d9ac374e7cc2859004f1718f8e0 found in review request 111172 2017-02-14 13:41:21,149 - INFO - - bz://1338086/Sylvestre: commit ID 3X4CIucTfGG for 50b5aa840f942cb2f43c253f7f29c25d47547768 found in review request 111170 2017-02-14 13:41:22,364 - INFO - - importing Bugzilla users from query "ehsan": 187cpp@gmail.com, ehsan@mozilla.com, ehsanbayern@yahoo.com, malikehsan66@yahoo.com, tavanfar@gmail.com 2017-02-14 13:41:23,318 - INFO - - bz://1338086/Sylvestre: commit ID GTb9ME8pfVq for 58e9a55f6d165fce3686c1e108c91177ddd4fedc found in review request 111168 2017-02-14 13:41:24,789 - INFO - - importing Bugzilla users from query "francois": d13warrior@msn.com, f-x.p@laposte.net, frale-co@student.42.fr, francois.vedrine@unilog.fr, francois@lebeau-luthier.com, francois@mozilla.com, pfrancois_99@yahoo.fr 2017-02-14 13:41:25,860 - INFO - - bz://1338086/Sylvestre: commit ID IdbRm6QFZb8 for 6b929907f385f3c7ab6126ff468c05a4515f3c43 found in review request 111166 2017-02-14 13:41:26,233 - INFO - - bz://1338086/Sylvestre: commit ID 2xcvOyxtDsh for 0a127581c0930c901286ed6036eee95fcc49718b found in review request 111164 2017-02-14 13:41:26,598 - INFO - - bz://1338086/Sylvestre: commit ID 5UWtAe6THd6 for 76e28e244ccfe487a87147f7101b0c4f84f535dd found in review request 111162 2017-02-14 13:41:27,661 - INFO - - importing Bugzilla users from query "gcp": gpascutto@mozilla.com 2017-02-14 13:41:28,602 - INFO - - bz://1338086/Sylvestre: commit ID 3boyTyUFUAI for aaa963192aab1cf76fdf3457477a583a06109a30 found in review request 111160 2017-02-14 13:41:29,760 - INFO - - importing Bugzilla users from query "pike": l10n@mozilla.com, pike-bugzilla@kw.nl, pike@kw.nl 2017-02-14 13:41:30,755 - INFO - - bz://1338086/Sylvestre: commit ID Btyl5N6EsUY for d72832ce5c1f2e96063731ee1d113d75934f85b4 found in review request 111158 2017-02-14 13:41:31,089 - INFO - - bz://1338086/Sylvestre: commit ID EGiX5NWdj6r for 9d34ae145cc5dfb610852f8d20eee1663e7435c7 found in review request 111156 2017-02-14 13:41:31,431 - INFO - - bz://1338086/Sylvestre: commit ID LvDRxqoEAoY for 497b60940ddd50d977152803accc4423a1f499cc found in review request 111154 2017-02-14 13:41:31,773 - INFO - - bz://1338086/Sylvestre: commit ID GyAIRI7Tsei for 222cae81cef0fa1a3f269f99ad945710c8228e96 found in review request 111152 2017-02-14 13:41:32,753 - INFO - - importing Bugzilla users from query "mhowell": mhowell@mozilla.com 2017-02-14 13:41:33,643 - INFO - - bz://1338086/Sylvestre: commit ID sbiCAKDekh for 20e8a0fbbf551210df843f6e3dd3c7600c716d3f found in review request 111150 2017-02-14 13:41:34,662 - INFO - - importing Bugzilla users from query "jmaher": jmaher@mozilla.com 2017-02-14 13:41:35,657 - INFO - - bz://1338086/Sylvestre: commit ID EjMufQ1PReI for f9c693dd1890f75a21eef4fc9b51e716eaefc495 found in review request 111148 2017-02-14 13:41:36,710 - INFO - - importing Bugzilla users from query "dexter": alessio.placitelli@gmail.com, dex.mbox@gmail.com, dextepayne@aol.com, dexter.ktwong@gmail.com, dexter@csb.yale.edu, dexterion1218@gmail.com, note@dexterpayne.com, pornnut@mail.gr, sailfish1957@yahoo.com, sailfish@sportsfish.com.au 2017-02-14 13:41:37,614 - INFO - - bz://1338086/Sylvestre: commit ID 9Hvf7kGOi2s for e97773431c4dda2c6eb6ea3ef39fe79f1e83e211 found in review request 111146 2017-02-14 13:41:38,575 - INFO - - importing Bugzilla users from query "drno": drno@ohlmeier.org 2017-02-14 13:41:39,483 - INFO - - bz://1338086/Sylvestre: commit ID JUJARn5Nspp for 04ae0a29d415097c8408ace22e4035d71fae5bdb found in review request 111144 2017-02-14 13:41:39,852 - INFO - - bz://1338086/Sylvestre: commit ID 6H794QjWZ1t for e8f5c5d5cc9b0bb2787ca0980fd2c5aaffe93cd5 found in review request 111142 2017-02-14 13:41:40,803 - INFO - - importing Bugzilla users from query "tnikkel": tnikkel@gmail.com 2017-02-14 13:41:41,783 - INFO - - bz://1338086/Sylvestre: commit ID 2TSxhHWmL2H for 346194ed2784fda94dc91eb0885af3decd628468 found in review request 111140 2017-02-14 13:41:42,860 - INFO - - importing Bugzilla users from query "dragana": dd.mozilla@gmail.com 2017-02-14 13:41:43,806 - INFO - - bz://1338086/Sylvestre: commit ID G7jBKlDHshQ for 316737dc788a3a2343219ba361c76f872ceacae3 found in review request 111138 2017-02-14 13:41:44,761 - INFO - - importing Bugzilla users from query "njn": n.nethercote@gmail.com 2017-02-14 13:41:45,751 - INFO - - bz://1338086/Sylvestre: commit ID 9s4z7bYXisU for cecf47b60560b151b5ac92d8e52bb8c77c84fb60 found in review request 111134 2017-02-14 13:41:46,793 - INFO - - importing Bugzilla users from query "heycam": cam@mcc.id.au 2017-02-14 13:41:47,729 - INFO - - bz://1338086/Sylvestre: commit ID Giwp0K1YoBH for 93d13f99f514a85fb02e2190c52c4f8ff319b516 found in review request 111132 2017-02-14 13:41:48,811 - INFO - - importing Bugzilla users from query "bbouvier": bbouvier@mozilla.com 2017-02-14 13:41:49,726 - INFO - - bz://1338086/Sylvestre: commit ID ANIe9jnCdah for 9e6dba3849e13b4606cd680e67f539e397abdafb found in review request 111178 2017-02-14 13:41:50,085 - INFO - - bz://1338086/Sylvestre: commit ID 5ewd0uy2Kgk for bb341eb1952edd377e42eeb498a4f5242e347cda found in review request 111124 2017-02-14 13:41:50,500 - INFO - - bz://1338086/Sylvestre: commit ID 5sCNbqC4ew3 for a406d81b410db01c979672b07201892793fa0edd found in review request 111110 2017-02-14 13:41:50,998 - INFO - - bz://1338086/Sylvestre: commit ID EU5B0cUYp6c for 9a045bb0e539902c2215427c6091693a0dc235ab found in review request 111136 2017-02-14 13:41:52,035 - INFO - - importing Bugzilla users from query "jesup": rjesup@jesup.org 2017-02-14 13:41:53,094 - INFO - - bz://1338086/Sylvestre: 37/37 mapped after commit ID matching 2017-02-14 13:41:53,094 - INFO - - bz://1338086/Sylvestre: 0 unclaimed review requests 2017-02-14 13:41:53,094 - INFO - - bz://1338086/Sylvestre: 0 unclaimed review requests left over 2017-02-14 13:41:53,441 - INFO - - bz://1338086/Sylvestre: finished processing 111104 -- publishing log 2017-02-14 13:44:20,604 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:20,871 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:21,855 - INFO - - Posting review request 111128 to bug 1338086. 2017-02-14 13:44:22,034 - INFO - - Posting review request 111126 to bug 1338086. 2017-02-14 13:44:22,203 - INFO - - Posting review request 111122 to bug 1338086. 2017-02-14 13:44:22,418 - INFO - - Posting review request 111120 to bug 1338086. 2017-02-14 13:44:22,605 - INFO - - Posting review request 111118 to bug 1338086. 2017-02-14 13:44:22,785 - INFO - - Posting review request 111116 to bug 1338086. 2017-02-14 13:44:22,802 - INFO - - Posting review request 111114 to bug 1338086. 2017-02-14 13:44:22,819 - INFO - - Posting review request 111112 to bug 1338086. 2017-02-14 13:44:22,997 - INFO - - Posting review request 111108 to bug 1338086. 2017-02-14 13:44:23,183 - INFO - - Posting review request 111106 to bug 1338086. 2017-02-14 13:44:23,365 - INFO - - Posting review request 111130 to bug 1338086. 2017-02-14 13:44:23,543 - INFO - - Posting review request 111176 to bug 1338086. 2017-02-14 13:44:23,719 - INFO - - Posting review request 111174 to bug 1338086. 2017-02-14 13:44:23,736 - INFO - - Posting review request 111172 to bug 1338086. 2017-02-14 13:44:23,906 - INFO - - Posting review request 111170 to bug 1338086. 2017-02-14 13:44:24,081 - INFO - - Posting review request 111168 to bug 1338086. 2017-02-14 13:44:24,099 - INFO - - Posting review request 111166 to bug 1338086. 2017-02-14 13:44:24,116 - INFO - - Posting review request 111164 to bug 1338086. 2017-02-14 13:44:24,297 - INFO - - Posting review request 111162 to bug 1338086. 2017-02-14 13:44:24,468 - INFO - - Posting review request 111160 to bug 1338086. 2017-02-14 13:44:24,485 - INFO - - Posting review request 111158 to bug 1338086. 2017-02-14 13:44:24,503 - INFO - - Posting review request 111156 to bug 1338086. 2017-02-14 13:44:24,520 - INFO - - Posting review request 111154 to bug 1338086. 2017-02-14 13:44:24,703 - INFO - - Posting review request 111152 to bug 1338086. 2017-02-14 13:44:24,891 - INFO - - Posting review request 111150 to bug 1338086. 2017-02-14 13:44:25,068 - INFO - - Posting review request 111148 to bug 1338086. 2017-02-14 13:44:25,253 - INFO - - Posting review request 111146 to bug 1338086. 2017-02-14 13:44:25,271 - INFO - - Posting review request 111144 to bug 1338086. 2017-02-14 13:44:25,453 - INFO - - Posting review request 111142 to bug 1338086. 2017-02-14 13:44:25,634 - INFO - - Posting review request 111140 to bug 1338086. 2017-02-14 13:44:25,818 - INFO - - Posting review request 111138 to bug 1338086. 2017-02-14 13:44:26,024 - INFO - - Posting review request 111134 to bug 1338086. 2017-02-14 13:44:26,330 - INFO - - Posting review request 111132 to bug 1338086. 2017-02-14 13:44:26,354 - INFO - - Posting review request 111178 to bug 1338086. 2017-02-14 13:44:26,378 - INFO - - Posting review request 111124 to bug 1338086. 2017-02-14 13:44:26,399 - INFO - - Posting review request 111110 to bug 1338086. 2017-02-14 13:44:26,590 - INFO - - Posting review request 111136 to bug 1338086. 2017-02-14 13:44:26,598 - INFO - - Doing attachment updates for bug 1338086 2017-02-14 13:44:31,993 - ERROR - - Failed to update the following attachments: set([8835398, 8835399, 8835400, 8835401, 8835402, 8835403, 8835404, 8835405, 8835406, 8835407, 8835408, 8835409, 8835410, 8835411, 8835412, 8835413, 8835414, 8835415, 8835416, 8835417, 8835418, 8835419, 8835420, 8835421, 8835422, 8835423, 8835424, 8835425, 8835426, 8835427, 8835428, 8835429, 8835430, 8835431, 8835432, 8835433, 8835434]) 2017-02-14 13:44:32,014 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:32,298 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:32,602 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:32,897 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:33,182 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:33,442 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:33,721 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:33,983 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:34,254 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:34,525 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:34,785 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:35,058 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:35,329 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:35,612 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:35,880 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:36,139 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:36,403 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:36,704 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:37,014 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:37,294 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:37,578 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:37,861 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:38,141 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:38,533 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:38,784 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:39,047 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:39,286 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:39,576 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:39,860 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:40,135 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:40,429 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:40,709 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:41,003 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:41,263 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:41,544 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:41,906 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:42,204 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:42,552 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:42,842 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:43,165 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:43,452 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:43,726 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:44,010 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:44,292 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:44,549 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:44,924 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:45,188 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:45,592 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:45,838 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:46,115 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:46,402 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:46,751 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:47,035 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:47,308 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:47,709 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:47,993 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:48,308 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:48,591 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:48,838 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:49,127 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:49,395 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:49,668 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:49,915 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:50,166 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:50,414 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:50,678 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:50,936 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:51,243 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:51,488 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:51,904 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:52,153 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:52,427 - INFO - - Bug 1338086 confidential: False. 2017-02-14 13:44:52,686 - INFO - - Checking if bug 1338086 is confidential. 2017-02-14 13:44:52,966 - INFO - - Bug 1338086 confidential: False.
Assignee: pzalewa → nobody
Priority: -- → P1
Assignee: nobody → pzalewa
I can see the same issue when I haven't pushed to mozreview for a while. When I get this error and I push again, everything works fine.
I've seen this multiple times last week and again today.
hgweb on reviewboard-hg2 is throwing the http/500 after the request has been processed by reviewboard. > [14/Mar/2017:06:28:38 +0000] "POST /gecko?cmd=unbundle HTTP/1.1" 500 255 "-" "mercurial/proto-1.0 (Mercurial 4.0)" unfortunately it looks like hgweb doesn't write errors to the error log (or anywhere). i'm working on figuring this out.
Assignee: pzalewa → glob
Summary: Push is failing on "Error 500: Internal Server Error" → Push is failing on "Error 500: Internal Server Error", however the review request appears to have worked in Review Board
zeus's status pings also appear to trigger 500s: > [14/Mar/2017:07:11:15 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > [14/Mar/2017:07:11:15 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > [14/Mar/2017:07:11:19 +0000] "GET / HTTP/1.0" 200 7209 "-" "HTTP-Monitor/1.1" > [14/Mar/2017:07:11:19 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > [14/Mar/2017:07:11:25 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" it's interesting that the 200 and 500 responses have the exact same size.
(In reply to Byron Jones ‹:glob› from comment #7) > hgweb on reviewboard-hg2 is throwing the http/500 after the request has been > processed by reviewboard. > > [14/Mar/2017:06:28:38 +0000] "POST /gecko?cmd=unbundle HTTP/1.1" 500 255 "-" "mercurial/proto-1.0 (Mercurial 4.0)" > unfortunately it looks like hgweb doesn't write errors to the error log (or > anywhere). > > i'm working on figuring this out. Note that the log you're quoting is from the push itself, while the reported bug is about the reviewboard submission failing with an HTTP error 500.
(In reply to Byron Jones ‹:glob› from comment #8) > zeus's status pings also appear to trigger 500s: > > > [14/Mar/2017:07:11:15 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > > [14/Mar/2017:07:11:15 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > > [14/Mar/2017:07:11:19 +0000] "GET / HTTP/1.0" 200 7209 "-" "HTTP-Monitor/1.1" > > [14/Mar/2017:07:11:19 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > > [14/Mar/2017:07:11:25 +0000] "GET / HTTP/1.0" 500 7209 "-" "HTTP-Monitor/1.1" > > it's interesting that the 200 and 500 responses have the exact same size. while the logs state http/500 was returned, inspecting the actual response sent back to zeus shows that it was a http/200. it's _very_ weird, but just a distraction with regards to this issue.
if you're hitting this issue frequently, can you please ensure you're running the latest version of mercurial.
I just got this pushing with git-cinnabar 0.4.0rc2 & Mercurial 4.1.1. At about 11:06 UTC (16 Mar). It is on a newly created branch that I created from a pull of central this morning. Re-pushing a couple of minutes later with no changes works fine. This is a pattern I've been seeing for a week or so now. Traceback (most recent call last): File "/Users/mark/.mozbuild/version-control-tools/git/cinnabar-debug-push.py", line 110, in <module> sys.exit(main(sys.argv[1:])) File "/Users/mark/.mozbuild/version-control-tools/git/cinnabar-debug-push.py", line 78, in main pushed = push(repo, store, {commit: (None, False)}, heads, ()) File "/Users/mark/dev/git-cinnabar/cinnabar/hg/__init__.py", line 674, in push reply = repo.unbundle(cg, repo_heads, '') File "/usr/local/lib/python2.7/site-packages/mercurial/wireproto.py", line 442, in unbundle stream = self._calltwowaystream('unbundle', cg, heads=heads) File "/usr/local/lib/python2.7/site-packages/mercurial/httppeer.py", line 339, in _calltwowaystream return self._callstream(cmd, data=fp_, headers=headers, **args) File "/usr/local/lib/python2.7/site-packages/mercurial/httppeer.py", line 216, in _callstream resp = self.urlopener.open(req) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 467, in error result = self._call_chain(*args) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 909, in http_error_401 url, req, headers) File "/usr/local/lib/python2.7/site-packages/mercurial/url.py", line 405, in http_error_auth_reqed self, auth_header, host, req, headers) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 887, in http_error_auth_reqed return self.retry_http_basic_auth(host, req, realm) File "/usr/local/lib/python2.7/site-packages/mercurial/url.py", line 416, in retry_http_basic_auth return self.parent.open(req) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 473, in error return self._call_chain(*args) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/local/Cellar/python/2.7.13/Frameworks/Python.framework/Versions/2.7/lib/python2.7/urllib2.py", line 556, in http_error_default raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) urllib2.HTTPError: HTTP Error 500: Internal Server Error abort: error performing cinnabar push; please report this bug
(In reply to Byron Jones ‹:glob› from comment #11) > if you're hitting this issue frequently, can you please ensure you're > running the latest version of mercurial. I was seeing this frequently on Mercurial 4.1. I've just upgrade to 4.1.1, so we'll see if that helps.
I was seeing this with 4.0 and am still seeing this with 4.1.1. The problem manifests for me as follows: Every time I re-push after I change a patch, the first push succeeds at pushing the changesets but gives the 500 result as it tries to submit them to mozreview. Then I push again, with the same syntax, and I get "no changes found", "submitting 7 changesets for review", and it succeeds. I have [reviewboard] autopublish = true in my .hgrc, and I push to https://reviewboard-hg.mozilla.org/autoreview .
Depends on: 1349408
I'm seeing the same problem as Markus. Here's my log, if it helps: https://gist.github.com/kitcambridge/8721db8af0c780f0863617cbaf38929f
Depends on: 1350007
I've got some forensics running on the server to try to get to the bottom of this. If you get an HTTP 500, please ping me on IRC as soon as possible so I know where to look for the needle in the haystack.
I've got a packet trace from a recent push from jaws. I'd post it here, but jaws would need delete the BMO API key contained within in. So I'll just describe it. 0.000: SYN+ACK 0.001: HTTP POST 30.432: FIN, ACK from load balancer 30.891: ACK from origin server 35.400: HTTP response as 2 TCP segments 35.401: 2 RST from load balancer So it looks like the HTTP POST is taking a hair over 30s to process on the server. That's a bit slow, but whatever. After ~30s of idle, a FIN, ACK is sent to terminate the connection. This is either an idle timeout on the load balancer or it was initiated from the Mercurial client. I'm looking at the load balancer config right now and there is a setting with the following description: How long the pool should wait for a response from the node before either discarding the request or trying another node (retryable requests only). If you guessed its value is 30, you'd be correct. So, I'm willing to wager money that the load balancer is sending the FIN, ACK for the idle connection. I don't have any evidence to support this, but I suspect the load balancer also issues a "fake" HTTP 500 response, which is what the Mercurial client sees. The HTTP server logs on the origin server just happen to record an HTTP 500 status code when the response disappears into an RST'd TCP socket (no such HTTP 500 is ever issued on the origin server, which is why packet tracing can't find it). We should definitely increase the idle timeout on the load balancer. Our mod_wsgi settings related to timeouts are currently deadlock-timeout=60 inactivity-timeout=300. Those are documented at https://modwsgi.readthedocs.io/en/develop/configuration-directives/WSGIDaemonProcess.html. We probably want the load balancer timeout strictly greater than inactivity-timeout. That's high and can result in worker exhaustion on the origin server. But I'd rather have origin servers in charge of timeouts and TCP connection behavior than the load balancer (I like when load balancers are dumb because I've seen enough bugs with load balancer behavior over the years that I've learned to not trust them). fubar: could you please bump max_reply_time for the reviewboard-hg http pool? I'd like it strictly greater than inactivity-timeout in mod_wsgi. So how about 310?
Flags: needinfo?(klibby)
Setting max_reply_time to 310 yields the following warning: "WARNING: The maximum reply time should be less than the timeout of all virtual servers which use this pool, otherwise client connections might be timed out for slow responding servers. The current minimum value of 'timeout' for virtual servers which use this pool is '40' for virtual server 'reviewboard-hg.mozilla.org-http'" In this case, the reviewboard-hg.mozilla.org-http VS simply redirects to reviewboard-hg.mozilla.org-https, so I've increased the timeout on that virtual server to 315 and applied the changed to max_reply_time, overriding the warning.
Flags: needinfo?(klibby)
Blocks: 1350121
There hasn't been an HTTP 500 on an unbundle request reported in the httpd logs since the load balancer change. So calling this one done. The MOTD about this error on MozReview has also been removed.
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Assignee: glob → gps
You need to log in before you can comment on or make changes to this bug.