I am using MySQL 5.7, today this is a long time query stuck me. this is my table DML:
CREATE TABLE `h_round_pump_record` (
`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT '',
`tenant_id` bigint(20) NOT NULL COMMENT '',
`tenant_name` varchar(256) NOT NULL DEFAULT '' COMMENT '',
`created_time` bigint(20) NOT NULL COMMENT '',
`updated_time` bigint(20) NOT NULL COMMENT '',
`app_id` bigint(11) NOT NULL COMMENT '',
`app_mark` varchar(256) NOT NULL DEFAULT '' COMMENT '',
`app_name` varchar(256) NOT NULL DEFAULT '' COMMENT '',
`settlement_time` bigint(20) NOT NULL COMMENT '',
`biz_id` bigint(20) NOT NULL COMMENT '',
`room_play_id` bigint(20) NOT NULL COMMENT '',
`room_amount_fmt` varchar(256) NOT NULL DEFAULT '' COMMENT '',
`tenant_revenue` bigint(20) GENERATED ALWAYS AS ((`real_people_revenue` + `robot_profit`)) STORED,
PRIMARY KEY (`id`),
UNIQUE KEY `biz_id` (`biz_id`,`tenant_id`,`app_id`),
KEY `round_record_idx` (`settlement_time`,`having_real_people`,`tenant_id`,`app_id`)
) ENGINE=InnoDB AUTO_INCREMENT=907725 DEFAULT CHARSET=utf8mb4;
and this is my query sql:
select *
from h_round_pump_record
WHERE ( settlement_time <= 1601481599000
and settlement_time >= 1598889600000
and tenant_id =
and app_id in
(
1
) )
to speed up query, I create a index in settlement_time. In Sequel Pro the SQL will return result in 3 seconds, but In apps query using MyBatis, it will take 30s to return, why the MyBatis query takes so long(the sql is the same because I am copied from slow_log table)? This is my slow log settings:
set global slow_query_log=ON
set global log_output='table';
set long_query_time = 5;
select *
from mysql.slow_log;
this is the log output of MyBatis:
org.springframework.dao.QueryTimeoutException:
### Error querying database. Cause: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
### The error may exist in class path resource [mybatis/mapper/illidan/RoundPumpRecordMapper.xml]
### The error may involve com.sportswin.soa.illidan.hub.dao.RoundPumpRecordMapper.selectByExample-Inline
### The error occurred while setting parameters
### SQL: select 'true' as QUERYID, id, tenant_id, tenant_name, agent_id, agent_name, created_time, updated_time, app_id, app_mark, app_name, settlement_time, biz_id, room_play_id, room_amount_fmt, ratio, tenant_revenue, real_pump_amount, real_people_profit, robot_profit, robot_revenue, real_people_revenue, having_real_people from h_round_pump_record WHERE ( settlement_time <= ? and settlement_time >= ? and tenant_id = ? and app_id in ( ? ) )
### Cause: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
; Statement cancelled due to timeout or client request; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:76) ~[spring-jdbc-5.1.13.RELEASE.jar!/:5.1.13.RELEASE]
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) ~[spring-jdbc-5.1.13.RELEASE.jar!/:5.1.13.RELEASE]
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81) ~[spring-jdbc-5.1.13.RELEASE.jar!/:5.1.13.RELEASE]
at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:74) ~[mybatis-spring-2.0.2.jar!/:2.0.2]
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:440) ~[mybatis-spring-2.0.2.jar!/:2.0.2]
at com.sun.proxy.$Proxy178.selectList(Unknown Source) ~[na:na]
at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:223) ~[mybatis-spring-2.0.2.jar!/:2.0.2]
at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:147) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:80) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:57) ~[mybatis-3.5.2.jar!/:3.5.2]
at com.sun.proxy.$Proxy187.selectByExample(Unknown Source) ~[na:na]
at com.sportswin.soa.illidan.hub.service.impl.HubRoundPumpRecordService.lambda$page$0(HubRoundPumpRecordService.java:63) ~[classes!/:na]
at com.github.pagehelper.Page.doSelectPageInfo(Page.java:353) ~[pagehelper-5.1.11.jar!/:na]
at com.sportswin.soa.illidan.hub.service.impl.HubRoundPumpRecordService.page(HubRoundPumpRecordService.java:62) ~[classes!/:na]
at com.sportswin.soa.illidan.hub.common.HubCommonUtil.getRoundPump(HubCommonUtil.java:164) ~[classes!/:na]
at com.sportswin.soa.illidan.hub.common.HubScheduleTask.generateImpl(HubScheduleTask.java:177) ~[classes!/:na]
at com.sportswin.soa.illidan.hub.common.HubScheduleTask.generateFilesTask(HubScheduleTask.java:159) ~[classes!/:na]
at com.sportswin.soa.illidan.hub.common.HubScheduleTask.lambda$generateExportFile$0(HubScheduleTask.java:103) ~[classes!/:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_212]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_212]
at com.sportswin.soa.misc.config.async.pool.MdcTaskDecorator.lambda$decorate$0(MdcTaskDecorator.java:31) ~[soa-misc-1.0.0-SNAPSHOT.jar!/:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_212]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_212]
at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_212]
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:113) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.StatementImpl.checkCancelTimeout(StatementImpl.java:2191) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:1020) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:1075) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:930) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.execute$original$zlbDqAbk(ClientPreparedStatement.java:370) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.execute$original$zlbDqAbk$accessor$77RRWgJE(ClientPreparedStatement.java) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement$auxiliary$WZ5P0ECx.call(Unknown Source) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:93) ~[skywalking-agent.jar:6.5.0]
at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3051) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.filter.FilterAdapter.preparedStatement_execute(FilterAdapter.java:1080) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3049) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:440) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3049) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.execute(PreparedStatementProxyImpl.java:167) ~[druid-1.1.9.jar!/:1.1.9]
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:498) ~[druid-1.1.9.jar!/:1.1.9]
at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156) ~[mybatis-3.5.2.jar!/:3.5.2]
at sun.reflect.GeneratedMethodAccessor237.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:63) ~[mybatis-3.5.2.jar!/:3.5.2]
at com.sun.proxy.$Proxy254.query(Unknown Source) ~[na:na]
at sun.reflect.GeneratedMethodAccessor237.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:63) ~[mybatis-3.5.2.jar!/:3.5.2]
at com.sun.proxy.$Proxy254.query(Unknown Source) ~[na:na]
at com.github.pagehelper.util.ExecutorUtil.pageQuery(ExecutorUtil.java:180) ~[pagehelper-5.1.11.jar!/:na]
at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:104) ~[pagehelper-5.1.11.jar!/:na]
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) ~[mybatis-3.5.2.jar!/:3.5.2]
at com.sun.proxy.$Proxy254.query(Unknown Source) ~[na:na]
at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]
at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:49) ~[mybatis-3.5.2.jar!/:3.5.2]
at tk.mybatis.orderbyhelper.OrderByHelper.intercept(OrderByHelper.java:115) ~[orderby-helper-0.0.2.jar!/:na]
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) ~[mybatis-3.5.2.jar!/:3.5.2]
at com.sun.proxy.$Proxy254.query(Unknown Source) ~[na:na]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147) ~[mybatis-3.5.2.jar!/:3.5.2]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140) ~[mybatis-3.5.2.jar!/:3.5.2]
at sun.reflect.GeneratedMethodAccessor414.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_212]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_212]
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:426) ~[mybatis-spring-2.0.2.jar!/:2.0.2]
... 19 common frames omitted
Best Answer
This is the query that you send to the MySQL server(as you can see clearly in the trace log), as you can see , you made an error and didn't replace the place holder.
You should check your code why this happens