Issue 1066: Guice provision errors: Cannot open ReviewDB
Status:  New
Owner: ----
Reported by jhans...@myyearbook.com, Jul 26, 2011
Affected Version:

2.2.1

What steps will reproduce the problem?

It is unknown what steps caused the problem, but it started overnight.  Gerrit's UI stops responding at some point, and displays a "502 Proxy Error".  Checking the log shows the excerpt below.  Restarting Gerrit will bring it back up, but this is the second time this morning that this has happened.  Is this related to a bad changeset?  How can we find out?


Please provide any additional information below.

[2011-07-26 09:54:21,266] WARN  / : Error in changeDetail
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 3 at com.google.gerrit.httpd.rpc.changedetail.ChangeDetailFactory.<init>(ChangeDetailFactory.java:78)
  while locating com.google.gerrit.httpd.rpc.changedetail.ChangeDetailFactory

1 error
        at com.google.inject.InjectorImpl$4.get(InjectorImpl.java:767)
        at com.google.inject.assistedinject.FactoryProvider2.invoke(FactoryProvider2.java:218)
        at $Proxy85.create(Unknown Source)
        at com.google.gerrit.httpd.rpc.changedetail.ChangeDetailServiceImpl.changeDetail(ChangeDetailServiceImpl.java:47)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.google.gwtjsonrpc.server.MethodHandle.invoke(MethodHandle.java:91)
        at com.google.gwtjsonrpc.server.JsonServlet.doService(JsonServlet.java:382)
        at com.google.gwtjsonrpc.server.JsonServlet.service(JsonServlet.java:268)
        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.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.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:619)
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.java:43)
        at com.google.gerrit.server.config.RequestScopedReviewDbProvider.get(RequestScopedReviewDbProvider.java:27)
        at com.google.inject.BoundProviderFactory.get(BoundProviderFactory.java:58)
        at com.google.inject.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:45)
        at com.google.inject.InjectorImpl.callInContext(InjectorImpl.java:811)
        at com.google.inject.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:42)
        at com.google.inject.servlet.ServletScopes$1$1.get(ServletScopes.java:53)
        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)
        ... 47 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.open(Database.java:185)
        ... 62 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)
        ... 64 more
Jul 26, 2011
#1 jhans...@myyearbook.com
Just ran across this thread[1], which indicates it may have been a slow LDAP server (we do use LDAP authentication).  I'll continue looking, and consider the database.poolLimit increase suggested in that thread.

[1]: http://groups.google.com/group/repo-discuss/browse_thread/thread/807452afea1230b9
Jul 27, 2011
#2 jhans...@myyearbook.com
To add a little more information about this...  I did make the poolLimit change, and I haven't seen the issue again so far.  But I found out today that around the time this was happening yesterday, one of our developers was pushing a massive 5.8MB change (all deleting code, not binary data).  I believe the db connection issue was a direct result of that 5.8MB commit that he was pushing, but I'm not sure how I can prove that.  I'm going to open a separate issue about the size of that commit breaking Gerrit.
Jul 27, 2011
#3 jhans...@myyearbook.com
While gathering information for the new issue (#1068), I found out the 5.8MB was just what shows up in "git show" (i.e., no binary data).  With a full binary patch from "git format-patch", the patch comes out to 64MB.