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

BranchIndexing deadlock with health check - Jenkins slowness

XMLWordPrintable

      Jenkins becomes very slow with the below message in the health-checker.log

      The branch indexing for My-Multi-Branch-SNAPSHOT succeeds without issues most of the time. But at times, it gets into a deadlock like below.

      Over time, jenkins completes hangs up and we end up restarting to restore the server.

      Requesting help in identifying the root cause of the issue and solution for the same.

      Jenkins version: 2.7.4

      Branch indexing log: It hangs forever

      Branch Indexing Log

      Started by timer > git rev-parse --is-inside-work-tree # timeout=10 Setting origin to ssh://git@mystash/myproject.git > git config remote.origin.url ssh://git@mystash/myproject.git # timeout=10 Fetching & pruning origin... Fetching upstream changes from origin > git --version # timeout=10 using GIT_SSH to set credentials credentails for GIT > git fetch --tags --progress origin +refs/heads/:refs/remotes/origin/ --prune Getting remote branches... Seen branch in repository origin/develop Seen branch in repository origin/master Seen branch in repository origin/release Seen 3 remote branches Checking branch master No changes detected in master (still at 7c4f090ce09229b6900258a79755a72eb16f5a1e) Checking branch develop

       

      health-checker.log

      Starting health checks at Fri Jan 25 04:48:02 PST 2019

      Health check results at Fri Jan 25 04:48:02 PST 2019:

       * disk-space: Result{isHealthy=true}

       * mesos: Result{isHealthy=true}

       * plugins: Result{isHealthy=true, message=No failed plugins}

       * temporary-space: Result{isHealthy=true}

       * thread-deadlock: Result{isHealthy=false, message=[Handling GET /job/ENF/ from 10.111.9.36 : RequestHandlerThread225 View/index.jelly LastSuccessColumn/column.jelly locked on hudson.model.RunMap@1e716e7e (owned by Executor #-1 for master : executing BranchIndexing[My-Multi-Branch-SNAPSHOT]):

               at jenkins.model.lazy.AbstractLazyLoadRunMap.getByNumber(AbstractLazyLoadRunMap.java:356)

               at jenkins.model.lazy.LazyBuildMixIn.getBuildByNumber(LazyBuildMixIn.java:233)

               at hudson.model.AbstractProject.getBuildByNumber(AbstractProject.java:978)

               at hudson.model.AbstractProject.getBuildByNumber(AbstractProject.java:144)

               at jenkins.model.PeepholePermalink.resolve(PeepholePermalink.java:95)

               at hudson.model.Job.getLastSuccessfulBuild(Job.java:909)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenMultiBranchProject.getLastSuccessfulBuild(TemplateDrivenMultiBranchProject.java:406)

               at sun.reflect.GeneratedMethodAccessor360.invoke(Unknown Source)

               at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

               at java.lang.reflect.Method.invoke(Method.java:497)

               at org.apache.commons.jexl.util.PropertyExecutor.execute(PropertyExecutor.java:125)

               at org.apache.commons.jexl.util.introspection.UberspectImpl$VelGetterImpl.invoke(UberspectImpl.java:314)

               at org.apache.commons.jexl.parser.ASTArrayAccess.evaluateExpr(ASTArrayAccess.java:185)

               at org.apache.commons.jexl.parser.ASTIdentifier.execute(ASTIdentifier.java:75)

               at org.apache.commons.jexl.parser.ASTReference.execute(ASTReference.java:83)

               at org.apache.commons.jexl.parser.ASTReference.value(ASTReference.java:57)

               at org.apache.commons.jexl.parser.ASTReferenceExpression.value(ASTReferenceExpression.java:51)

               at org.apache.commons.jexl.ExpressionImpl.evaluate(ExpressionImpl.java:80)

               at hudson.ExpressionFactory2$JexlExpression.evaluate(ExpressionFactory2.java:74)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$3.run(CoreTagLibrary.java:134)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)

               at org.kohsuke.stapler.jelly.JellyViewScript.run(JellyViewScript.java:95)

               at org.kohsuke.stapler.jelly.IncludeTag.doTag(IncludeTag.java:147)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)

               at org.apache.commons.jelly.tags.core.ForEachTag.doTag(ForEachTag.java:150)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)

               at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161)

               at org.apache.commons.jelly.tags.core.ForEachTag.doTag(ForEachTag.java:150)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$1.run(CoreTagLibrary.java:98)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)

               at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120)

               at org.kohsuke.stapler.jelly.groovy.JellyBuilder.doInvokeMethod(JellyBuilder.java:276)

               at org.kohsuke.stapler.jelly.groovy.Namespace$ProxyImpl.invoke(Namespace.java:92)

               at com.sun.proxy.$Proxy85.projectView(Unknown Source)

               at lib.JenkinsTagLib$projectView$1.call(Unknown Source)

               at hudson.model.View.main.run(main.groovy:14)

               at org.kohsuke.stapler.jelly.groovy.GroovierJellyScript.run(GroovierJellyScript.java:74)

               at org.kohsuke.stapler.jelly.groovy.GroovierJellyScript.run(GroovierJellyScript.java:62)

               at org.kohsuke.stapler.jelly.IncludeTag.doTag(IncludeTag.java:147)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.CallTagLibScript$1.run(CallTagLibScript.java:99)

               at org.apache.commons.jelly.tags.define.InvokeBodyTag.doTag(InvokeBodyTag.java:91)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$1.run(CoreTagLibrary.java:98)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)

               at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.CallTagLibScript$1.run(CallTagLibScript.java:99)

               at org.apache.commons.jelly.tags.define.InvokeBodyTag.doTag(InvokeBodyTag.java:91)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)

               at org.apache.commons.jelly.impl.ScriptBlock.run(ScriptBlock.java:95)

               at org.apache.commons.jelly.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105)

               at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120)

               at org.kohsuke.stapler.jelly.CompressTag.doTag(CompressTag.java:44)

               at org.apache.commons.jelly.impl.TagScript.run(TagScript.java:269)

               at org.kohsuke.stapler.jelly.JellyViewScript.run(JellyViewScript.java:95)

               at org.kohsuke.stapler.jelly.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:63)

               at org.kohsuke.stapler.jelly.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:53)

               at org.kohsuke.stapler.jelly.JellyClassTearOff.serveIndexJelly(JellyClassTearOff.java:112)

               at org.kohsuke.stapler.jelly.JellyFacet.handleIndexRequest(JellyFacet.java:127)

               at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:735)

               at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)

               at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:813)

               at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)

               at org.kohsuke.stapler.MetaClass$5.doDispatch(MetaClass.java:233)

               at org.kohsuke.stapler.NameBasedDispatcher.dispatch(NameBasedDispatcher.java:58)

               at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746)

               at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)

               at org.kohsuke.stapler.Stapler.invoke(Stapler.java:649)

               at org.kohsuke.stapler.Stapler.service(Stapler.java:238)

               at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

               at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)

               at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)

               at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:135)

      , Executor #-1 for master : executing BranchIndexing[My-Multi-Branch-SNAPSHOT] locked on hudson.maven.MavenModuleSet@5f2aa04b (owned by pool-13-thread-1):

               at hudson.model.AbstractProject.save(AbstractProject.java:305)

               at hudson.model.Job.addProperty(Job.java:516)

               at hudson.model.AbstractProject.addProperty(AbstractProject.java:785)

               at hudson.plugins.disk_usage.DiskUsageUtil.addProperty(DiskUsageUtil.java:58)

               at hudson.plugins.disk_usage.BuildDiskUsageAction.<init>(BuildDiskUsageAction.java:38)

               at hudson.plugins.disk_usage.DiskUsageBuildActionFactory.createFor(DiskUsageBuildActionFactory.java:31)

               at hudson.plugins.disk_usage.DiskUsageBuildActionFactory.createFor(DiskUsageBuildActionFactory.java:21)

               at hudson.model.Actionable.createFor(Actionable.java:107)

               at hudson.model.Actionable.getAllActions(Actionable.java:98)

               at hudson.model.Run.onLoad(Run.java:346)

               at hudson.maven.MavenModuleSetBuild.onLoad(MavenModuleSetBuild.java:155)

               at hudson.model.RunMap.retrieve(RunMap.java:224)

               at hudson.model.RunMap.retrieve(RunMap.java:56)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:487)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:469)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.getByNumber(AbstractLazyLoadRunMap.java:367)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.search(AbstractLazyLoadRunMap.java:332)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.newestBuild(AbstractLazyLoadRunMap.java:274)

               at jenkins.model.lazy.LazyBuildMixIn.getLastBuild(LazyBuildMixIn.java:247)

               at hudson.model.AbstractProject.getLastBuild(AbstractProject.java:993)

               at hudson.maven.AbstractMavenProject.createTransientActions(AbstractMavenProject.java:227)

               at hudson.maven.MavenModuleSet.createTransientActions(MavenModuleSet.java:472)

               at hudson.model.AbstractProject.updateTransientActions(AbstractProject.java:755)

               at hudson.maven.MavenModuleSet.updateTransientActions(MavenModuleSet.java:468)

               at hudson.model.AbstractProject.onLoad(AbstractProject.java:339)

               at hudson.maven.MavenModuleSet.onLoad(MavenModuleSet.java:806)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenBranchProjectFactory$1.call(TemplateDrivenBranchProjectFactory.java:200)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenBranchProjectFactory$1.call(TemplateDrivenBranchProjectFactory.java:196)

               at hudson.model.Items.whileUpdatingByXml(Items.java:96)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenBranchProjectFactory.updateByXml(TemplateDrivenBranchProjectFactory.java:196)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenBranchProjectFactory.decorate(TemplateDrivenBranchProjectFactory.java:140)

               at com.github.mjdetullio.jenkins.plugins.multibranch.TemplateDrivenBranchProjectFactory.decorate(TemplateDrivenBranchProjectFactory.java:57)

               at jenkins.branch.MultiBranchProject$1.observe(MultiBranchProject.java:307)

               at jenkins.plugins.git.AbstractGitSCMSource$2.run(AbstractGitSCMSource.java:281)

               at jenkins.plugins.git.AbstractGitSCMSource$2.run(AbstractGitSCMSource.java:233)

               at jenkins.plugins.git.AbstractGitSCMSource.doRetrieve(AbstractGitSCMSource.java:204)

               at jenkins.plugins.git.AbstractGitSCMSource.retrieve(AbstractGitSCMSource.java:233)

               at jenkins.scm.api.SCMSource.fetch(SCMSource.java:148)

               at jenkins.branch.MultiBranchProject.computeChildren(MultiBranchProject.java:294)

               at com.cloudbees.hudson.plugins.folder.computed.ComputedFolder.updateChildren(ComputedFolder.java:187)

               at com.cloudbees.hudson.plugins.folder.computed.FolderComputation.run(FolderComputation.java:137)

               at hudson.model.ResourceController.execute(ResourceController.java:98)

               at hudson.model.Executor.run(Executor.java:410)

      , pool-13-thread-1 locked on hudson.model.RunMap@1e716e7e (owned by Executor #-1 for master : executing BranchIndexing[My-Multi-Branch-SNAPSHOT]):

               at jenkins.model.lazy.AbstractLazyLoadRunMap.getByNumber(AbstractLazyLoadRunMap.java:356)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.search(AbstractLazyLoadRunMap.java:332)

               at jenkins.model.lazy.AbstractLazyLoadRunMap.newestBuild(AbstractLazyLoadRunMap.java:274)

               at jenkins.model.lazy.LazyBuildMixIn.getLastBuild(LazyBuildMixIn.java:247)

               at hudson.model.AbstractProject.getLastBuild(AbstractProject.java:993)

               at hudson.maven.AbstractMavenProject.createTransientActions(AbstractMavenProject.java:227)

               at hudson.maven.MavenModuleSet.createTransientActions(MavenModuleSet.java:472)

               at hudson.model.AbstractProject.updateTransientActions(AbstractProject.java:755)

               at hudson.maven.MavenModuleSet.updateTransientActions(MavenModuleSet.java:468)

               at hudson.model.AbstractProject.save(AbstractProject.java:306)

               at hudson.model.Job.addProperty(Job.java:516)

               at hudson.model.AbstractProject.addProperty(AbstractProject.java:785)

               at com.sonyericsson.hudson.plugins.metadata.contributors.JobContributorsController$SaveableOperation.getOrCreateProperty(JobContributorsController.java:233)

               at com.sonyericsson.hudson.plugins.metadata.contributors.JobContributorsController$SaveableOperation.run(JobContributorsController.java:156)

               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:1142)

               at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

               at java.lang.Thread.run(Thread.java:745)

      threadDump is also attached

            Unassigned Unassigned
            radhika_kv Radhika KV
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated: