[users at bb.net] 0.8.12 status/web/hooks/gitlab.py order of changes wrong?

Sun Dec 11 22:46:34 UTC 2016

Hi all,
(bit of a brain dump here.  I have a bad habit of posting before my
investigations are complete.
I'll probably figure this out on my own and post what happened.)

I'm using buildbot 0.8.x with git 2.7.4, using method 'copy', and
getting changes from a gitlab webhook, e.g.
    factory.addStep(steps.Git(repourl=repourl, mode='full',
submodules=True, method='copy', ...))
    ...
    self['status'].append(
            buildbot.status.html.WebStatus(change_hook_dialects={
'gitlab' : True },
    ....

Most of the time it works fine, but I've been fighting an odd
problem somewhat like that described in
http://www.xerxesb.com/2010/12/20/git-describe-and-the-tale-of-the-wrong-commits/
where 'git describe' gives the wrong answer after a merge from a bugfix branch.

I thought I'd licked that problem, but today, I noticed the same
symptom on all builders.
Oddly, although the web interface shows that the change
to be built had both the bugfix and the merge commit,
the log shows that the git reset --hard was for the commit
before the branch.
Doing a 'git clone' manually results in the correct output from 'git describe'.

Clicking 'force build' works around the problem, too, and I suspect
the next change in master would also build properly.

Here's the relevant log section showing the incoming change from the webhook:

2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] Attempting to
load module buildbot.status.web.hooks.gitlab
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] New revision: 862a2776
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] New revision: 6999798c
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] New revision: 2ef5e653
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] Received 3
changes from gitlab
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] Got the
following changes [{'files': [u'bld/ob-machine-setup.pl'], 'project':
'', 'repository': u'git at gitlab.foobaz.com:platform/myapp.git',
'branch': u'master', 'author': u'Dan Kegel <dank at foobaz.com>',
'when_timestamp': datetime.datetime(2016, 12, 9, 23, 1, 23,
tzinfo=tzutc()), 'revlink':
u'https://gitlab.foobaz.com/platform/myapp/commit/862a2776e1907d5bdfb42edd2fbd4b393c3c4636',
'comments': u"Merge branch 'bfx-3.28' into master\n", 'revision':
u'862a2776e1907d5bdfb42edd2fbd4b393c3c4636'}, {'files':
[u'bld/ob-machine-setup.pl'], 'project': '', 'repository':
u'git at gitlab.foobaz.com:platform/myapp.git', 'branch': u'master',
'author': u'Dan Kegel <dank at foobaz.com>', 'when_timestamp':
datetime.datetime(2016, 12, 9, 23, 1, 2, tzinfo=tzutc()), 'revlink':
u'https://gitlab.foobaz.com/platform/myapp/commit/6999798c1608dbc95703db8683801be2134902f5',
'comments': u"Merge branch 'bug17852' into bfx-3.28\n", 'revision':
u'6999798c1608dbc95703db8683801be2134902f5'}, {'files':
[u'bld/ob-machine-setup.pl'], 'project': '', 'repository':
u'git at gitlab.foobaz.com:platform/myapp.git', 'branch': u'master',
'author': u'Dan Kegel <dank at foobaz.com>', 'when_timestamp':
datetime.datetime(2016, 12, 9, 21, 12, 19, tzinfo=tzutc()), 'revlink':
u'https://gitlab.foobaz.com/platform/myapp/commit/2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5',
'comments': u'Work around bug 17852.\n', 'revision':
u'2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5'}]
2016-12-09 15:29:48-0800 [HTTPChannel,70,10.10.169.29] Payload: {}
2016-12-09 15:29:49-0800 [-] added change
Change(revision=u'862a2776e1907d5bdfb42edd2fbd4b393c3c4636', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u"Merge branch
'bfx-3.28' into master\n", when=1481324483, category=None,
project=u'', repository=u'git at gitlab.foobaz.com:platform/myapp.git',
codebase=u'') to database
2016-12-09 15:29:49-0800 [-] injected change
Change(revision=u'862a2776e1907d5bdfb42edd2fbd4b393c3c4636', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u"Merge branch
'bfx-3.28' into master\n", when=1481324483, category=None,
project=u'', repository=u'git at gitlab.foobaz.com:platform/myapp.git',
codebase=u'')
2016-12-09 15:29:49-0800 [-] added change
Change(revision=u'6999798c1608dbc95703db8683801be2134902f5', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u"Merge branch
'bug17852' into bfx-3.28\n", when=1481324462, category=None,
project=u'', repository=u'git at gitlab.foobaz.com:platform/myapp.git',
codebase=u'') to database
2016-12-09 15:29:49-0800 [-] injected change
Change(revision=u'6999798c1608dbc95703db8683801be2134902f5', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u"Merge branch
'bug17852' into bfx-3.28\n", when=1481324462, category=None,
project=u'', repository=u'git at gitlab.foobaz.com:platform/myapp.git',
codebase=u'')
2016-12-09 15:29:49-0800 [-] added change
Change(revision=u'2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u'Work around bug
17852.\n', when=1481317939, category=None, project=u'',
repository=u'git at gitlab.foobaz.com:platform/myapp.git', codebase=u'')
to database
2016-12-09 15:29:49-0800 [-] injected change
Change(revision=u'2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5', who=u'Dan
Kegel <dank at foobaz.com>', branch=u'master', comments=u'Work around bug
17852.\n', when=1481317939, category=None, project=u'',
repository=u'git at gitlab.foobaz.com:platform/myapp.git', codebase=u'')
2016-12-09 15:30:49-0800 [-] added buildset 119565 to database

'git log --decorate' on a good client says

commit 862a2776e1907d5bdfb42edd2fbd4b393c3c4636 (HEAD -> master,
origin/master, origin/HEAD)
Merge: 0edf517 6999798
Author: Dan Kegel <dank at foobaz.com>
Date:   Fri Dec 9 23:01:23 2016 +0000

    Merge branch 'bfx-3.28' into master

commit 6999798c1608dbc95703db8683801be2134902f5 (origin/bfx-3.28)
Merge: 6886fa3 2ef5e65
Author: Dan Kegel <dank at foobaz.com>
Date:   Fri Dec 9 23:01:02 2016 +0000

    Merge branch 'bug17852' into bfx-3.28

commit 2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5
Author: Dan Kegel <dank at foobaz.com>
Date:   Fri Dec 9 21:12:19 2016 +0000

    Work around bug 17852.

'git log --decorate' on a client updated by buildbot's Git class says

commit 2ef5e65370ef9c2b586e4b3b269901aa9cfe26d5 (HEAD -> master)
Author: Dan Kegel <dank at foobaz.com>
Date:   Fri Dec 9 21:12:19 2016 +0000

    Work around bug 17852.

because buildbot told git to do a hard reset to that commit, probably
because buildset 119565's SourceStamp was created with the oldest
commit's hash rather than the newest one's.

SourceStamp clearly tries to do the right thing:
                # set branch and revision to most recent change
                self.branch = changes[-1].branch
                revision = changes[-1].revision

So suspicion falls on status/web/hooks/gitlab.py.
Maybe it returns a list of changes in the wrong order in this case.
https://gitlab.com/gitlab-org/gitlab-ce/blob/master/doc/web_hooks/web_hooks.md
claims the json payload is in time order, at least for normal commits.

Time for some experimentation.  I'll post more later.
- Dan