Upgraded from 2.6.1 to 2.6.9, now Rundeck sometimes fails with "MySQLNonTransientConnectionException: Too many connections"

332 views

Skip to first unread message

Jeff Runningen

unread,

Sep 9, 2016, 1:27:37 PM9/9/16

to rundeck-discuss

After upgrading from 2.6.1 to 2.6.9, our Rundeck instance sometimes becomes unusable. Any page displays a Java stacktrace, with the root cause apparently being "com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Too many connections". Restarting the rundeckd service fixes it, temporarily.

I'm using Google Cloud SQL as the database backend. I upgraded one Rundeck server on August 30, and another on September 6. I've attached a graph that shows a large increase of database connections on those dates.

Was there a change in how Rundeck manages database connections between 2.6.1 and 2.6.9 that would cause it to open a whole lot more of them? Is this behavior configurable? Or is this simply a bug?

Here's an example stacktrace:

2016-09-09 05:16:56,077 [qtp675524964-123] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - Too many connections

2016-09-09 05:16:56,103 [qtp675524964-123] ERROR org.codehaus.groovy.grails.web.errors.GrailsExceptionResolver - MySQLNonTransientConnectionException occurred when processing request

: [GET] /

Too many connections. Stacktrace follows:

org.hibernate.exception.JDBCConnectionException: could not prepare statement

at rundeck.services.DbStorageService.listDirectory(DbStorageService.groovy:183)

at com.dtolabs.rundeck.core.storage.ResolvedExtTree.listDirectory(ResolvedExtTree.java:62)

at org.rundeck.storage.impl.DelegateTree.listDirectory(DelegateTree.java:55)

at org.rundeck.storage.conf.ListenerTree.listDirectory(ListenerTree.java:81)

at org.rundeck.storage.impl.DelegateTree.listDirectory(DelegateTree.java:55)

at org.rundeck.storage.impl.StringToPathTree.listDirectory(StringToPathTree.java:50)

at rundeck.services.ConfigStorageService.$tt__listDirPaths(ConfigStorageService.groovy:55)

at rundeck.services.AuthorizationService.loadStoredPolicies(AuthorizationService.groovy:133)

at rundeck.services.AuthorizationService.getStoredPolicies(AuthorizationService.groovy:116)

at rundeck.services.AuthorizationService.getRoleList(AuthorizationService.groovy:66)

at rundeck.services.FrameworkService.getFrameworkRoles(FrameworkService.groovy:654)

at org.rundeck.web.infosec.ContainerRoleSource.getUserRoles(ContainerRoleSource.groovy:19)

at rundeck.filters.AuthorizationFilters$_createAuthSubject_closure2.doCall(AuthorizationFilters.groovy:166)

at rundeck.filters.AuthorizationFilters.createAuthSubject(AuthorizationFilters.groovy:164)

at rundeck.filters.AuthorizationFilters$_closure1_closure4_closure7.doCall(AuthorizationFilters.groovy:63)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:565)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1360)

at grails.plugin.cache.web.filter.PageFragmentCachingFilter.doFilter(PageFragmentCachingFilter.java:198)

at grails.plugin.cache.web.filter.AbstractFilter.doFilter(AbstractFilter.java:63)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1331)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:477)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:539)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1031)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:186)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:965)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)

at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:288)

at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:115)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1331)

at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1331)

at com.google.servlet.GoogleSsoFilter.doFilter(GoogleSsoFilter.java:106)

at com.google.servlet.AbstractHttpFilter.doFilter(AbstractHttpFilter.java:30)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1331)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:477)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:521)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1031)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:406)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:186)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:965)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111)

at org.eclipse.jetty.server.Server.handle(Server.java:349)

at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:449)

at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:910)

at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:634)

at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230)

at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:76)

at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:609)

at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:45)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)

at java.lang.Thread.run(Thread.java:745)

Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Too many connections

at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)

at com.mysql.jdbc.Util.getInstance(Util.java:372)

at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:958)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3835)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3771)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:870)

at com.mysql.jdbc.MysqlIO.proceedHandshakeWithPluggableAuthentication(MysqlIO.java:1659)

at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1206)

at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2239)

at com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2270)

at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2069)

at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:794)

at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:44)

at com.mysql.jdbc.Util.handleNewInstance(Util.java:389)

at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:399)

at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:325)

at java.sql.DriverManager.getConnection(DriverManager.java:571)

at java.sql.DriverManager.getConnection(DriverManager.java:187)

... 66 more

rundeck-connections.png

Jeff Runningen

unread,

Sep 16, 2016, 6:27:28 PM9/16/16

to rundeck-discuss

I think there is a steady leak of sleeping database connections in Rundeck 2.6.9.

Connecting to my SQL database and running "show processlist;", I see a few hundred connections, all of them in the "Sleep" command, and it looks like a new one is spawned every 90 seconds. Selecting for a single host shows a clear pattern:

mysql> SELECT * FROM INFORMATION_SCHEMA.PROCESSLIST where host = "1.2.3.4";

+-------+----------+----------------+-------+---------+------+-------+------+

+-------+----------+----------------+-------+---------+------+-------+------+

| 21667 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 72 | | NULL |

| 21661 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 163 | | NULL |

| 21656 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 253 | | NULL |

| 21650 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 344 | | NULL |

| 21645 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 435 | | NULL |

| 21639 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 524 | | NULL |

| 21634 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 616 | | NULL |

| 21628 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 706 | | NULL |

| 21623 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 797 | | NULL |

| 21617 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 887 | | NULL |

| 21612 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 978 | | NULL |

| 21606 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1068 | | NULL |

| 21601 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1159 | | NULL |

| 21595 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1249 | | NULL |

| 21590 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1340 | | NULL |

| 21584 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1430 | | NULL |

| 21579 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1521 | | NULL |

| 21573 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1612 | | NULL |

| 21568 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1702 | | NULL |

| 21562 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1793 | | NULL |

| 21557 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1883 | | NULL |

| 21551 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 1974 | | NULL |

| 21546 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 2064 | | NULL |

| 21540 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 2155 | | NULL |

...

| 20929 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 8402 | | NULL |

| 20920 | rundeck_db | 1.2.3.4 | rundeck | Sleep | 8492 | | NULL |

+-------+----------+----------------+-------+---------+------+-------+------+

94 rows in set (0.01 sec)

With all my Rundeck nodes sharing the same database, this hits the connection limit before too long.

Any suggestions on what might cause this? Is there a configuration option that might disable it?

I was also looking at some of the datasource options in http://commons.apache.org/proper/commons-dbcp/api-1.2.2/org/apache/commons/dbcp/BasicDataSource.html, which should be supported by Grails as described at http://docs.grails.org/2.2.1/guide/conf.html#dataSource. I'd like to try setting dataSource.properties.maxIdle, to see if that would get rid of the excess sleeping connections, but I'm not sure how to configure that from /etc/rundeck/rundeck-config.properties or similar.

Domingo Galdos

unread,

Sep 21, 2016, 2:09:15 PM9/21/16

to rundeck-discuss

I'm working with Jeff on this, and we've noticed another possibly useful symptom: Forcibly invoking System.gc() causes all the stale connections to go away. I tested this several times to gain confidence it's repeatable every time.

This suggests that somewhere in rundeck (or perhaps more likely, one of its dependencies such as grails, hibernate, mysql-connector, etc) some connection (or datasource, or transaction, or something, whatever indirectly owns the connection) object is simply being allowed to pass out of scope rather than being properly closed (ideally a try/finally or try-with-resources should ensure this does not happen). Thus, finalizers are being relied upon to actually close the underlying TCP connection (at least in some cases). This also neatly explains the sawtooth graph patterns and the general unpredictability of the behavior -- it depends on when GC cycles happen to run.

Anyone recognize this behavior and have any ideas?

Greg Schueler

unread,

Sep 21, 2016, 4:16:39 PM9/21/16

to rundeck...@googlegroups.com

You can look at the Grails DataSource documentation here: http://docs.grails.org/2.4.4/guide/conf.html#dataSource

They have a "groovy" format for the DataSource config. For Rundeck we load the rundeck-config.properties to setup the dataSource. You can try using `dataSource.properties.maxIdle=...` in the .properties file, but I think it may not work. You may have to convert your config to groovy format in order to set the "properties" section. (see https://github.com/rundeck/rundeck/wiki/Faq#how-do-i-convert-my-rundeck-config-file-to-groovy and https://github.com/rundeck/rundeck/wiki/Faq#how-do-i-specify-a-new-config-file-location)

then in "rundeck-config.groovy" you could do:

dataSource{

url = "..."

dbCreate = "update"

driverClassName = "com.mysql.jdbc.Driver"

properties{

maxIdle=...

}

--
You received this message because you are subscribed to the Google Groups "rundeck-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rundeck-discuss+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/rundeck-discuss/c076c416-79c7-4199-b302-6e7efc85e08f%40googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

Reply all

Reply to author

Forward

0 new messages