New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tried to complete 1 buildrequests, but only completed 0 #3472

Closed
lancelodliu opened this Issue Jul 26, 2017 · 19 comments

Comments

Projects
None yet
3 participants
@lancelodliu
Contributor

lancelodliu commented Jul 26, 2017

This happens when 3 changes comes at a time. The first one got handled perfectly. Problem is the 2nd and 3rd change when the 2nd change was merged to 3rd and a NotClaimedError was raised. I use Perforce as CVS.
and log is:

2017-07-26 11:39:39+0800 [-] added change with revision 98 to database
2017-07-26 11:39:59+0800 [-] added buildset 324 to database
2017-07-26 11:39:59+0800 [-] added change with revision 99 to database
2017-07-26 11:40:19+0800 [-] starting build <Build runtests number:None results:success> using worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=AVAILABLE>
2017-07-26 11:40:19+0800 [-] <Build runtests number:None results:success>.startBuild
2017-07-26 11:40:21+0800 [-] added buildset 325 to database
2017-07-26 11:40:22+0800 [-] acquireLocks(worker <Worker u'example-worker'>, locks [])
2017-07-26 11:40:22+0800 [-] starting build <Build runtests number:295 results:success>.. pinging the worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=BUILDING>
2017-07-26 11:40:22+0800 [-] sending ping
2017-07-26 11:40:22+0800 [Broker,0,127.0.0.1] ping finished: success
// Blabla...OMIT a lot P4 sync command
2017-07-26 11:40:28+0800 [-]  step 'p4' complete: success (None)
2017-07-26 11:40:28+0800 [-]  <Build runtests number:295 results:success>: build finished
2017-07-26 11:40:28+0800 [-] releaseLocks(<Worker u'example-worker'>): []
2017-07-26 11:40:29+0800 [-] tried to complete 1 buildrequests, but only completed 0
2017-07-26 11:40:29+0800 [-] Got fatal Exception on DB
	Traceback (most recent call last):
	Failure: buildbot.db.buildrequests.NotClaimedError: 
@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

I found the NotClaimedError is raised at db/buildrequest.py:214 as below.

            for batch in self.doBatch(brids, 100):

                q = reqs_tbl.update()
                q = q.where(reqs_tbl.c.id.in_(batch))
                q = q.where(reqs_tbl.c.complete != 1)
                res = conn.execute(q,
                                   complete=1,
                                   results=results,
                                   complete_at=complete_at)

                # if an incorrect number of rows were updated, then we failed.
                if res.rowcount != len(batch):
                    log.msg("tried to complete %d buildrequests, "
                            "but only completed %d" % (len(batch), res.rowcount))
                    transaction.rollback()
                    raise NotClaimedError
Contributor

lancelodliu commented Jul 26, 2017

I found the NotClaimedError is raised at db/buildrequest.py:214 as below.

            for batch in self.doBatch(brids, 100):

                q = reqs_tbl.update()
                q = q.where(reqs_tbl.c.id.in_(batch))
                q = q.where(reqs_tbl.c.complete != 1)
                res = conn.execute(q,
                                   complete=1,
                                   results=results,
                                   complete_at=complete_at)

                # if an incorrect number of rows were updated, then we failed.
                if res.rowcount != len(batch):
                    log.msg("tried to complete %d buildrequests, "
                            "but only completed %d" % (len(batch), res.rowcount))
                    transaction.rollback()
                    raise NotClaimedError
@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member

which version of buildbot is it?

looks like it is similar to #3406 fixed it #3411

Member

tardyp commented Jul 26, 2017

which version of buildbot is it?

looks like it is similar to #3406 fixed it #3411

@tardyp tardyp added the To Reject? label Jul 26, 2017

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

Buildbot version: 0.9.9.post2
Twisted version: 16.6.0

Contributor

lancelodliu commented Jul 26, 2017

Buildbot version: 0.9.9.post2
Twisted version: 16.6.0

@tardyp tardyp added bug and removed To Reject? labels Jul 26, 2017

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member

looks like a new bug then.

Can you please post the results of those rest api when this happend to understand what happen?

https://xx/api/v2/builds?limit=10
https://xx/api/v2/buildrequests?limit=10
https://xx/api/v2/buildsets?limit=10

Member

tardyp commented Jul 26, 2017

looks like a new bug then.

Can you please post the results of those rest api when this happend to understand what happen?

https://xx/api/v2/builds?limit=10
https://xx/api/v2/buildrequests?limit=10
https://xx/api/v2/buildsets?limit=10

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

You can reproduce this as below:

  1. Use polling source(I use Perforce)
  2. Set the poll interval a bit larger like 15 seconds.
  3. Submit 3 commits at a time(1~2 seconds, just make sure they are pushed in the same poll interval).
  4. Wait

P.S.: If you push 5 commits #1-#5, then the first will raise the Error and there will be only 3 builds to be done which consists of #1, #2-#3 and #4-#5 seperately.

Contributor

lancelodliu commented Jul 26, 2017

You can reproduce this as below:

  1. Use polling source(I use Perforce)
  2. Set the poll interval a bit larger like 15 seconds.
  3. Submit 3 commits at a time(1~2 seconds, just make sure they are pushed in the same poll interval).
  4. Wait

P.S.: If you push 5 commits #1-#5, then the first will raise the Error and there will be only 3 builds to be done which consists of #1, #2-#3 and #4-#5 seperately.

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member

just to confirm, I believe you have configured the buildrequest collapser, right?

Member

tardyp commented Jul 26, 2017

just to confirm, I believe you have configured the buildrequest collapser, right?

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

First

{
  "builds": [
    {
      "builderid": 4, 
      "buildid": 18, 
      "buildrequestid": 26, 
      "complete": true, 
      "complete_at": 1501061524, 
      "masterid": 1, 
      "number": 18, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061516, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 17, 
      "buildrequestid": 24, 
      "complete": true, 
      "complete_at": 1501061515, 
      "masterid": 1, 
      "number": 17, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061507, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 16, 
      "buildrequestid": 23, 
      "complete": true, 
      "complete_at": 1501061368, 
      "masterid": 1, 
      "number": 16, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061360, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 15, 
      "buildrequestid": 21, 
      "complete": true, 
      "complete_at": 1501061359, 
      "masterid": 1, 
      "number": 15, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061351, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 14, 
      "buildrequestid": 20, 
      "complete": true, 
      "complete_at": 1501061236, 
      "masterid": 1, 
      "number": 14, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061228, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 13, 
      "buildrequestid": 18, 
      "complete": true, 
      "complete_at": 1501061227, 
      "masterid": 1, 
      "number": 13, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061211, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 12, 
      "buildrequestid": 17, 
      "complete": true, 
      "complete_at": 1501059636, 
      "masterid": 1, 
      "number": 12, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059628, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 11, 
      "buildrequestid": 15, 
      "complete": true, 
      "complete_at": 1501059628, 
      "masterid": 1, 
      "number": 11, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059611, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 10, 
      "buildrequestid": 14, 
      "complete": true, 
      "complete_at": 1501059056, 
      "masterid": 1, 
      "number": 10, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059048, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 9, 
      "buildrequestid": 13, 
      "complete": true, 
      "complete_at": 1501059048, 
      "masterid": 1, 
      "number": 9, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059040, 
      "state_string": "build successful", 
      "workerid": 3
    }
  ], 
  "meta": {
    "total": 10
  }
}

Second

{
  "buildrequests": [
    {
      "builderid": 4, 
      "buildrequestid": 26, 
      "buildsetid": 26, 
      "claimed": true, 
      "claimed_at": 1501061516, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061524, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061509, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 25, 
      "buildsetid": 25, 
      "claimed": true, 
      "claimed_at": 1501061510, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061511, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061506, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 24, 
      "buildsetid": 24, 
      "claimed": true, 
      "claimed_at": 1501061507, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061507, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061506, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 23, 
      "buildsetid": 23, 
      "claimed": true, 
      "claimed_at": 1501061360, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061368, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061352, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 22, 
      "buildsetid": 22, 
      "claimed": true, 
      "claimed_at": 1501061354, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061354, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061350, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 21, 
      "buildsetid": 21, 
      "claimed": true, 
      "claimed_at": 1501061351, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061351, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061349, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 20, 
      "buildsetid": 20, 
      "claimed": true, 
      "claimed_at": 1501061228, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061236, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061218, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 19, 
      "buildsetid": 19, 
      "claimed": true, 
      "claimed_at": 1501061221, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061222, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061211, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 18, 
      "buildsetid": 18, 
      "claimed": true, 
      "claimed_at": 1501061211, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061228, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061184, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 17, 
      "buildsetid": 17, 
      "claimed": true, 
      "claimed_at": 1501059628, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501059637, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501059616, 
      "waited_for": false
    }
  ], 
  "meta": {
    "total": 10
  }
}

Third, http://localhost:8020/api/v2/buildsets?limit=10&order=-bsid

{
  "buildsets": [
    {
      "bsid": 26, 
      "complete": true, 
      "complete_at": 1501061524, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061507, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "192", 
          "ssid": 26
        }
      ], 
      "submitted_at": 1501061509
    }, 
    {
      "bsid": 25, 
      "complete": true, 
      "complete_at": 1501061512, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061506, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "191", 
          "ssid": 25
        }
      ], 
      "submitted_at": 1501061506
    }, 
    {
      "bsid": 24, 
      "complete": true, 
      "complete_at": 1501061508, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061506, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "190", 
          "ssid": 24
        }
      ], 
      "submitted_at": 1501061506
    }, 
    {
      "bsid": 23, 
      "complete": true, 
      "complete_at": 1501061368, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061350, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "189", 
          "ssid": 23
        }
      ], 
      "submitted_at": 1501061352
    }, 
    {
      "bsid": 22, 
      "complete": true, 
      "complete_at": 1501061356, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061349, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "188", 
          "ssid": 22
        }
      ], 
      "submitted_at": 1501061350
    }, 
    {
      "bsid": 21, 
      "complete": true, 
      "complete_at": 1501061352, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061349, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "187", 
          "ssid": 21
        }
      ], 
      "submitted_at": 1501061349
    }, 
    {
      "bsid": 20, 
      "complete": true, 
      "complete_at": 1501061237, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061211, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "186", 
          "ssid": 20
        }
      ], 
      "submitted_at": 1501061218
    }, 
    {
      "bsid": 19, 
      "complete": true, 
      "complete_at": 1501061222, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061211, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "185", 
          "ssid": 19
        }
      ], 
      "submitted_at": 1501061211
    }, 
    {
      "bsid": 18, 
      "complete": true, 
      "complete_at": 1501061228, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061184, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "184", 
          "ssid": 18
        }
      ], 
      "submitted_at": 1501061184
    }, 
    {
      "bsid": 17, 
      "complete": true, 
      "complete_at": 1501059637, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501059611, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "183", 
          "ssid": 17
        }
      ], 
      "submitted_at": 1501059616
    }
  ], 
  "meta": {
    "total": 10
  }
}
Contributor

lancelodliu commented Jul 26, 2017

First

{
  "builds": [
    {
      "builderid": 4, 
      "buildid": 18, 
      "buildrequestid": 26, 
      "complete": true, 
      "complete_at": 1501061524, 
      "masterid": 1, 
      "number": 18, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061516, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 17, 
      "buildrequestid": 24, 
      "complete": true, 
      "complete_at": 1501061515, 
      "masterid": 1, 
      "number": 17, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061507, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 16, 
      "buildrequestid": 23, 
      "complete": true, 
      "complete_at": 1501061368, 
      "masterid": 1, 
      "number": 16, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061360, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 15, 
      "buildrequestid": 21, 
      "complete": true, 
      "complete_at": 1501061359, 
      "masterid": 1, 
      "number": 15, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061351, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 14, 
      "buildrequestid": 20, 
      "complete": true, 
      "complete_at": 1501061236, 
      "masterid": 1, 
      "number": 14, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061228, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 13, 
      "buildrequestid": 18, 
      "complete": true, 
      "complete_at": 1501061227, 
      "masterid": 1, 
      "number": 13, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501061211, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 12, 
      "buildrequestid": 17, 
      "complete": true, 
      "complete_at": 1501059636, 
      "masterid": 1, 
      "number": 12, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059628, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 11, 
      "buildrequestid": 15, 
      "complete": true, 
      "complete_at": 1501059628, 
      "masterid": 1, 
      "number": 11, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059611, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 10, 
      "buildrequestid": 14, 
      "complete": true, 
      "complete_at": 1501059056, 
      "masterid": 1, 
      "number": 10, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059048, 
      "state_string": "build successful", 
      "workerid": 3
    }, 
    {
      "builderid": 4, 
      "buildid": 9, 
      "buildrequestid": 13, 
      "complete": true, 
      "complete_at": 1501059048, 
      "masterid": 1, 
      "number": 9, 
      "properties": {}, 
      "results": 0, 
      "started_at": 1501059040, 
      "state_string": "build successful", 
      "workerid": 3
    }
  ], 
  "meta": {
    "total": 10
  }
}

Second

{
  "buildrequests": [
    {
      "builderid": 4, 
      "buildrequestid": 26, 
      "buildsetid": 26, 
      "claimed": true, 
      "claimed_at": 1501061516, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061524, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061509, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 25, 
      "buildsetid": 25, 
      "claimed": true, 
      "claimed_at": 1501061510, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061511, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061506, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 24, 
      "buildsetid": 24, 
      "claimed": true, 
      "claimed_at": 1501061507, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061507, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061506, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 23, 
      "buildsetid": 23, 
      "claimed": true, 
      "claimed_at": 1501061360, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061368, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061352, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 22, 
      "buildsetid": 22, 
      "claimed": true, 
      "claimed_at": 1501061354, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061354, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061350, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 21, 
      "buildsetid": 21, 
      "claimed": true, 
      "claimed_at": 1501061351, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061351, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061349, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 20, 
      "buildsetid": 20, 
      "claimed": true, 
      "claimed_at": 1501061228, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061236, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061218, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 19, 
      "buildsetid": 19, 
      "claimed": true, 
      "claimed_at": 1501061221, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061222, 
      "priority": 0, 
      "results": 3, 
      "submitted_at": 1501061211, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 18, 
      "buildsetid": 18, 
      "claimed": true, 
      "claimed_at": 1501061211, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501061228, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501061184, 
      "waited_for": false
    }, 
    {
      "builderid": 4, 
      "buildrequestid": 17, 
      "buildsetid": 17, 
      "claimed": true, 
      "claimed_at": 1501059628, 
      "claimed_by_masterid": 1, 
      "complete": true, 
      "complete_at": 1501059637, 
      "priority": 0, 
      "results": 0, 
      "submitted_at": 1501059616, 
      "waited_for": false
    }
  ], 
  "meta": {
    "total": 10
  }
}

Third, http://localhost:8020/api/v2/buildsets?limit=10&order=-bsid

{
  "buildsets": [
    {
      "bsid": 26, 
      "complete": true, 
      "complete_at": 1501061524, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061507, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "192", 
          "ssid": 26
        }
      ], 
      "submitted_at": 1501061509
    }, 
    {
      "bsid": 25, 
      "complete": true, 
      "complete_at": 1501061512, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061506, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "191", 
          "ssid": 25
        }
      ], 
      "submitted_at": 1501061506
    }, 
    {
      "bsid": 24, 
      "complete": true, 
      "complete_at": 1501061508, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061506, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "190", 
          "ssid": 24
        }
      ], 
      "submitted_at": 1501061506
    }, 
    {
      "bsid": 23, 
      "complete": true, 
      "complete_at": 1501061368, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061350, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "189", 
          "ssid": 23
        }
      ], 
      "submitted_at": 1501061352
    }, 
    {
      "bsid": 22, 
      "complete": true, 
      "complete_at": 1501061356, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061349, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "188", 
          "ssid": 22
        }
      ], 
      "submitted_at": 1501061350
    }, 
    {
      "bsid": 21, 
      "complete": true, 
      "complete_at": 1501061352, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061349, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "187", 
          "ssid": 21
        }
      ], 
      "submitted_at": 1501061349
    }, 
    {
      "bsid": 20, 
      "complete": true, 
      "complete_at": 1501061237, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061211, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "186", 
          "ssid": 20
        }
      ], 
      "submitted_at": 1501061218
    }, 
    {
      "bsid": 19, 
      "complete": true, 
      "complete_at": 1501061222, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061211, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "185", 
          "ssid": 19
        }
      ], 
      "submitted_at": 1501061211
    }, 
    {
      "bsid": 18, 
      "complete": true, 
      "complete_at": 1501061228, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501061184, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "184", 
          "ssid": 18
        }
      ], 
      "submitted_at": 1501061184
    }, 
    {
      "bsid": 17, 
      "complete": true, 
      "complete_at": 1501059637, 
      "external_idstring": null, 
      "parent_buildid": null, 
      "parent_relationship": null, 
      "reason": "The SingleBranchScheduler scheduler named 'all' triggered this build", 
      "results": 0, 
      "sourcestamps": [
        {
          "branch": null, 
          "codebase": "", 
          "created_at": 1501059611, 
          "patch": null, 
          "project": "Test", 
          "repository": "", 
          "revision": "183", 
          "ssid": 17
        }
      ], 
      "submitted_at": 1501059616
    }
  ], 
  "meta": {
    "total": 10
  }
}
@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

No, I configure it as the tutorial.

c['builders'] = []
c['builders'].append(
    util.BuilderConfig(name="runtests",
      workernames=["example-worker"],
      factory=factory))
Contributor

lancelodliu commented Jul 26, 2017

No, I configure it as the tutorial.

c['builders'] = []
c['builders'].append(
    util.BuilderConfig(name="runtests",
      workernames=["example-worker"],
      factory=factory))
@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

Should I set collapseRequests to False explicitly to disable this function?
After doing that, the error doesn't happen again. It seems that the collapse function is to blame.

Contributor

lancelodliu commented Jul 26, 2017

Should I set collapseRequests to False explicitly to disable this function?
After doing that, the error doesn't happen again. It seems that the collapse function is to blame.

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member

for the last set of builds that you sent, what is the exact error message?
In the original error, it refers build 295, which is not part of your dump.

Member

tardyp commented Jul 26, 2017

for the last set of builds that you sent, what is the exact error message?
In the original error, it refers build 295, which is not part of your dump.

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor
2017-07-26 17:31:46+0800 [-] added change with revision 190 to database
2017-07-26 17:31:46+0800 [-] added buildset 24 to database
2017-07-26 17:31:46+0800 [-] added change with revision 191 to database
2017-07-26 17:31:47+0800 [-] added change with revision 192 to database
2017-07-26 17:31:47+0800 [-] starting build <Build runtests number:None results:success> using worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=AVAILABLE>
2017-07-26 17:31:47+0800 [-] <Build runtests number:None results:success>.startBuild
2017-07-26 17:31:49+0800 [-] added buildset 25 to database
2017-07-26 17:31:49+0800 [-] acquireLocks(worker <Worker u'example-worker'>, locks [])
2017-07-26 17:31:50+0800 [-] starting build <Build runtests number:17 results:success>.. pinging the worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=BUILDING>
2017-07-26 17:31:50+0800 [-] sending ping
2017-07-26 17:31:50+0800 [Broker,0,127.0.0.1] ping finished: success
# blabla...
2017-07-26 17:31:53+0800 [-] added buildset 26 to database
2017-07-26 17:31:54+0800 [-] releaseLocks(P4(p4passwd='xxx', p4port='localhost:1666', mode='incremental', p4user='lancelodliu', p4base='//depot')): []
2017-07-26 17:31:55+0800 [-]  step 'p4' complete: success (None)
2017-07-26 17:31:55+0800 [-]  <Build runtests number:17 results:success>: build finished
2017-07-26 17:31:56+0800 [-] releaseLocks(<Worker u'example-worker'>): []
2017-07-26 17:31:56+0800 [-] tried to complete 1 buildrequests, but only completed 0
2017-07-26 17:31:56+0800 [-] Got fatal Exception on DB
	Traceback (most recent call last):
	Failure: buildbot.db.buildrequests.NotClaimedError: 
Contributor

lancelodliu commented Jul 26, 2017

2017-07-26 17:31:46+0800 [-] added change with revision 190 to database
2017-07-26 17:31:46+0800 [-] added buildset 24 to database
2017-07-26 17:31:46+0800 [-] added change with revision 191 to database
2017-07-26 17:31:47+0800 [-] added change with revision 192 to database
2017-07-26 17:31:47+0800 [-] starting build <Build runtests number:None results:success> using worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=AVAILABLE>
2017-07-26 17:31:47+0800 [-] <Build runtests number:None results:success>.startBuild
2017-07-26 17:31:49+0800 [-] added buildset 25 to database
2017-07-26 17:31:49+0800 [-] acquireLocks(worker <Worker u'example-worker'>, locks [])
2017-07-26 17:31:50+0800 [-] starting build <Build runtests number:17 results:success>.. pinging the worker <WorkerForBuilder builder=u'runtests' worker=u'example-worker' state=BUILDING>
2017-07-26 17:31:50+0800 [-] sending ping
2017-07-26 17:31:50+0800 [Broker,0,127.0.0.1] ping finished: success
# blabla...
2017-07-26 17:31:53+0800 [-] added buildset 26 to database
2017-07-26 17:31:54+0800 [-] releaseLocks(P4(p4passwd='xxx', p4port='localhost:1666', mode='incremental', p4user='lancelodliu', p4base='//depot')): []
2017-07-26 17:31:55+0800 [-]  step 'p4' complete: success (None)
2017-07-26 17:31:55+0800 [-]  <Build runtests number:17 results:success>: build finished
2017-07-26 17:31:56+0800 [-] releaseLocks(<Worker u'example-worker'>): []
2017-07-26 17:31:56+0800 [-] tried to complete 1 buildrequests, but only completed 0
2017-07-26 17:31:56+0800 [-] Got fatal Exception on DB
	Traceback (most recent call last):
	Failure: buildbot.db.buildrequests.NotClaimedError: 
@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member

So build 17 is associated with buildrequest 24, which is marked skipped in the DB, which means it has been collapsed. So there might be a race to claim between the collapser and the distributor.
If the same master is claiming the same buildrequest (one for collapser, one for distributor) maybe our race condition mechanism do not work..

Member

tardyp commented Jul 26, 2017

So build 17 is associated with buildrequest 24, which is marked skipped in the DB, which means it has been collapsed. So there might be a race to claim between the collapser and the distributor.
If the same master is claiming the same buildrequest (one for collapser, one for distributor) maybe our race condition mechanism do not work..

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

Maybe. Disabling the collapse solves this anyway.

Contributor

lancelodliu commented Jul 26, 2017

Maybe. Disabling the collapse solves this anyway.

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Jul 26, 2017

Member
Member

tardyp commented Jul 26, 2017

@lancelodliu

This comment has been minimized.

Show comment
Hide comment
@lancelodliu

lancelodliu Jul 26, 2017

Contributor

I already set treeStableTimer to None to start a separate build immediately for each Change.

Contributor

lancelodliu commented Jul 26, 2017

I already set treeStableTimer to None to start a separate build immediately for each Change.

@aj062

This comment has been minimized.

Show comment
Hide comment
@aj062

aj062 Oct 4, 2017

I am also seeing this issue multiple times every day. I have many builders using collapseRequests and I can't disable collapseRequests on all of them. Is there any fix/workaround for this issue?

I have not configured treestabletimer. Will treestabletimer help in this case?

aj062 commented Oct 4, 2017

I am also seeing this issue multiple times every day. I have many builders using collapseRequests and I can't disable collapseRequests on all of them. Is there any fix/workaround for this issue?

I have not configured treestabletimer. Will treestabletimer help in this case?

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Oct 5, 2017

Member

This should be fixed in next release..

Member

tardyp commented Oct 5, 2017

This should be fixed in next release..

@tardyp

This comment has been minimized.

Show comment
Hide comment
@tardyp

tardyp Oct 5, 2017

Member

duplicate of #3591

Member

tardyp commented Oct 5, 2017

duplicate of #3591

@tardyp tardyp closed this Oct 5, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment