Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-19314

CVS plugin queues up multiple builds on same changes when poll time < build time

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Major
    • Resolution: Fixed
    • Component/s: cvs-plugin
    • Labels:
    • Environment:
      CentOS 5.5 master, Windows 7 enterprise node
    • Similar Issues:

      Description

      When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

      For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

      Started on Aug 22, 2013 9:20:58 AM
      Using locally configured password for connection to :pserver:someone@someplace:/cvshome
      cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule 
      ...
      Changes Found

      This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:

      Started on Aug 22, 2013 9:25:58 AM
      Using locally configured password for connection to :pserver:someone@someplace:/cvshome
      cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
      ...
      Changes Found

      And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log. The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)

      When the second build starts building, this is how it gets its changelog

      Using locally configured password for connection to :pserver:someone@someplace:/cvshome
      cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 someModule 
      

      Where 9:21:14 is the time in which the first build finished. Thus we have this "phantom build" triggered by "no changes"

      Workaround: Set polling longer interval, but this comes at the cost of responsiveness.

        Attachments

          Activity

          efusciardi Eric Fusciardi created issue -
          efusciardi Eric Fusciardi made changes -
          Field Original Value New Value
          Description When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log (because surprise, when it goes to actually execute the build, this is how it gets its change set....
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 vp
          {code} Where 9:21:14 is the time in which the first build finished.

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log (because surprise, when it goes to actually execute the build, this is how it gets its change set... The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 vp
          {code} Where 9:21:14 is the time in which the first build finished.

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          efusciardi Eric Fusciardi made changes -
          Description When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log (because surprise, when it goes to actually execute the build, this is how it gets its change set... The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 vp
          {code} Where 9:21:14 is the time in which the first build finished.

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log. The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)

          When the second build starts building, this is how it gets its changelog
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 vp
          {code} Where 9:21:14 is the time in which the first build finished. Thus we have this "phantom build" triggered by "no changes"

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          efusciardi Eric Fusciardi made changes -
          Description When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log. The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)

          When the second build starts building, this is how it gets its changelog
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 vp
          {code} Where 9:21:14 is the time in which the first build finished. Thus we have this "phantom build" triggered by "no changes"

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          When CVS polling is enabled, the "high watermark" timestamp that cvs polls on for changes does not update until a build finishes. This causes multiple builds to trigger on the same changes.

          For example, a build that take 7 mins, set to poll every 5, produces the following output on its first poll.

          {code}Started on Aug 22, 2013 9:20:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:20:58 -0400 someModule
          ...
          Changes Found{code}
          This triggers a build based on changes committed at 9:15, it starts building. 5mins later this is the poll log:
          {code}Started on Aug 22, 2013 9:25:58 AM
          Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 08:30:03 -0400<22 Aug 2013 09:25:58 -0400 someModule
          ...
          Changes Found{code}
          And queues up another build based on the same changes at 9:15. This is problematic because it doubles node usage, and the second build shows nothing in it's Changes log. The changes at 9:15 already successfully triggered a build into the queue, the date range of this poll should be from 9:20:58(prev) - 9:25:58(now)

          When the second build starts building, this is how it gets its changelog
          {code}Using locally configured password for connection to :pserver:someone@someplace:/cvshome
          cvs rlog -S -d22 Aug 2013 09:21:14 -0400<22 Aug 2013 09:26:20 -0400 someModule
          {code} Where 9:21:14 is the time in which the first build finished. Thus we have this "phantom build" triggered by "no changes"

          Workaround: Set polling longer interval, but this comes at the cost of responsiveness.
          Hide
          scm_issue_link SCM/JIRA link daemon added a comment -

          Code changed in jenkins
          User: Michael Clarke
          Path:
          src/main/java/hudson/scm/AbstractCvs.java
          src/test/java/hudson/scm/CVSSCMTest.java
          http://jenkins-ci.org/commit/cvs-plugin/7b503541e02587b41e962910e90f4a203a7b026d
          Log:
          [FIXED JENKINS-19314] Don't poll if last checkout has not completed

          Show
          scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Michael Clarke Path: src/main/java/hudson/scm/AbstractCvs.java src/test/java/hudson/scm/CVSSCMTest.java http://jenkins-ci.org/commit/cvs-plugin/7b503541e02587b41e962910e90f4a203a7b026d Log: [FIXED JENKINS-19314] Don't poll if last checkout has not completed
          scm_issue_link SCM/JIRA link daemon made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          pelchats Simon Pelchat added a comment -

          This is still an issue for me (using 2.11). From a very quick glance at the code, it seems like this line in AbstractCVS.java might be the problem:

          final List<CvsFile> changes = calculateRepositoryState(project.getLastCompletedBuild().getTime(),
          currentPollDate, repository, listener, envVars, workspace);

          I think
          project.getLastCompletedBuild()
          should be
          project.getLastBuild()

          Either way, this is quite a big problem for us, since we're building a large C++ project that takes ~3 hours to build and test (using up 16 slaves in total).

          I've set the polling to 4 hours, but this isn't ideal.

          Show
          pelchats Simon Pelchat added a comment - This is still an issue for me (using 2.11). From a very quick glance at the code, it seems like this line in AbstractCVS.java might be the problem: final List<CvsFile> changes = calculateRepositoryState(project.getLastCompletedBuild().getTime(), currentPollDate, repository, listener, envVars, workspace); I think project.getLastCompletedBuild() should be project.getLastBuild() Either way, this is quite a big problem for us, since we're building a large C++ project that takes ~3 hours to build and test (using up 16 slaves in total). I've set the polling to 4 hours, but this isn't ideal.
          pelchats Simon Pelchat made changes -
          Resolution Fixed [ 1 ]
          Status Resolved [ 5 ] Reopened [ 4 ]
          Hide
          scm_issue_link SCM/JIRA link daemon added a comment -

          Code changed in jenkins
          User: Simon Pelchat
          Path:
          src/main/java/hudson/scm/AbstractCvs.java
          http://jenkins-ci.org/commit/cvs-plugin/c709d104fa1cebd12fdcf98f425c00673e3f4e2e
          Log:
          [FIXED JENKINS-19314] diff from last successfully checked out build
          (which might currently be building) rather than last finished build

          Show
          scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Simon Pelchat Path: src/main/java/hudson/scm/AbstractCvs.java http://jenkins-ci.org/commit/cvs-plugin/c709d104fa1cebd12fdcf98f425c00673e3f4e2e Log: [FIXED JENKINS-19314] diff from last successfully checked out build (which might currently be building) rather than last finished build
          scm_issue_link SCM/JIRA link daemon made changes -
          Status Reopened [ 4 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          scm_issue_link SCM/JIRA link daemon added a comment -

          Code changed in jenkins
          User: Michael Clarke
          Path:
          src/main/java/hudson/scm/AbstractCvs.java
          http://jenkins-ci.org/commit/cvs-plugin/1e259e91ba5f8966e818c9ef30f9b55bcc24f570
          Log:
          Merge pull request #28 from myrbock/master

          [FIXED JENKINS-19314] diff from last successfully checked out build

          Compare: https://github.com/jenkinsci/cvs-plugin/compare/eb2a491ba66c...1e259e91ba5f

          Show
          scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Michael Clarke Path: src/main/java/hudson/scm/AbstractCvs.java http://jenkins-ci.org/commit/cvs-plugin/1e259e91ba5f8966e818c9ef30f9b55bcc24f570 Log: Merge pull request #28 from myrbock/master [FIXED JENKINS-19314] diff from last successfully checked out build Compare: https://github.com/jenkinsci/cvs-plugin/compare/eb2a491ba66c...1e259e91ba5f
          Hide
          manishgo Manish Goyal added a comment -

          When can we expect a release for this bug fix?

          Show
          manishgo Manish Goyal added a comment - When can we expect a release for this bug fix?
          Hide
          theandrewducker Andrew Ducker added a comment -

          We are still being affected by this as well. Any chance of a fix?

          (Specifically, a new build started when the old one was still in progress, despite no changes occurring in-between. We have version 2.11 of the plugin installed.)

          Show
          theandrewducker Andrew Ducker added a comment - We are still being affected by this as well. Any chance of a fix? (Specifically, a new build started when the old one was still in progress, despite no changes occurring in-between. We have version 2.11 of the plugin installed.)
          Hide
          theandrewducker Andrew Ducker added a comment -

          Not quite fixed. Have been informed that there is a fix that is not yet released.

          Show
          theandrewducker Andrew Ducker added a comment - Not quite fixed. Have been informed that there is a fix that is not yet released.
          theandrewducker Andrew Ducker made changes -
          Resolution Fixed [ 1 ]
          Status Resolved [ 5 ] Reopened [ 4 ]
          Hide
          theandrewducker Andrew Ducker added a comment -

          Michael offered to take ownership

          Show
          theandrewducker Andrew Ducker added a comment - Michael offered to take ownership
          theandrewducker Andrew Ducker made changes -
          Assignee Michael Clarke [ mc1arke ]
          Hide
          mc1arke Michael Clarke added a comment -

          Release in V2.12 of the CVS plugin

          Show
          mc1arke Michael Clarke added a comment - Release in V2.12 of the CVS plugin
          mc1arke Michael Clarke made changes -
          Status Reopened [ 4 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          manishgo Manish Goyal added a comment -

          Thanks for fixing this bug. When is v2.12 expected to go public?

          Show
          manishgo Manish Goyal added a comment - Thanks for fixing this bug. When is v2.12 expected to go public?
          Hide
          mc1arke Michael Clarke added a comment -

          It's live now.

          Show
          mc1arke Michael Clarke added a comment - It's live now.
          rtyler R. Tyler Croy made changes -
          Workflow JNJira [ 150762 ] JNJira + In-Review [ 193661 ]

            People

            • Assignee:
              mc1arke Michael Clarke
              Reporter:
              efusciardi Eric Fusciardi
            • Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: