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

Please wait while Jenkins is getting ready to work - jenkins 2.60.1

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Critical
    • Resolution: Not A Defect
    • Component/s: _unsorted
    • Labels:
      None
    • Environment:
      centos7, jenkins 2.60.1, java 1.8.0_131, kernel 3.10.0-514.21.2.el7.x86_64
    • Similar Issues:

      Description

      After upgrade to Jenkins v2.60.1 service never started normally again.

      Stuck on "Please wait while Jenkins is getting ready to work."

      Initially in jenkins.log I saw these errors:

      Jun 29, 2017 12:58:02 PM org.jenkinsci.plugins.puppetenterprise.models.HieraConfig loadGlobalConfig
      SEVERE: Error loading Hiera configuration: Unable to read /data/jenkins/puppet_enterprise_hiera_store.xml
      Jun 29, 2017 12:58:02 PM org.jenkinsci.plugins.puppetenterprise.models.HieraConfig loadGlobalConfig
      SEVERE: Error loading Hiera configuration: Unable to read /data/jenkins/puppet_enterprise_hiera_store.xml

      This file is in place and is empty; giving it 777 permission didn't solve the problem.

      I've never used/configured this plugin it was installed for experimentation in future.

      Next, I've manually removed puppet-enterprise-plugin from plugins directory.

      Restarted server but still, no luck.

      Here is full log output from last restart, where i don't see severe errors, or java errors:

      Running from: /usr/lib/jenkins/jenkins.war
      Jun 29, 2017 1:23:01 PM Main deleteWinstoneTempContents
      WARNING: Failed to delete the temporary Winstone file /tmp/winstone/jenkins.war
      Jun 29, 2017 1:23:01 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Logging initialized @984ms
      Jun 29, 2017 1:23:01 PM winstone.Logger logInternal
      INFO: Beginning extraction from war file
      Jun 29, 2017 1:23:01 PM org.eclipse.jetty.util.log.JavaUtilLog warn
      WARNING: Empty contextPath
      Jun 29, 2017 1:23:01 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: jetty-9.2.z-SNAPSHOT
      Jun 29, 2017 1:23:03 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: NO JSP Support for /, did not find org.eclipse.jetty.jsp.JettyJspServlet
      Jenkins home directory: /data/jenkins found at: SystemProperties.getProperty("JENKINS_HOME")
      Jun 29, 2017 1:23:04 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started w.@6440112d{/,file:/var/cache/jenkins/war/,AVAILABLE}{/var/cache/jenkins/war}
      Jun 29, 2017 1:23:05 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started ServerConnector@35841320{HTTP/1.1}{0.0.0.0:8080}
      Jun 29, 2017 1:23:05 PM org.eclipse.jetty.util.log.JavaUtilLog info
      INFO: Started @4437ms
      Jun 29, 2017 1:23:05 PM winstone.Logger logInternal
      INFO: Winstone Servlet Engine v2.0 running: controlPort=disabled
      Jun 29, 2017 1:23:05 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Started initialization
      Jun 29, 2017 1:23:27 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Listed all plugins
      Jun 29, 2017 1:23:30 PM hudson.plugins.ansicolor.PluginImpl start
      INFO: AnsiColor: eliminating boring output (https://github.com/dblock/jenkins-ansicolor-plugin)
      Jun 29, 2017 1:23:35 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Prepared all plugins
      Jun 29, 2017 1:23:36 PM hudson.ExtensionFinder$GuiceFinder$FaultTolerantScope$1 error
      INFO: Failed to instantiate optional component hudson.plugins.build_timeout.operations.AbortAndRestartOperation$DescriptorImpl; skipping
      Jun 29, 2017 1:23:36 PM org.jenkinsci.plugins.dockerbuildstep.DockerBuilder$DescriptorImpl <init>
      WARNING: Docker URL is not set, docker client won't be initialized
      Jun 29, 2017 1:23:36 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Started all plugins
      Jun 29, 2017 1:23:37 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Augmented all extensions
      Jun 29, 2017 1:23:40 PM jenkins.InitReactorRunner$1 onAttained
      INFO: Loaded all jobs
      Jun 29, 2017 1:23:40 PM hudson.model.AsyncPeriodicWork$1 run
      INFO: Started Download metadata
      Jun 29, 2017 1:23:40 PM hudson.model.AsyncPeriodicWork$1 run
      INFO: Finished Download metadata. 12 ms
      Jun 29, 2017 1:23:41 PM org.springframework.context.support.AbstractApplicationContext prepareRefresh
      INFO: Refreshing org.springframework.web.context.support.StaticWebApplicationContext@486dd257: display name [Root WebApplicationContext]; startup date [Thu Jun 29 13:23:41 UTC 2017]; root of context hierarchy
      Jun 29, 2017 1:23:41 PM org.springframework.context.support.AbstractApplicationContext obtainFreshBeanFactory
      INFO: Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@486dd257]: org.springframework.beans.factory.support.DefaultListableBeanFactory@26e6a44d
      Jun 29, 2017 1:23:41 PM org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
      INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@26e6a44d: defining beans [authenticationManager]; root of factory hierarchy
      Jun 29, 2017 1:23:41 PM org.springframework.context.support.AbstractApplicationContext prepareRefresh
      INFO: Refreshing org.springframework.web.context.support.StaticWebApplicationContext@7c2855a8: display name [Root WebApplicationContext]; startup date [Thu Jun 29 13:23:41 UTC 2017]; root of context hierarchy
      Jun 29, 2017 1:23:41 PM org.springframework.context.support.AbstractApplicationContext obtainFreshBeanFactory
      INFO: Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@7c2855a8]: org.springframework.beans.factory.support.DefaultListableBeanFactory@5820fcc8
      Jun 29, 2017 1:23:41 PM org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
      INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@5820fcc8: defining beans [filter,legacy]; root of factory hierarchy
      

        Attachments

          Activity

          Hide
          den_is Denis Iskandarov added a comment -

          replacing jenkins 2.60 war with 2.46 didn't help as well

          Show
          den_is Denis Iskandarov added a comment - replacing jenkins 2.60 war with 2.46 didn't help as well
          Hide
          oleg_nenashev Oleg Nenashev added a comment -

          Please provide a stacktrace of the instance when it hangs

          Show
          oleg_nenashev Oleg Nenashev added a comment - Please provide a stacktrace of the instance when it hangs
          Hide
          den_is Denis Iskandarov added a comment - - edited

          how to get it ? asking  beacause I don't see usual java stacktraces. web page shows only this text. and i've coppied full log output... nothing happens after that

          Show
          den_is Denis Iskandarov added a comment - - edited how to get it ? asking  beacause I don't see usual java stacktraces. web page shows only this text. and i've coppied full log output... nothing happens after that
          Hide
          oleg_nenashev Oleg Nenashev added a comment -
          Show
          oleg_nenashev Oleg Nenashev added a comment - Easiest approach - use jstack tool: http://docs.oracle.com/javase/1.5.0/docs/tooldocs/share/jstack.html
          Hide
          den_is Denis Iskandarov added a comment - - edited

          I got only this

          jstack -l 14309
          14309: Unable to open socket file: target process not responding or HotSpot VM not loaded
          The -F option can be used when the target process is not responding
          
          # jstack -F 14309 
          Attaching to process ID 14309, please wait...
          Exception in thread "main" java.lang.reflect.InvocationTargetException
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          at java.lang.reflect.Method.invoke(Method.java:606)
          at sun.tools.jstack.JStack.runJStackTool(JStack.java:136)
          at sun.tools.jstack.JStack.main(JStack.java:102)
          Caused by: sun.jvm.hotspot.runtime.VMVersionMismatchException: Supported versions are 24.141-b02. Target VM is 25.131-b12
          at sun.jvm.hotspot.runtime.VM.checkVMVersion(VM.java:234)
          at sun.jvm.hotspot.runtime.VM.<init>(VM.java:297)
          at sun.jvm.hotspot.runtime.VM.initialize(VM.java:368)
          at sun.jvm.hotspot.bugspot.BugSpotAgent.setupVM(BugSpotAgent.java:598)
          at sun.jvm.hotspot.bugspot.BugSpotAgent.go(BugSpotAgent.java:493)
          at sun.jvm.hotspot.bugspot.BugSpotAgent.attach(BugSpotAgent.java:331)
          at sun.jvm.hotspot.tools.Tool.start(Tool.java:163)
          at sun.jvm.hotspot.tools.JStack.main(JStack.java:86)
          ... 6 more
          Show
          den_is Denis Iskandarov added a comment - - edited I got only this jstack -l 14309 14309: Unable to open socket file: target process not responding or HotSpot VM not loaded The -F option can be used when the target process is not responding # jstack -F 14309 Attaching to process ID 14309, please wait... Exception in thread "main" java.lang.reflect.InvocationTargetException at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at sun.tools.jstack.JStack.runJStackTool(JStack.java:136) at sun.tools.jstack.JStack.main(JStack.java:102) Caused by: sun.jvm.hotspot.runtime.VMVersionMismatchException: Supported versions are 24.141-b02. Target VM is 25.131-b12 at sun.jvm.hotspot.runtime.VM.checkVMVersion(VM.java:234) at sun.jvm.hotspot.runtime.VM.<init>(VM.java:297) at sun.jvm.hotspot.runtime.VM.initialize(VM.java:368) at sun.jvm.hotspot.bugspot.BugSpotAgent.setupVM(BugSpotAgent.java:598) at sun.jvm.hotspot.bugspot.BugSpotAgent.go(BugSpotAgent.java:493) at sun.jvm.hotspot.bugspot.BugSpotAgent.attach(BugSpotAgent.java:331) at sun.jvm.hotspot.tools.Tool.start(Tool.java:163) at sun.jvm.hotspot.tools.JStack.main(JStack.java:86) ... 6 more
          Hide
          oleg_nenashev Oleg Nenashev added a comment -

          Likely you are trying to connect to Java 8 process with Java 7 jstack

          Show
          oleg_nenashev Oleg Nenashev added a comment - Likely you are trying to connect to Java 8 process with Java 7 jstack
          Hide
          den_is Denis Iskandarov added a comment - - edited

          Problem somehow resolved by itself.

          Two possible solutions to problem:

          1. I had both java 7 and java 8 installed on the system. java8 was default. uninstalled java7
          2. Time - as not much errors were in startup logs, it was looking like jenkins were starting normally and just processing something. Activity was seen in process managers. Process was spawning childs. Before I've started to panic, I was waiting like 30 minutes before initial service/server restart. Then it was working some additional small amounts of time between my restart . Just I had same issues before and server restart was helping or was just coincidence.

          Feel free to close the issue.

          And thanks for your time!

          Show
          den_is Denis Iskandarov added a comment - - edited Problem somehow resolved by itself. Two possible solutions to problem: I had both java 7 and java 8 installed on the system. java8 was default. uninstalled java7 Time - as not much errors were in startup logs, it was looking like jenkins were starting normally and just processing something. Activity was seen in process managers. Process was spawning childs. Before I've started to panic, I was waiting like 30 minutes before initial service/server restart. Then it was working some additional small amounts of time between my restart . Just I had same issues before and server restart was helping or was just coincidence. Feel free to close the issue. And thanks for your time!
          Hide
          oleg_nenashev Oleg Nenashev added a comment -

          you are welcome

          Show
          oleg_nenashev Oleg Nenashev added a comment - you are welcome

            People

            • Assignee:
              oleg_nenashev Oleg Nenashev
              Reporter:
              den_is Denis Iskandarov
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: