stale connections in gerrit mysql connection pool

Bug #978199 reported by James E. Blair
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Core Infrastructure
Fix Released
Low
aeva black

Bug Description

Now that we use a connection pool with gerrit, if it sits idle for a long period of time, we see this:

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 57,610,636 milliseconds ago. The last packet sent successfully to the server was 57,610,636 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.

Gerrit in production is rarely (if ever) idle, so we're not likely to see it in practice. And if it does happen, a few reloads will cycle through all the dead connections and it will start working again. But it would still be nice to fix the problem. Full traceback:

Full traceback:

[2012-04-10 17:08:36,393] WARN / : Error in allQueryNext
com.google.gwtorm.client.OrmException: fetch failure on changes
        at com.google.gwtorm.schema.sql.SqlDialect.convertError(SqlDialect.java:150)
        at com.google.gwtorm.jdbc.JdbcAccess.convertError(JdbcAccess.java:298)
        at com.google.gwtorm.jdbc.JdbcAccess.queryList(JdbcAccess.java:145)
        at com.google.gerrit.reviewdb.Change_Access_changes_GwtOrm$$0.allOpenNext(Unknown Source)
        at com.google.gerrit.server.query.change.ChangeQueryRewriter$8.scan(ChangeQueryRewriter.java:277)
        at com.google.gerrit.server.query.change.ChangeQueryRewriter$PaginatedSource.scan(ChangeQueryRewriter.java:616)
        at com.google.gerrit.server.query.change.ChangeQueryRewriter$ChangeSource.read(ChangeQueryRewriter.java:579)
        at com.google.gerrit.server.query.change.AndSource.read(AndSource.java:94)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl.searchQuery(ChangeListServiceImpl.java:170)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl.access$100(ChangeListServiceImpl.java:56)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl$6.query(ChangeListServiceImpl.java:137)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl$QueryNext.run(ChangeListServiceImpl.java:339)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl$QueryNext.run(ChangeListServiceImpl.java:321)
        at com.google.gerrit.httpd.rpc.BaseServiceImplementation.run(BaseServiceImplementation.java:63)
        at com.google.gerrit.httpd.rpc.ChangeListServiceImpl.allQueryNext(ChangeListServiceImpl.java:133)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        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: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.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.RequireSslFilter.doFilter(RequireSslFilter.java:68)
        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.FilterDefinition.doFilter(FilterDefinition.java:134)
        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:679)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 57,610,636 milliseconds ago. The last packet sent successfully to the server was 57,610,636 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:532)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3313)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1940)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2109)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2642)
        at com.mysql.jdbc.StatementImpl.executeSimpleNonQuery(StatementImpl.java:1544)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2215)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
        at com.google.gwtorm.jdbc.JdbcAccess.queryList(JdbcAccess.java:133)
        ... 59 more
Caused by: java.net.SocketException: Broken pipe
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3294)
        ... 67 more

Tags: gerrit
Revision history for this message
Monty Taylor (mordred) wrote :

I'm pretty sure we fixed this one by modifying a jdbc connection option, no?

Changed in openstack-ci:
status: Triaged → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.