昨天遇到一個問題,開發說一個jar包啟動后,幾分鍾就出現oracle數據庫用戶連接超時;但是該服務器上的其他war或jar都是正常連接數據庫!!!
詳細錯誤
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:109) at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:136) at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47) at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146) at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172) at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148) at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1984) at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1914) at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1892) at org.hibernate.loader.Loader.doQuery(Loader.java:937) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:340) at org.hibernate.loader.Loader.doList(Loader.java:2689) at org.hibernate.loader.Loader.doList(Loader.java:2672) at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2506) at org.hibernate.loader.Loader.list(Loader.java:2501) at org.hibernate.loader.custom.CustomLoader.list(CustomLoader.java:338) at org.hibernate.internal.SessionImpl.listCustomQuery(SessionImpl.java:2223) at org.hibernate.internal.AbstractSharedSessionContract.list(AbstractSharedSessionContract.java:1053) at org.hibernate.query.internal.NativeQueryImpl.doList(NativeQueryImpl.java:170) at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1505) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.orm.jpa.SharedEntityManagerCreator$DeferredQueryInvocationHandler.invoke(SharedEntityManagerCreator.java:402) at com.sun.proxy.$Proxy117.list(Unknown Source) at com.ceiec.report.task.dao.impl.ReportDutyDaoImpl.getEffectiveDutyList(ReportDutyDaoImpl.java:103) at com.ceiec.report.task.dao.impl.ReportDutyDaoImpl$$FastClassBySpringCGLIB$$b0b803b.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139) ... 18 common frames omitted Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30003ms. at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35) at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:106) ... 49 common frames omitted
檢查順序:
1 檢查oracle 用戶連接,登錄並查看process參數,數據庫等信息-----------發現用戶正常連接-----排除用戶,數據庫等異常
2 該服務器上有啟動3個war程序,多個jar包,只有這一個jar包出現了oracle用戶連接問題,--------懷疑是jar包問題,將jar包拷貝到其他服務器,或本地windows,運行,還是3分鍾后就出現 用戶連接超時---排除服務器異常
3 檢查sql語句-------------由於該jar包里面是一個10秒鍾的定時程序,執行一條sql,把sql放在sqlplus中執行,結果返回2行,時間很快(100ms)----排除sql問題
4 查看服務器內存
[root@localhost upload]# free -m total used free shared buffers cached Mem: 15953 15670 282 0 263 2138 -/+ buffers/cache: 13267 2685 Swap: 5983 201 5782
以為是內存用完,將該服務器上所有java程序重啟(該服務有多個服務器進行負載均衡,可以重啟任意一個服務器的java服務)
再次查看內存
[root@localhost report]# free -m total used free shared buffers cached Mem: 15953 10754 5199 0 262 2394 -/+ buffers/cache: 8097 7855 Swap: 5983 67 5916
在內存正常情況下, 該jar包服務還是啟動后3分鍾就報錯~!!!!!---------排除內存異常
5 top查看服務器,cpu,load,mem等都是正常。-------
top - 09:46:22 up 38 days, 16:05, 2 users, load average: 0.00, 0.00, 0.00 Tasks: 284 total, 2 running, 282 sleeping, 0 stopped, 0 zombie Cpu(s): 1.2%us, 0.5%sy, 0.0%ni, 98.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 16335960k total, 12137624k used, 4198336k free, 278312k buffers Swap: 6127608k total, 69288k used, 6058320k free, 2648196k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3974 root 20 0 9390m 2.2g 20m S 3.6 14.1 44:05.30 java 35 root 20 0 0 0 0 S 0.3 0.0 2:56.82 events/0 39 root 20 0 0 0 0 S 0.3 0.0 2:12.62 events/4 2594 rabbitmq 20 0 5331m 50m 3528 S 0.3 0.3 284:39.65 beam.smp 2807 rabbitmq 20 0 10800 436 404 S 0.3 0.0 0:04.58 inet_gethost 3453 root 20 0 7748m 1.1g 13m S 0.3 6.9 5:08.01 java 3594 root 20 0 7774m 1.0g 13m S 0.3 6.6 2:59.17 java 3674 root 20 0 5278m 672m 13m S 0.3 4.2 2:33.51 java 3812 root 20 0 6129m 613m 13m S 0.3 3.8 3:31.06 java 3878 root 20 0 4693m 528m 12m S 0.3 3.3 3:16.51 java 4665 root 20 0 4623m 439m 13m S 0.3 2.8 3:09.45 java 15295 root 20 0 15172 1392 948 R 0.3 0.0 0:00.02 top 1 root 20 0 19356 1300 1088 S 0.0 0.0 0:40.50 init
6 無賴之,進行谷歌,百度~~~
有提到什么springboot配置,
spring.datasource.hikari.read-only=false spring.datasource.hikari.connection-timeout=60000 spring.datasource.hikari.idle-timeout=60000 spring.datasource.hikari.validation-timeout=3000 spring.datasource.hikari.max-lifetime=60000 spring.datasource.hikari.login-timeout=5 spring.datasource.hikari.maximum-pool-size=60 spring.datasource.hikari.minimum-idle=10
看不懂~~~發給開發同學。。。等了一段時間。答復到,加了一個事務,自動提交。。。程序就正常了。~~~~~~~!!!!!!!
由於只執行了一條sql查詢語句,不存在需要提交的情況,應該是框架的問題
總結:不懂開發,這種問題還是不好排查啊!!!!----什么狗屁總結