Crowd server stopping unexpectedly

[Gael Martin]

Hi 

Our crowd server stopped suddenly few times during last 2 days.

I found the following logs, anyone able to help?

2017-07-10 16:01:32,287 http-bio-8095-exec-25 INFO [atlassian.johnson.filters.JohnsonFilter] The application is not yet setup. Redirecting request from '/console/index.jsp' to '/console/setup/selectsetupstep
2017-07-10 16:02:44,840 http-bio-8095-exec-7 INFO [atlassian.johnson.filters.JohnsonFilter] The application is not yet setup. Redirecting request from '/console/index.jsp' to '/console/setup/selectsetupstep.
2017-07-10 16:03:06,788 http-bio-8095-exec-11 INFO [atlassian.johnson.filters.JohnsonFilter] The application is not yet setup. Redirecting request from '/console/index.jsp' to '/console/setup/selectsetupstep
2017-07-10 16:03:25,828 localhost-startStop-2 INFO [ContainerBase.[Catalina].[localhost].[/crowd]] org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
2017-07-10 16:03:25,832 localhost-startStop-2 INFO [com.atlassian.crowd.startup] Stopping Crowd

Many thanks

[Ann Worley]

I understand Crowd has recently stopped running repeatedly. Please let me know more.

• When it stops, is the Java process still running?
• Is there any error in the browser or is it just very slow to respond?
• Is the console slow or inaccessible, or does Crowd just stop authenticating users?
• What version of Crowd do you run?

The error messages you included are INFO messages that appear to be from the Crowd setup. I was not able to find a reason for the crashes from those entries.

Please check for ERROR or WARN messages in the following logs:

• <crowd-home>/logs/atlassian-crowd.log
• <crowd-install>/apache-tomcat/logs/catalina.out

I look forward to hearing more about the Crowd performance issues you are experiencing.

[Gael Martin]

Hi Ann

thanks for the reply.

• I'm not sure Java running or not at that time.
• There was no error in the browser
• Crowd just stopped authenticating users
• Crowd Version: 2.12.0 

Please find the logs

2017-10-11 09:22:56,162 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:22:56,163 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShuttingDownEvent@32a43255] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@1324c226]
2017-10-11 09:23:06,275 localhost-startStop-2 ERROR [internal.util.concurrent.RunnableTimedExecution] Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.analytics.client, 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
2017-10-11 09:23:26,324 Gemini Blueprint context shutdown thread1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:26,324 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:26,328 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:26,330 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:36,293 Gemini Blueprint context shutdown thread1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:36,293 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:36,295 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:36,296 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 12:43:55,436 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@1789573d] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@29722bf1]
2017-10-11 17:12:04,464 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@6b4982f4] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@29722bf1]

2017-10-11 09:22:56,145 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3387fbd2 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:22:56,146 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:22:56,162 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:22:56,308 Gemini Blueprint context shutdown thread1 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:06,276 localhost-startStop-2 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:26,323 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@58216615 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:26,324 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:23:26,323 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#0 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@68cba172 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:26,324 Gemini Blueprint context shutdown thread1 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:26,324 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:26,324 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#0 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:23:26,327 localhost-startStop-2 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:26,331 Gemini Blueprint context shutdown thread1 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:36,292 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@50b21fbf -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:36,293 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:23:36,293 Gemini Blueprint context shutdown thread1 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:36,293 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null

Catalina out
2017-10-11 09:22:56,162 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:22:56,163 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShuttingDownEvent@32a43255] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@1324c226]
2017-10-11 09:23:06,275 localhost-startStop-2 ERROR [internal.util.concurrent.RunnableTimedExecution] Closing runnable for context NonValidatingOsgiBundleXmlApplicationContext(bundle=com.atlassian.analytics.client, 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
2017-10-11 09:23:26,324 Gemini Blueprint context shutdown thread1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:26,324 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
ERROR: Bundle com.atlassian.crowd.crowd-sal [35] EventDispatcher: Error during dispatch. (org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Could not open connection)
ERROR: Bundle com.atlassian.crowd.crowd-sal [35] EventDispatcher: Error during dispatch. (org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Could not open connection)
2017-10-11 09:23:26,328 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:26,330 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:36,293 Gemini Blueprint context shutdown thread1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
2017-10-11 09:23:36,293 localhost-startStop-2 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!
ERROR: Bundle com.atlassian.crowd.crowd-sal [35] EventDispatcher: Error during dispatch. (org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Could not open connection)
ERROR: Bundle com.atlassian.crowd.crowd-sal [35] EventDispatcher: Error during dispatch. (org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.exception.GenericJDBCException: Could not open connection)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)2017-10-11 09:23:36,295 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 09:23:36,296 FelixDispatchQueue ERROR [osgi.container.felix.FelixOsgiContainerManager] Framework error in bundle com.atlassian.crowd.crowd-sal
2017-10-11 12:43:55,436 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@1789573d] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@29722bf1]
2017-10-11 17:12:04,464 localhost-startStop-2 ERROR [atlassian.event.internal.AsynchronousAbleEventDispatcher] There was an exception thrown trying to dispatch event [com.atlassian.plugin.event.events.PluginFrameworkShutdownEvent@6b4982f4] from the invoker [com.atlassian.plugin.event.impl.MethodSelectorListenerHandler$1$1@29722bf1]


2017-10-11 09:22:56,145 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3387fbd2 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:22:56,146 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:22:56,162 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:22:56,308 Gemini Blueprint context shutdown thread1 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:06,276 localhost-startStop-2 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:26,323 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@58216615 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:26,324 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:23:26,323 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#0 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@68cba172 -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:26,324 Gemini Blueprint context shutdown thread1 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:26,324 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:26,324 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#0 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
 at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:372)2017-10-11 09:23:26,327 localhost-startStop-2 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:26,331 Gemini Blueprint context shutdown thread1 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:23:36,292 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@50b21fbf -- Acquisition Attempt Failed!!! Clearing pending acquires. While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception:
2017-10-11 09:23:36,293 C3P0PooledConnectionPoolManager[identityToken->1bqrq4q9qzdy4r49ywu4o|74aa0426]-HelperThread-#1 WARN [mchange.v2.resourcepool.BasicResourcePool] Having failed to acquire a resource, com.mchange.v2.resourcepool.BasicResourcePool@53e8a001 is interrupting all Threads waiting on a resource to check out. Will try again in response to new client requests.
2017-10-11 09:23:36,293 Gemini Blueprint context shutdown thread1 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:36,293 localhost-startStop-2 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 0, SQLState: null
2017-10-11 09:23:36,295 localhost-startStop-2 WARN [sal.core.lifecycle.DefaultLifecycleManager] Notifying with LifecycleAware.onStop() on service unregister
2017-10-11 09:25:41,742 localhost-startStop-1 WARN [org.openid4java.server.RealmVerifier] RP discovery / realm validation disabled;
2017-10-11 09:26:12,872 localhost-startStop-1 WARN [org.twdata.pkgscanner.ExportPackageListBuilder] Package Scanner found duplicates for package 'javax.activation' with different versions. Files: activation-1.1.1.jar and activation-1.1.jar
2017-10-11 09:26:12,874 localhost-startStop-1 WARN [org.twdata.pkgscanner.ExportPackageListBuilder] Package Scanner found duplicates for package 'com.atlassian.crowd' with different versions. Files: crowd-api-2.12.0.jar and atlassian-extras-3.2.jar
2017-10-11 09:26:12,875 localhost-startStop-1 WARN [org.twdata.pkgscanner.ExportPackageListBuilder] Package Scanner found duplicates for package 'javax.transaction.xa' with different versions. Files: jboss-transaction-api_1.1_spec-1.0.1.Final.jar and jta-1.1.jar
2017-10-11 09:26:12,875 localhost-startStop-1 WARN [org.twdata.pkgscanner.ExportPackageListBuilder] Package Scanner found duplicates for package 'javax.transaction' with different versions. Files: jboss-transaction-api_1.1_spec-1.0.1.Final.jar and jta-1.1.jar
2017-10-11 09:26:12,876 localhost-startStop-1 WARN [org.twdata.pkgscanner.ExportPackageListBuilder] Package Scanner found duplicates for package 'javax.xml.namespace' with different versions. Files: xml-apis-1.4.01.jar and xbean-2.2.0.jar

[Ann Worley]

Hi Gael,

It looks like your Crowd instance is running out of database connections:

2017-10-11 09:23:36,293 Gemini Blueprint context shutdown thread1 ERROR [engine.jdbc.spi.SqlExceptionHelper] Connections could not be acquired from the underlying database!

Please edit the file crowd.cfg.xml from the root of the Crowd home directory. Find this line:

 <property name="hibernate.c3p0.max_size">30</property>

and change it to allow more database connections:

 <property name="hibernate.c3p0.max_size">60</property>

Restart Crowd to pick up the changes afterward.

I look forward to hearing whether this makes the Crowd instance more stable.

Thanks,

Ann

[Gael Martin]

Thanks Ann

I will apply changes and see how it goes

Nipuna