Closed Bug 1202309 Opened 9 years ago Closed 6 years ago

Large patch set gives exception when pushing to MozReview

Categories

(MozReview Graveyard :: General, defect)

Product:
MozReview Graveyard
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED INVALID

People

(Reporter: jryans, Unassigned)

References

Details

In bug 912121, I am moving many files to /devtools as well as making various tweaks in subsequent patches. Here is a pushlog to try which includes all the changes: https://hg.mozilla.org/try/pushloghtml?changeset=517f8cb02c89 I had wanted to push them to MozReview for review of specific pieces, but I got the following error: submitting 26 changesets for review remote: ** Unknown exception encountered with possibly-broken third-party extension pushlog-feed remote: ** which supports versions unknown of Mercurial. remote: ** Please disable pushlog-feed and try your action again. remote: ** If that fixes the bug please report it to the extension author. remote: ** Python 2.7.9 (default, Dec 12 2014, 10:25:20) [GCC 4.4.7 20120313 (Red Hat 4.4.7-11)] remote: ** Mercurial Distributed SCM (version 3.4.2) remote: ** Extensions loaded: pushlog, pushlog-feed, buglink, serverlog, rbserver remote: Traceback (most recent call last): remote: File "/repo/hg/venv_pash/bin/hg", line 43, in <module> remote: mercurial.dispatch.run() remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 29, in run remote: sys.exit((dispatch(request(sys.argv[1:])) or 0) & 255) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 91, in dispatch remote: ret = _runcatch(req) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 160, in _runcatch remote: return _dispatch(req) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 885, in _dispatch remote: cmdpats, cmdoptions) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 646, in runcommand remote: ret = _runcommand(ui, options, cmd, d) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 976, in _runcommand remote: return checkargs() remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 947, in checkargs remote: return cmdfunc() remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/dispatch.py", line 882, in <lambda> remote: d = lambda: util.checksignature(func)(ui, *args, **cmdoptions) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/util.py", line 716, in check remote: return func(*args, **kwargs) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/commands.py", line 5661, in serve remote: s.serve_forever() remote: File "/repo/hg/version-control-tools/hgext/serverlog/__init__.py", line 332, in serve_forever remote: return super(sshserverwrapped, self).serve_forever() remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/sshserver.py", line 94, in serve_forever remote: while self.serve_one(): remote: File "/repo/hg/version-control-tools/hgext/serverlog/__init__.py", line 361, in serve_one remote: return super(sshserverwrapped, self).serve_one() remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/sshserver.py", line 112, in serve_one remote: rsp = wireproto.dispatch(self.repo, self, cmd) remote: File "/repo/hg/version-control-tools/hgext/serverlog/__init__.py", line 353, in dispatch remote: return origdispatch(repo, proto, cmd) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/mercurial/wireproto.py", line 511, in dispatch remote: return func(repo, proto, *args) remote: File "/repo/hg/version-control-tools/hgext/reviewboard/hgrb/proto.py", line 329, in reviewboard remote: apikey=bzapikey) remote: File "/repo/hg/version-control-tools/hgext/reviewboard/hgrb/proto.py", line 91, in post_reviews remote: return pr(*args, **kwargs) remote: File "/repo/hg/version-control-tools/pylib/reviewboardmods/reviewboardmods/pushhooks.py", line 129, in post_reviews remote: return _post_reviews(root, repoid, identifier, commits, hgresp) remote: File "/repo/hg/version-control-tools/pylib/reviewboardmods/reviewboardmods/pushhooks.py", line 164, in _post_reviews remote: base_commit_id=commits["squashed"].get('base_commit_id', None)) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/rbtools/api/decorators.py", line 27, in request_method remote: *args, **kwargs) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/rbtools/api/transport/sync.py", line 65, in execute_request_method remote: return self._execute_request(request) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/rbtools/api/transport/sync.py", line 74, in _execute_request remote: rsp = self.server.make_request(request) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/rbtools/api/request.py", line 536, in make_request remote: self.process_error(e.code, e.read()) remote: File "/repo/hg/venv_pash/lib64/python2.7/site-packages/rbtools/api/request.py", line 512, in process_error remote: raise APIError(http_status, None, None, data) remote: rbtools.api.errors.APIError: HTTP 500 abort: unexpected response: empty string
This is reproducible?
Flags: needinfo?(jryans)
(In reply to Gregory Szorc [:gps] from comment #1) > This is reproducible? Hmm, apparently not. I just tried again and it worked.
Status: NEW → RESOLVED
Closed: 9 years ago
Flags: needinfo?(jryans)
Resolution: --- → WORKSFORME
This is happening for me right now.
I have been getting this reliably when pushing bug 1208371 (102 patches) to mozreview. When timing it it always ends at just over 2 minutes (3-8 seconds more). Though looking at the mozreview page for bug 1208371 it looks correct, after having this happen 5 out of 6 times (one errored sooner (78s) with message "abort: reviewboard error: "One or more fields had errors (HTTP 400, API Error 105)". please try submitting the review again. if that doesn't work, you've likely encountered a bug."). You might want to look closer at this error.
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
See Also: → 1208371
I discarded the draft and tried again. (still happens) There's no draft as I get the error, but one becomes available after another couple of minutes (hard to judge how many but before the next push attempt had errored out - so after 1-3 minutes).
We just pushed a server update that fixed a HTTP 500 on the server and should prevent the display of these stacks on the client. If you can reproduce, please post us the new output.
Flags: needinfo?(jryans)
I have not experienced this myself recently, so let's ask the new people.
Flags: needinfo?(pehrsons)
Flags: needinfo?(mdoglio)
Flags: needinfo?(jryans)
I just tried with what I have, and got: > pehrsons:~/Comoyo/mozilla-central $ hg push review > pushing to ssh://reviewboard-hg.mozilla.org/gecko > searching for changes > remote: adding changesets > remote: adding manifests > remote: adding file changes > remote: added 93 changesets with 29 changes to 95 files (+1 heads) > remote: recorded push in pushlog > submitting 102 changesets for review > abort: reviewboard error: HTTP 500
Flags: needinfo?(pehrsons)
Flags: needinfo?(mdoglio)
102 changesets?! The last stack I see on NewRelic is https://rpm.newrelic.com/accounts/263620/applications/7083195/traced_errors/6c14bc-18cf015d-c568-11e5-ad22-c81f66b8ceca: Traceback (most recent call last): File "/usr/lib64/python2.6/site-packages/newrelic-2.44.0.36/newrelic/hooks/framework_django.py", line 497, in wrapper return wrapped(*args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/views/decorators/cache.py", line 52, in _wrapped_view_func response = view_func(request, *args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/views/decorators/vary.py", line 19, in inner_func response = func(*args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/resources/base.py", line 195, in __call__ request, method, view, api_format=api_format, *args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/resources/mixins/api_tokens.py", line 65, in call_method_view return view(request, *args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 120, in _call return view_func(*args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 301, in _validate return view_func(*args, **new_kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 120, in _call return view_func(*args, **kwargs) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/resources/review_request_summary.py", line 146, in get_list summaries = self._summarize_families(request, families) File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/resources/review_request_summary.py", line 282, in _summarize_families for child_rrid in child_rrids KeyError: 28733 This occurred at 1837 PST. Sound right?
(In reply to Gregory Szorc [:gps] from comment #10) > 102 changesets?! Yeah, that's why I'm making so much trouble, isn't it? ;-) > This occurred at 1837 PST. Sound right? Not sure. It shouldn't be long before comment 9 but that sounds like 15 minutes.
Another attempt, now with timing info: > pehrsons:~/Comoyo/mozilla-central $ date; time hg push review; date > Tor 28 Jan 2016 11:19:02 CST > pushing to ssh://reviewboard-hg.mozilla.org/gecko > searching for changes > no changes found > submitting 102 changesets for review > abort: reviewboard error: HTTP 500 > > real 121.264 user 1.317 sys 0.259 pcpu 1.29 > > Tor 28 Jan 2016 11:21:03 CST
I couldn't find any HTTP 500s on the application servers. As I looked at the logs in real time (which don't contain nearly enough info to debug this kind of thing) while Andreas was giving reports over IRC, apparently the client displayed a HTTP 500 while the logs indicated it was still processing! This felt suspiciously like a timeout coupled with a "phantom" HTTP 500 status code (I've seen HTTP clients and network devices invent HTTP status codes). I logged into the zlb and increased max_reply_time from 90s to 300s and had Andreas push again. No HTTP 500. So, this was the zlb hitting a timeout and inventing a HTTP 500. I think I would have preferred 503 or 504 to distinguish this error scenario. But what can you do. Anyway, it's pretty obvious that processing a series of 100 commits takes ages. Even the Mercurial server takes 18s CPU time before it sends the batch submit request to Review Board! I assume most of that is in diff generation. The server is a VM running a CPU from 2012. Sadness. This partially explains why the new batch submit API didn't make things as fast as I thought it would. Anyway, this extremely long review series is at https://reviewboard.mozilla.org/r/22565/. I'm tempted to profile the batch submit API with it to see where all the time is spent because it takes a looong time to handle this request.
Product: Developer Services → MozReview
MozReview is now obsolete. Please use Phabricator instead. Closing this bug.
Status: REOPENED → RESOLVED
Closed: 9 years ago → 6 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.