大佬们好:升级v6.5.1后,某些查询变的非常慢,这是怎么了?

【 TiDB 使用环境】生产环境 /测试/ Poc
【 TiDB 版本】v 6.5.1
【复现路径】做过哪些操作出现的问题
【遇到的问题:问题现象及影响】
在老的tidb集群进行版本升级测试 v4.0.9 → v5.0.5 → 6.5.1(有数据,但是没跑业务)
升级完成了,但是某些查询慢的非常慢(大部分查询速度较4.0.9变快了的)
这个查询在v4.0.9大概为40秒左右,但在v6.5.1查询要7分多钟。。慢了非常多,我想问下这是什么原因?怎么排查呢?
SQL语句如下:

explain v6.5.1版本信息如下:

explain v4.0.9版本信息如下:

尝试 states version 改为 2,手动将表统计信息收集一遍

1 个赞

大佬,这个states version 是啥,没搜索到有关信息,能说的详细些吗?
是指 tidb_row_format_version 这个吗?

https://docs.pingcap.com/zh/tidb/stable/statistics analyze version

1 个赞

为什么会有这个问题呢,我不太理解,并且大部分SQL的查询速度是变快的
是需要把所有的表都需要重新 ANALYZE TABLE table_name ; 这样操作一下吗? 这样太麻烦了我们库中有很多表

我们老集群可能是从v3.x 版本升级上来的,是因为初装版本太低升级上来的原因吗?
我们生产的集群初装版本是v4.0.9,升级到v6.5.1 也会遇到这个问题吗?

我看你两个版本的sql explain没什么区别啊,不都是走的idx_xpost_entryid索引的range scan吗?为什么速度会差那么多。。。

1 个赞

这是explain的执行计划吧,把explain analyze的执行计划贴下

新版本是 v2 默认,有重构部分统计信息模型。手动更新下可能可以解决问题。这是通用方案 不一定能解决。慢是要 case by case 的看 SQL 的

1 个赞

以下是老库v6.0.5 explain analyze信息:

mysql> 
mysql> explain analyze SELECT xpost.postid, xpost.facetid, xpost.entryid, xpost.title, xpost.url, xpost.abstract, xpost.click, xpost.reply, xpost.repost, xpost.praise, xpost.collect, xpost.wordscount, xpost.siteid, xpost.domain, xpost.author, xpost.author_id, xpost.posttime, xpost.include_t, xpost.type, xpost.source, xpost.hidden, xpost.sourcetype, xpost.crisis_post, xpost.ontop, xpost.type_rank, xpost.pos_type_rank, xpost.noise_rank, xpost.device, xpost.is_origin, xpost.is_top, xpost.media_type, xpost.author_type, xpost.content_type, xpost.client_type, xpost.industry, xpost.tags, xpost.post_type, xpost.type_reason, xpost.update_time, xpost.origin_source, xpost.media_id, xpost.w_level, xpost.watch, xpost.keywordcount, xpost.location, xpost.is_comment, xpost.text, xpost.spider_time, xpost.process_time, xpost.tidb_in_time FROM xpost FORCE INDEX (idx_xpost_entryid) WHERE (xpost.entryid IN (4856577, 4855938, 4856069, 4855686, 4856079, 4857488, 4857618, 4855699, 4856087, 4855966, 4854815, 4855201, 4855714, 4855076, 4851496, 4855083, 4854830, 4856371, 4855608, 4851514, 4857916, 4852797, 4855743, 4851522, 4855748, 4855365, 4851526, 4855624, 4855626, 4856654, 4856018, 4855635, 4855764, 4855637, 4855766, 4854986, 4857305, 4855134, 4855135, 4857706, 4857454, 4855408, 4857211, 4856062) AND (1) AND xpost.hidden IN (-2, -1, 0, 2, 3, 4)) ORDER BY xpost.posttime DESC \G; 
*************************** 1. row ***************************
            id: Sort_5
       estRows: 9978.21
       actRows: 1244055
          task: root
 access object: 
execution info: time:7m37.3s, loops:1216
 operator info: bsppr.xpost.posttime:desc
        memory: 956.7 MB
          disk: 1.06 GB
*************************** 2. row ***************************
            id: └─Projection_7
       estRows: 9978.21
       actRows: 1244055
          task: root
 access object: 
execution info: time:7.45s, loops:1216, Concurrency:5
 operator info: bsppr.xpost.postid, bsppr.xpost.facetid, bsppr.xpost.entryid, bsppr.xpost.title, bsppr.xpost.url, bsppr.xpost.abstract, bsppr.xpost.click, bsppr.xpost.reply, bsppr.xpost.repost, bsppr.xpost.praise, bsppr.xpost.collect, bsppr.xpost.wordscount, bsppr.xpost.siteid, bsppr.xpost.domain, bsppr.xpost.author, bsppr.xpost.author_id, bsppr.xpost.posttime, bsppr.xpost.include_t, bsppr.xpost.type, bsppr.xpost.source, bsppr.xpost.hidden, bsppr.xpost.sourcetype, bsppr.xpost.crisis_post, bsppr.xpost.ontop, bsppr.xpost.type_rank, bsppr.xpost.pos_type_rank, bsppr.xpost.noise_rank, bsppr.xpost.device, bsppr.xpost.is_origin, bsppr.xpost.is_top, bsppr.xpost.media_type, bsppr.xpost.author_type, bsppr.xpost.content_type, bsppr.xpost.client_type, bsppr.xpost.industry, bsppr.xpost.tags, bsppr.xpost.post_type, bsppr.xpost.type_reason, bsppr.xpost.update_time, bsppr.xpost.origin_source, bsppr.xpost.media_id, bsppr.xpost.w_level, bsppr.xpost.watch, bsppr.xpost.keywordcount, bsppr.xpost.location, bsppr.xpost.is_comment, bsppr.xpost.text, bsppr.xpost.spider_time, bsppr.xpost.process_time, bsppr.xpost.tidb_in_time
        memory: 4.49 MB
          disk: N/A
*************************** 3. row ***************************
            id:   └─IndexLookUp_11
       estRows: 9978.21
       actRows: 1244055
          task: root
 access object: 
execution info: time:7.83s, loops:1216, index_task: {total_time: 7.32s, fetch_handle: 131.1ms, build: 197.4µs, wait: 7.18s}, table_task: {total_time: 38s, num: 65, concurrency: 5}, next: {wait_index: 2.97ms, wait_table_lookup_build: 1.05ms, wait_table_lookup_resp: 3.67s}
 operator info: 
        memory: 181.9 MB
          disk: N/A
*************************** 4. row ***************************
            id:     ├─IndexRangeScan_8(Build)
       estRows: 83843.43
       actRows: 1244114
          task: cop[tikv]
 access object: table:xpost, index:idx_xpost_entryid(entryid)
execution info: time:27.3ms, loops:1237, cop_task: {num: 138, max: 194.7ms, min: 1.23ms, avg: 24ms, p95: 106.5ms, max_proc_keys: 50144, p95_proc_keys: 50144, tot_proc: 930ms, tot_wait: 127ms, rpc_num: 138, rpc_time: 3.31s, copr_cache_hit_ratio: 0.09, distsql_concurrency: 15}, tikv_task:{proc max:59ms, min:0s, avg: 7.15ms, p80:9ms, p95:28ms, iters:1742, tasks:138}, scan_detail: {total_process_keys: 1192678, total_process_keys_size: 54863188, total_keys: 1482570, get_snapshot_time: 134.4ms, rocksdb: {delete_skipped_count: 19, key_skipped_count: 1482423, block: {cache_hit_count: 2451, read_count: 5, read_byte: 83.5 KB, read_time: 207.5µs}}}
 operator info: range:[4851496,4851496], [4851514,4851514], [4851522,4851522], [4851526,4851526], [4852797,4852797], [4854815,4854815], [4854830,4854830], [4854986,4854986], [4855076,4855076], [4855083,4855083], [4855134,4855134], [4855135,4855135], [4855201,4855201], [4855365,4855365], [4855408,4855408], [4855608,4855608], [4855624,4855624], [4855626,4855626], [4855635,4855635], [4855637,4855637], [4855686,4855686], [4855699,4855699], [4855714,4855714], [4855743,4855743], [4855748,4855748], [4855764,4855764], [4855766,4855766], [4855938,4855938], [4855966,4855966], [4856018,4856018], [4856062,4856062], [4856069,4856069], [4856079,4856079], [4856087,4856087], [4856371,4856371], [4856577,4856577], [4856654,4856654], [4857211,4857211], [4857305,4857305], [4857454,4857454], [4857488,4857488], [4857618,4857618], [4857706,4857706], [4857916,4857916], keep order:false
        memory: N/A
          disk: N/A
*************************** 5. row ***************************
            id:     └─Selection_10(Probe)
       estRows: 9978.21
       actRows: 1244055
          task: cop[tikv]
 access object: 
execution info: time:37s, loops:1354, cop_task: {num: 8457, max: 1.28s, min: 728.6µs, avg: 51.8ms, p95: 218.7ms, max_proc_keys: 16590, p95_proc_keys: 636, tot_proc: 56.4s, tot_wait: 12.9s, rpc_num: 8457, rpc_time: 7m17.7s, copr_cache_hit_ratio: 0.09, distsql_concurrency: 15}, tikv_task:{proc max:620ms, min:0s, avg: 7.78ms, p80:7ms, p95:35ms, iters:15378, tasks:8457}, scan_detail: {total_process_keys: 1078696, total_process_keys_size: 739576989, total_keys: 1227196, get_snapshot_time: 12.6s, rocksdb: {delete_skipped_count: 16, key_skipped_count: 413543, block: {cache_hit_count: 11354691, read_count: 5, read_byte: 80.2 KB, read_time: 1.37ms}}}
 operator info: in(bsppr.xpost.hidden, -2, -1, 0, 2, 3, 4)
        memory: N/A
          disk: N/A
*************************** 6. row ***************************
            id:       └─TableRowIDScan_9
       estRows: 83843.43
       actRows: 1244114
          task: cop[tikv]
 access object: table:xpost
execution info: tikv_task:{proc max:620ms, min:0s, avg: 7.76ms, p80:7ms, p95:35ms, iters:15378, tasks:8457}
 operator info: keep order:false
        memory: N/A
          disk: N/A
6 rows in set (7 min 37.55 sec)

因为老库已经升级了没法回退去explain ,所以看的生产库v4.0.9 的explain analyze信息:

MySQL [bsppr]> 
MySQL [bsppr]> 
MySQL [bsppr]> explain analyze SELECT xpost.postid, xpost.facetid, xpost.entryid, xpost.title, xpost.url, xpost.abstract, xpost.click, xpost.reply, xpost.repost, xpost.praise, xpost.collect, xpost.wordscount, xpost.siteid, xpost.domain, xpost.author, xpost.author_id, xpost.posttime, xpost.include_t, xpost.type, xpost.source, xpost.hidden, xpost.sourcetype, xpost.crisis_post, xpost.ontop, xpost.type_rank, xpost.pos_type_rank, xpost.noise_rank, xpost.device, xpost.is_origin, xpost.is_top, xpost.media_type, xpost.author_type, xpost.content_type, xpost.client_type, xpost.industry, xpost.tags, xpost.post_type, xpost.type_reason, xpost.update_time, xpost.origin_source, xpost.media_id, xpost.w_level, xpost.watch, xpost.keywordcount, xpost.location, xpost.is_comment, xpost.text, xpost.spider_time, xpost.process_time, xpost.tidb_in_time FROM xpost FORCE INDEX (idx_xpost_entryid) WHERE (xpost.entryid IN (4856577, 4855938, 4856069, 4855686, 4856079, 4857488, 4857618, 4855699, 4856087, 4855966, 4854815, 4855201, 4855714, 4855076, 4851496, 4855083, 4854830, 4856371, 4855608, 4851514, 4857916, 4852797, 4855743, 4851522, 4855748, 4855365, 4851526, 4855624, 4855626, 4856654, 4856018, 4855635, 4855764, 4855637, 4855766, 4854986, 4857305, 4855134, 4855135, 4857706, 4857454, 4855408, 4857211, 4856062) AND (1) AND xpost.hidden IN (-2, -1, 0, 2, 3, 4)) ORDER BY xpost.posttime DESC\G;  
*************************** 1. row ***************************
            id: Sort_5
       estRows: 27643.42
       actRows: 1244179
          task: root
 access object: 
execution info: time:24.614187157s, loops:1217
 operator info: bsppr.xpost.posttime:desc
        memory: 982.008674621582 MB
          disk: 1.2011287668719888 GB
*************************** 2. row ***************************
            id: └─Projection_7
       estRows: 27643.42
       actRows: 1244179
          task: root
 access object: 
execution info: time:7.16124316s, loops:1217, Concurrency:4
 operator info: bsppr.xpost.postid, bsppr.xpost.facetid, bsppr.xpost.entryid, bsppr.xpost.title, bsppr.xpost.url, bsppr.xpost.abstract, bsppr.xpost.click, bsppr.xpost.reply, bsppr.xpost.repost, bsppr.xpost.praise, bsppr.xpost.collect, bsppr.xpost.wordscount, bsppr.xpost.siteid, bsppr.xpost.domain, bsppr.xpost.author, bsppr.xpost.author_id, bsppr.xpost.posttime, bsppr.xpost.include_t, bsppr.xpost.type, bsppr.xpost.source, bsppr.xpost.hidden, bsppr.xpost.sourcetype, bsppr.xpost.crisis_post, bsppr.xpost.ontop, bsppr.xpost.type_rank, bsppr.xpost.pos_type_rank, bsppr.xpost.noise_rank, bsppr.xpost.device, bsppr.xpost.is_origin, bsppr.xpost.is_top, bsppr.xpost.media_type, bsppr.xpost.author_type, bsppr.xpost.content_type, bsppr.xpost.client_type, bsppr.xpost.industry, bsppr.xpost.tags, bsppr.xpost.post_type, bsppr.xpost.type_reason, bsppr.xpost.update_time, bsppr.xpost.origin_source, bsppr.xpost.media_id, bsppr.xpost.w_level, bsppr.xpost.watch, bsppr.xpost.keywordcount, bsppr.xpost.location, bsppr.xpost.is_comment, bsppr.xpost.text, bsppr.xpost.spider_time, bsppr.xpost.process_time, bsppr.xpost.tidb_in_time
        memory: 3.3519744873046875 MB
          disk: N/A
*************************** 3. row ***************************
            id:   └─IndexLookUp_11
       estRows: 27643.42
       actRows: 1244179
          task: root
 access object: 
execution info: time:7.18731351s, loops:1217, index_task:35.031861ms, table_task:{num:64, concurrency:4, time:28.32257032s}
 operator info: 
        memory: 115.38516521453857 MB
          disk: N/A
*************************** 4. row ***************************
            id:     ├─IndexRangeScan_8(Build)
       estRows: 98574.13
       actRows: 1244179
          task: cop[tikv]
 access object: table:xpost, index:idx_xpost_entryid(entryid)
execution info: time:6.61509143s, loops:64, cop_task: {num: 18, max: 446.377326ms, min: 1.085309ms, avg: 56.777582ms, p95: 446.377326ms, max_proc_keys: 601446, p95_proc_keys: 601446, tot_proc: 685ms, tot_wait: 24ms, rpc_num: 18, rpc_time: 1.021157901s, copr_cache_hit_ratio: 0.00}, tikv_task:{proc max:284ms, min:0s, p80:50ms, p95:284ms, iters:1288, tasks:18}
 operator info: range:[4851496,4851496], [4851514,4851514], [4851522,4851522], [4851526,4851526], [4852797,4852797], [4854815,4854815], [4854830,4854830], [4854986,4854986], [4855076,4855076], [4855083,4855083], [4855134,4855134], [4855135,4855135], [4855201,4855201], [4855365,4855365], [4855408,4855408], [4855608,4855608], [4855624,4855624], [4855626,4855626], [4855635,4855635], [4855637,4855637], [4855686,4855686], [4855699,4855699], [4855714,4855714], [4855743,4855743], [4855748,4855748], [4855764,4855764], [4855766,4855766], [4855938,4855938], [4855966,4855966], [4856018,4856018], [4856062,4856062], [4856069,4856069], [4856079,4856079], [4856087,4856087], [4856371,4856371], [4856577,4856577], [4856654,4856654], [4857211,4857211], [4857305,4857305], [4857454,4857454], [4857488,4857488], [4857618,4857618], [4857706,4857706], [4857916,4857916], keep order:false
        memory: N/A
          disk: N/A
*************************** 5. row ***************************
            id:     └─Selection_10(Probe)
       estRows: 27643.42
       actRows: 1244179
          task: cop[tikv]
 access object: 
execution info: time:27.787962775s, loops:1365, cop_task: {num: 7672, max: 914.553597ms, min: 253.422µs, avg: 29.557717ms, p95: 148.712729ms, max_proc_keys: 15765, p95_proc_keys: 689, tot_proc: 31.68s, tot_wait: 9.802s, rpc_num: 7672, rpc_time: 3m46.707013743s, copr_cache_hit_ratio: 0.00}, tikv_task:{proc max:288ms, min:0s, p80:3ms, p95:16ms, iters:14441, tasks:7672}
 operator info: in(bsppr.xpost.hidden, -2, -1, 0, 2, 3, 4)
        memory: N/A
          disk: N/A
*************************** 6. row ***************************
            id:       └─TableRowIDScan_9
       estRows: 98574.13
       actRows: 1244179
          task: cop[tikv]
 access object: table:xpost
execution info: time:0ns, loops:0, tikv_task:{proc max:286ms, min:0s, p80:3ms, p95:16ms, iters:14441, tasks:7672}
 operator info: keep order:false
        memory: N/A
          disk: N/A
6 rows in set (24.82 sec)

把order by去掉试下,看起来像sort算子出现的问题

1 个赞

是的,把order by 去掉后,速度直接8秒,这是怎么回事?

mysql> explain analyze SELECT xpost.postid, xpost.facetid, xpost.entryid, xpost.title, xpost.url, xpost.abstract, xpost.click, xpost.reply, xpost.repost, xpost.praise, xpost.collect, xpost.wordscount, xpost.siteid, xpost.domain, xpost.author, xpost.author_id, xpost.posttime, xpost.include_t, xpost.type, xpost.source, xpost.hidden, xpost.sourcetype, xpost.crisis_post, xpost.ontop, xpost.type_rank, xpost.pos_type_rank, xpost.noise_rank, xpost.device, xpost.is_origin, xpost.is_top, xpost.media_type, xpost.author_type, xpost.content_type, xpost.client_type, xpost.industry, xpost.tags, xpost.post_type, xpost.type_reason, xpost.update_time, xpost.origin_source, xpost.media_id, xpost.w_level, xpost.watch, xpost.keywordcount, xpost.location, xpost.is_comment, xpost.text, xpost.spider_time, xpost.process_time, xpost.tidb_in_time FROM xpost FORCE INDEX (idx_xpost_entryid) WHERE (xpost.entryid IN (4856577, 4855938, 4856069, 4855686, 4856079, 4857488, 4857618, 4855699, 4856087, 4855966, 4854815, 4855201, 4855714, 4855076, 4851496, 4855083, 4854830, 4856371, 4855608, 4851514, 4857916, 4852797, 4855743, 4851522, 4855748, 4855365, 4851526, 4855624, 4855626, 4856654, 4856018, 4855635, 4855764, 4855637, 4855766, 4854986, 4857305, 4855134, 4855135, 4857706, 4857454, 4855408, 4857211, 4856062) AND (1) AND xpost.hidden IN (-2, -1, 0, 2, 3, 4))  \G;
*************************** 1. row ***************************
            id: Projection_4
       estRows: 9978.21
       actRows: 1244055
          task: root
 access object: 
execution info: time:7.85s, loops:1216, Concurrency:5
 operator info: bsppr.xpost.postid, bsppr.xpost.facetid, bsppr.xpost.entryid, bsppr.xpost.title, bsppr.xpost.url, bsppr.xpost.abstract, bsppr.xpost.click, bsppr.xpost.reply, bsppr.xpost.repost, bsppr.xpost.praise, bsppr.xpost.collect, bsppr.xpost.wordscount, bsppr.xpost.siteid, bsppr.xpost.domain, bsppr.xpost.author, bsppr.xpost.author_id, bsppr.xpost.posttime, bsppr.xpost.include_t, bsppr.xpost.type, bsppr.xpost.source, bsppr.xpost.hidden, bsppr.xpost.sourcetype, bsppr.xpost.crisis_post, bsppr.xpost.ontop, bsppr.xpost.type_rank, bsppr.xpost.pos_type_rank, bsppr.xpost.noise_rank, bsppr.xpost.device, bsppr.xpost.is_origin, bsppr.xpost.is_top, bsppr.xpost.media_type, bsppr.xpost.author_type, bsppr.xpost.content_type, bsppr.xpost.client_type, bsppr.xpost.industry, bsppr.xpost.tags, bsppr.xpost.post_type, bsppr.xpost.type_reason, bsppr.xpost.update_time, bsppr.xpost.origin_source, bsppr.xpost.media_id, bsppr.xpost.w_level, bsppr.xpost.watch, bsppr.xpost.keywordcount, bsppr.xpost.location, bsppr.xpost.is_comment, bsppr.xpost.text, bsppr.xpost.spider_time, bsppr.xpost.process_time, bsppr.xpost.tidb_in_time
        memory: 13.6 MB
          disk: N/A
*************************** 2. row ***************************
            id: └─IndexLookUp_8
       estRows: 9978.21
       actRows: 1244055
          task: root
 access object: 
execution info: time:7.85s, loops:1216, index_task: {total_time: 7.21s, fetch_handle: 126ms, build: 183.1µs, wait: 7.09s}, table_task: {total_time: 37.9s, num: 65, concurrency: 5}, next: {wait_index: 10.9ms, wait_table_lookup_build: 53.4ms, wait_table_lookup_resp: 6.33s}
 operator info: 
        memory: 174.5 MB
          disk: N/A
*************************** 3. row ***************************
            id:   ├─IndexRangeScan_5(Build)
       estRows: 83843.43
       actRows: 1244114
          task: cop[tikv]
 access object: table:xpost, index:idx_xpost_entryid(entryid)
execution info: time:13ms, loops:1239, cop_task: {num: 138, max: 134.1ms, min: 362µs, avg: 15ms, p95: 71.5ms, max_proc_keys: 50144, p95_proc_keys: 50144, tot_proc: 842ms, tot_wait: 80ms, rpc_num: 138, rpc_time: 2.07s, copr_cache_hit_ratio: 0.09, distsql_concurrency: 15}, tikv_task:{proc max:70ms, min:0s, avg: 6.7ms, p80:10ms, p95:26ms, iters:1742, tasks:138}, scan_detail: {total_process_keys: 1194726, total_process_keys_size: 54957396, total_keys: 1484878, get_snapshot_time: 86ms, rocksdb: {delete_skipped_count: 18, key_skipped_count: 1484732, block: {cache_hit_count: 2400, read_count: 10, read_byte: 159.9 KB, read_time: 294µs}}}
 operator info: range:[4851496,4851496], [4851514,4851514], [4851522,4851522], [4851526,4851526], [4852797,4852797], [4854815,4854815], [4854830,4854830], [4854986,4854986], [4855076,4855076], [4855083,4855083], [4855134,4855134], [4855135,4855135], [4855201,4855201], [4855365,4855365], [4855408,4855408], [4855608,4855608], [4855624,4855624], [4855626,4855626], [4855635,4855635], [4855637,4855637], [4855686,4855686], [4855699,4855699], [4855714,4855714], [4855743,4855743], [4855748,4855748], [4855764,4855764], [4855766,4855766], [4855938,4855938], [4855966,4855966], [4856018,4856018], [4856062,4856062], [4856069,4856069], [4856079,4856079], [4856087,4856087], [4856371,4856371], [4856577,4856577], [4856654,4856654], [4857211,4857211], [4857305,4857305], [4857454,4857454], [4857488,4857488], [4857618,4857618], [4857706,4857706], [4857916,4857916], keep order:false
        memory: N/A
          disk: N/A
*************************** 4. row ***************************
            id:   └─Selection_7(Probe)
       estRows: 9978.21
       actRows: 1244055
          task: cop[tikv]
 access object: 
execution info: time:34.5s, loops:1362, cop_task: {num: 8238, max: 1.28s, min: 669.6µs, avg: 47.2ms, p95: 215.9ms, max_proc_keys: 20480, p95_proc_keys: 630, tot_proc: 55.6s, tot_wait: 9.34s, rpc_num: 8238, rpc_time: 6m28.8s, copr_cache_hit_ratio: 0.11, distsql_concurrency: 15}, tikv_task:{proc max:724ms, min:0s, avg: 8.1ms, p80:7ms, p95:35ms, iters:15178, tasks:8238}, scan_detail: {total_process_keys: 1056051, total_process_keys_size: 721790478, total_keys: 1205112, get_snapshot_time: 8.88s, rocksdb: {delete_skipped_count: 19, key_skipped_count: 417205, block: {cache_hit_count: 11070198, read_count: 55, read_byte: 677.0 KB, read_time: 6.7ms}}}
 operator info: in(bsppr.xpost.hidden, -2, -1, 0, 2, 3, 4)
        memory: N/A
          disk: N/A
*************************** 5. row ***************************
            id:     └─TableRowIDScan_6
       estRows: 83843.43
       actRows: 1244114
          task: cop[tikv]
 access object: table:xpost
execution info: tikv_task:{proc max:723ms, min:0s, avg: 8.07ms, p80:7ms, p95:35ms, iters:15178, tasks:8238}
 operator info: keep order:false
        memory: N/A
          disk: N/A
5 rows in set (7.86 sec)
mysql> explain analyze SELECT xpost.postid, xpost.facetid, xpost.entryid, xpost.title, xpost.url, xpost.abstract, xpost.click, xpost.reply, xpost.repost, xpost.praise, xpost.collect, xpost.wordscount, xpost.siteid, xpost.domain, xpost.author, xpost.author_id, xpost.posttime, xpost.include_t, xpost.type, xpost.source, xpost.hidden, xpost.sourcetype, xpost.crisis_post, xpost.ontop, xpost.type_rank, xpost.pos_type_rank, xpost.noise_rank, xpost.device, xpost.is_origin, xpost.is_top, xpost.media_type, xpost.author_type, xpost.content_type, xpost.client_type, xpost.industry, xpost.tags, xpost.post_type, xpost.type_reason, xpost.update_time, xpost.origin_source, xpost.media_id, xpost.w_level, xpost.watch, xpost.keywordcount, xpost.location, xpost.is_comment, xpost.text, xpost.spider_time, xpost.process_time, xpost.tidb_in_time FROM xpost FORCE INDEX (idx_xpost_entryid) WHERE (xpost.entryid IN (4856577, 4855938, 4856069, 4855686, 4856079, 4857488, 4857618, 4855699, 4856087, 4855966, 4854815, 4855201, 4855714, 4855076, 4851496, 4855083, 4854830, 4856371, 4855608, 4851514, 4857916, 4852797, 4855743, 4851522, 4855748, 4855365, 4851526, 4855624, 4855626, 4856654, 4856018, 4855635, 4855764, 4855637, 4855766, 4854986, 4857305, 4855134, 4855135, 4857706, 4857454, 4855408, 4857211, 4856062) AND (1) AND xpost.hidden IN (-2, -1, 0, 2, 3, 4))  ;

+---------------------------------+----------+---------+-----------+-----------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+------+
| id                              | estRows  | actRows | task      | access object                                 | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           | operator info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    | memory   | disk |
+---------------------------------+----------+---------+-----------+-----------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+------+
| Projection_4                    | 9978.21  | 1244055 | root      |                                               | time:7.66s, loops:1216, Concurrency:5                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    | bsppr.xpost.postid, bsppr.xpost.facetid, bsppr.xpost.entryid, bsppr.xpost.title, bsppr.xpost.url, bsppr.xpost.abstract, bsppr.xpost.click, bsppr.xpost.reply, bsppr.xpost.repost, bsppr.xpost.praise, bsppr.xpost.collect, bsppr.xpost.wordscount, bsppr.xpost.siteid, bsppr.xpost.domain, bsppr.xpost.author, bsppr.xpost.author_id, bsppr.xpost.posttime, bsppr.xpost.include_t, bsppr.xpost.type, bsppr.xpost.source, bsppr.xpost.hidden, bsppr.xpost.sourcetype, bsppr.xpost.crisis_post, bsppr.xpost.ontop, bsppr.xpost.type_rank, bsppr.xpost.pos_type_rank, bsppr.xpost.noise_rank, bsppr.xpost.device, bsppr.xpost.is_origin, bsppr.xpost.is_top, bsppr.xpost.media_type, bsppr.xpost.author_type, bsppr.xpost.content_type, bsppr.xpost.client_type, bsppr.xpost.industry, bsppr.xpost.tags, bsppr.xpost.post_type, bsppr.xpost.type_reason, bsppr.xpost.update_time, bsppr.xpost.origin_source, bsppr.xpost.media_id, bsppr.xpost.w_level, bsppr.xpost.watch, bsppr.xpost.keywordcount, bsppr.xpost.location, bsppr.xpost.is_comment, bsppr.xpost.text, bsppr.xpost.spider_time, bsppr.xpost.process_time, bsppr.xpost.tidb_in_time | 13.5 MB  | N/A  |
| └─IndexLookUp_8                 | 9978.21  | 1244055 | root      |                                               | time:7.65s, loops:1216, index_task: {total_time: 7.01s, fetch_handle: 130ms, build: 278.5µs, wait: 6.88s}, table_task: {total_time: 37s, num: 65, concurrency: 5}, next: {wait_index: 2.65ms, wait_table_lookup_build: 1.06ms, wait_table_lookup_resp: 6.02s}                                                                                                                                                                                                                                                                                                                                                                                            |                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  | 159.2 MB | N/A  |
|   ├─IndexRangeScan_5(Build)     | 83843.43 | 1244114 | cop[tikv] | table:xpost, index:idx_xpost_entryid(entryid) | time:16.7ms, loops:1239, cop_task: {num: 138, max: 461ms, min: 570.3µs, avg: 25.4ms, p95: 105.4ms, max_proc_keys: 50144, p95_proc_keys: 50144, tot_proc: 974ms, tot_wait: 221ms, rpc_num: 138, rpc_time: 3.51s, copr_cache_hit_ratio: 0.07, distsql_concurrency: 15}, tikv_task:{proc max:69ms, min:0s, avg: 7.51ms, p80:10ms, p95:32ms, iters:1742, tasks:138}, scan_detail: {total_process_keys: 1213094, total_process_keys_size: 55802324, total_keys: 1506275, get_snapshot_time: 235.3ms, rocksdb: {delete_skipped_count: 19, key_skipped_count: 1506126, block: {cache_hit_count: 2468, read_count: 2, read_byte: 36.3 KB, read_time: 30.2µs}}}   | range:[4851496,4851496], [4851514,4851514], [4851522,4851522], [4851526,4851526], [4852797,4852797], [4854815,4854815], [4854830,4854830], [4854986,4854986], [4855076,4855076], [4855083,4855083], [4855134,4855134], [4855135,4855135], [4855201,4855201], [4855365,4855365], [4855408,4855408], [4855608,4855608], [4855624,4855624], [4855626,4855626], [4855635,4855635], [4855637,4855637], [4855686,4855686], [4855699,4855699], [4855714,4855714], [4855743,4855743], [4855748,4855748], [4855764,4855764], [4855766,4855766], [4855938,4855938], [4855966,4855966], [4856018,4856018], [4856062,4856062], [4856069,4856069], [4856079,4856079], [4856087,4856087], [4856371,4856371], [4856577,4856577], [4856654,4856654], [4857211,4857211], [4857305,4857305], [4857454,4857454], [4857488,4857488], [4857618,4857618], [4857706,4857706], [4857916,4857916], keep order:false                                                                                                                                                                       | N/A      | N/A  |
|   └─Selection_7(Probe)          | 9978.21  | 1244055 | cop[tikv] |                                               | time:36s, loops:1362, cop_task: {num: 8355, max: 1.18s, min: 652.6µs, avg: 51.5ms, p95: 228.9ms, max_proc_keys: 14779, p95_proc_keys: 623, tot_proc: 57.7s, tot_wait: 13s, rpc_num: 8355, rpc_time: 7m9.7s, copr_cache_hit_ratio: 0.10, distsql_concurrency: 15}, tikv_task:{proc max:603ms, min:0s, avg: 8.15ms, p80:7ms, p95:35ms, iters:15331, tasks:8355}, scan_detail: {total_process_keys: 1063027, total_process_keys_size: 728082827, total_keys: 1211079, get_snapshot_time: 12.5s, rocksdb: {delete_skipped_count: 16, key_skipped_count: 413568, block: {cache_hit_count: 11172803, read_count: 5, read_byte: 21.2 KB, read_time: 21.1µs}}}   | in(bsppr.xpost.hidden, -2, -1, 0, 2, 3, 4)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       | N/A      | N/A  |
|     └─TableRowIDScan_6          | 83843.43 | 1244114 | cop[tikv] | table:xpost                                   | tikv_task:{proc max:601ms, min:0s, avg: 8.12ms, p80:7ms, p95:35ms, iters:15331, tasks:8355}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              | keep order:false                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 | N/A      | N/A  |
+---------------------------------+----------+---------+-----------+-----------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------+------+
5 rows in set (7.66 sec)

mysql>

那就定位到慢确实是sort算子的原因,你先看下资源,比如内存等如何,然后看下这张表的健康度,看下show analyze status有没有频繁的analyze的操作等,另外把这张表的表结构补充下,另外这参数的配置看下两套环境的

1 个赞

我在pd dashboard找到了这条慢sql ,这个是这条sql 最大的内存是吧?

这是我tidb_mem_quota_query 变量信息, 是不是这条sql 的内存占用超过了最大内存 导致的变慢呀?
image

看来就这个内存的问题, 我把内存调大就快了,感谢大佬!!

mysql> SET tidb_mem_quota_query = 8 << 30;
Query OK, 0 rows affected (0.00 sec)

mysql> SET tidb_mem_quota_query = 8 << 30;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT xpost.postid, xpost.facetid, xpost.entryid, xpost.title, xpost.url, xpost.abstract, xpost.click, xpost.reply, xpost.repost, xpost.praise, xpost.collect, xpost.wordscount, xpost.siteid, xpost.domain, xpost.author, xpost.author_id, xpost.posttime, xpost.include_t, xpost.type, xpost.source, xpost.hidden, xpost.sourcetype, xpost.crisis_post, xpost.ontop, xpost.type_rank, xpost.pos_type_rank, xpost.noise_rank, xpost.device, xpost.is_origin, xpost.is_top, xpost.media_type, xpost.author_type, xpost.content_type, xpost.client_type, xpost.industry, xpost.tags, xpost.post_type, xpost.type_reason, xpost.update_time, xpost.origin_source, xpost.media_id, xpost.w_level, xpost.watch, xpost.keywordcount, xpost.location, xpost.is_comment, xpost.text, xpost.spider_time, xpost.process_time, xpost.tidb_in_time FROM xpost FORCE INDEX (idx_xpost_entryid) WHERE (xpost.entryid IN (4856577, 4855938, 4856069, 4855686, 4856079, 4857488, 4857618, 4855699, 4856087, 4855966, 4854815, 4855201, 4855714, 4855076, 4851496, 4855083, 4854830, 4856371, 4855608, 4851514, 4857916, 4852797, 4855743, 4851522, 4855748, 4855365, 4851526, 4855624, 4855626, 4856654, 4856018, 4855635, 4855764, 4855637, 4855766, 4854986, 4857305, 4855134, 4855135, 4857706, 4857454, 4855408, 4857211, 4856062) AND (1) AND xpost.hidden IN (-2, -1, 0, 2, 3, 4)) ORDER BY xpost.posttime DESC;  
1244055 rows in set (30.22 sec)

mysql> 
mysql> 
mysql>

客气了,看来就是太小导致sort算子走磁盘了,但是也得注意下监控,别因为太大导致oom了

1 个赞

好的 :kiss: :kiss: :kiss:

调整内存是能临时解决问题,看你4.x版本的也有落盘情况,但是并没有很慢。而且6.5版本才100多万记录需要7分钟,这种排序就算落盘也不正常,过慢了,我感觉需要深入分析下才行。得看下pprof耗时主要在什么地方。

我自己测试了下,不过是7.0版本的,也是很慢,测试如下:

mysql> select version();
+--------------------+
| version()          |
+--------------------+
| 5.7.25-TiDB-v7.0.0 |
+--------------------+
1 row in set (0.00 sec)
mysql> explain analyze select * from customer order by C_ADDRESS desc;
+-------------------------+-------------+----------+-----------+----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+-----------+---------+
| id                      | estRows     | actRows  | task      | access object  | execution info                                                                                                                                                                                                                                                                                                                                                       | operator info                   | memory    | disk    |
+-------------------------+-------------+----------+-----------+----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+-----------+---------+
| Sort_4                  | 15000000.00 | 15000000 | root      |                | time:11m31.8s, loops:14650, RRU:94859.635554, WRU:0.000000                                                                                                                                                                                                                                                                                                           | tpch100.customer.c_address:desc | 1011.0 MB | 3.09 GB |
| └─TableReader_8         | 15000000.00 | 15000000 | root      |                | time:17.4s, loops:14686, cop_task: {num: 565, max: 2.18s, min: 2.13ms, avg: 430.5ms, p95: 1.3s, max_proc_keys: 50144, p95_proc_keys: 50144, tot_proc: 2m24.4s, tot_wait: 1.22s, rpc_num: 565, rpc_time: 4m3.2s, copr_cache_hit_ratio: 0.00, build_task_duration: 17.4ms, max_distsql_concurrency: 15}                                                                | data:TableFullScan_7            | 180.3 MB  | N/A     |
|   └─TableFullScan_7     | 15000000.00 | 15000000 | cop[tikv] | table:customer | tikv_task:{proc max:1.86s, min:1ms, avg: 302.2ms, p80:559ms, p95:916ms, iters:16879, tasks:565}, scan_detail: {total_process_keys: 15000000, total_process_keys_size: 3052270577, total_keys: 15000565, get_snapshot_time: 262.7ms, rocksdb: {key_skipped_count: 15000000, block: {cache_hit_count: 5046, read_count: 49981, read_byte: 1.13 GB, read_time: 32.1s}}} | keep order:false                | N/A       | N/A     |
+-------------------------+-------------+----------+-----------+----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+-----------+---------+
3 rows in set (11 min 32.36 sec)

看时间真正排序花费时间很短,主要时间用在1、从磁盘中读取数据时候chunk.(*rowInDisk).ReadFrom(一直有的问题);2、chunk.New函数这里,最终主要是因为用完对象后调用runtime.mallocgc占用大量的CPU时间。

因此不知道是不是相比于4.x版本在从磁盘中读取数据到内存新创建chunk的时候发生了变化。这里看着感觉像是chunk数据返回给客户端后需要进行gc花费了很多时间,如果能采用类似于arena的技术手动大块(连续多个chunk)回收不知道效果上是否会更好。

我这个xpost表有58亿的数量,不理解这个一百多万是怎么回事