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

Takes 10 minutes to start Jenkins service after upgrading from 2.11 to 2.12

    XMLWordPrintable

    Details

    • Similar Issues:

      Description

      After "sudo apt-get upgrade" to upgrade Jenkins from 2.11 to 2.12,
      the "sudo service jenkins start" will take 10 minutes to be fully up and running.

      It will stuck in the error below for 10 minutes.
      Attach the full jenkins.log.

      Running from: /usr/share/jenkins/jenkins.war
      Jul 07, 2016 11:09:52 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Logging initialized @515ms
      Jul 07, 2016 11:09:52 AM winstone.Logger logInternal
      INFO: Beginning extraction from war file
      Jul 07, 2016 11:09:52 AM org.eclipse.jetty.util.log.JavaUtilLog warn
      WARNING: Empty contextPath
      Jul 07, 2016 11:09:52 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: jetty-9.2.z-SNAPSHOT
      Jul 07, 2016 11:09:53 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: NO JSP Support for /, did not find org.eclipse.jetty.jsp.JettyJspServlet
      Jenkins home directory: /var/lib/jenkins found at: EnvVars.masterEnvVars.get("JENKINS_HOME")
      Jul 07, 2016 11:09:54 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started w.@7515ff74{/,file:/var/cache/jenkins/war/,AVAILABLE}{/var/cache/jenkins/war}
      Jul 07, 2016 11:09:54 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started ServerConnector@279a3e0c{HTTP/1.1}{0.0.0.0:8080}
      Jul 07, 2016 11:09:54 AM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started @2037ms
      Jul 07, 2016 11:09:54 AM winstone.Logger logInternal
      INFO: Winstone Servlet Engine v2.0 running: controlPort=disabled
      Jul 07, 2016 11:09:54 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Started initialization
      Jul 07, 2016 11:09:54 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Listed all plugins
      Jul 07, 2016 11:09:55 AM org.jenkinsci.plugins.scriptler.ScriptlerPluginImpl synchronizeConfig
      INFO: initialize scriptler
      Jul 07, 2016 11:10:00 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Prepared all plugins
      Jul 07, 2016 11:10:01 AM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
      INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyBranchProjectFactory$DescriptorImpl; skipping
      Jul 07, 2016 11:10:01 AM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
      INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject$DescriptorImpl; skipping
      Jul 07, 2016 11:10:01 AM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
      WARNING: Failed to instantiate Key[type=hudson.plugins.build_timeout.operations.AbortAndRestartOperation$DescriptorImpl, annotation=[none]]; skipping this component
      com.google.inject.ProvisionException: Guice provision errors:
      
      1) Error injecting constructor, java.lang.NoClassDefFoundError: com/chikli/hudson/plugin/naginator/ScheduleDelay
        at hudson.plugins.build_timeout.operations.AbortAndRestartOperation$DescriptorImpl.<init>(AbortAndRestartOperation.java:120)
      
      1 error
              at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:52)
              at com.google.inject.Scopes$1$1.get(Scopes.java:65)
              at hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1.get(ExtensionFinder.java:424)
              at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
              at com.google.inject.internal.InjectorImpl$3$1.call(InjectorImpl.java:1005)
              at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1051)
              at com.google.inject.internal.InjectorImpl$3.get(InjectorImpl.java:1001)
              at hudson.ExtensionFinder$GuiceFinder._find(ExtensionFinder.java:386)
              at hudson.ExtensionFinder$GuiceFinder.find(ExtensionFinder.java:377)
              at hudson.ClassicPluginStrategy.findComponents(ClassicPluginStrategy.java:471)
              at hudson.ExtensionList.load(ExtensionList.java:349)
              at hudson.ExtensionList.ensureLoaded(ExtensionList.java:287)
              at hudson.ExtensionList.getComponents(ExtensionList.java:167)
              at hudson.DescriptorExtensionList.load(DescriptorExtensionList.java:185)
              at hudson.ExtensionList.ensureLoaded(ExtensionList.java:287)
              at hudson.ExtensionList.iterator(ExtensionList.java:156)
              at hudson.ExtensionList.get(ExtensionList.java:147)
              at com.cloudbees.jenkins.GitHubPushTrigger$DescriptorImpl.get(GitHubPushTrigger.java:359)
              at org.jenkinsci.plugins.github.migration.Migrator.migrate(Migrator.java:40)
              at org.jenkinsci.plugins.github.GitHubPlugin.postInitialize(GitHubPlugin.java:39)
              at hudson.PluginManager$2$1$2.run(PluginManager.java:536)
              at org.jvnet.hudson.reactor.TaskGraphBuilder$TaskImpl.run(TaskGraphBuilder.java:169)
              at org.jvnet.hudson.reactor.Reactor.runTask(Reactor.java:282)
              at jenkins.model.Jenkins$7.runTask(Jenkins.java:999)
              at org.jvnet.hudson.reactor.Reactor$2.run(Reactor.java:210)
              at org.jvnet.hudson.reactor.Reactor$Node.run(Reactor.java:117)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.NoClassDefFoundError: com/chikli/hudson/plugin/naginator/ScheduleDelay
              at java.lang.Class.getDeclaredMethods0(Native Method)
              at java.lang.Class.privateGetDeclaredMethods(Class.java:2625)
              at java.lang.Class.getMethod0(Class.java:2866)
              at java.lang.Class.getMethod(Class.java:1676)
              at hudson.model.Descriptor.<init>(Descriptor.java:287)
              at hudson.plugins.build_timeout.BuildTimeOutOperationDescriptor.<init>(BuildTimeOutOperationDescriptor.java:38)
              at hudson.plugins.build_timeout.operations.AbortAndRestartOperation$DescriptorImpl.<init>(AbortAndRestartOperation.java:120)
              at hudson.plugins.build_timeout.operations.AbortAndRestartOperation$DescriptorImpl$$FastClassByGuice$$7e648b1.newInstance(<generated>)
              at com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(FastConstructor.java:40)
              at com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(DefaultConstructionProxyFactory.java:61)
              at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:108)
              at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:88)
              at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:269)
              at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
              at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1058)
              at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
              ... 28 more
      Caused by: java.lang.ClassNotFoundException: com.chikli.hudson.plugin.naginator.ScheduleDelay
              at jenkins.util.AntClassLoader.findClassInComponents(AntClassLoader.java:1376)
              at jenkins.util.AntClassLoader.findClass(AntClassLoader.java:1326)
              at jenkins.util.AntClassLoader.loadClass(AntClassLoader.java:1079)
              at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
              ... 44 more
      
      Jul 07, 2016 11:10:01 AM org.jvnet.hudson.annotation_indexer.Index$2$1 fetch
      WARNING: Failed to load com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject
      java.lang.NoClassDefFoundError: hudson/ivy/IvyModuleSet
              at java.lang.Class.getDeclaredMethods0(Native Method)
              at java.lang.Class.privateGetDeclaredMethods(Class.java:2625)
              at java.lang.Class.getDeclaredMethods(Class.java:1868)
              at org.jvnet.hudson.annotation_indexer.Index$2$1.fetch(Index.java:103)
              at org.jvnet.hudson.annotation_indexer.Index$2$1.hasNext(Index.java:73)
              at org.jvnet.hudson.annotation_indexer.SubtypeIterator.fetch(SubtypeIterator.java:18)
              at org.jvnet.hudson.annotation_indexer.SubtypeIterator.hasNext(SubtypeIterator.java:28)
              at hudson.init.TaskMethodFinder.discoverTasks(TaskMethodFinder.java:56)
              at hudson.init.InitializerFinder.discoverTasks(InitializerFinder.java:33)
              at hudson.PluginManager$2$1$3.run(PluginManager.java:550)
              at org.jvnet.hudson.reactor.TaskGraphBuilder$TaskImpl.run(TaskGraphBuilder.java:169)
              at org.jvnet.hudson.reactor.Reactor.runTask(Reactor.java:282)
              at jenkins.model.Jenkins$7.runTask(Jenkins.java:999)
              at org.jvnet.hudson.reactor.Reactor$2.run(Reactor.java:210)
              at org.jvnet.hudson.reactor.Reactor$Node.run(Reactor.java:117)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.ClassNotFoundException: hudson.ivy.IvyModuleSet
              at jenkins.util.AntClassLoader.findClassInComponents(AntClassLoader.java:1376)
              at jenkins.util.AntClassLoader.findClass(AntClassLoader.java:1326)
              at jenkins.util.AntClassLoader.loadClass(AntClassLoader.java:1079)
              at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
              ... 18 more
      
      
      Jul 07, 2016 11:20:37 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Started all plugins
      Jul 07, 2016 11:20:37 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Augmented all extensions
      Jul 07, 2016 11:20:37 AM jenkins.advancedqueue.PrioritySorterPlugin init1
      INFO: Configuring the Priority Sorter ...
      Jul 07, 2016 11:20:37 AM hudson.slaves.SlaveComputer tryReconnect
      INFO: Attempting to reconnect jenkins-slave03(192.168.100.162)
      Jul 07, 2016 11:20:37 AM hudson.slaves.SlaveComputer tryReconnect
      INFO: Attempting to reconnect jenkins-z3700D-3(172.18.125.223)
      [07/07/16 11:20:42] SSH Launch of jenkins-z3700D-3(172.18.125.223) on 172.18.125.223 completed in 5,265 ms
      Jul 07, 2016 11:20:52 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Projects/FortiOS/br_5/br_5_60dm_3g4g (1505.3%)
      Jul 07, 2016 11:20:53 AM hudson.model.ItemGroupMixIn loadChildren
      WARNING: could not find file /var/lib/jenkins/jobs/Projects/jobs/FortiOS/jobs/5.2/config.xml
      [07/07/16 11:20:59] SSH Launch of jenkins-slave03(192.168.100.162) on 192.168.100.162 completed in 21,602 ms
      Jul 07, 2016 11:21:07 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Projects/FortiOS/br_5-4/br_5-4_SDK (3073.7%)
      Jul 07, 2016 11:21:22 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Projects/FortiOS/br_5-0/br_5-0_IPv6 (4510.5%)
      Jul 07, 2016 11:21:32 AM hudson.model.ItemGroupMixIn loadChildren
      WARNING: could not find file /var/lib/jenkins/jobs/Projects/jobs/FortiOS/jobs/trunk/branches/5.0/config.xml
      Jul 07, 2016 11:21:32 AM hudson.model.ItemGroupMixIn loadChildren
      WARNING: could not find file /var/lib/jenkins/jobs/Projects/jobs/FortiOS/jobs/trunk/branches/5.2/config.xml
      Jul 07, 2016 11:21:37 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Tests/Multi_Branch_Matrix/br_5-4_fos_30e_3g4g_NAM_INTL (5478.9%)
      Jul 07, 2016 11:21:55 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Tests/Multi_Branch_Matrix/br_5-4_3940D (5515.8%)
      Jul 07, 2016 11:22:11 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Tests/Multi_Branch_Matrix/br_5-4_2x00E (5531.6%)
      Jul 07, 2016 11:22:29 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Tests/Multi_Branch_Matrix/br_5-4_virtual_wire_pair (5547.4%)
      Jul 07, 2016 11:22:44 AM com.cloudbees.hudson.plugins.folder.AbstractFolder$2 call
      INFO: Loading job Tests/Multi_Branch_Matrix/br_5-4_fos_loc_pmf (5594.7%)
      Jul 07, 2016 11:22:54 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Loaded all jobs
      Jul 07, 2016 11:22:54 AM jenkins.advancedqueue.PrioritySorterPlugin init2
      INFO: Sorting existing Queue ...
      Jul 07, 2016 11:22:54 AM jenkins.advancedqueue.sorter.AdvancedQueueSorter init
      INFO: Initialized the QueueSorter with 0 Buildable Items
      Jul 07, 2016 11:22:54 AM hudson.model.AsyncPeriodicWork$1 run
      INFO: Started Download metadata
      Jul 07, 2016 11:22:54 AM hudson.model.AsyncPeriodicWork$1 run
      INFO: Finished Download metadata. 19 ms
      Jul 07, 2016 11:22:54 AM org.jenkinsci.main.modules.sshd.SSHD start
      INFO: Started SSHD at port 41845
      Jul 07, 2016 11:22:54 AM jenkins.InitReactorRunner$1 onAttained
      INFO: Completed initialization
      Jul 07, 2016 11:22:54 AM org.springframework.context.support.AbstractApplicationContext prepareRefresh
      INFO: Refreshing org.springframework.web.context.support.StaticWebApplicationContext@2158401f: display name [Root WebApplicationContext]; startup date [Thu Jul 07 11:22:54 PDT 2016]; root of context hierarchy
      Jul 07, 2016 11:22:54 AM org.springframework.context.support.AbstractApplicationContext obtainFreshBeanFactory
      INFO: Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@2158401f]: org.springframework.beans.factory.support.DefaultListableBeanFactory@ef07d20
      Jul 07, 2016 11:22:54 AM org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
      INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@ef07d20: defining beans [initialDirContextFactory,bindAuthenticator,ldapUserSearch,authenticationManager,authoritiesPopulator]; root of factory hierarchy
      Jul 07, 2016 11:22:54 AM org.acegisecurity.ldap.DefaultInitialDirContextFactory setProviderUrl
      Jul 07, 2016 11:22:55 AM org.springframework.context.support.AbstractApplicationContext prepareRefresh
      INFO: Refreshing org.springframework.web.context.support.StaticWebApplicationContext@1e52d740: display name [Root WebApplicationContext]; startup date [Thu Jul 07 11:22:55 PDT 2016]; root of context hierarchy
      Jul 07, 2016 11:22:55 AM org.springframework.context.support.AbstractApplicationContext obtainFreshBeanFactory
      INFO: Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@1e52d740]: org.springframework.beans.factory.support.DefaultListableBeanFactory@196f5636
      Jul 07, 2016 11:22:55 AM org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
      INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@196f5636: defining beans [filter,legacy]; root of factory hierarchy
      Jul 07, 2016 11:22:56 AM hudson.WebAppMain$3 run
      INFO: Jenkins is fully up and running
      

        Attachments

          Activity

          Hide
          integer Kanstantsin Shautsou added a comment -

          I see no relation to github-plugin. Remove assignee and component.

          Show
          integer Kanstantsin Shautsou added a comment - I see no relation to github-plugin. Remove assignee and component.
          Hide
          mjdetullio Matthew DeTullio added a comment - - edited
          INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyBranchProjectFactory$DescriptorImpl; skipping
          Jul 07, 2016 11:10:01 AM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
          INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject$DescriptorImpl; skipping
          ... snip ...
          WARNING: Failed to load com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject
          java.lang.NoClassDefFoundError: hudson/ivy/IvyModuleSet
          ... snip stacktrace ...
          

          These are expected messages, since the Ivy Plugin is an optional dependency of the Multi-Branch Project Plugin. This error is harmless and you will always see it if you do not have the Ivy Plugin installed.

          Show
          mjdetullio Matthew DeTullio added a comment - - edited INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyBranchProjectFactory$DescriptorImpl; skipping Jul 07, 2016 11:10:01 AM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error INFO: Failed to instantiate optional component com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject$DescriptorImpl; skipping ... snip ... WARNING: Failed to load com.github.mjdetullio.jenkins.plugins.multibranch.IvyMultiBranchProject java.lang.NoClassDefFoundError: hudson/ivy/IvyModuleSet ... snip stacktrace ... These are expected messages, since the Ivy Plugin is an optional dependency of the Multi-Branch Project Plugin. This error is harmless and you will always see it if you do not have the Ivy Plugin installed.
          Hide
          totoroliu Rick Liu added a comment -

          Let me try if I can fix this by installing Ivy plugin

          Show
          totoroliu Rick Liu added a comment - Let me try if I can fix this by installing Ivy plugin
          Hide
          totoroliu Rick Liu added a comment - - edited

          Attach jenkins.log with Ivy plugin installed and screenshot.

          After install Ivy plugin,
          the jenkins service start doesn't stuck for 10 mins anymore.

          However,
          after Ivy plugin is installed,
          I can't uninstall the Ivy plugin anymore.
          It will show there are dependencies.

          Does this imply Ivy plugin should be installed but somehow is not installed through plugin depdency?

          Show
          totoroliu Rick Liu added a comment - - edited Attach jenkins.log with Ivy plugin installed and screenshot. After install Ivy plugin, the jenkins service start doesn't stuck for 10 mins anymore. However, after Ivy plugin is installed, I can't uninstall the Ivy plugin anymore. It will show there are dependencies. Does this imply Ivy plugin should be installed but somehow is not installed through plugin depdency?
          Hide
          danielbeck Daniel Beck added a comment -

          Not enough information to determine what's going on during these 10 minutes, should have taken a thread dump as described here: https://wiki.jenkins-ci.org/display/JENKINS/Obtaining+a+thread+dump

          Are you able to reproduce this issue by deleting the ivy plugin (manually) and restarting Jenkins? Otherwise we can close this as not reproducible.

          Show
          danielbeck Daniel Beck added a comment - Not enough information to determine what's going on during these 10 minutes, should have taken a thread dump as described here: https://wiki.jenkins-ci.org/display/JENKINS/Obtaining+a+thread+dump Are you able to reproduce this issue by deleting the ivy plugin (manually) and restarting Jenkins? Otherwise we can close this as not reproducible.
          Hide
          totoroliu Rick Liu added a comment -

          Ok please close this as not reproducible

          after manually delete the ivy plugin from the plugin/ folder,
          everything is still working properly.

          Show
          totoroliu Rick Liu added a comment - Ok please close this as not reproducible after manually delete the ivy plugin from the plugin/ folder, everything is still working properly.
          Hide
          totoroliu Rick Liu added a comment -

          Ok please close this as not reproducible

          after manually delete the ivy plugin from the plugin/ folder,
          everything is still working properly.

          Show
          totoroliu Rick Liu added a comment - Ok please close this as not reproducible after manually delete the ivy plugin from the plugin/ folder, everything is still working properly.

            People

            • Assignee:
              tbingaman Timothy Bingaman
              Reporter:
              totoroliu Rick Liu
            • Votes:
              1 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: