jpa应用程序在运行数小时后不会从对jpa存储库的调用返回

brgchamk  于 2021-06-19  发布在  Mysql
关注(0)|答案(1)|浏览(287)

我有一个应用程序在开发中使用springbootjpa和mysql数据库都在windows10上。
应用程序通常运行良好,但有时在中运行数小时后,无法从对jpa存储库的调用返回。
process explorer显示最小的cpu/io活动。应用程序中的其他线程继续访问数据库而没有问题。
我几乎不知道从哪里开始寻找问题,欢迎任何建议。
我的存储库定义是:

@Repository
public interface TradeRepository extends JpaRepository<TradeDbo, Long>{ 
  ... 
  @Query("select t.tradeId from TradeDbo t where t.currencyPair.id = :currencyPairId") 
  HashBag<String> getTradeIdListByCurrencyPairId(@Param("currencyPairId") Long currencyPairId);
}

调用代码是:

log.trace("Entering tradeRepository.getTradeIdListByCurrencyPairId");
Bag<String> tradeIdsInDb = tradeRepository.getTradeIdListByCurrencyPairId(currencyPairId);
log.trace("Back from tradeRepository.getTradeIdListByCurrencyPairId");

正常的日志条目是:

2018-09-30 00:34:12,458 TRACE [TradesFetcher-Gdax] [CoinDbService.java:484] biz.ianw.coindatabase.services.data.CoinDbService - Entering tradeRepository.getTradeIdListByCurrencyPairId
2018-09-30 00:34:20,509 TRACE [TradesFetcher-Gdax] [CoinDbService.java:486] biz.ianw.coindatabase.services.data.CoinDbService - Back from tradeRepository.getTradeIdListByCurrencyPairId

但是当它挂起来的时候我会得到这样的东西:

2018-09-30 00:34:22,732 TRACE [TradesFetcher-Gdax] [CoinDbService.java:484] biz.ianw.coindatabase.services.data.CoinDbService - Entering tradeRepository.getTradeIdListByCurrencyPairId
2018-09-30 01:05:37,626 INFO  [coinLister-gdax] [CoinListerTask.java:170] biz.ianw.coindatabase.services.CoinListerTask - coinLister-gdax starting...
...

直到我打破它(^c),然后我得到:

2018-09-30 05:11:13,441 WARN  [TradesFetcher-Gdax] [ProxyConnection.java:161] com.zaxxer.hikari.pool.ProxyConnection - HikariPool-1 - Connection com.mysql.jdbc.JDBC4Connection@57ee5254 marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 16,604,912 milliseconds ago.  The last packet sent successfully to the server was 16,610,693 milliseconds ago.
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
    at java.lang.reflect.Constructor.newInstance(Unknown Source)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3562)
    at com.mysql.jdbc.MysqlIO.nextRowFast(MysqlIO.java:2088)
    at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1992)
    at com.mysql.jdbc.MysqlIO.readSingleRowSet(MysqlIO.java:3413)
    at com.mysql.jdbc.MysqlIO.getResultSet(MysqlIO.java:471)
    at com.mysql.jdbc.MysqlIO.readResultsForQueryOrUpdate(MysqlIO.java:3115)
    at com.mysql.jdbc.MysqlIO.readAllResults(MysqlIO.java:2344)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2739)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2486)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858)
    at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
    at net.sf.log4jdbc.sql.jdbcapi.PreparedStatementSpy.executeQuery(PreparedStatementSpy.java:780)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:60)
    at org.hibernate.loader.Loader.getResultSet(Loader.java:2168)
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1931)
    at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1893)
    at org.hibernate.loader.Loader.doQuery(Loader.java:938)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341)
    at org.hibernate.loader.Loader.doList(Loader.java:2692)
    at org.hibernate.loader.Loader.doList(Loader.java:2675)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2507)
    at org.hibernate.loader.Loader.list(Loader.java:2502)
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502)
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:392)
    at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1489)
    at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445)
    at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414)
    at org.hibernate.query.Query.getResultList(Query.java:146)
    at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:129)
    at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:91)
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:136)
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:125)
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:590)
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:578)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:59)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:135)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
    at com.sun.proxy.$Proxy146.getTradeIdListByCurrencyPairId(Unknown Source)
    at biz.ianw.coindatabase.services.data.CoinDbService.addLatestTradesGdax(CoinDbService.java:485)
    at biz.ianw.coindatabase.services.data.CoinDbService$$FastClassBySpringCGLIB$$264af1e2.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
...

2018-09-30 05:11:13,456 ERROR [TradesFetcher-Gdax] [Slf4jSpyLogDelegator.java:135] jdbc.audit - 918447. PreparedStatement.executeQuery() select tradedbo0_.trade_id as col_0_0_ from trade tradedbo0_ where tradedbo0_.currency_pair_id=21185892 

2018-09-30 05:11:13,472 ERROR [TradesFetcher-Gdax] [Slf4jSpyLogDelegator.java:154] jdbc.sqltiming - 918447. PreparedStatement.executeQuery() FAILED! select tradedbo0_.trade_id as col_0_0_ from trade tradedbo0_ where tradedbo0_.currency_pair_id=21185892 
 {FAILED after 16610724 msec}
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

最后几行显示了prepared语句的执行,以及kill时的堆栈跟踪,暗示了语句执行中的一些问题,但我不清楚这是bug还是资源耗尽。
更新
今天的测试在运行不到2小时后,在另一个地方出现了一个错误,即保存:

2018-10-01 11:40:33,458 INFO  [TradesFetcher-Gdax] [CoinDbService.java:504] biz.ianw.coindatabase.services.data.CoinDbService - Saving...
2018-10-01 17:28:11,066 INFO  [Thread-6] [Shutdown.java:12] biz.ianw.coindatabase.Shutdown - TradesFetcher-Gdax: shutdown hook started

log.info("Saving...");  
currencyPairRepository.save(currencyPairDboToProcess);
log.info("Save complete");

此测试还包括添加60秒超时,但没有效果:

@Transactional(readOnly=false, rollbackFor=Exception.class, timeout=60)

我打开了log4jdbc选项:

logging.level.jdbc.sqlonly=info
logging.level.jdbc.connection=info

我再次跑去看看,如果我能从中学到什么的话。。。
更新
显然很少。跑了3个半小时,挂在不同的地方:

03:35:44.208 INFO  [TradesFetcher-Gdax] [Slf4jSpyLogDelegator.java:228] jdbc.sqlonly - insert into trade (creation_date, last_modified_date, currency_pair_id, original_amount, price,
timestamp, trade_id, type, version, id) values ('10/02/2018 03:35:40.806', '10/02/2018 03:35:40.806',
21185896, '0.69562553', '133.33000000', 1521469001403, '2893530', 'BID', 0, 34504324)

06:03:46.589 INFO  [Thread-6] [Shutdown.java:12] biz.ianw.coindatabase.Shutdown - TradesFetcher-Gdax: shutdown hook started
n8ghc7c1

n8ghc7c11#

这似乎是由我使用的spring引导包中的底层hikari和/或jdbc驱动程序引起的。更新hikari给了我一个关于jdbc无法检查连接是否仍然有效的警告,并且更新驱动程序使这个警告消失了。从那以后,我就再也没有在测试中遇到什么问题了。

相关问题