1290889 - http/500 error during pushing for review (list index out of range)

Status: RESOLVED FIXED

(MozReview Graveyard :: General, defect)

Description

[:glob ✱]

callek@Centaurus:~/mozilla/hg/buildbot-configs$ hg push review -r .
pushing to ssh://reviewboard-hg.mozilla.org/autoreview
searching for appropriate review repository
redirecting push to ssh://reviewboard-hg.mozilla.org/buildbot-configs
(adding commit id to 1 changesets)
saved backup bundle to /home/callek/mozilla/hg/buildbot-configs/.hg/strip-backup/13b5123e04d4-0b9eac03-addcommitid.hg
searching for changes
remote: adding changesets
remote: adding manifests
remote: adding file changes
remote: added 2 changesets with 5 changes to 5 files (+1 heads)
remote: recorded push in pushlog
submitting 1 changesets for review
commit message for 6c7691afe99b has r=mtabara but they have not granted a ship-it. review will be requested on your behalf
changeset:  14407:6c7691afe99b
summary:    Bug 1278260 - Tracking bug for Aug-1-2016 migration work. r=mtabara
review:     https://reviewboard.mozilla.org/r/68302 (draft)
review id:  bz://1278260/Callek
review url: https://reviewboard.mozilla.org/r/68300 (draft)
publish these review requests now (Yn)? y
error publishing review request 68300: HTTP 500
(review requests not published; visit review url to attempt publishing there)

2016-08-01 13:07:56,306 - ERROR -  - Error when calling <function on_review_request_publishing at 0x7f13f8740f50> from SignalHook: list index out of range
Traceback (most recent call last):
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/extensions/hooks.py", line 196, in _wrap_callback
    self.callback(extension=self.extension, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/errors.py", line 28, in _transform_errors
    return func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/signal_handlers.py", line 346, in on_review_request_publishing
    children_to_obsolete)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/attachments.py", line 65, in update_bugzilla_attachments
    email = users[0].email
IndexError: list index out of range

Comment 1

[:glob ✱]

jlund just hit this on bug 1290918

2016-08-01 15:56:19,972 - ERROR -  - Exception thrown for user jlund at https://reviewboard.mozilla.org/api/review-requests/68320/draft/

list index out of range
Traceback (most recent call last):
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/core/handlers/base.py", line 112, in get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  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 196, 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/resources/base.py", line 464, in put
    return self.update(request, *args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 122, in _call
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/ReviewBoard-2.5.4.moz-py2.6.egg/reviewboard/webapi/decorators.py", line 139, in _check
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 122, in _call
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 143, in _checklogin
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 122, in _call
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 122, in _call
    return view_func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/webapi/decorators.py", line 307, in _validate
    return view_func(*args, **new_kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/ReviewBoard-2.5.4.moz-py2.6.egg/reviewboard/webapi/resources/review_request_draft.py", line 493, in update
    review_request.publish(user=request.user, trivial=trivial)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/ReviewBoard-2.5.4.moz-py2.6.egg/reviewboard/reviews/models/review_request.py", line 809, in publish
    review_request_draft=draft)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/dispatch/dispatcher.py", line 185, in send
    response = receiver(signal=self, sender=sender, **named)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/extensions/hooks.py", line 196, in _wrap_callback
    self.callback(extension=self.extension, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/errors.py", line 28, in _transform_errors
    return func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/signal_handlers.py", line 346, in on_review_request_publishing
    children_to_obsolete)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/attachments.py", line 65, in update_bugzilla_attachments
    email = users[0].email

Comment 2

[Māris Fogels [:mars] (please needinfo)]

glob and I found the cause of this after discussion over Vidyo.  It's an edge case where the user has merged two Bugzilla accounts, but both accounts and their Bugzilla user IDs are still present in MozReview's database.  MozReview is choosing the wrong account to perform the code review.  When the MozReview code looks up the user's old Bugzilla account ID in Bugzilla it receives an empty response (the old Bugzilla account was deleted as part of the Bugzilla account merge).  BMO user IDs almost never get deleted, except during an account merge.  The MozReview code doesn't expect or protect against this rare case, so when it receives the empty result from Bugzilla it crashes.

This will continue to happen to any code review that is published with r= or r? mtabara until we can work around the old account or remove the old account from the MozReview database.

It could happen again to someone who creates two Bugzilla accounts (e.g. one for personal use and one for staff use), does code reviews, and later decides to merge their Bugzilla accounts.

Handling deleted Bugzilla accounts transparently could be tricky.  Because this case is rare, it may be best to just catch the empty response to the BMO account lookup and fail gracefully.  We may be able to improve the logic that picks the correct code reviewer, too (see bug 1243343 comment 10).

Comment 3

[Mihai Tabara [:mtabara]⌚️GMT]

Heard my name and came out running. Is there anything I could help with with respect to my BMO account?

Comment 5

[Dustin J. Mitchell [:dustin] (he/him)]

:mars, can we manually fix the mozreview database for the time being?  I'm sure Mihai would be happy to do fewer reviews, but in many cases we do need his feedback!

Comment 6

[Māris Fogels [:mars] (please needinfo)]

(In reply to Dustin J. Mitchell [:dustin] from comment #5)
> :mars, can we manually fix the mozreview database for the time being?  I'm
> sure Mihai would be happy to do fewer reviews, but in many cases we do need
> his feedback!

:glob, do you think that's possible?

Comment 7

[:glob ✱]

sorry about the delay - i've deleted the errant row from the database.

Comment 8

[Rail Aliiev [:rail]]

Still getting an error :/


hg push -r . review
pushing to https://reviewboard-hg.mozilla.org/autoreview
searching for appropriate review repository
redirecting push to https://reviewboard-hg.mozilla.org/build-tools
(adding commit id to 1 changesets)
saved backup bundle to /home/rail/work/mozilla/build/tools/.hg/strip-backup/4a9f79ab88db-e4fffe13-addcommitid.hg
searching for changes
remote: adding changesets
remote: adding manifests
remote: adding file changes
remote: added 10 changesets with 20 changes to 11 files
remote: recorded push in pushlog
submitting 1 changesets for review
commit message for 194478c35998 has r=mtabara but they have not granted a ship-it. review will be requested on your behalf

changeset:  7041:194478c35998
summary:    Bug 1304474 - Patcher config failed to set pretty version properly in Firefox 50 r=mtabara
review:     https://reviewboard.mozilla.org/r/80180 (draft)

review id:  bz://1304474/rail
review url: https://reviewboard.mozilla.org/r/80178 (draft)

publish these review requests now (Yn)?  
error publishing review request 80178: HTTP 500
(review requests not published; visit review url to attempt publishing there)

Comment 9

[Mihai Tabara [:mtabara]⌚️GMT]

This still doesn't work. I can't get reviews in MozReview. Failing with:

publish these review requests now (Yn)?  y
error publishing review request 88080: HTTP 500
(review requests not published; visit review url to attempt publishing there)

Can you please take another look at this whenever you have some spare time?
Thank you!

Comment 10

[:glob ✱]

i had a quick look between meetings, and it isn't the same issue:
> BugzillaUserMap matching query does not exist.
(leaving NI open to investigate later)

Comment 11

[Mihai Tabara [:mtabara]⌚️GMT]

(In reply to Byron Jones ‹:glob› from comment #10)
> i had a quick look between meetings, and it isn't the same issue:
> > BugzillaUserMap matching query does not exist.
> (leaving NI open to investigate later)

Thanks a lot for looking into it! 

It's not an emergency as I can always default to classic Bugzilla-review process but it's nice to have this solved soon. It's nice to enjoy MozReview features :)

Comment 12

[Piotr Zalewa [:zalun]]

In comment #10 <:glob> mentioned that it is a different issue. It is for MozReview devs, as different exception is raised. For the commiter the feedback looks exactly the same as before. There should be a message in the `hg push` response saying "unrecognized reviewer: mtabara", but instead one sees "commit message for 194478c35998 has r=mtabara but they have not granted a ship-it. review will be requested on your behalf".

The reason behind is that the `batch_review_request.ReviewerCache` stored the reviewer and user mtabara is not included in `unrecognized_requal_reviewers`. The cache has no expiration time.

I see two issues here:
1. batch_review_request.ReviewerCache remembers the reviewers "forever".
2. Out of sync BugzillaUserMap which holds id to non-existing Bugzilla user.

I think that to solve these issues we would need to do two changes:
1. Modify (remove/expire/update) entry from BugzillaUserMap if its related Bugzilla user doesn't exist.
2. Add expiration time to the ReviewerCache.

Comment 13

[Mihai Tabara [:mtabara]⌚️GMT]

Thanks for looking into this. Honestly, I've lost hope that this might actually ever get fixed. Good to see it's being resurrected. Please let me know if there's anything I could do to help to finally solve this.

Comment 14

[Piotr Zalewa [:zalun]]

I've replicated the issue in my local test environment:

Created accounts a and b
    ./mozreview create-user [e-mail] password ‘A :a' --uid 2004 --scm-level 2 --bugzilla-group editbugs
    ./mozreview create-user [e-mail] password ‘B :b' --uid 2005 --scm-level 2 --bugzilla-group editbugs
    ./reviewboard dump-user a
    7:
      [...]
      username: a
    ./reviewboard dump-user b
    8:
      [...]
      username: b

Accounts are merged in Bugzilla (a to b)
    root@5916be0b751a:/var/lib/bugzilla/bugzilla# perl -T scripts/merge-users.pl [e-mail] [e-mail]
    pushing with r?a results with 
    500, IndexError: list index out of range
    Bugzilla REST API is responding with 400 (the same as for a non-existing account), for match it is an empty string.
        400, u'{"code":51,"message":"There is no user named \'[e-mail]\'. ...

User logged in to Bugzilla and changed name in bugzilla to “B :a” to keep old username
    pushing with r?a results with 
    500, IndexError: list index out of range

Removed mozreview_bugzillausermap entry
    pushing with r?a results with 
    500, DoesNotExist: BugzillaUserMap matching query does not exist.

**** This is the situation at the moment. ****

I've renamed old username in MozReview and it solved the issue after a onetime caching issue.

Removed username "a" (username a->_a)
    ./reviewboard dump-user a
    404
    ./reviewboard dump-user b
    8:
      [...]
      username: b
    pushing with r?a results with (no change)
    500, DoesNotExist: BugzillaUserMap matching query does not exist.

    pushing with r?b results with
    200, reviewer is assigned
    no change in dump-user

    pushing with r?a results with
    200, reviewer is assigned

    ./reviewboard dump-user a
    8:
        username: a
    ./reviewboard dump-user b
    404

    pushing with r?b results with
    200, unrecognized reviewer: b

If we rename mtabara's MozReview database entry we would "fix" the link with Bugzilla account.

Comment 15

[Piotr Zalewa [:zalun]]

Attachment: mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user (bug 1290889),

If BugzillaUserMap is out of sync with Bugzilla database push is failing
without explanation. This situation might happen for merged Bugzilla accounts.

Instead of failing without explanation MozReview is now giving a message:
Error publishing: Chosen reviewer (username) is assigned to a non-existing
Bugzilla user. If you believe you received this message in error, please ask
for help on IRC#mozreview. (HTTP 500, API Error 225)

Review commit: https://reviewboard.mozilla.org/r/112368/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/112368/

Comment 16

[Māris Fogels [:mars] (please needinfo)]

Comment on attachment 8837492 [details]
mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user (bug 1290889),

https://reviewboard.mozilla.org/r/112368/#review116520

::: pylib/mozreview/mozreview/tests/test-merged-account.py:20
(Diff revision 1)
> +from mozreview.bugzilla import attachments
> +from mozreview.errors import BugzillaUserMapError
> +from mozreview.tests.helpers import UserFactory
> +
> +
> +class TestUpdateBugzillaAttachments(unittest.TestCase):

Do we want to use pytest-style instead of xUnit-style for this test?

::: pylib/mozreview/mozreview/tests/test-merged-account.py:62
(Diff revision 1)
> +        children_to_obsolete = []
> +        bug_id = 1
> +
> +        # In case there is an entry in BugzillaUserMap and no user is found
> +        # in Bugzilla with given id a BugzillaUserMapError should be raised
> +        with self.assertRaises(BugzillaUserMapError) as context:

If you do rewrite this test in pytest-style, you can use the [raises context manager](http://doc.pytest.org/en/latest/builtin.html#helpers-for-assertions-about-exceptions-warnings) instead of self.assertRaises()

::: pylib/mozreview/mozreview/tests/test-merged-account.py:66
(Diff revision 1)
> +        # in Bugzilla with given id a BugzillaUserMapError should be raised
> +        with self.assertRaises(BugzillaUserMapError) as context:
> +            attachments.update_bugzilla_attachments(bugzilla, bug_id,
> +                                                    children_to_post,
> +                                                    children_to_obsolete)
> +        assert draft.target_people.user.username in unicode(context.exception)

Continuing from the comment about using pytest.raises(), you can use the [match()](http://doc.pytest.org/en/latest/builtin.html#_pytest._code.ExceptionInfo.match) method of the pytest.raises.ExcInfo object to match the username.

Comment 17

[Piotr Zalewa [:zalun]]

Comment on attachment 8837492 [details]
mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user (bug 1290889),

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/112368/diff/1-2/

Comment 18

[Māris Fogels [:mars] (please needinfo)]

Comment on attachment 8837492 [details]
mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user (bug 1290889),

https://reviewboard.mozilla.org/r/112368/#review116812

LGTM

Comment 19

[Mark Côté [:mcote]]

Comment on attachment 8837492 [details]
mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user (bug 1290889),

https://reviewboard.mozilla.org/r/112368/#review116956

rs for landing

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/hgcustom/version-control-tools/rev/186057014454
mozreview: fail silently when BugzillaUserMap refers to non-existing Bugzilla user , r=mars,mcote

Comment 21

[Dustin J. Mitchell [:dustin] (he/him)]

This is still failing as of today for mtabara, in http://bugzil.la/1340564.  Same symptoms as before.

Comment 22

[Piotr Zalewa [:zalun]]

I've checked it locally (reproduce steps posted above) and it looks fine.
:dustin, could you paste the exact 500 error message? Thanks

Comment 23

[Dustin J. Mitchell [:dustin] (he/him)]

I just get an alert in the UI that says "500 INTERNAL SERVER ERROR".  You can probably try it with bug 1340564.

Comment 24

[Piotr Zalewa [:zalun]]

Could you run with traceback? - I'm wondering if that is indeed the same issue
(`hg push  --debug --traceback`)

Comment 25

[Piotr Zalewa [:zalun]]

:dustin no need to do it. I've created a dummy bug and checked.

changeset:  5139:095c98eeacf1
summary:    This is a dummy review to check mtabara as a reviewer (bug 1345048) r=mtabara
review:     https://reviewboard.mozilla.org/r/117856 (draft)

review id:  bz://1345048/zalun
review url: https://reviewboard.mozilla.org/r/117854 (draft)

publish these review requests now (Yn)?
using auth.autobmoapikey0.* for authentication
error publishing review request 117854: HTTP 500
(review requests not published; visit review url to attempt publishing there)

Comment 26

[Piotr Zalewa [:zalun]]

:glob could you please provide logs about it? I can run it anytime

Comment 27

[:glob ✱]

creation:

2017-03-07 09:09:32,369 - INFO -  - Login attempt (apikey) for user [e-mail]:
2017-03-07 09:09:32,782 - INFO -  - Login successful (apikey) for user [e-mail]:
2017-03-07 09:09:32,792 - INFO -  - processing BatchReviewRequest for zalun
2017-03-07 09:09:32,796 - INFO -  - processing batch submission bz://1345048/zalun to version-control-tools with 1 commits
2017-03-07 09:09:32,830 - INFO -  - created squashed review request #117854
2017-03-07 09:09:32,830 - INFO -  - bz://1345048/zalun: generating squashed diffset for 117854
2017-03-07 09:09:32,945 - INFO -  - bz://1345048/zalun: updated squashed diffset for 117854
2017-03-07 09:09:32,947 - INFO -  - bz://1345048/zalun: 0 previous commits; 0 discard on publish; 0 unpublished
2017-03-07 09:09:32,947 - INFO -  - bz://1345048/zalun: 0/1 commits mapped exactly
2017-03-07 09:09:32,948 - INFO -  - bz://1345048/zalun: 0/1 mapped exactly or to precursors
2017-03-07 09:09:32,948 - INFO -  - bz://1345048/zalun: 0/1 mapped after commit ID matching
2017-03-07 09:09:32,948 - INFO -  - bz://1345048/zalun: 0 unclaimed review requests
2017-03-07 09:09:32,968 - INFO -  - bz://1345048/zalun: created review request 117856 for commit 095c98eeacf1e3b73d14b9ec114a8de4199a81a5
2017-03-07 09:09:34,109 - INFO -  - importing Bugzilla users from query "mtabara": [e-mail]
2017-03-07 09:09:34,114 - INFO -  - updating username of 695523 from mtabara+514212 to mtabara
2017-03-07 09:09:34,120 - INFO -  - could not update username of 695523; keeping as mtabara+514212
2017-03-07 09:09:34,858 - INFO -  - bz://1345048/zalun: 0 unclaimed review requests left over
2017-03-07 09:09:34,893 - INFO -  - bz://1345048/zalun: finished processing 117854

publish:

2017-03-07 09:09:43,057 - INFO -  - Checking if bug 1345048 is confidential.
2017-03-07 09:09:43,282 - INFO -  - Bug 1345048 confidential: False.
2017-03-07 09:09:43,297 - ERROR -  - Error when calling <function on_review_request_publishing at 0x7f2d606c28c0> from SignalHook: BugzillaUserMap matching query does not exist.
Traceback (most recent call last):
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/djblets/extensions/hooks.py", line 196, in _wrap_callback
    self.callback(extension=self.extension, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/errors.py", line 28, in _transform_errors
    return func(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/signal_handlers.py", line 350, in on_review_request_publishing
    children_to_obsolete)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/mozreview-0.1.2a0-py2.6.egg/mozreview/bugzilla/attachments.py", line 59, in update_bugzilla_attachments
    bum = BugzillaUserMap.objects.get(user=u)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/db/models/manager.py", line 151, in get
    return self.get_queryset().get(*args, **kwargs)
  File "/data/www/reviewboard.mozilla.org/venv/lib/python2.6/site-packages/django/db/models/query.py", line 310, in get
    self.model._meta.object_name)
DoesNotExist: BugzillaUserMap matching query does not exist.

Comment 28

[Piotr Zalewa [:zalun]]

:glob made the necessary changes to the database and it is fixed.
I was able to add mtabara as a reviewer from r=mtabara in commit message: https://reviewboard.mozilla.org/r/117856/
Please confirm and then we will close the bug.

Comment 29

[Mihai Tabara [:mtabara]⌚️GMT]

(In reply to Piotr Zalewa [:zalun] from comment #28)
> :glob made the necessary changes to the database and it is fixed.
> I was able to add mtabara as a reviewer from r=mtabara in commit message:
> https://reviewboard.mozilla.org/r/117856/
> Please confirm and then we will close the bug.

Sweet mother of what is good and pure, this finally works after 4 months \o/
:zalun - Thank you - margaritas are on me in December!

Comment 30

[Dustin J. Mitchell [:dustin] (he/him)]

Well, how could I possibly top that comment?