SSH Server doesn't start

Miscellaneous

On this page

Related content

  • No related content found

Still need help?

The Atlassian Community is here for you.

Ask the community

Symptoms

Stash comes up but the SSH server won't start.

We mapped out a few situations in which that could happen.

Issue #1:

The following appears in the atlassian-stash.log:

2015-03-15 21:45:39,968 INFO  [spring-startup]  c.a.s.i.server.BuildInfoLogger Starting Stash 3.7.1 (b3e3aaf built on Tue Mar 10 05:08:08 CET 2015)
2015-03-15 21:45:39,978 INFO  [spring-startup]  c.a.s.i.server.BuildInfoLogger JVM: Oracle Corporation Java HotSpot(TM) 64-Bit Server VM 1.7.0_17-b02
2015-03-15 21:45:39,992 INFO  [spring-startup]  c.a.s.internal.home.HomeLockAcquirer Successfully acquired lock on home directory /var/atlassian/application-data/stash
2015-03-15 21:45:44,176 INFO  [spring-startup]  c.a.s.internal.home.HomeLockAcquirer Successfully acquired lock on home directory /var/atlassian/application-data/stash/shared
...
...
...
2015-03-15 21:47:23,040 ERROR [spring-startup]  o.s.o.e.i.u.c.RunnableTimedExecution Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.stash.ssh, config=osgibundle:/META-INF/spring/*.xml) did not finish in 10000ms; consider taking a snapshot and then shutdown the VM in case the thread still hangs
2015-03-15 21:47:23,063 ERROR [spring-startup]  c.a.plugin.manager.PluginEnabler Unable to start the following plugins due to timeout while waiting for plugin to enable: com.atlassian.stash.ssh-plugin
...
...
...
2015-03-15 21:47:26,966 ERROR [ThreadPoolAsyncTaskExecutor::Thread 12]  o.s.b.f.s.DefaultListableBeanFactory Destroy method on bean with name 'sshScmProtocol_osgiService' threw an exception
java.lang.IllegalStateException: Invalid BundleContext.
	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:457) ~[org.apache.felix.framework-3.2.2.jar:na]
	at com.atlassian.stash.plugin.util.EventListenerBeanRegistrar.postProcessBeforeDestruction(EventListenerBeanRegistrar.java:50) ~[stash-plugin-util-3.7.1.jar:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_17]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_17]
	... 30 frames trimmed
2015-03-15 21:47:26,971 ERROR [ThreadPoolAsyncTaskExecutor::Thread 12]  o.s.b.f.s.DefaultListableBeanFactory Destroy method on bean with name 'sshScmProtocol' threw an exception
java.lang.IllegalStateException: Invalid BundleContext.
	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:457) ~[org.apache.felix.framework-3.2.2.jar:na]
	at com.atlassian.stash.plugin.util.EventListenerBeanRegistrar.postProcessBeforeDestruction(EventListenerBeanRegistrar.java:50) ~[stash-plugin-util-3.7.1.jar:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_17]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_17]
	... 30 frames trimmed
2015-03-15 21:47:26,973 ERROR [ThreadPoolAsyncTaskExecutor::Thread 12]  o.s.b.f.s.DefaultListableBeanFactory Destroy method on bean with name 'sshKeyService_osgiService' threw an exception
java.lang.IllegalStateException: Invalid BundleContext.
	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:457) ~[org.apache.felix.framework-3.2.2.jar:na]
	at com.atlassian.stash.plugin.util.EventListenerBeanRegistrar.postProcessBeforeDestruction(EventListenerBeanRegistrar.java:50) ~[stash-plugin-util-3.7.1.jar:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_17]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_17]
	... 30 frames trimmed
2015-03-15 21:47:26,976 ERROR [ThreadPoolAsyncTaskExecutor::Thread 12]  o.s.b.f.s.DefaultListableBeanFactory Destroy method on bean with name 'sshConfigurationService_osgiService' threw an exception
java.lang.IllegalStateException: Invalid BundleContext.
	at org.apache.felix.framework.BundleContextImpl.checkValidity(BundleContextImpl.java:457) ~[org.apache.felix.framework-3.2.2.jar:na]
	at com.atlassian.stash.plugin.util.EventListenerBeanRegistrar.postProcessBeforeDestruction(EventListenerBeanRegistrar.java:50) ~[stash-plugin-util-3.7.1.jar:na]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_17]
	at java.lang.Thread.run(Thread.java:722) [na:1.7.0_17]
	... 30 frames trimmed

 

The following appears in the catalina.out:

15-Mar-2015 21:13:08.554 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [65,569] milliseconds.
(...)
15-Mar-2015 21:25:46.539 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [59,369] milliseconds.
(...)
15-Mar-2015 21:38:40.935 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [97,334] milliseconds.
(...)
15-Mar-2015 21:45:36.446 INFO [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [107,258] milliseconds.
(...)

 

Issue #2:

The following appears in the atlassian.stash.log

2015-06-10 00:26:21,021 ERROR [ThreadPoolAsyncTaskExecutor::Thread 22]  c.a.plugin.osgi.factory.OsgiPlugin Unable to start the plugin container for plugin 'com.atlassian.stash.ssh-plugin'
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sshServer' defined in URL [bundle://49.0:0/META-INF/spring/atlassian-plugins-components.xml]: Instantiation of bean failed; nested exception is org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [com.atlassian.stash.internal.ssh.server.SshServer]: Constructor threw exception; nested exception is java.lang.IllegalStateException: BouncyCastle is not registered as expected
	at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:254) ~[spring-beans-4.1.6.RELEASE.jar:4.1.6.RELEASE]
	at java.security.AccessController.doPrivileged(Native Method) ~[na:1.8.0_40]
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:728) ~[spring-context-4.1.6.RELEASE.jar:4.1.6.RELEASE]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_40]
	at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_40]
	... 17 frames trimmed
Caused by: org.springframework.beans.BeanInstantiationException: Could not instantiate bean class [com.atlassian.stash.internal.ssh.server.SshServer]: Constructor threw exception; nested exception is java.lang.IllegalStateException: BouncyCastle is not registered as expected
	at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:115) ~[spring-beans-4.1.6.RELEASE.jar:4.1.6.RELEASE]
	... 5 common frames omitted
Caused by: java.lang.IllegalStateException: BouncyCastle is not registered as expected
	at com.google.common.base.Preconditions.checkState(Preconditions.java:145) ~[guava-11.0.2-atlassian-02.jar:na]
	at com.atlassian.stash.internal.ssh.server.SshServer.<init>(SshServer.java:61) ~[na:na]
	at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:100) ~[spring-beans-4.1.6.RELEASE.jar:4.1.6.RELEASE]
	... 5 common frames omitted

Cause

Issue #1:

From catalina.out, we can see a long time being taken to create SecureRandom.

The problem is down to the /dev/random device having insufficient entropy when Stash is started and because this device blocks until sufficient entropy is attained in the system it blocks both the Tomcat start-up process and the SSH plugin start-up process.

Issue #2:

The presence of the following JAVA option will cause this to occur;

-Dsun.net.spi.nameservice.provider.1=dns,sun


Resolution

Issue #1:

The best workaround is to specify the /dev/urandom device as the preferred egd or entropy gathering daemon. This is done by editing setenv.sh and adding -Djava.security.egd=file:/dev/./urandom to JVM_SUPPORT_RECOMMENDED_ARGS and and restarting the Stash service.

#
# Occasionally Atlassian Support may recommend that you set some specific JVM arguments.  You can use this variable
# below to do that.
#
JVM_SUPPORT_RECOMMENDED_ARGS="-Djava.security.egd=file:/dev/./urandom"

Please note that the dots and slashed in java.security.egd must be exactly as above (due to this Java not-quite-a-bug): https://bugs.openjdk.java.net/browse/JDK-6202721

For a definitive solution, you should try to work out why your system has insufficient entropy at the point Stash is launched. This will probably be tightly coupled to what else is running on in your virtual machine before Stash is started.

 

Issue #2:

Remove the option and restart the Stash service.

Last modified on Apr 6, 2016

Was this helpful?

Yes
No
Provide feedback about this article

Related content

  • No related content found
Powered by Confluence and Scroll Viewport.