一,现象
1,重启进程,执行Scheduled task,调用mysql查询,报错mysql:Could not get JDBC Connection
二,报错现场
o.s.boot.SpringApplication - Application run failed
org.apache.dubbo.rpc.RpcException: Fail to start server Failed to bind NettyServer , cause: Cannot assign requested address
at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol.createServer(DubboProtocol.java:351)
at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol.openServer(DubboProtocol.java:323)
at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol.export(DubboProtocol.java:306)
at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper.export(ProtocolFilterWrapper.java:122)
at org.apache.dubbo.rpc.protocol.ProtocolListenerWrapper.export(ProtocolListenerWrapper.java:61)
at org.apache.dubbo.qos.protocol.QosProtocolWrapper.export(QosProtocolWrapper.java:64)
at org.apache.dubbo.rpc.Protocol$Adaptive.export(Protocol$Adaptive.java)
at org.apache.dubbo.registry.integration.RegistryProtocol.lambda$doLocalExport$2(RegistryProtocol.java:246)
at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660)
at org.apache.dubbo.registry.integration.RegistryProtocol.doLocalExport(RegistryProtocol.java:244)
at org.apache.dubbo.registry.integration.RegistryProtocol.export(RegistryProtocol.java:210)
at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper.export(ProtocolFilterWrapper.java:120)
at org.apache.dubbo.rpc.protocol.ProtocolListenerWrapper.export(ProtocolListenerWrapper.java:59)
at org.apache.dubbo.qos.protocol.QosProtocolWrapper.export(QosProtocolWrapper.java:62)
at org.apache.dubbo.rpc.Protocol$Adaptive.export(Protocol$Adaptive.java)
at org.apache.dubbo.config.ServiceConfig.doExportUrlsFor1Protocol(ServiceConfig.java:609)
at org.apache.dubbo.config.ServiceConfig.doExportUrls(ServiceConfig.java:458)
at org.apache.dubbo.config.ServiceConfig.doExport(ServiceConfig.java:416)
at org.apache.dubbo.config.ServiceConfig.export(ServiceConfig.java:379)
at org.apache.dubbo.config.spring.ServiceBean.export(ServiceBean.java:336)
at org.apache.dubbo.config.spring.ServiceBean.onApplicationEvent(ServiceBean.java:114)
at org.apache.dubbo.config.spring.ServiceBean.onApplicationEvent(ServiceBean.java:60)
at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:403)
at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:360)
at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:897)
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.finishRefresh(ServletWebServerApplicationContext.java:162)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:553)
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:141)
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:747)
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1215)
at com.ihuman.search.SearchApplication.main(SearchApplication.java:28)
Caused by: org.apache.dubbo.remoting.RemotingException: Failed to bind NettyServer on /10.148.20.12:20885, cause: Cannot assign requested address
at org.apache.dubbo.remoting.transport.AbstractServer.<init>(AbstractServer.java:77)
at org.apache.dubbo.remoting.transport.netty4.NettyServer.<init>(NettyServer.java:79)
at org.apache.dubbo.remoting.transport.netty4.NettyTransporter.bind(NettyTransporter.java:35)
at org.apache.dubbo.remoting.Transporter$Adaptive.bind(Transporter$Adaptive.java)
at org.apache.dubbo.remoting.Transporters.bind(Transporters.java:56)
at org.apache.dubbo.remoting.exchange.support.header.HeaderExchanger.bind(HeaderExchanger.java:44)
at org.apache.dubbo.remoting.exchange.Exchangers.bind(Exchangers.java:70)
at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol.createServer(DubboProtocol.java:349)
... 36 common frames omitted
Caused by: java.net.BindException: Cannot assign requested address
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:551)
at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1346)
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:503)
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:488)
at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:985)
at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:247)
at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:344)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518)
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:745)
2021-07-08 15:34:53 880 [,] [springboot-task3] DBResourceLoader.java 39 loadOpTimer ERROR
c.i.search.task.DBResourceLoader - op load timer failed.
org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException
### The error may exist in com/ihuman/search/mapper/biz/DBResourceSwitchMapper.java (best guess)
### The error may involve com.ihuman.search.mapper.biz.DBResourceSwitchMapper.selectCurrentOpInfo
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException
at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:77)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:446)
at com.sun.proxy.$Proxy124.selectOne(Unknown Source)
at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:87)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:58)
at com.sun.proxy.$Proxy126.selectCurrentOpInfo(Unknown Source)
at com.ihuman.search.task.DBResourceLoader.loadOpTimer(DBResourceLoader.java:31)
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.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException
### The error may exist in com/ihuman/search/mapper/biz/DBResourceSwitchMapper.java (best guess)
### The error may involve com.ihuman.search.mapper.biz.DBResourceSwitchMapper.selectCurrentOpInfo
### The error occurred while executing a query
### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:149)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:76)
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.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)
... 19 common frames omitted
Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLException
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:82)
at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:82)
at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:68)
at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:85)
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147)
... 26 common frames omitted
Caused by: java.sql.SQLException: null
at com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:981)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1369)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1365)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:109)
at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79)
... 36 common frames omitted
Caused by: java.lang.InterruptedException: null
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1302)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
at com.alibaba.druid.pool.DruidDataSource.init(DruidDataSource.java:956)
... 42 common frames omitted
三,结果
1,dubbo配置异常,导致线程执行了中断:interrupt(),触发了druid 在获取连接池链接时,DruidDataSource中init()下initedLatch.await()为null, 报InterruptedException异常,继而报CannotGetJdbcConnectionException
四,排查过程
1,首先看到的异常是mysql :CannotGetJdbcConnectionException异常,则怀疑:
1)DataSource配置格式有问题,例如数据库名,或多或少一些 / 字符等问题
2)账号权限问题
3)mysql版本和mysql-connector-java-bin.jar的版本匹配问题
4)驱动配置有误:driver=com.mysql.jdbc.Driver or com.mysql.cj.jdbc.Driver
结果:核实都没什么问题
2,继而看错误现场,发现有 DruidDataSource 中的InterruptedException 异常,是init()时,initedLatch.await()报null的异常,则怀疑:
1)druid的版本是否有问题
2)其他问题,导致线程Interrupted
结果:1)druid的版本和其他能正常运行的项目,版本一样,排除
2)看到 https://blog.csdn.net/baozhutang/article/details/90521123 这个,触发灵感,可能是其他导致线程Interrupted,接着看异常现场,发现还有dubbo异常Cannot assign requested address
3,排查dubbo:Cannot assign requested address异常,则怀疑:
1)端口占用
2)配置问题
结果:1)发现dubbo分配的端口没有被占用
2)对比dubbo新旧配置,发现配置有一点点不一样,修改,重启,解决