Issue 1679: gerrit 2.5 looses connection to postgres database
Status:  Invalid
Owner: ----
Closed:  Dec 2012
Reported by sp3...@gmail.com, Nov 23, 2012
Affected Version: v2.5

We were running v2.1.7 for 1.5 year without any problem. Yesterday we upgraded gerrit from v2.1.7 to v2.5 (only gerrit - the rest of the system is untouched). Sometimes gerrit hangs claiming it lost connection to database. DB is on the same host reached via 127.0.0.1.

During hang web interface shows:

HTTP ERROR: 500

Problem accessing /. Reason:

Guice provision errors:  1) Cannot open ReviewDb while locating com.google.gerrit.server.config.RequestScopedReviewDbProvider at com.google.gerrit.server.config.GerritRequestModule.configure(GerritRequestModule.java:68) while locating com.google.gerrit.reviewdb.server.ReviewDb  1 error

Postgres log:

2012-11-23 11:52:07 CET LOG:  unexpected EOF on client connection
2012-11-23 11:52:07 CET LOG:  unexpected EOF on client connection

Gerrit error log:

[2012-11-23 11:49:33,509] WARN  com.google.gerrit.server.account.AccountCacheImpl : Cannot load AccountState for 1000990
java.util.concurrent.ExecutionException: com.google.gwtorm.server.OrmException: Cannot open database connection
        at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:289)
        at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:276)
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:111)
        at com.google.common.util.concurrent.Uninterruptibles.getUninterruptibly(Uninterruptibles.java:132)
        at com.google.common.cache.LocalCache$Segment.getAndRecordStats(LocalCache.java:2403)
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2373)
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2335)
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2250)
        at com.google.common.cache.LocalCache.get(LocalCache.java:3985)
        at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3989)
        at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4873)
        at com.google.gerrit.server.account.AccountCacheImpl.get(AccountCacheImpl.java:83)
        at com.google.gerrit.server.IdentifiedUser.state(IdentifiedUser.java:212)
        at com.google.gerrit.server.IdentifiedUser.getEffectiveGroups(IdentifiedUser.java:264)
        at com.google.gerrit.server.project.ProjectControl.match(ProjectControl.java:403)
        at com.google.gerrit.server.project.ProjectControl.match(ProjectControl.java:396)
        at com.google.gerrit.server.project.RefControl.access(RefControl.java:413)
        at com.google.gerrit.server.project.RefControl.canPerform(RefControl.java:380)
        at com.google.gerrit.server.project.RefControl.isVisible(RefControl.java:105)
        at com.google.gerrit.server.project.ChangeControl.isRefVisible(ChangeControl.java:175)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl$3$1.isVisible(SuggestServiceImpl.java:234)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl.addSuggestion(SuggestServiceImpl.java:174)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl.suggestAccount(SuggestServiceImpl.java:143)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl.access$100(SuggestServiceImpl.java:58)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl$3.run(SuggestServiceImpl.java:238)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl$3.run(SuggestServiceImpl.java:219)
        at com.google.gerrit.httpd.rpc.BaseServiceImplementation.run(BaseServiceImplementation.java:64)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl.suggestChangeReviewer(SuggestServiceImpl.java:219)
        at sun.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at com.google.gwtjsonrpc.server.MethodHandle.invoke(MethodHandle.java:91)
        at com.google.gwtjsonrpc.server.JsonServlet.doService(JsonServlet.java:379)
        at com.google.gwtjsonrpc.server.JsonServlet.service(JsonServlet.java:265)
        at com.google.gerrit.httpd.rpc.GerritJsonServlet.service(GerritJsonServlet.java:118)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263)
        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178)
        at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gwtexpui.server.CacheControlFilter.doFilter(CacheControlFilter.java:76)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:64)
        at com.google.gerrit.httpd.AllRequestFilter$FilterProxy.doFilter(AllRequestFilter.java:57)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gerrit.httpd.RequestContextFilter.doFilter(RequestContextFilter.java:75)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118)

        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113)
        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.session.SessionHandler.doHandle(SessionHandler.java:224)
        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.session.SessionHandler.doScope(SessionHandler.java:184)
        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.content(HttpConnection.java:1069)
        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:805)
        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:218)
        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(Thread.java:679)
Caused by: com.google.gwtorm.server.OrmException: Cannot open database connection
        at com.google.gwtorm.jdbc.Database.newConnection(Database.java:129)
        at com.google.gwtorm.jdbc.JdbcSchema.<init>(JdbcSchema.java:40)
        at com.google.gerrit.reviewdb.server.ReviewDb_Schema_GwtOrm$$25.<init>(Unknown Source)
        at com.google.gerrit.reviewdb.server.ReviewDb_Schema_GwtOrm$$25_Factory_GwtOrm$$26.open(Unknown Source)
        at com.google.gwtorm.jdbc.Database.open(Database.java:121)
        at com.google.gerrit.server.account.AccountCacheImpl$ByIdLoader.load(AccountCacheImpl.java:135)
        at com.google.gerrit.server.account.AccountCacheImpl$ByIdLoader.load(AccountCacheImpl.java:120)
        at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3584)
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2372)
        ... 74 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for 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.newConnection(Database.java:127)
        ... 82 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1144)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
        ... 84 more
[2012-11-23 11:49:33,530] WARN  / : Error in suggestChangeReviewer
com.google.inject.ProvisionException: Guice provision errors:

1) Cannot open ReviewDb
  while locating com.google.gerrit.server.config.RequestScopedReviewDbProvider
  at com.google.gerrit.server.config.GerritRequestModule.configure(GerritRequestModule.java:68)
  while locating com.google.gerrit.reviewdb.server.ReviewDb

1 error
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987)
        at com.google.gerrit.httpd.rpc.BaseServiceImplementation.run(BaseServiceImplementation.java:64)
        at com.google.gerrit.httpd.rpc.SuggestServiceImpl.suggestChangeReviewer(SuggestServiceImpl.java:219)
        at sun.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:616)
        at com.google.gwtjsonrpc.server.MethodHandle.invoke(MethodHandle.java:91)
        at com.google.gwtjsonrpc.server.JsonServlet.doService(JsonServlet.java:379)
        at com.google.gwtjsonrpc.server.JsonServlet.service(JsonServlet.java:265)
        at com.google.gerrit.httpd.rpc.GerritJsonServlet.service(GerritJsonServlet.java:118)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263)
        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178)
        at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gwtexpui.server.CacheControlFilter.doFilter(CacheControlFilter.java:76)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:168)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:64)
        at com.google.gerrit.httpd.AllRequestFilter$FilterProxy.doFilter(AllRequestFilter.java:57)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.gerrit.httpd.RequestContextFilter.doFilter(RequestContextFilter.java:75)
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118)
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113)
        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.session.SessionHandler.doHandle(SessionHandler.java:224)
        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.session.SessionHandler.doScope(SessionHandler.java:184)
        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.content(HttpConnection.java:1069)
        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:805)
        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:218)
        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(Thread.java:679)
Caused by: com.google.gwtorm.server.OrmException: Cannot open database connection
        at com.google.gwtorm.jdbc.Database.newConnection(Database.java:129)
        at com.google.gwtorm.jdbc.JdbcSchema.<init>(JdbcSchema.java:40)
        at com.google.gerrit.reviewdb.server.ReviewDb_Schema_GwtOrm$$25.<init>(Unknown Source)
        at com.google.gerrit.reviewdb.server.ReviewDb_Schema_GwtOrm$$25_Factory_GwtOrm$$26.open(Unknown Source)
        at com.google.gwtorm.jdbc.Database.open(Database.java:121)
        at com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:43)
        at com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:27)
        at com.google.inject.internal.BoundProviderFactory.get(BoundProviderFactory.java:55)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.servlet.ServletScopes$1$1.get(ServletScopes.java:88)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
        at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
        at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
        ... 54 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for 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.newConnection(Database.java:127)
        ... 69 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1144)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
        ... 71 more

etc ...
Nov 23, 2012
#1 sop@google.com
This indicates either your database pool is sized too low, or there is a database connection leak in 2.5.

I would start by trying to increase database.poolLimit:

  https://gerrit-review.googlesource.com/Documentation/config-gerrit.html#database.poolLimit

If this doesn't actually solve the problem, there may be a connection leak in the 2.5 release. :-(
Status: AwaitingInformation
Dec 3, 2012
#2 sp3...@gmail.com
I increased database pool and the issue doesn't show anymore. The environment didn't change too much (same amount of commits per day as previously, etc). So this must be somehow related to the new gerrit version that for v2.1.7 default was sufficient and for v2.5 it is not.

Thanks for hint.
Dec 11, 2012
#3 sp3...@gmail.com
Hi. This issue can be closed as resolved now. I'd do that myself except that the only thing I can do here is add comments or open new 'minor' bug ;)
Dec 11, 2012
Project Member #4 edwin.ke...@gmail.com
(No comment was entered for this change.)
Status: Invalid