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

Deadlock between hudson.model.RunMap and java.util.logging.StreamHandler

    Details

    • Similar Issues:

      Description

      The following deadlock was caught on a support bundle

      ==============
      Deadlock Found
      ==============
      "Handling POST /ajaxExecutors from 127.0.0.1 : RequestHandlerThread[#29] - /ajaxExecutors View/ajaxExecutors.jelly ExecutorStepExecution/PlaceholderTask/PlaceholderExecutable/executorCell.jelly" id=532 (0x214) state=BLOCKED cpu=99%
          - waiting to lock <0x49f5a4fd> (a java.util.logging.StreamHandler)
            owned by "Executor #0 for Test_Slave : executing PlaceholderExecutable::null" id=101 (0x65)
          at java.util.logging.StreamHandler.publish(StreamHandler.java:206)
          at com.cloudbees.jenkins.support.impl.JenkinsLogs$LogFile.publish(JenkinsLogs.java:213)
          at com.cloudbees.jenkins.support.impl.JenkinsLogs$CustomHandler.publish(JenkinsLogs.java:252)
          at java.util.logging.Logger.log(Logger.java:738)
          at java.util.logging.Logger.doLog(Logger.java:765)
          at java.util.logging.Logger.log(Logger.java:788)
          at org.eclipse.jetty.util.log.JavaUtilLog.debug(JavaUtilLog.java:111)
          at org.eclipse.jetty.security.authentication.FormAuthenticator.validateRequest(FormAuthenticator.java:378)
          at org.eclipse.jetty.security.authentication.DeferredAuthentication.authenticate(DeferredAuthentication.java:68)
          at org.eclipse.jetty.server.Request.getUserPrincipal(Request.java:1479)
          at org.eclipse.jetty.server.Request.getRemoteUser(Request.java:1087)
          at net.bull.javamelody.CounterError.<init>(CounterError.java:79)
          at net.bull.javamelody.Counter.addRequestForSystemError(Counter.java:553)
          at net.bull.javamelody.LoggingHandler.addErrorLogToCounter(LoggingHandler.java:77)
          at net.bull.javamelody.LoggingHandler.addErrorLogToCounter(LoggingHandler.java:72)
          at net.bull.javamelody.LoggingHandler.publish(LoggingHandler.java:113)
          at java.util.logging.Logger.log(Logger.java:738)
          at java.util.logging.Logger.doLog(Logger.java:765)
          at java.util.logging.Logger.log(Logger.java:875)
          at hudson.model.RunMap.retrieve(RunMap.java:234)
          at hudson.model.RunMap.retrieve(RunMap.java:56)
          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)
          at jenkins.model.lazy.LazyBuildMixIn.getBuildByNumber(LazyBuildMixIn.java:231)
          at org.jenkinsci.plugins.workflow.job.WorkflowJob.getBuildByNumber(WorkflowJob.java:228)
          at org.jenkinsci.plugins.workflow.job.WorkflowJob.getBuildByNumber(WorkflowJob.java:106)
          at hudson.model.Run.fromExternalizableId(Run.java:2290)
          at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution$PlaceholderTask.runForDisplay(ExecutorStepExecution.java:375)
          at sun.reflect.GeneratedMethodAccessor250.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.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:258)
          at org.apache.commons.jexl.parser.ASTMethod.execute(ASTMethod.java:104)
          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.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$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.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.kohsuke.stapler.jelly.ReallyStaticTagLibrary$1.run(ReallyStaticTagLibrary.java:99)
          at org.apache.commons.jelly.tags.core.CoreTagLibrary$1.run(CoreTagLibrary.java:98)
          at org.apache.commons.jelly.impl.DynamicTag.doTag(DynamicTag.java:81)
          at org.apache.commons.jelly.impl.StaticTagScript.run(StaticTagScript.java:124)
          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.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.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.JellyFacet$1.dispatch(JellyFacet.java:95)
          at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746)
          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.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 com.cloudbees.jenkins.ha.HAHealthCheckFilter.doFilter(HAHealthCheckFilter.java:35)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:135)
          at com.cloudbees.jenkins.support.slowrequest.SlowRequestFilter.doFilter(SlowRequestFilter.java:37)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at com.cloudbees.opscenter.client.plugin.OfflineSecurityRealmFilter._doFilter(OfflineSecurityRealmFilter.java:90)
          at com.cloudbees.opscenter.client.plugin.OfflineSecurityRealmFilter.doFilter(OfflineSecurityRealmFilter.java:67)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at com.cloudbees.opscenter.security.ClusterSessionFilter._doFilter(ClusterSessionFilter.java:69)
          at com.cloudbees.opscenter.security.ClusterSessionFilter.doFilter(ClusterSessionFilter.java:44)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at hudson.security.UnwrapSecurityExceptionFilter.doFilter(UnwrapSecurityExceptionFilter.java:51)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at org.jenkinsci.plugins.suppress_stack_trace.SuppressionFilter.doFilter(SuppressionFilter.java:34)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:201)
          at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:178)
          at net.bull.javamelody.PluginMonitoringFilter.doFilter(PluginMonitoringFilter.java:85)
          at org.jvnet.hudson.plugins.monitoring.HudsonMonitoringFilter.doFilter(HudsonMonitoringFilter.java:104)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at hudson.plugins.greenballs.GreenBallFilter.doFilter(GreenBallFilter.java:59)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at jenkins.metrics.impl.MetricsFilter.doFilter(MetricsFilter.java:125)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at hudson.plugins.audit_trail.AuditTrailFilter.doFilter(AuditTrailFilter.java:95)
          at hudson.util.PluginServletFilter$1.doFilter(PluginServletFilter.java:132)
          at hudson.util.PluginServletFilter.doFilter(PluginServletFilter.java:126)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at hudson.security.csrf.CrumbFilter.doFilter(CrumbFilter.java:49)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          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:76)
          at hudson.security.HudsonFilter.doFilter(HudsonFilter.java:171)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at org.kohsuke.stapler.compression.CompressionFilter.doFilter(CompressionFilter.java:49)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at hudson.util.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:82)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at org.kohsuke.stapler.DiagnosticThreadNameFilter.doFilter(DiagnosticThreadNameFilter.java:30)
          at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
          at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
          at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:553)
          at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
          at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
          at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
          at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
          at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
          at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
          at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
          at org.eclipse.jetty.server.Server.handle(Server.java:499)
          at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)
          at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
          at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)
          at winstone.BoundedExecutorService$1.run(BoundedExecutorService.java:77)
          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)
      
      "Executor #0 for Test_Slave : executing PlaceholderExecutable::null" id=101 (0x65) state=BLOCKED cpu=98%
          - waiting to lock <0x4829e185> (a hudson.model.RunMap)
            owned by "Handling POST /ajaxExecutors from 127.0.0.1 : RequestHandlerThread[#29] - /ajaxExecutors View/ajaxExecutors.jelly ExecutorStepExecution/PlaceholderTask/PlaceholderExecutable/executorCell.jelly" id=532 (0x214)
          at jenkins.model.lazy.AbstractLazyLoadRunMap.getByNumber(AbstractLazyLoadRunMap.java:369)
          at jenkins.model.lazy.LazyBuildMixIn.getBuildByNumber(LazyBuildMixIn.java:231)
          at org.jenkinsci.plugins.workflow.job.WorkflowJob.getBuildByNumber(WorkflowJob.java:228)
          at org.jenkinsci.plugins.workflow.job.WorkflowJob.getBuildByNumber(WorkflowJob.java:106)
          at hudson.model.Run.fromExternalizableId(Run.java:2290)
          at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution$PlaceholderTask.runForDisplay(ExecutorStepExecution.java:375)
          at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution$PlaceholderTask.getUrl(ExecutorStepExecution.java:382)
          at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable.getUrl(ExecutorStepExecution.java:610)
          at org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution$PlaceholderTask$PlaceholderExecutable.toString(ExecutorStepExecution.java:614)
          at java.text.MessageFormat.subformat(MessageFormat.java:1280)
          at java.text.MessageFormat.format(MessageFormat.java:865)
          at java.text.Format.format(Format.java:157)
          at java.text.MessageFormat.format(MessageFormat.java:841)
          at java.util.logging.Formatter.formatMessage(Formatter.java:138)
          at com.cloudbees.jenkins.support.SupportLogFormatter.format(SupportLogFormatter.java:89)
          at java.util.logging.StreamHandler.publish(StreamHandler.java:211)
          at com.cloudbees.jenkins.support.impl.JenkinsLogs$LogFile.publish(JenkinsLogs.java:213)
          at com.cloudbees.jenkins.support.impl.JenkinsLogs$CustomHandler.publish(JenkinsLogs.java:252)
          at java.util.logging.Logger.log(Logger.java:738)
          at java.util.logging.Logger.doLog(Logger.java:765)
          at java.util.logging.Logger.log(Logger.java:850)
          at hudson.model.Executor.finish1(Executor.java:448)
          at hudson.model.Executor.run(Executor.java:424)
      

        Attachments

          Issue Links

            Activity

            fbelzunc Félix Belzunce Arcos created issue -
            jglick Jesse Glick made changes -
            Field Original Value New Value
            Priority Minor [ 4 ] Critical [ 2 ]
            jglick Jesse Glick made changes -
            Component/s workflow-durable-task-step-plugin [ 21715 ]
            Component/s workflow-step-api-plugin [ 21718 ]
            jglick Jesse Glick made changes -
            Labels support-core deadlock support-core
            jglick Jesse Glick made changes -
            Assignee Jesse Glick [ jglick ]
            jglick Jesse Glick made changes -
            Status Open [ 1 ] In Progress [ 3 ]
            jglick Jesse Glick made changes -
            Remote Link This issue links to "PR 25 (Web Link)" [ 15244 ]
            jglick Jesse Glick made changes -
            Status In Progress [ 3 ] In Review [ 10005 ]
            jglick Jesse Glick made changes -
            Status In Review [ 10005 ] Resolved [ 5 ]
            Resolution Fixed [ 1 ]
            Hide
            recampbell Ryan Campbell added a comment -

            Released in workflow-durable-task-step-2.8

            Show
            recampbell Ryan Campbell added a comment - Released in workflow-durable-task-step-2.8
            cloudbees CloudBees Inc. made changes -
            Remote Link This issue links to "CloudBees Internal OSS-1835 (Web Link)" [ 18544 ]

              People

              • Assignee:
                jglick Jesse Glick
                Reporter:
                fbelzunc Félix Belzunce Arcos
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: