我有一个应用程序在开发中使用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
1条答案
按热度按时间n8ghc7c11#
这似乎是由我使用的spring引导包中的底层hikari和/或jdbc驱动程序引起的。更新hikari给了我一个关于jdbc无法检查连接是否仍然有效的警告,并且更新驱动程序使这个警告消失了。从那以后,我就再也没有在测试中遇到什么问题了。