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

Pipeline extremely slow when triggered by a user in comparison with the time triggered pipeline

    Details

    • Similar Issues:

      Description

      I recently setup a new Jenkins server on Linux. I am facing issues with the pipeline execution time. The pipeline script takes much longer to execute when triggered by a user. On the contrary, it is quite fast when built periodically by a time trigger (This is also the expected behavior). This is causing a huge overhead for complicated pipelines we are using in our project. See the following example pipeline I created for demo (see the attached image for the results):

      pipeline {
          agent {label "${NODE_LABEL}"}
          stages {
              stage('One'){
                  steps {
                      echo 'First stage...'
                  }
              }
              stage('Two'){
                  steps {
                      echo 'Second stage...'
                  }
              }
              stage('Three'){
                  steps {
                      echo 'Third stage...'
                  }
              }
              stage('Four'){
                  steps {
                      echo 'Fourth stage...'
                  }
              }
              stage('Five'){
                  steps {
                      echo 'Fifth stage...'
                  }
              }
          }
      }
      

       After looking into the jenkins.log file, the difference I see between the two runs is that at every stage execution in the slower build (executed by the user) there is warning due to an exception in CpsFlowExecution as below:

      2019-11-08 16:21:31.222+0000 [id=48479] INFO hudson.model.AsyncPeriodicWork$1#run: Started Download metadata2019-11-08 16:21:31.222+0000 [id=48479] INFO hudson.model.AsyncPeriodicWork$1#run: Started Download metadata2019-11-08 16:21:32.036+0000 [id=48479] INFO h.m.DownloadService$Downloadable#load: Obtained the updated data file for hudson.tasks.Maven.MavenInstaller2019-11-08 16:21:32.412+0000 [id=48479] INFO h.m.DownloadService$Downloadable#load: Obtained the updated data file for hudson.plugins.gradle.GradleInstaller2019-11-08 16:21:32.686+0000 [id=48479] INFO h.m.DownloadService$Downloadable#load: Obtained the updated data file for hudson.tasks.Ant.AntInstaller2019-11-08 16:21:33.805+0000 [id=48479] INFO h.m.DownloadService$Downloadable#load: Obtained the updated data file for hudson.tools.JDKInstaller2019-11-08 16:21:33.805+0000 [id=48479] INFO hudson.model.AsyncPeriodicWork$1#run: Finished Download metadata. 2,583 ms2019-11-08 16:21:35.616+0000 [id=22366] WARNING o.j.p.w.cps.CpsFlowExecution#blocksRestart: Not blocking restart due to problem checking running steps in CpsFlowExecution[Owner[test_pipeline_general/2:test_pipeline_general #2]]java.util.concurrent.TimeoutException: Timeout waiting for task. at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:259) at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:91) at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.blocksRestart(CpsFlowExecution.java:940) at org.jenkinsci.plugins.workflow.job.WorkflowRun$2.blocksRestart(WorkflowRun.java:377) at org.jenkinsci.plugins.workflow.job.WorkflowRun$2.displayCell(WorkflowRun.java:380) at hudson.model.Executor.isDisplayCell(Executor.java:668) at hudson.model.Computer.getDisplayExecutors(Computer.java:1009) at sun.reflect.GeneratedMethodAccessor194.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) 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.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.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.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99) at org.apache.commons.jelly.TagSupport.invokeBody(TagSupport.java:161) at org.apache.commons.jelly.tags.core.OtherwiseTag.doTag(OtherwiseTag.java:41) 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.TagSupport.invokeBody(TagSupport.java:161) at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38) 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.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.tags.core.CoreTagLibrary$2.run(CoreTagLibrary.java:105) at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120) 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.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$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.OtherwiseTag.doTag(OtherwiseTag.java:41) 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.TagSupport.invokeBody(TagSupport.java:161) at org.apache.commons.jelly.tags.core.ChooseTag.doTag(ChooseTag.java:38) 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$2.run(CoreTagLibrary.java:105) at org.kohsuke.stapler.jelly.CallTagLibScript.run(CallTagLibScript.java:120) 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.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:63) at org.kohsuke.stapler.jelly.DefaultScriptInvoker.invokeScript(DefaultScriptInvoker.java:53) at org.kohsuke.stapler.jelly.ScriptInvoker.execute(ScriptInvoker.java:56) at org.kohsuke.stapler.jelly.ScriptInvoker.execute(ScriptInvoker.java:43) at org.kohsuke.stapler.Facet$1.dispatch(Facet.java:238) at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:747) at org.kohsuke.stapler.Stapler.invoke(Stapler.java:878) at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:815) at org.kohsuke.stapler.Stapler.invoke(Stapler.java:878) at org.kohsuke.stapler.Stapler.invoke(Stapler.java:676) 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:873) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:154) at org.jenkinsci.plugins.ssegateway.Endpoint$SSEListenChannelFilter.doFilter(Endpoint.java:246) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at io.jenkins.blueocean.ResourceCacheControl.doFilter(ResourceCacheControl.java:134) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at io.jenkins.blueocean.auth.jwt.impl.JwtAuthenticationFilter.doFilter(JwtAuthenticationFilter.java:61) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at com.smartcodeltd.jenkinsci.plugin.assetbundler.filters.LessCSS.doFilter(LessCSS.java:47) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:239) at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:215) at net.bull.javamelody.PluginMonitoringFilter.doFilter(PluginMonitoringFilter.java:88) at org.jvnet.hudson.plugins.monitoring.HudsonMonitoringFilter.doFilter(HudsonMonitoringFilter.java:114) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at org.jenkinsci.plugins.modernstatus.ModernStatusFilter.doFilter(ModernStatusFilter.java:52) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at jenkins.metrics.impl.MetricsFilter.doFilter(MetricsFilter.java:125) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at hudson.plugins.locale.LocaleFilter.doFilter(LocaleFilter.java:42) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at jenkins.telemetry.impl.UserLanguages$AcceptLanguageFilter.doFilter(UserLanguages.java:128) at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:151) at hudson.util.PluginServletFilter.doFilter(PluginServletFilter.java:157) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at hudson.security.csrf.CrumbFilter.doFilter(CrumbFilter.java:99) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:84) at hudson.security.UnwrapSecurityExceptionFilter.doFilter(UnwrapSecurityExceptionFilter.java:51) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at jenkins.security.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:117) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at org.acegisecurity.ui.rememberme.RememberMeProcessingFilter.doFilter(RememberMeProcessingFilter.java:142) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:271) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at jenkins.security.BasicHeaderProcessor.doFilter(BasicHeaderProcessor.java:93) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:249) at hudson.security.HttpSessionContextIntegrationFilter2.doFilter(HttpSessionContextIntegrationFilter2.java:67) at hudson.security.ChainedServletFilter$1.doFilter(ChainedServletFilter.java:87) at hudson.security.ChainedServletFilter.doFilter(ChainedServletFilter.java:90) at hudson.security.HudsonFilter.doFilter(HudsonFilter.java:171) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at org.kohsuke.stapler.compression.CompressionFilter.doFilter(CompressionFilter.java:49) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at hudson.util.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:82) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at org.kohsuke.stapler.DiagnosticThreadNameFilter.doFilter(DiagnosticThreadNameFilter.java:30) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1700) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1667) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) at org.eclipse.jetty.server.Server.handle(Server.java:505) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:427) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:321) at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:159) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:698) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:804) at java.lang.Thread.run(Thread.java:748)
      

        Attachments

          Issue Links

            Activity

            Show
            allan_burdajewicz Allan BURDAJEWICZ added a comment - I wonder, could the impersonation at https://github.com/jenkinsci/jenkins/blob/jenkins-2.204.2/core/src/main/java/hudson/model/User.java#L388 leverage the https://github.com/jenkinsci/jenkins/blob/jenkins-2.204.2/core/src/main/java/jenkins/security/UserDetailsCache.java ?
            Hide
            seancdugan Sean Dugan added a comment -

            Thank you Jon Denly. This has saved us a lot of headaches!!

            Show
            seancdugan Sean Dugan added a comment - Thank you Jon Denly . This has saved us a lot of headaches!!
            Hide
            jondenly Jon Denly added a comment -

            For anyone else that comes across this ticket, the following change to the security caching (under Configure Global Security) resolved this performance issue for us.

             

            Before the caching was turned on, we saw many threads waiting for LDAP requests, afterwards there were none and Jenkins performance was significantly improved.

            "Computer.threadPoolForRemoting [#9537]" Id=2072540 Group=main TIMED_WAITING on com.sun.jndi.ldap.LdapRequest@7ca9d12a
             at java.lang.Object.wait(Native Method)
             - waiting on com.sun.jndi.ldap.LdapRequest@7ca9d12a
             at com.sun.jndi.ldap.Connection.readReply(Connection.java:484)
             at com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:632)
             at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:555)
             at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1985)
             at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1844)
             at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1769)
             at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1786)
             at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:418)
             at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:396)
             at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:378)
             at hudson.plugins.active_directory.LDAPSearchBuilder.search(LDAPSearchBuilder.java:120)
             at hudson.plugins.active_directory.ActiveDirectoryUnixAuthenticationProvider.resolveGroups(ActiveDirectoryUnixAuthenticationProvider.java:667)
            Show
            jondenly Jon Denly added a comment - For anyone else that comes across this ticket, the following change to the security caching (under Configure Global Security) resolved this performance issue for us.   Before the caching was turned on, we saw many threads waiting for LDAP requests, afterwards there were none and Jenkins performance was significantly improved. "Computer.threadPoolForRemoting [#9537]" Id=2072540 Group=main TIMED_WAITING on com.sun.jndi.ldap.LdapRequest@7ca9d12a at java.lang.Object.wait(Native Method) - waiting on com.sun.jndi.ldap.LdapRequest@7ca9d12a at com.sun.jndi.ldap.Connection.readReply(Connection.java:484) at com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:632) at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:555) at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1985) at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1844) at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1769) at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1786) at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:418) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:396) at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:378) at hudson.plugins.active_directory.LDAPSearchBuilder.search(LDAPSearchBuilder.java:120) at hudson.plugins.active_directory.ActiveDirectoryUnixAuthenticationProvider.resolveGroups(ActiveDirectoryUnixAuthenticationProvider.java:667)
            Hide
            saad_azam Saad Azam added a comment -

            Devin Nusbaum Thanks for your hypothesis and suggestion. The warning has indeed disappeared after we stopped using Authorize Project Plugin. I will follow your suggestion If I run into the issue again.

            Show
            saad_azam Saad Azam added a comment - Devin Nusbaum Thanks for your hypothesis and suggestion. The warning has indeed disappeared after we stopped using Authorize Project Plugin. I will follow your suggestion If I run into the issue again.
            Hide
            dnusbaum Devin Nusbaum added a comment -

            Thanks for the report!

            My guess for the reason for the slowdown is that when you ran builds triggered by users as the triggering user using Authorize Project Plugin, permission checks during the course of the build had to interact with your security realm and authorization strategy to figure out what permissions the user had based on your configuration. Builds that are triggered automatically run as the Jenkins SYSTEM user, which always has all permissions, and so permission checks are very quick.

            Maybe you could configure more aggressive caching or optimize your LDAP settings or something to improve the performance, depends on how things are configured in your instance. You could take thread dumps while the Pipeline is running slowly and see where threads are usually blocked to confirm/deny my hypothesis.

            I'm not sure about the warning. Perhaps the slowdown is significant enough to cause the relevant code to time out. If you aren't seeing it once you remove Authorize Project Plugin, I think you can safely ignore it.

            I'm going to close this issue, if you get thread dumps and think there is a bug somewhere based on that data, feel free to reopen it.

            Show
            dnusbaum Devin Nusbaum added a comment - Thanks for the report! My guess for the reason for the slowdown is that when you ran builds triggered by users as the triggering user using Authorize Project Plugin, permission checks during the course of the build had to interact with your security realm and authorization strategy to figure out what permissions the user had based on your configuration. Builds that are triggered automatically run as the Jenkins SYSTEM user, which always has all permissions, and so permission checks are very quick. Maybe you could configure more aggressive caching or optimize your LDAP settings or something to improve the performance, depends on how things are configured in your instance. You could take thread dumps while the Pipeline is running slowly and see where threads are usually blocked to confirm/deny my hypothesis. I'm not sure about the warning. Perhaps the slowdown is significant enough to cause the relevant code to time out. If you aren't seeing it once you remove Authorize Project Plugin, I think you can safely ignore it. I'm going to close this issue, if you get thread dumps and think there is a bug somewhere based on that data, feel free to reopen it.
            Hide
            saad_azam Saad Azam added a comment -

            The issue was found to be connected to the "Authorize Project plugin" when using authorization mode "Run as the user who triggered the build". However, we already switched to Role-Based authorization. So after removing the plugin the issue is resolved. But it would be nice to understand the warning occurring in the log I provided and to get insight into the root cause of the behavior.

            Show
            saad_azam Saad Azam added a comment - The issue was found to be connected to the "Authorize Project plugin" when using authorization mode "Run as the user who triggered the build". However, we already switched to Role-Based authorization. So after removing the plugin the issue is resolved. But it would be nice to understand the warning occurring in the log I provided and to get insight into the root cause of the behavior.

              People

              • Assignee:
                Unassigned
                Reporter:
                saad_azam Saad Azam
              • Votes:
                2 Vote for this issue
                Watchers:
                6 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: