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

Locked resources are not always freed up on Pipeline hard kill when there are other pipelines waiting on the Resource

    Details

    • Similar Issues:

      Description

      Resource lock is not always released when there is some contention over it.

      This can, intermittently, be reproduced by running two builds of the below pipeline concurrently. Retry will simulate inability to cancel the build which should make hard kill link to appear. Canceling the builds in turn as they acquire the lock will sometimes produce the dangling lock.

      retry(5) {
        node('linux') {
          lock('my-resource') {
            println ("running find")
            sh "find / -name hello.txt"
          }
        }
      }
      

        Attachments

          Issue Links

            Activity

            Hide
            recampbell Ryan Campbell added a comment -

            Would be great to have a stack trace of this reproduction.

            Show
            recampbell Ryan Campbell added a comment - Would be great to have a stack trace of this reproduction.
            Hide
            jglick Jesse Glick added a comment -

            A sleeping build should periodically (say, every hour?) verify that what it thought it was waiting for is indeed still valid and holding the lock.

            Show
            jglick Jesse Glick added a comment - A sleeping build should periodically (say, every hour?) verify that what it thought it was waiting for is indeed still valid and holding the lock.
            Hide
            duemir Denys Digtiar added a comment -

            Ryan Campbell Not sure exactly what stack trace to supply. Bellow is the FlowInterruptedException stack trace from when I click on forcible termination link.

            ERROR: Execution failed
            org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun.doTerm(WorkflowRun.java:323)
            	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
            	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            	at java.lang.reflect.Method.invoke(Method.java:498)
            	at org.kohsuke.stapler.Function$InstanceFunction.invoke(Function.java:335)
            	at org.kohsuke.stapler.interceptor.RequirePOST$Processor.invoke(RequirePOST.java:52)
            	at org.kohsuke.stapler.PreInvokeInterceptedFunction.invoke(PreInvokeInterceptedFunction.java:26)
            	at org.kohsuke.stapler.Function.bindAndInvoke(Function.java:175)
            	at org.kohsuke.stapler.Function.bindAndInvokeAndServeResponse(Function.java:108)
            	at org.kohsuke.stapler.MetaClass$1.doDispatch(MetaClass.java:124)
            	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.MetaClass$10.dispatch(MetaClass.java:362)
            	at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746)
            	at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876)
            	at org.kohsuke.stapler.MetaClass$5.doDispatch(MetaClass.java:236)
            	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)
            	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:80)
            	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)
            

            In terms of LockableResource, I have observed both build property still set to aborted Build and a build up of CpsStepContext in the queuedContexts. Unfotunatelly, I have not found a stable way to reproduce either.

            Show
            duemir Denys Digtiar added a comment - Ryan Campbell Not sure exactly what stack trace to supply. Bellow is the FlowInterruptedException stack trace from when I click on forcible termination link. ERROR: Execution failed org.jenkinsci.plugins.workflow.steps.FlowInterruptedException at org.jenkinsci.plugins.workflow.job.WorkflowRun.doTerm(WorkflowRun.java:323) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.kohsuke.stapler.Function$InstanceFunction.invoke(Function.java:335) at org.kohsuke.stapler.interceptor.RequirePOST$Processor.invoke(RequirePOST.java:52) at org.kohsuke.stapler.PreInvokeInterceptedFunction.invoke(PreInvokeInterceptedFunction.java:26) at org.kohsuke.stapler.Function.bindAndInvoke(Function.java:175) at org.kohsuke.stapler.Function.bindAndInvokeAndServeResponse(Function.java:108) at org.kohsuke.stapler.MetaClass$1.doDispatch(MetaClass.java:124) 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.MetaClass$10.dispatch(MetaClass.java:362) at org.kohsuke.stapler.Stapler.tryInvoke(Stapler.java:746) at org.kohsuke.stapler.Stapler.invoke(Stapler.java:876) at org.kohsuke.stapler.MetaClass$5.doDispatch(MetaClass.java:236) 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) 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:80) 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) In terms of LockableResource , I have observed both build property still set to aborted Build and a build up of CpsStepContext in the queuedContexts . Unfotunatelly, I have not found a stable way to reproduce either.
            Hide
            amuniz Antonio Muñiz added a comment -

            Reproduced locally. The problem is that LockableResourcesManager is supposing a queued context will always have a valid linked build (waiting for the lock), but that turns to be false under some circumstances (like the one described in this issue: a hard killed job which for some other reason does not call LockRunListener.onComplete - something to be investigated separately, as it can happen if Jenkins is stopped abruptly so there is no chance to call anything, thus a fix here is needed at any rate).

            This is the stack trace (where #20 is a hard killed job while it was holding a lock):

            java.io.IOException: test #20 did not yet start
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun$Owner.get(WorkflowRun.java:724)
            	at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getFlowExecution(CpsStepContext.java:432)
            	at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getThreadGroupSynchronously(CpsStepContext.java:239)
            	at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getThreadSynchronously(CpsStepContext.java:233)
            	at org.jenkinsci.plugins.workflow.cps.CpsStepContext.doGet(CpsStepContext.java:285)
            	at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:71)
            	at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlockNames(LockableResourcesManager.java:332)
            	at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlockNames(LockableResourcesManager.java:338)
            	at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlock(LockableResourcesManager.java:285)
            	at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlock(LockableResourcesManager.java:273)
            	at org.jenkins.plugins.lockableresources.actions.LockableResourcesRootAction.doUnlock(LockableResourcesRootAction.java:103)
            
            Show
            amuniz Antonio Muñiz added a comment - Reproduced locally. The problem is that LockableResourcesManager is supposing a queued context will always have a valid linked build (waiting for the lock), but that turns to be false under some circumstances (like the one described in this issue: a hard killed job which for some other reason does not call LockRunListener.onComplete - something to be investigated separately, as it can happen if Jenkins is stopped abruptly so there is no chance to call anything, thus a fix here is needed at any rate). This is the stack trace (where #20 is a hard killed job while it was holding a lock): java.io.IOException: test #20 did not yet start at org.jenkinsci.plugins.workflow.job.WorkflowRun$Owner.get(WorkflowRun.java:724) at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getFlowExecution(CpsStepContext.java:432) at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getThreadGroupSynchronously(CpsStepContext.java:239) at org.jenkinsci.plugins.workflow.cps.CpsStepContext.getThreadSynchronously(CpsStepContext.java:233) at org.jenkinsci.plugins.workflow.cps.CpsStepContext.doGet(CpsStepContext.java:285) at org.jenkinsci.plugins.workflow.support.DefaultStepContext.get(DefaultStepContext.java:71) at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlockNames(LockableResourcesManager.java:332) at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlockNames(LockableResourcesManager.java:338) at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlock(LockableResourcesManager.java:285) at org.jenkins.plugins.lockableresources.LockableResourcesManager.unlock(LockableResourcesManager.java:273) at org.jenkins.plugins.lockableresources.actions.LockableResourcesRootAction.doUnlock(LockableResourcesRootAction.java:103)
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Andrew Bayer
            Path:
            src/test/java/org/jenkins/plugins/lockableresources/LockStepTest.java
            http://jenkins-ci.org/commit/lockable-resources-plugin/4d396d8acb03788f5424d93c9e214ef86c8c074c
            Log:
            JENKINS-40368 Test that reproduces the hard kill bug.

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Andrew Bayer Path: src/test/java/org/jenkins/plugins/lockableresources/LockStepTest.java http://jenkins-ci.org/commit/lockable-resources-plugin/4d396d8acb03788f5424d93c9e214ef86c8c074c Log: JENKINS-40368 Test that reproduces the hard kill bug.
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Antonio Muniz
            Path:
            src/test/java/org/jenkins/plugins/lockableresources/LockStepTest.java
            http://jenkins-ci.org/commit/lockable-resources-plugin/c6f911316529d469d79be06d873453c6c6ee8ba7
            Log:
            Merge pull request #47 from abayer/jenkins-40368-test

            JENKINS-40368 Test that reproduces the hard kill bug.

            Compare: https://github.com/jenkinsci/lockable-resources-plugin/compare/3a8fb0e690f4...c6f911316529

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Antonio Muniz Path: src/test/java/org/jenkins/plugins/lockableresources/LockStepTest.java http://jenkins-ci.org/commit/lockable-resources-plugin/c6f911316529d469d79be06d873453c6c6ee8ba7 Log: Merge pull request #47 from abayer/jenkins-40368-test JENKINS-40368 Test that reproduces the hard kill bug. Compare: https://github.com/jenkinsci/lockable-resources-plugin/compare/3a8fb0e690f4...c6f911316529
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Antonio Muñiz
            Path:
            src/main/java/org/jenkins/plugins/lockableresources/LockableResourcesManager.java
            http://jenkins-ci.org/commit/lockable-resources-plugin/3218afc093278d0561f34000d51ca584930366fa
            Log:
            JENKINS-40368 Resources not locked after hard kill

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Antonio Muñiz Path: src/main/java/org/jenkins/plugins/lockableresources/LockableResourcesManager.java http://jenkins-ci.org/commit/lockable-resources-plugin/3218afc093278d0561f34000d51ca584930366fa Log: JENKINS-40368 Resources not locked after hard kill
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Antonio Muniz
            Path:
            src/main/java/org/jenkins/plugins/lockableresources/LockableResourcesManager.java
            http://jenkins-ci.org/commit/lockable-resources-plugin/95de850a15a6b125f27a26b8f8866a7d75fb909d
            Log:
            Merge pull request #46 from amuniz/JENKINS-40368

            JENKINS-40368 Resources not unlocked after a hard kill

            Compare: https://github.com/jenkinsci/lockable-resources-plugin/compare/c6f911316529...95de850a15a6

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Antonio Muniz Path: src/main/java/org/jenkins/plugins/lockableresources/LockableResourcesManager.java http://jenkins-ci.org/commit/lockable-resources-plugin/95de850a15a6b125f27a26b8f8866a7d75fb909d Log: Merge pull request #46 from amuniz/ JENKINS-40368 JENKINS-40368 Resources not unlocked after a hard kill Compare: https://github.com/jenkinsci/lockable-resources-plugin/compare/c6f911316529...95de850a15a6

              People

              • Assignee:
                amuniz Antonio Muñiz
                Reporter:
                duemir Denys Digtiar
              • Votes:
                3 Vote for this issue
                Watchers:
                10 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: