Gerrit 2.1.6.1 internal hang, cannot connect to reviewdb

[Chris Barrera]

We updated to the latest Java JRE last week to solve a number of
squirrely issues that seem to have gone away. Now there is a new one
not seen before:

- Parts of web ui hung, particularly not being able to open changes
- Git fetches/pulls working fine for some people but not others.

Error log shows two kinds of errors, both ultimately showing inability
to make connections to the internal gerrit DB.

Any ideas?

(both errors list below)

[2011-05-11 02:34:33,957] ERROR com.google.gerrit.sshd.BaseCommand :
Internal server error (user <REDACTED> account <REDACTED>) during git-
receive-pack '<REDACTED>'
com.google.inject.ProvisionException: Guice provision errors:

1) Cannot open ReviewDb
while locating
com.google.gerrit.server.config.RequestScopedReviewDbProvider
while locating com.google.gerrit.reviewdb.ReviewDb
for parameter 0 at
com.google.gerrit.server.git.ReceiveCommits.<init>(ReceiveCommits.java:
183)
while locating com.google.gerrit.server.git.ReceiveCommits

1 error
at com.google.inject.InjectorImpl$4.get(InjectorImpl.java:767)
at
com.google.inject.assistedinject.FactoryProvider2.invoke(FactoryProvider2.java:
218)
at $Proxy39.create(Unknown Source)
at
com.google.gerrit.sshd.commands.Receive.runImpl(Receive.java:72)
at
com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:
104)
at com.google.gerrit.sshd.AbstractGitCommand.access
$000(AbstractGitCommand.java:34)
at com.google.gerrit.sshd.AbstractGitCommand
$1.run(AbstractGitCommand.java:69)
at com.google.gerrit.sshd.BaseCommand
$TaskThunk.run(BaseCommand.java:395)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown
Source)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown
Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.access$301(Unknown Source)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.run(Unknown Source)
at com.google.gerrit.server.git.WorkQueue
$Task.run(WorkQueue.java:324)
at java.util.concurrent.ThreadPoolExecutor
$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
at java.lang.Thread.run(Unknown Source)
Caused by: com.google.gwtorm.client.OrmException: Cannot open database
connection
at com.google.gwtorm.jdbc.Database.open(Database.java:187)
at
com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.j
ava:43)
at
com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.j
ava:27)
at
com.google.inject.BoundProviderFactory.get(BoundProviderFactory.java:
58)
at com.google.inject.ProviderToInternalFactoryAdapter
$1.call(ProviderToInternalFactoryAdapter.java:4
5)
at
com.google.inject.InjectorImpl.callInContext(InjectorImpl.java:811)
at
com.google.inject.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:
42)
at com.google.gerrit.sshd.SshScope$Context.get(SshScope.java:
78)
at com.google.gerrit.sshd.SshScope$1$1.get(SshScope.java:125)
at
com.google.inject.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:
48)
at
com.google.inject.SingleParameterInjector.inject(SingleParameterInjector.java:
42)
at
com.google.inject.SingleParameterInjector.getAll(SingleParameterInjector.java:
66)
at
com.google.inject.ConstructorInjector.construct(ConstructorInjector.java:
84)
at com.google.inject.ConstructorBindingImpl
$Factory.get(ConstructorBindingImpl.java:111)
at com.google.inject.InjectorImpl$4$1.call(InjectorImpl.java:
758)
at
com.google.inject.InjectorImpl.callInContext(InjectorImpl.java:804)
at com.google.inject.InjectorImpl$4.get(InjectorImpl.java:754)
... 16 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a
connection, pool error Timeout waiting f
or idle object
at
org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:
114)
at
org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:
1044)
at com.google.gwtorm.jdbc.Database.open(Database.java:185)
... 32 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle
object
at
org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:
1134)
at
org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:
106)
... 34 more


[2011-05-11 02:35:09,616] ERROR
com.google.gerrit.httpd.auth.container.HttpLoginServlet : Unable to
authenticate user "<REDACTED>"
com.google.gerrit.server.account.AccountException: Authentication
error
at
com.google.gerrit.server.account.AccountManager.authenticate(AccountManager.java:
133)
at
com.google.gerrit.httpd.auth.container.HttpLoginServlet.doGet(HttpLoginServlet.java:
123)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:
617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:
717)
at
com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:
216)
at
com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:
141)
at
com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:
93)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
63)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
134)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
134)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
134)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.gwtexpui.server.CacheControlFilter.doFilter(CacheControlFilter.java:
76)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
129)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
134)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.gerrit.httpd.RequestCleanupFilter.doFilter(RequestCleanupFilter.java:
54)
at
com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:
129)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:
59)
at
com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:
122)
at
com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:110)
at org.eclipse.jetty.servlet.ServletHandler
$CachedChain.doFilter(ServletHandler.java:1322)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:
473)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:
921)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:
403)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:
856)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:
117)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:
114)
at org.eclipse.jetty.server.Server.handle(Server.java:352)
at
org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:
596)
at org.eclipse.jetty.server.HttpConnection
$RequestHandler.headerComplete(HttpConnection.java:1052)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:
590)
at
org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at
org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:
426)
at
org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:
510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access
$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint
$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool
$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Unknown Source)
Caused by: com.google.gwtorm.client.OrmException: Cannot open database
connection
at com.google.gwtorm.jdbc.Database.open(Database.java:187)
at
com.google.gerrit.server.account.AccountManager.authenticate(AccountManager.java:
108)
... 41 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a
connection, pool error Timeout waiting f
or idle object
at
org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:
114)
at
org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:
1044)
at com.google.gwtorm.jdbc.Database.open(Database.java:185)
... 42 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle
object
at
org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:
1134)
at
org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:
106)
... 44 more

[Sasa Zivkov]

On Wed, May 11, 2011 at 8:38 PM, Chris Barrera <wildw...@gmail.com> wrote:

We updated to the latest Java JRE last week to solve a number of
squirrely issues that seem to have gone away. Now there is a new one
not seen before:

- Parts of web ui hung, particularly not being able to open changes
- Git fetches/pulls working fine for some people but not others.

Error log shows two kinds of errors, both ultimately showing inability
to make connections to the internal gerrit DB.

Any ideas?

 

We had similar issues few days ago. In our case we upgraded to 2.1.7-rc0.
We also saw the same exception as you reported:
Timeout waiting for idle object at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114)
...
We found out that a slow LDAP server (or whatever you are using for authentication)
can cause exactly this symptom i.e. exhausted DB connection pool.
With default Gerrit configuration this can happen because:
- default number of worker threads (25) is larger than the DB connection pool size (8)
- each request implicitly allocates one DB connection
If a request blocks waiting on an authentication request it also keeps the DB connection allocated.

Configuring the connection pool size (database.poolLimit) to a number larger than
the total number of worker threads (httpd.maxThreads + sshd.threads) will then report
a better error message (Service Unavailable) to clients before the DB connection pool
gets exhausted.
 

Sasa Zivkov