Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Incomplete
    • Component/s: build-timeout-plugin
    • Labels:
      None
    • Environment:
      Ubuntu 11.10 inside KVM, Tomcat 6 (from Ubuntu repo), Jenkins 1.461 and previously saw it on 1.460

      Description

      This is different from tickets 800 and 813 because I'm not using SVN, I'm doing a checkout from git.

      What happens is that I notice that no new builds have been occurring on schedule for awhile. If I try to launch one manually, I get the output I pasted at the bottom. If I restart tomcat, the issue goes away.

      Started by user anonymous
      Building in workspace /usr/share/tomcat6/.jenkins/jobs/Busybody/workspace
      Checkout:workspace / /usr/share/tomcat6/.jenkins/jobs/Busybody/workspace - hudson.remoting.LocalChannel@11da1f99
      Using strategy: Default
      Last Built Revision: Revision 54b002eea7747a9c952cecb64aedb582a36a9179 (origin/master)
      Checkout:workspace / /usr/share/tomcat6/.jenkins/jobs/Busybody/workspace - hudson.remoting.LocalChannel@11da1f99
      Fetching changes from 1 remote Git repository
      Fetching upstream changes from git://git.vs-networks.com/vsn
      Commencing build of Revision be94cec2e46a1828e628e719541dc9a583a3d1f8 (origin/master)
      Checking out Revision be94cec2e46a1828e628e719541dc9a583a3d1f8 (origin/master)
      FATAL: Timer already cancelled.
      java.lang.IllegalStateException: Timer already cancelled.
      at java.util.Timer.sched(Timer.java:376)
      at java.util.Timer.schedule(Timer.java:192)
      at hudson.plugins.build_timeout.BuildTimeoutWrapper$1EnvironmentImpl.<init>(BuildTimeoutWrapper.java:74)
      at hudson.plugins.build_timeout.BuildTimeoutWrapper.setUp(BuildTimeoutWrapper.java:84)
      at hudson.model.Build$RunnerImpl.doRun(Build.java:133)
      at hudson.model.AbstractBuild$AbstractRunner.run(AbstractBuild.java:475)
      at hudson.model.Run.run(Run.java:1434)
      at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
      at hudson.model.ResourceController.execute(ResourceController.java:88)
      at hudson.model.Executor.run(Executor.java:239)

        Issue Links

          Activity

          jdboyd Joshua Boyd created issue -
          Hide
          chantivlad chanti vlad added a comment -

          Hi,
          we are also affected by this issue. It happens randomly on our server.
          Any news on that?

          Show
          chantivlad chanti vlad added a comment - Hi, we are also affected by this issue. It happens randomly on our server. Any news on that?
          Hide
          sogabe sogabe added a comment -

          If you have build timeout plugin installed, try to configure time-out.

          Show
          sogabe sogabe added a comment - If you have build timeout plugin installed, try to configure time-out.
          Hide
          mhschroe Martin Schröder added a comment - - edited

          Hi everyone.

          We encounter the same issue repeatedly. It can't be replicated easily, but it happens every few days to every few weeks. Our Jenkins is the LTS release v1.509.1 and is set up on Ubuntu 12.04 with Java 1.6.0_45.

          The error we get looks like this as soon as it has infested the system and starts to abort builds when they start:

          --------------------------------
          FATAL: Timer already cancelled.
          java.lang.IllegalStateException: Timer already cancelled.
          at java.util.Timer.sched(Timer.java:354)
          at java.util.Timer.schedule(Timer.java:170)
          at hudson.plugins.build_timeout.BuildTimeoutWrapper$1EnvironmentImpl.<init>(BuildTimeoutWrapper.java:149)
          at hudson.plugins.build_timeout.BuildTimeoutWrapper.setUp(BuildTimeoutWrapper.java:184)
          at hudson.model.Build$BuildExecution.doRun(Build.java:154)
          [...]
          --------------------------------

          When the error happens for the first time, it aborts at different stages in the build; but most often when the publishers start to be executed. All new builds fail with the above message, though.

          It's a real showstopper for us.

          As an additional note, all our builds have a fixed value of 3 hours set for the BuildTimeout plugin, so the comment from Sogabe does not really apply to us.

          The version of the timeout plugin is 1.11 (the newest at the time of writing).

          Thanks in advance,
          Martin Schröder.

          Show
          mhschroe Martin Schröder added a comment - - edited Hi everyone. We encounter the same issue repeatedly. It can't be replicated easily, but it happens every few days to every few weeks. Our Jenkins is the LTS release v1.509.1 and is set up on Ubuntu 12.04 with Java 1.6.0_45. The error we get looks like this as soon as it has infested the system and starts to abort builds when they start: -------------------------------- FATAL: Timer already cancelled. java.lang.IllegalStateException: Timer already cancelled. at java.util.Timer.sched(Timer.java:354) at java.util.Timer.schedule(Timer.java:170) at hudson.plugins.build_timeout.BuildTimeoutWrapper$1EnvironmentImpl.<init>(BuildTimeoutWrapper.java:149) at hudson.plugins.build_timeout.BuildTimeoutWrapper.setUp(BuildTimeoutWrapper.java:184) at hudson.model.Build$BuildExecution.doRun(Build.java:154) [...] -------------------------------- When the error happens for the first time, it aborts at different stages in the build; but most often when the publishers start to be executed. All new builds fail with the above message, though. It's a real showstopper for us. As an additional note, all our builds have a fixed value of 3 hours set for the BuildTimeout plugin, so the comment from Sogabe does not really apply to us. The version of the timeout plugin is 1.11 (the newest at the time of writing). Thanks in advance, Martin Schröder.
          Hide
          sogabe sogabe added a comment -

          Build timeout Plugin seems to cause this plugin.

          Show
          sogabe sogabe added a comment - Build timeout Plugin seems to cause this plugin.
          sogabe sogabe made changes -
          Field Original Value New Value
          Assignee Nicolas De Loof [ ndeloof ]
          Component/s build-timeout [ 15530 ]
          Component/s git [ 15543 ]
          Component/s python [ 16018 ]
          Hide
          mhschroe Martin Schröder added a comment - - edited

          Hello Sogabe.

          I admit, that I have no insight into the actual behaviour of the build-timeout plug-in, so I can't say whether or not it is to blame for this issue.

          But if I look at the source-code of the plug-in [1], I see that the line that causes the failure is this:

          public EnvironmentImpl() {
              long timeout;
              
              [... assigning value to'timeout' ...]
          
              this.effectiveTimeout = timeout;
              task = new TimeoutTimerTask(build, listener);
              Trigger.timer.schedule(task, timeout);
          }
          

          [1] - https://github.com/jenkinsci/build-timeout-plugin/blob/master/src/main/java/hudson/plugins/build_timeout/BuildTimeoutWrapper.java

          The plug-in fails at that last line. The interesting thing is just that it DOES NOT complain about the task being invalid. Instead, it complains about "Trigger.timer" having been already cancelled.

          So the root question is, what cancels this field 'timer' in "hudson.triggers.Trigger"? I can't see anything in the plug-in's code that would do that. The only cancel() it calls is on the task itself – but that should as far as I know not cancel the Trigger.timer field it is contained in.

          Additionally, even if the plug-in checks this field for if it has been cancelled or not, all that would do is to move the failure from the Build-Timeout-plugin to the next plug-in that makes use of this field from the Trigger class. As far as I know, many plug-ins directly or indirectly use this field via the many "<something>PeriodicWork" classes of Jenkins.

          Best regards,
          Martin Schröder.

          Show
          mhschroe Martin Schröder added a comment - - edited Hello Sogabe. I admit, that I have no insight into the actual behaviour of the build-timeout plug-in, so I can't say whether or not it is to blame for this issue. But if I look at the source-code of the plug-in [1] , I see that the line that causes the failure is this: public EnvironmentImpl() { long timeout; [... assigning value to'timeout' ...] this.effectiveTimeout = timeout; task = new TimeoutTimerTask(build, listener); Trigger.timer.schedule(task, timeout); } [1] - https://github.com/jenkinsci/build-timeout-plugin/blob/master/src/main/java/hudson/plugins/build_timeout/BuildTimeoutWrapper.java The plug-in fails at that last line. The interesting thing is just that it DOES NOT complain about the task being invalid. Instead, it complains about "Trigger.timer" having been already cancelled. So the root question is, what cancels this field 'timer' in "hudson.triggers.Trigger"? I can't see anything in the plug-in's code that would do that. The only cancel() it calls is on the task itself – but that should as far as I know not cancel the Trigger.timer field it is contained in. Additionally, even if the plug-in checks this field for if it has been cancelled or not, all that would do is to move the failure from the Build-Timeout-plugin to the next plug-in that makes use of this field from the Trigger class. As far as I know, many plug-ins directly or indirectly use this field via the many "<something>PeriodicWork" classes of Jenkins. Best regards, Martin Schröder.
          Hide
          mhschroe Martin Schröder added a comment -

          Assigned to Kohsuke, as he is the lead for the build-timeout plug-in. And if the root-cause is not there, he's the most likely person to know what else might cause it.

          Show
          mhschroe Martin Schröder added a comment - Assigned to Kohsuke, as he is the lead for the build-timeout plug-in. And if the root-cause is not there, he's the most likely person to know what else might cause it.
          mhschroe Martin Schröder made changes -
          Assignee Kohsuke Kawaguchi [ kohsuke ]
          Hide
          mhschroe Martin Schröder added a comment - - edited

          We have checked the issue with the latest LTS releases (1.509.3/4) again.

          If the "build-timeout" plug-in is not installed or deactivated; the "Timer already cancelled" issue does not appears.
          If it is enabled, the issue will sooner or later occur (with time-before-failure sometimes up to a month) and cause all builds to fail until the server is restarted.

          Therefore, we presume that it is either due to a bug in that plug-in or at least triggered by it.

          Show
          mhschroe Martin Schröder added a comment - - edited We have checked the issue with the latest LTS releases (1.509.3/4) again. If the "build-timeout" plug-in is not installed or deactivated; the "Timer already cancelled" issue does not appears. If it is enabled, the issue will sooner or later occur (with time-before-failure sometimes up to a month) and cause all builds to fail until the server is restarted. Therefore, we presume that it is either due to a bug in that plug-in or at least triggered by it.
          Hide
          bmallick Bitan Mallick added a comment -

          We encountered a similar issue with Jenkins 1.5.0 and build-timeout-1.11.

          Show
          bmallick Bitan Mallick added a comment - We encountered a similar issue with Jenkins 1.5.0 and build-timeout-1.11.
          ikedam ikedam made changes -
          Link This issue is duplicated by JENKINS-3917 [ JENKINS-3917 ]
          Hide
          ikedam ikedam added a comment -

          I finally succeeded to reproduce this problem:

          Steps: Tested with Jenkins 1.509.2 + build-timeout plugin 1.14

          1. Go to Manage Jenkins > Script Console
          2. Run following script
            hudson.triggers.Trigger.timer.schedule(new java.util.TimerTask() {
              public void run() {
                throw new RuntimeException("Exception from TimerTask with love");
              }
            }, 1000);
            
          3. Following log is output
            Exception in thread "Jenkins cron thread" java.lang.RuntimeException: Exception from TimerTask with love
                    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
                    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
                    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
                    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
                    at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:77)
                    at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrapNoCoerce.callConstructor(ConstructorSite.java:102)
                    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:54)
                    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:182)
                    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:190)
                    at Script1$1.run(Script1.groovy:3)
                    at java.util.TimerThread.mainLoop(Timer.java:555)
                    at java.util.TimerThread.run(Timer.java:505)
            
          4. Run a job configured with build-timeout. It always fails with following output:
            FATAL: Timer already cancelled.
            java.lang.IllegalStateException: Timer already cancelled.
            	at java.util.Timer.sched(Timer.java:397)
            	at java.util.Timer.schedule(Timer.java:193)
            	at hudson.plugins.build_timeout.BuildTimeoutWrapper$EnvironmentImpl.reschedule(BuildTimeoutWrapper.java:179)
            	at hudson.plugins.build_timeout.BuildTimeoutWrapper$EnvironmentImpl.<init>(BuildTimeoutWrapper.java:164)
            	at hudson.plugins.build_timeout.BuildTimeoutWrapper.setUp(BuildTimeoutWrapper.java:204)
            	at hudson.model.Build$BuildExecution.doRun(Build.java:154)
            	at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:584)
            	at hudson.model.Run.execute(Run.java:1575)
            	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
            	at hudson.model.ResourceController.execute(ResourceController.java:88)
            	at hudson.model.Executor.run(Executor.java:237)
            
          5. You need restart Jenkins to recover from this problem.
          Show
          ikedam ikedam added a comment - I finally succeeded to reproduce this problem: Steps: Tested with Jenkins 1.509.2 + build-timeout plugin 1.14 Go to Manage Jenkins > Script Console Run following script hudson.triggers.Trigger.timer.schedule( new java.util.TimerTask() { public void run() { throw new RuntimeException( "Exception from TimerTask with love" ); } }, 1000); Following log is output Exception in thread "Jenkins cron thread" java.lang.RuntimeException: Exception from TimerTask with love at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:526) at org.codehaus.groovy.reflection.CachedConstructor.invoke(CachedConstructor.java:77) at org.codehaus.groovy.runtime.callsite.ConstructorSite$ConstructorSiteNoUnwrapNoCoerce.callConstructor(ConstructorSite.java:102) at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCallConstructor(CallSiteArray.java:54) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:182) at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callConstructor(AbstractCallSite.java:190) at Script1$1.run(Script1.groovy:3) at java.util.TimerThread.mainLoop(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) Run a job configured with build-timeout. It always fails with following output: FATAL: Timer already cancelled. java.lang.IllegalStateException: Timer already cancelled. at java.util.Timer.sched(Timer.java:397) at java.util.Timer.schedule(Timer.java:193) at hudson.plugins.build_timeout.BuildTimeoutWrapper$EnvironmentImpl.reschedule(BuildTimeoutWrapper.java:179) at hudson.plugins.build_timeout.BuildTimeoutWrapper$EnvironmentImpl.<init>(BuildTimeoutWrapper.java:164) at hudson.plugins.build_timeout.BuildTimeoutWrapper.setUp(BuildTimeoutWrapper.java:204) at hudson.model.Build$BuildExecution.doRun(Build.java:154) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:584) at hudson.model.Run.execute(Run.java:1575) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46) at hudson.model.ResourceController.execute(ResourceController.java:88) at hudson.model.Executor.run(Executor.java:237) You need restart Jenkins to recover from this problem.
          Hide
          ikedam ikedam added a comment -

          This should be triggered by a problem of another plugin.
          Once that plugin throws excption from its timer task in a shared timer thread, build-timeout cannot register new timer tasks to the shared timer thread anymore.
          That exception should be recorded in Jenkins logs, and please check that and see what is the root cause.

          Details:

          • Java timer consists from timer threads and timer tasks.
          • Build-timeout registers timer tasks triggering timeouts to the timer thread which is provided by Jenkins core and is shared by all plugins.
          • A timer thread gets out of service once a registered timer task throws an exception (this is "Timer already cancelled").
          • Jenkins provides SafeTimerTask to avoid this problem. Plugins should use SafeTimerTask instead of TimerTask provided in JDK, and any exceptions in timer tasks will be blocked.
          • Build-timeout also uses SafeTimerTask, and should not be the root cause of this problem.
          • It seems that some plugin uses TimerTask and throws an exception. It can affect all other plugins using the shared timer thread.
          Show
          ikedam ikedam added a comment - This should be triggered by a problem of another plugin. Once that plugin throws excption from its timer task in a shared timer thread, build-timeout cannot register new timer tasks to the shared timer thread anymore. That exception should be recorded in Jenkins logs, and please check that and see what is the root cause. Details: Java timer consists from timer threads and timer tasks. Build-timeout registers timer tasks triggering timeouts to the timer thread which is provided by Jenkins core and is shared by all plugins. A timer thread gets out of service once a registered timer task throws an exception (this is "Timer already cancelled"). Jenkins provides SafeTimerTask to avoid this problem. Plugins should use SafeTimerTask instead of TimerTask provided in JDK, and any exceptions in timer tasks will be blocked. Build-timeout also uses SafeTimerTask , and should not be the root cause of this problem. It seems that some plugin uses TimerTask and throws an exception. It can affect all other plugins using the shared timer thread.
          Hide
          ikedam ikedam added a comment -

          This should be an issue triggered by errors in other plugins as described before.
          No more reports for a year and I close this ticket.

          Show
          ikedam ikedam added a comment - This should be an issue triggered by errors in other plugins as described before. No more reports for a year and I close this ticket.
          ikedam ikedam made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Incomplete [ 4 ]

            People

            • Assignee:
              kohsuke Kohsuke Kawaguchi
              Reporter:
              jdboyd Joshua Boyd
            • Votes:
              5 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: