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

Extremely slow queuing time due to blue ocean

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Fixed
    • Component/s: blueocean-plugin
    • Labels:
      None
    • Environment:
      Jenkins 2.73.1, Blue ocean 1.2.4
    • Epic Link:
    • Sprint:
      Blue Ocean 1.3
    • Similar Issues:

      Description

      When queuing large numbers of builds at the same time (say 10-20 because of push action), blue ocean bogs down in the enricher.  This blocks other builds from starting or finishing.  It could block for many minutes.

       

      "GitHubPushTrigger [#1178]" Id=131870 Group=main RUNNABLE
      	at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
      	at sun.nio.ch.FileDispatcherImpl.read(FileDispatcherImpl.java:46)
      	at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
      	at sun.nio.ch.IOUtil.read(IOUtil.java:197)
      	at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:159)
      	-  locked java.lang.Object@5c8c18b2
      	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:65)
      	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:109)
      	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
      	-  locked sun.nio.ch.ChannelInputStream@198e9d47
      	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
      	at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
      	-  locked java.io.BufferedInputStream@6c1117d7
      	at java.io.FilterInputStream.read(FilterInputStream.java:83)
      	at java.io.PushbackInputStream.read(PushbackInputStream.java:139)
      	at com.thoughtworks.xstream.core.util.XmlHeaderAwareReader.getHeader(XmlHeaderAwareReader.java:79)
      	at com.thoughtworks.xstream.core.util.XmlHeaderAwareReader.<init>(XmlHeaderAwareReader.java:61)
      	at com.thoughtworks.xstream.io.xml.AbstractXppDriver.createReader(AbstractXppDriver.java:65)
      	at hudson.XmlFile.unmarshal(XmlFile.java:160)
      	at hudson.model.Run.reload(Run.java:337)
      	at hudson.model.Run.<init>(Run.java:325)
      	at hudson.model.AbstractBuild.<init>(AbstractBuild.java:173)
      	at hudson.model.Build.<init>(Build.java:104)
      	at hudson.model.FreeStyleBuild.<init>(FreeStyleBuild.java:38)
      	at sun.reflect.GeneratedConstructorAccessor225.newInstance(Unknown Source)
      	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
      	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
      	at jenkins.model.lazy.LazyBuildMixIn.loadBuild(LazyBuildMixIn.java:165)
      	at jenkins.model.lazy.LazyBuildMixIn$1.create(LazyBuildMixIn.java:142)
      	at hudson.model.RunMap.retrieve(RunMap.java:224)
      	at hudson.model.RunMap.retrieve(RunMap.java:57)
      	at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:500)
      	at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:482)
      	at jenkins.model.lazy.AbstractLazyLoadRunMap.getByNumber(AbstractLazyLoadRunMap.java:380)
      	-  locked hudson.model.RunMap@28dd655e
      	at jenkins.model.lazy.AbstractLazyLoadRunMap.search(AbstractLazyLoadRunMap.java:345)
      	at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:74)
      	at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:63)
      	at java.util.AbstractMap$2$1.next(AbstractMap.java:418)
      	at com.google.common.collect.Iterators$7.computeNext(Iterators.java:648)
      	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
      	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
      	at com.google.common.collect.Iterators.find(Iterators.java:738)
      	at com.google.common.collect.Iterables.find(Iterables.java:656)
      	at io.jenkins.blueocean.service.embedded.rest.QueueUtil.getRun(QueueUtil.java:41)
      	at io.jenkins.blueocean.events.BlueMessageEnricher.enrich(BlueMessageEnricher.java:104)
      	at org.jenkinsci.plugins.pubsub.PubsubBus.publish(PubsubBus.java:133)
      	at org.jenkinsci.plugins.pubsub.listeners.SyncQueueListener.publish(SyncQueueListener.java:178)
      	at org.jenkinsci.plugins.pubsub.listeners.SyncQueueListener.publish(SyncQueueListener.java:172)
      	at org.jenkinsci.plugins.pubsub.listeners.SyncQueueListener.onEnterWaiting(SyncQueueListener.java:139)
      	at hudson.model.Queue$WaitingItem.enter(Queue.java:2393)
      	at hudson.model.Queue.scheduleInternal(Queue.java:632)
      	at hudson.model.Queue.schedule2(Queue.java:588)
      	at jenkins.model.ParameterizedJobMixIn.scheduleBuild2(ParameterizedJobMixIn.java:155)
      	at jenkins.model.ParameterizedJobMixIn.scheduleBuild(ParameterizedJobMixIn.java:115)
      	at jenkins.model.ParameterizedJobMixIn.scheduleBuild(ParameterizedJobMixIn.java:104)
      	at com.cloudbees.jenkins.GitHubPushTrigger$1.run(GitHubPushTrigger.java:143)
      	at hudson.util.SequentialExecutionQueue$QueueEntry.run(SequentialExecutionQueue.java:119)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      
      	Number of locked synchronizers = 2
      	- java.util.concurrent.locks.ReentrantLock$NonfairSync@297dcced
      	- java.util.concurrent.ThreadPoolExecutor$Worker@7b91fe67

       

      This appears to be the offending set of frames:

      	at io.jenkins.blueocean.service.embedded.rest.QueueUtil.getRun(QueueUtil.java:41)
      	at io.jenkins.blueocean.events.BlueMessageEnricher.enrich(BlueMessageEnricher.java:104)

       

      @Nullable
      @SuppressWarnings("unchecked")
      public static <T extends Run> T getRun(@Nonnull Job job, final long queueId) {
          return Iterables.find((Iterable<T>) job.getBuilds(), new Predicate<Run>() {
                  @Override
                  public boolean apply(@Nullable Run input) {
                      return input != null && input.getQueueId() == queueId;
                  }
              }, null);
          }
      

      This appears to be very inefficient.  I had two questions about this code:

      1) Would this ever actually return anything other than null?  The new run hasn't been assigned a number, so would it even show up in "getBuilds"?

      2) Overall, loading the all builds is just horribly inefficent anyway.

        Attachments

          Issue Links

            Activity

            Hide
            vivek Vivek Pandey added a comment -

            Matthew Mitchell QueueUtil.getRun() is indeed expensive, specially looking for Run using queueId is. In fact we didn't need to do this lookup. Thanks for bringing it to our attention.

            In your PR https://github.com/jenkinsci/blueocean-plugin/pull/1433, I have added code to use the runId sent via pubsub event. PR has been merged to master and ported over to release/1.3 branch and will be made available in upcoming 1.3 release.

            Show
            vivek Vivek Pandey added a comment - Matthew Mitchell QueueUtil.getRun() is indeed expensive, specially looking for Run using queueId is. In fact we didn't need to do this lookup. Thanks for bringing it to our attention. In your PR https://github.com/jenkinsci/blueocean-plugin/pull/1433 , I have added code to use the runId sent via pubsub event. PR has been merged to master and ported over to release/1.3 branch and will be made available in upcoming 1.3 release.
            Hide
            jamesdumay James Dumay added a comment -

            Fixed in 1.3

            Show
            jamesdumay James Dumay added a comment - Fixed in 1.3

              People

              • Assignee:
                mmitche Matthew Mitchell
                Reporter:
                mmitche Matthew Mitchell
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: