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

Bitbucket Branch Source v2.2.4 introduces long delay in starting builds

    XMLWordPrintable

    Details

    • Similar Issues:

      Description

      Bitbucket Branch Source plugin v2.2.3 would instantly receive notifications from Bitbucket and begin building within 1-2 seconds.  However, after upgrading to 2.2.4, it could take up to 4 minutes to process the notification. 

      When manually selecting build, the job would hang at "Started by user ..." for 3-4 minutes before actually doing the build and checking out the pipeline script.

      2.2.3 Logging (after switching back):

      [Wed Oct 25 22:37:30 EDT 2017] com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 UPDATED event from 10.1.201.237 ⇒

      https://<jenkins server>/bitbucket-scmsource-hook/notify

      with timestamp Wed Oct 25 22:37:24 EDT 2017 processed in 1.7 sec

       

      2.2.4 Logging:

      [Wed Oct 25 22:25:40 EDT 2017] com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 UPDATED event from 10.1.201.237 ⇒

      https://<jenkins server>/bitbucket-scmsource-hook/notify

      with timestamp Wed Oct 25 22:22:12 EDT 2017 processed in 1 min 9 sec

       

      Notice the timestamp in 2.2.4 is over 3 minutes older than the logging timestamp.  Also, 2.2.4 shows it took 1 min 9 sec to process, whereas 2.2.3 only took 1.7 sec.  

      Doing a thread dump of Jenkins appeared to show that it was doing an SCM fetch, but I don't know what on, since nothing I could find was being loaded.

      It's also worth noting that this was working fine before upgrading to 2.2.4, then it worked fine again after reverting back to 2.2.3, so this is definitely an issue introduced in the latest version.

      Please let me know if any other logging would be useful.

        Attachments

          Issue Links

            Activity

            Hide
            argus_k Dmytro Kozlovskyi added a comment -

            Also affects me. Delay for >5 minutes on big repositories - it's pain. Any estimates? Any workaround except downgrade to 2.2.3?

             

            Show
            argus_k Dmytro Kozlovskyi added a comment - Also affects me. Delay for >5 minutes on big repositories - it's pain. Any estimates? Any workaround except downgrade to 2.2.3?  
            Hide
            gabrielbash Gabriel Ash added a comment -

            Affecting me as well. I updated to 2.2.7 to get the lightweight checkout feature, and while that does work I am seeing multi-minute long delays before builds are triggered now.

            Show
            gabrielbash Gabriel Ash added a comment - Affecting me as well. I updated to 2.2.7 to get the lightweight checkout feature, and while that does work I am seeing multi-minute long delays before builds are triggered now.
            Hide
            pixman20 pixman20 added a comment -

            I've finally had time to dig into this and found the code introduced in 2.2.4 that's causing the issue.
            The delay was introduced by PR #67 and it increases with the number of branches in the repository.

            https://github.com/jenkinsci/bitbucket-branch-source-plugin/pull/67/files#diff-81f8144a4562a48aab69a09415c9f3cf

             

                        for (BitbucketServerBranch branch: branches) {
                            BitbucketCommit commit = resolveCommit(branch.getRawNode());
                            if (commit != null) {
                                branch.setTimestamp(commit.getDateMillis());
                            }
                        }
            

            Thread dump:

            "Executor #-1 for master : executing <job full name> #8" Id=88 Group=main RUNNABLE
                    ...
                    at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
            	at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getRequest(BitbucketServerAPIClient.java:499)
            	at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.resolveCommit(BitbucketServerAPIClient.java:393)
            	at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getBranches(BitbucketServerAPIClient.java:377)
            	at com.cloudbees.jenkins.plugins.bitbucket.BitbucketSCMSource.retrieve(BitbucketSCMSource.java:782)
            	at jenkins.scm.api.SCMSource.fetch(SCMSource.java:564)
            	at org.jenkinsci.plugins.workflow.multibranch.SCMBinder.create(SCMBinder.java:95)
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:263)
            	at hudson.model.ResourceController.execute(ResourceController.java:97)
            	at hudson.model.Executor.run(Executor.java:419)
            

            This takes a considerable time to loop over all branches and resolve the commits:
            com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getBranches(BitbucketServerAPIClient.java:377)

             

            Show
            pixman20 pixman20 added a comment - I've finally had time to dig into this and found the code introduced in 2.2.4 that's causing the issue. The delay was introduced by PR #67 and it increases with the number of branches in the repository. https://github.com/jenkinsci/bitbucket-branch-source-plugin/pull/67/files#diff-81f8144a4562a48aab69a09415c9f3cf   for (BitbucketServerBranch branch: branches) { BitbucketCommit commit = resolveCommit(branch.getRawNode()); if (commit != null ) { branch.setTimestamp(commit.getDateMillis()); } } Thread dump: "Executor #-1 for master : executing <job full name> #8" Id=88 Group=main RUNNABLE ... at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323) at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getRequest(BitbucketServerAPIClient.java:499) at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.resolveCommit(BitbucketServerAPIClient.java:393) at com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getBranches(BitbucketServerAPIClient.java:377) at com.cloudbees.jenkins.plugins.bitbucket.BitbucketSCMSource.retrieve(BitbucketSCMSource.java:782) at jenkins.scm.api.SCMSource.fetch(SCMSource.java:564) at org.jenkinsci.plugins.workflow.multibranch.SCMBinder.create(SCMBinder.java:95) at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:263) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:419) This takes a considerable time to loop over all branches and resolve the commits: com.cloudbees.jenkins.plugins.bitbucket.server.client.BitbucketServerAPIClient.getBranches(BitbucketServerAPIClient.java:377)  
            Hide
            pixman20 pixman20 added a comment -

            I added logging for org.apache.commons.httpclient.HttpClient, and in my scenario we have 25 branches in the particular repository that I'm testing with.
            The "enter HttpClient.executeMethod(HostConfiguration,HttpMethod,HttpState)" entry was logged
            17 times for 2.2.3
            255 times for 2.2.4

            Show
            pixman20 pixman20 added a comment - I added logging for org.apache.commons.httpclient.HttpClient, and in my scenario we have 25 branches in the particular repository that I'm testing with. The "enter HttpClient.executeMethod(HostConfiguration,HttpMethod,HttpState)" entry was logged 17 times for 2.2.3 255 times for 2.2.4
            Hide
            stephenconnolly Stephen Connolly added a comment -

            2.2.8

            Show
            stephenconnolly Stephen Connolly added a comment - 2.2.8

              People

              • Assignee:
                Unassigned
                Reporter:
                pixman20 pixman20
              • Votes:
                5 Vote for this issue
                Watchers:
                9 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: