mysql - 使用 hibernate 和 c3p0 中断线程时的大延迟

Question

我在我们的日志中看到了这些警告，当我看到这些警告时，我发现我们数据库中的交易延迟比正常情况要大。我在互联网上搜索以寻找更多信息。

2014-12-01 18:14:03,866 [BoundedFuturePool-2] WARN  com.mchange.v2.resourcepool.BasicResourcePool  - {} com.mchange.v2.resourcepool.BasicResourcePool@2f18b0cb -- an attempt to checkout a resource was interrupted, and the pool is still live: some other thread must have either interrupted the Thread attempting checkout!
java.lang.InterruptedException
at java.lang.Object.wait(Native Method)
at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1414)
at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:606)
at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:526)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:755)
at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:682)
at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
at org.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:74)
at com.sun.proxy.$Proxy40.setReadOnly(Unknown Source)
at org.springframework.jdbc.datasource.DataSourceUtils.prepareConnectionForTransaction(DataSourceUtils.java:155)
at org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:508)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:371)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:329)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:105)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
at com.twitter.amplify.videoediting.data.TranscodingDao$$EnhancerByCGLIB$$696749fa.getTranscodeInfo(<generated>)
at com.twitter.amplify.videoediting.GetTranscodeInfoHandler$$anonfun$7.apply(GetTranscodeInfoHandler.scala:78)
at com.twitter.amplify.videoediting.GetTranscodeInfoHandler$$anonfun$7.apply(GetTranscodeInfoHandler.scala:78)
at com.twitter.util.Try$.apply(Try.scala:13)
at com.twitter.util.ExecutorServiceFuturePool$$anon$2.run(FuturePool.scala:112)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at com.twitter.amplify.util.LocalExecutorService$1.call(LocalExecutorService.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

下面是我们的配置对象。

Using DataSource [com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 5, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 2u120u951sgpypjpvvovo|73f2f11, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.mysql.jdbc.Driver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 2u120u951sgpypjpvvovo|73f2f11, idleConnectionTestPeriod -> 0, initialPoolSize -> 0, jdbcUrl -> jdbc:mysql://db-hat-rw-master-001.global-db.twttr.net/amplify?defaultFetchSize=200, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 60, maxIdleTimeExcessConnections -> 60, maxPoolSize -> 200, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 0, numHelperThreads -> 3, preferredTestQuery -> select 1, properties -> {user=******, password=******}, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> true, unreturnedConnectionTimeout -> 300, userOverrides -> {}, usesTraditionalReflectiveProxies -> false ]]

感谢您的帮助!最大

Answer 1

所以，警告告诉你 c3p0 直接知道的一切:一个客户端线程试图检查一个连接——并等待()来获得一个连接——调用了 interrupt()，迫使要从其 wait() 中断的线程。被阻止的线程是一个应用程序线程(它是一个 Scala 应用程序，调用 com.twitter.amplify.videoediting.GetTranscodeInfoHandler 中的内容)。最有可能的是，应用程序的某些其他部分监视这些线程并在它们挂起时中断()它们。如果是这样，那么您观察到的延迟就是核心问题。您的连接池已达到最大值，要么是因为它已达到 maxPoolSize，要么是尚未达到但需要从 DBMS 获取更多连接。线程卡在 wait()ing 中以等待连接，然后等待时间过长并被外部监视器杀死。

你的maxPoolSize为200已经很大了，但显然大得要根据需求来判断。也许您有 200 多个并发客户端线程。 (顺便说一句，您可以通过 JMX 监视这些东西，以非常直接地查看您的池是否达到了上限。)

但我的猜测(仅此而已)是您的问题与未能足够快地扩展池有关。对于您正在运行的规模的应用程序，c3p0 的默认线程池大小(通过名为 numHelperThreads 的配置参数巧妙地描述，对此感到抱歉)在 3 时太小了。我要做的第一件事将其增加到 10 或 20。如果这不能解决您的问题，您可能会检查 JMX 以查看您是否确实与数据源的 maxPoolSize 200 发生冲突。(如果是，你也可以提高它，尽管最终会随着线程争用而减少返回。)你也可以监控 numThreadsAwaitingCheckoutDefaultUser，它也应该由 JMX 提供。

但我会从 numHelperThreads 开始。它的值太小很可能是问题所在。