失眠网 > Nacos 报Statement cancelled due to timeout or client request

Nacos 报Statement cancelled due to timeout or client request

时间：2018-11-27 23:04:35

1. 问题：nacos 启动报错，启动失败，全部报错下面贴出。

2. 结论：排查结果为服务器带宽不够，mysql 查询的数量量太大，传输时间损坏在网络io上！

3. 下面开始回溯事故起因：

前期config_info 表数据量少的时候，并没有出现问题，当nacos 的配置中心的配置文件在逐渐增多之后，nacos 从偶尔启动失败，到一直启动失败。下图为错误堆栈信息：

org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'memoryMonitor' defined in URL [jar:file:/E:/gitlab/partner-cloud-plus/partner-visual/partner-nacos/src/main/resources/lib/nacos-config-2.1.2.jar!/com/alibaba/nacos/config/server/monitor/MemoryMonitor.class]: Unsatisfied dependency expressed through constructor parameter 0; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'asyncNotifyService': Unsatisfied dependency expressed through field 'dumpService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'externalDumpService': Invocation of init method failed; nested exception is ErrCode:500, ErrMsg:Nacos Server did not start because dumpservice bean construction failure :PreparedStatementCallback; SQL [SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?]; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:800)at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:229)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1372)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1222)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:582)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:953)at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:918)at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583)at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145)at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:745)at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:420)at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)at org.springframework.boot.SpringApplication.run(SpringApplication.java:1317)at org.springframework.boot.SpringApplication.run(SpringApplication.java:1306)at com.alibaba.nacos.Nacos.main(Nacos.java:41)Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'asyncNotifyService': Unsatisfied dependency expressed through field 'dumpService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'externalDumpService': Invocation of init method failed; nested exception is ErrCode:500, ErrMsg:Nacos Server did not start because dumpservice bean construction failure :PreparedStatementCallback; SQL [SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?]; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.resolveFieldValue(AutowiredAnnotationBeanPostProcessor.java:659)at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:639)at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:119)at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessProperties(AutowiredAnnotationBeanPostProcessor.java:399)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1431)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:619)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:276)at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1389)at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1309)at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:887)at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:791)... 19 common frames omittedCaused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'externalDumpService': Invocation of init method failed; nested exception is ErrCode:500, ErrMsg:Nacos Server did not start because dumpservice bean construction failure :PreparedStatementCallback; SQL [SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?]; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:160)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620)at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542)at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335)at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208)at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:276)at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1389)at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1309)at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.resolveFieldValue(AutowiredAnnotationBeanPostProcessor.java:656)... 34 common frames omittedCaused by: com.alibaba.nacos.api.exception.NacosException: Nacos Server did not start because dumpservice bean construction failure :PreparedStatementCallback; SQL [SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?]; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat com.alibaba.nacos.config.server.service.dump.DumpService.dumpOperate(DumpService.java:225)at com.alibaba.nacos.config.server.service.dump.ExternalDumpService.init(ExternalDumpService.java:52)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.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389)at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333)at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157)... 46 common frames omittedCaused by: org.springframework.dao.QueryTimeoutException: PreparedStatementCallback; SQL [SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?]; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:76)at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:70)at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79)at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1541)at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:667)at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:713)at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:744)at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:757)at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:810)at com.alibaba.nacos.config.server.service.repository.extrnal.ExternalStoragePaginationHelperImpl.fetchPageLimit(ExternalStoragePaginationHelperImpl.java:200)at com.alibaba.nacos.config.server.service.repository.extrnal.ExternalStoragePersistServiceImpl.findAllConfigInfoFragment(ExternalStoragePersistServiceImpl.java:1446)at com.alibaba.nacos.config.server.service.dump.processor.DumpAllProcessor.process(DumpAllProcessor.java:54)at com.alibaba.nacos.config.server.service.dump.DumpService.dumpConfigInfo(DumpService.java:282)at com.alibaba.nacos.config.server.service.dump.DumpService.dumpOperate(DumpService.java:195)... 54 common frames omittedCaused by: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client requestat com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:113)at com.mysql.cj.jdbc.StatementImpl.checkCancelTimeout(StatementImpl.java:2167)at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:1133)at com.mysql.cj.NativeSession.execSQL(NativeSession.java:665)at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:893)at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:972)at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:722)at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651)... 63 common frames omitted-01-20 08:05:05.655 WARN 9964 --- [ main] c.a.nacos.sys.file.WatchFileCenter : [WatchFileCenter] start close-01-20 08:05:05.655 WARN 9964 --- [ main] c.a.nacos.sys.file.WatchFileCenter : [WatchFileCenter] start to shutdown this watcher which is watch : C:\Users\Administrator\nacos\conf-01-20 08:05:05.655 WARN 9964 --- [ main] c.a.nacos.sys.file.WatchFileCenter : [WatchFileCenter] start to shutdown this watcher which is watch : C:\Users\Administrator\nacos\data\loader-01-20 08:05:05.656 WARN 9964 --- [ main] c.a.nacos.sys.file.WatchFileCenter : [WatchFileCenter] start to shutdown this watcher which is watch : C:\Users\Administrator\nacos\data\tps-01-20 08:05:05.656 WARN 9964 --- [ main] c.a.nacos.sys.file.WatchFileCenter : [WatchFileCenter] already closed-01-20 08:05:05.656 WARN 9964 --- [ main] c.mon.notify.NotifyCenter: [NotifyCenter] Start destroying Publisher-01-20 08:05:05.656 WARN 9964 --- [ main] c.mon.notify.NotifyCenter: [NotifyCenter] Destruction of the end-01-20 08:05:05.656 ERROR 9964 --- [ main] c.a.n.c.l.StartingApplicationListener : Nacos failed to start, please see C:\Users\Administrator\nacos\logs\nacos.log for more details.-01-20 08:05:05.668 INFO 9964 --- [ main] ConditionEvaluationReportLoggingListener :

2. 排查经过：

a. 开始进行了搜索, 一些博客指出在jdbc 连接加上queryTimeout=2400 试了之后并没有用

又去github 的 nacos官网 issue 也进行查看，并没有解决办法，反而issue说是mysql问题，我对此事疑惑的因为我查看的报错的sql ，是他慢呀，（心想是不是你sql 设计的有问题呀，索引没加？最终是我错了...）怎么就是mysql问题了 ==！

SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > ? ORDER BY id ASC LIMIT ?,?

b. debug跟踪nacos 的逻辑,看看是在什么地方调用了这条sql 缺省参数又是什么?

1. 这块有个启动方法跟进去

2. 就是DumpAllProcessor 的循环。在全量扫描config_info 表。这个方法找到 sql 的参数

SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > 0 ORDER BY id ASC LIMIT 0,1000

3. 查看mysql 索引，判断是否是索引问题，进行新增，删减索引。nacos依旧启动失败！

4. 执行计划：也没看出来哪里有问题

explain SELECT id,data_id,group_id,tenant_id,app_name,content,md5,gmt_modified,type,encrypted_data_key FROM config_info WHERE id > 0 ORDER BY id ASC LIMIT 0,1000

5. 查看config_info 表第一页数据时，加载就很慢。使用sql ；select * from config_info 4s左右的查询时间。nacos连接肯定慢呀，但是又找不到加大nacos 连接时间的参数。使用驱动连接，进行查询

这条sql 查询时间是4s 多。现在思路就是要不加大限制时间（queryTimeout 并没有用，也没找到..）要不mysql调优将sql 查询时间降下来。

6. 查看f 配置文件，增加配置，重启之后错误依旧。查询了很多配置优化也并没有什么效果，依旧查询超时。

7. 现在的sql 如果将content 的字段删除。 navicat 查询就很快，sql 将content 去掉也很快。

然后将content字段设置为varchar 8099 并没有用，字段数据量太大，设置失败。设置为blob, text 设置成功，nacos依旧启动失败.

8. 单位发的电脑。配置不行，我将这个表复制给同事，跑在本地环境，navicat 是很快的，貌似是配置不行，去服务器，在本地查询这条sql。发现很快就返回结构。此时思路有点清晰，但是还是有一层窗户纸，只知道这个中间传输环节出错了

9. 由于服务器的mysql ,和nacos 在相同地方，接下来，我又将地址换为localhost 进行更换，nacos启动成功，暂时先用着。换为ip 地址就启动失败

10. 晚上，我将config_info 表复制到买的小水管机器也是很慢。但是复制到另外一台8核心32g的腾讯云的机器上。速度竟然明显快。而且是快好几倍。产生了咨询下阿里云的想法。提交了下工单。进行问题的反馈

11. 最终确定问题，服务器带宽不够，这条sql 查询出来的数据量比较大，从本地查询出来，浪费在网络传输，5m 传的慢。阿里客服那边有不同带宽可以测试，10 m 是两秒 100m 是0. 2s 意思

sql 的剖析得话， executing 有点浪费时间，也不知道executing 代表啥

总结：

1. 时间耗费：两天

2. 客观条件: 公司网络不好，给配的机器配置低，导致不能快速排查问题，中间时断时续，搞不清，到底是哪里慢 = _=！（准备买台笔记本）

3. 我的问题：对于网络io，网络排查经验，排查工具不足。这块还要进行学习。补下 tcp/ip netty等

4. 最后：学到varchar 设置最大数据， github issue 提问题，现在已经到了问题都搜索不到的阶段，需要研究源码，研究底层..

祝大家宏图大展

写于腊月29

如果觉得《Nacos 报Statement cancelled due to timeout or client request》对你有帮助，请点赞、收藏，并留下你的观点哦！

本内容不代表本网观点和政治立场，如有侵犯你的权益请联系我们处理。

网友评论

网友评论仅供其表达个人看法，并不表明网站立场。