0

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
  • Some parts or your query seem to be missing? – Gerard H. Pille Oct 16 at 8:57
0

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.

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 ( ? ) )

You should check your code why this happens

| improve this answer | |

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.