search

gocd / gocd

GoCD - Continuous Delivery server main repository
https://www.gocd.org
Apache License 2.0
7.05k stars 973 forks source link

GO server fails to start due to JGitInternalException #1470

Closed jdsubz closed 8 years ago

jdsubz commented 8 years ago

The following error occurs when attempting to start GO server. Version: 14.2.0 OS: RHEL 6.5 Problem: It appears that the internal git configuration is incorrect but I am unsure what I am looking for in order to resolve the issue.

2015-09-01 15:09:22,024 ERROR [main] log:87 - Failed startup of context org.mortbay.jetty.webapp.WebAppContext@162893fc{/go,cruise.war}
java.lang.RuntimeException: java.lang.RuntimeException: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
        at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:132)
        at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:53)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:327)
        at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:941)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:475)
        at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:383)
        at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
        at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
        at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548)
        at org.mortbay.jetty.servlet.Context.startContext(Context.java:136)
        at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1250)
        at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517)
        at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:467)
        at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:152)
        at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
        at org.mortbay.jetty.Server.doStart(Server.java:224)
        at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        at com.thoughtworks.go.server.JettyServer.start(JettyServer.java:56)
        at com.thoughtworks.go.server.GoServer.startServer(GoServer.java:92)
        at com.thoughtworks.go.server.GoServer.go(GoServer.java:84)
        at com.thoughtworks.go.server.util.GoLauncher.main(GoLauncher.java:31)
        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 com.simontuffs.onejar.Boot.run(Boot.java:306)
        at com.simontuffs.onejar.Boot.main(Boot.java:159)
Caused by: java.lang.RuntimeException: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
        at com.thoughtworks.go.service.ConfigRepository.cleanAndResetToMaster(ConfigRepository.java:352)
        at com.thoughtworks.go.service.ConfigRepository.initialize(ConfigRepository.java:85)
        at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:100)
        ... 29 more
Caused by: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
        at org.eclipse.jgit.api.ResetCommand.call(ResetCommand.java:162)
        at com.thoughtworks.go.service.ConfigRepository.cleanAndResetToMaster(ConfigRepository.java:345)
        ... 31 more
srinivasupadhya commented 8 years ago

This can be safely ignored. Happens when the Config git repository isn't initialized. There could be someother error below if the server hasn't started.

jdsubz commented 8 years ago

Thanks for replying. Unfortunately, there doesn't seem to be any other error information. Here is an output when starting the GO server via the script server.sh

[mulrdgo@mulrd1gog go-server-14.2.0]$ . server.sh
Reading change scripts from directory /data/go/db/h2deltas...
dbdeploy v2.11
Creating index SYS:SYS_ID 0%
Creating index SYS:SYS_ID 0%
Changes currently applied to database:
  1..90, 221001, 230001..230009, 240001, 240002, 300001..300011, 1202001..1202003, 1203002..1203005, 1301001, 1302001, 1303001..1303004, 1304001, 1401001
Scripts available:
  1..90, 221001, 230001..230009, 240001, 240002, 300001..300011, 1202001..1202003, 1203002..1203005, 1301001, 1302001, 1303001..1303004, 1304001, 1401001
To be applied:
  (none)
Creating index SYS:SYS_ID 0%
Creating index SYS:SYS_ID 0%
Warning:  org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
Warning:  org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
Warning:  org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
Warning:  org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
Warning:  org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser: Property 'http://www.oracle.com/xml/jaxp/properties/entityExpansionLimit' is not recognized.
Compiler warnings:
  WARNING:  'org.apache.xerces.jaxp.SAXParserImpl: Property 'http://javax.xml.XMLConstants/property/accessExternalDTD' is not recognized.'
log4j:WARN No appenders could be found for logger (com.thoughtworks.go.server.util.H2EventListener).
log4j:WARN Please initialize the log4j system properly.
ERROR: Failed to start Go server. Please check the logs.
java.lang.RuntimeException: Failed to start Go server.
 at com.thoughtworks.go.server.GoServer.startServer(GoServer.java:98)
 at com.thoughtworks.go.server.GoServer.go(GoServer.java:84)
 at com.thoughtworks.go.server.util.GoLauncher.main(GoLauncher.java:31)
 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 com.simontuffs.onejar.Boot.run(Boot.java:306)
 at com.simontuffs.onejar.Boot.main(Boot.java:159)
Caused by: java.lang.RuntimeException: java.lang.RuntimeException: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
 at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:132)
 at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:53)
 at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
 at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:327)
 at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:941)
 at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:475)
 at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:383)
 at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
 at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
 at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548)
 at org.mortbay.jetty.servlet.Context.startContext(Context.java:136)
 at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1250)
 at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517)
 at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:467)
 at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
 at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:152)
 at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
 at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
 at org.mortbay.jetty.Server.doStart(Server.java:224)
 at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
 at com.thoughtworks.go.server.JettyServer.start(JettyServer.java:56)
 at com.thoughtworks.go.server.GoServer.startServer(GoServer.java:92)
 ... 8 more
Caused by: java.lang.RuntimeException: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
 at com.thoughtworks.go.service.ConfigRepository.cleanAndResetToMaster(ConfigRepository.java:352)
 at com.thoughtworks.go.service.ConfigRepository.initialize(ConfigRepository.java:85)
 at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:100)
 ... 29 more
Caused by: org.eclipse.jgit.api.errors.JGitInternalException: Invalid ref HEAD specified
 at org.eclipse.jgit.api.ResetCommand.call(ResetCommand.java:162)
 at com.thoughtworks.go.service.ConfigRepository.cleanAndResetToMaster(ConfigRepository.java:345)
 ... 31 more
arvindsv commented 8 years ago

On Tue, Sep 1, 2015 at 11:33 PM, jd notifications@github.com wrote:

Thanks for replying. Unfortunately, there doesn't seem to be any other error information. Here is an output when starting the GO server via the script server.sh

What do you mean by "fails to start"? Is the Java process running, or does it die? Are you running this on a VM? Maybe somewhere on a cloud?

FredrikWendt commented 8 years ago

This might be similar to what I'm seeing: docker image gocd/gocd-server takes ~20 minutes before the UI is available. Discussing this in gitter.

FredrikWendt commented 8 years ago

My problem was most certainly IO bound: http://fredrik.wendt.se/2015/09/11/cloudy-performance-in-cloud/ Sorry for the noise.

jdsubz commented 8 years ago

Unfortunately, I have not been able to get to this problem until now. We are keen to use GO for all our CI/CD requirements but unfortunately, here is what I get when trying to start the GO server. FYI, GO server is running on my local RedHat (v6.5, 64-bit Linux) instance.
I installed the server using the ZIP option. The error seems to be related to jetty server that is embedded with GO.

Causing ERROR details: Caused by: java.lang.RuntimeException: Assets directory does not exist /apps/go-server-15.2.0/work/jetty-0.0.0.0-8153-cruise.war-_go-any-/webapp/null/public/assets at com.thoughtworks.go.server.service.RailsAssetsService.initialize(RailsAssetsService.java:57) at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:131) ... 37 more

Any help would be very much appreciated. Thanks in advance.

jyotisingh commented 8 years ago

@jdsubz - You seem to have closed the issue, does that mean you got it resolved? If not, what command do you use to start up the server? Could you also share the go-server log.

jdsubz commented 8 years ago

This issue was not meant to be closed. Here is what I did at the command line to start the GO server on Linux RedHat. [go-server-15.2.0]$ . server.sh

Attached are logs:

  1. The output on the console and
  2. The output in log go-server.log Thanks for trying to help. console-output.txt go-server-log.txt
ketan commented 8 years ago

Did you by any chance extract the zip file as a user other than the user executing the app(mulrdgo)?

Can you run sudo chown -R mulrdgo.mulrdgo /apps/go-server-15.2.0 to make sure that the ownership is set correctly?

arvindsv commented 8 years ago

I wonder if the problem is that you ran it as:

. server.sh

Can you try running it as:

bash server.sh

OR

chmod +x server.sh
./server.sh
jdsubz commented 8 years ago

Thanks everyone for your comments but unfortunately the problem did not resolve after trying out what you all suggested.

arvindsv commented 8 years ago

:( So weird. @jyotisingh, can you think of any reason rails.root can be null? It should be picked up from the web.xml but it seems to be null.

ketan commented 8 years ago

Is RAILS_ROOT defined as an environment?

Can you provide the output of env after scrubbing any sensitive information?

jdsubz commented 8 years ago

RAILS_ROOT is not defined in my environment. Attached is the output of env. Thanks env.txt

ketan commented 8 years ago

That looks rather weird. Could you hop onto the gitter channel so we can help you out?

jdsubz commented 8 years ago

Unfortunately, we don't have access to gitter channel from work environment. :(

ketan commented 8 years ago

I see a bunch of sudo and ansible environment variables, can you tell us how you're running your go server startup script?

Is there a reason you're not using the rpm/deb package?

ketan commented 8 years ago

Here's how I'd expect to run this —

bob@mulrd1gog $ sudo su - mulrdgo # the `su - ` is important
mulrdgo@mulrd1gog ~ $ cd go-server-15.2.0
mulrdgo@mulrd1gog ~/go-server-15.2.0 $ bash -x ./server.sh

Once you run this, and things still fail. Can you provide the complete output that you see (again, make sure to scrub any sensitive information)

jdsubz commented 8 years ago

Here are the console output and go server logs. go-server-log.txt console-output.txt

Thanks a lot

jdsubz commented 8 years ago

hi Ketan, did you have any more thoughts based on the logs ? Thanks

ketan commented 8 years ago 
java.lang.NullPointerException
    at com.thoughtworks.go.server.AssetsContextHandler.init(AssetsContextHandler.java:49)
Caused by: java.lang.RuntimeException: Assets directory does not exist /apps/go-server-15.2.0/work/jetty-0.0.0.0-8153-cruise.war-_go-any-/webapp/null/public/assets
    at com.thoughtworks.go.server.service.RailsAssetsService.initialize(RailsAssetsService.java:57)
java.lang.RuntimeException: java.lang.RuntimeException: Assets directory does not exist /apps/go-server-15.2.0/work/jetty-0.0.0.0-8153-cruise.war-_go-any-/webapp/null/public/assets
    at com.thoughtworks.go.server.initializers.ApplicationInitializer.onApplicationEvent(ApplicationInitializer.java:137)

Based on the log statements above, and the code here, here it appears that the value of servletContext.getInitParameter("rails.root") is resolving to null. We're not sure why this is happening.

Can you confirm that —

jdsubz commented 8 years ago

Yes, I am running stable build downloaded from the location you mentioned. Yes, webdefault.xml is extracted into the folder you mentioned. Yes, the ownership is correct. See below drwxr-xr-x. 9 mulrdgo mulrdgo 4096 Nov 16 10:37 go-server-15.2.0

Thanks

ketan commented 8 years ago

Yes, webdefault.xml is extracted into the folder you mentioned.

Can you provide the contents here web.xml AND webdefault.xml?

Also could you email "support_at_thoughtworks.com" referencing this issue and providing a time of your convenience when someone can talk to you?

jdsubz commented 8 years ago

Here you go. I have just added .txt extensions to them.

web.xml.txt webdefault-jetty6.xml.txt webdefault.xml.txt

jyotisingh commented 8 years ago

@jdsubz - the web.xml you have uploaded is significantly different from the one that is packaged along with Go v15.2. Also, the entry in web.xml that sets rails.root is missing altogether. I have verified that 15.2 zip installers does have the right version of file packaged along with it. My guess is that you might not have the right version of the installers. Could you verify the checksum of the zip installer you have with the one published on go.cd. Go server Zip installer:

Server MD5 3f5d0ef2b1df5503f45f67b9c94c19a8
Server SHA1 ad816d1866c37c4a01d0714e011220e5b8778ed6
jdsubz commented 8 years ago

Thanks for your feedback. The checksum matches. Perhaps my installation (via Ansible) is corrupting the files. I will investigate further.

jdsubz commented 8 years ago

Thanks to everyone for your feedback. I will have to pause this thread here for a month as I will be away. Unfortunately, I have not been able to resolve the issue as yet but I will revisit the issue in a month which is when we require the GO servers.