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

    • Icon: Bug Bug
    • Resolution: Cannot Reproduce
    • Icon: Major Major
    • None
    • Ubuntu 14.04 x86_64
      Jenkins 2.12
      Multi-Branch Project Plugin 0.5
      GitHub plugin 1.19.2

      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
      

            tbingaman Timothy Bingaman
            totoroliu Rick Liu
            Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: