900w表添加索引超过一天还没执行完，如何排查？

🪐 TiDB 技术问题
1

【 TiDB 使用环境】线上
【 TiDB 版本】v5.2.2
【遇到的问题】900w表添加索引超过一天还没执行完, 执行admin show ddl jobs, ROW_COUNT到了一定值后很长时间都不变化了，根据ddl关键词过滤tidb.log如下
[2022/08/24 09:07:20.332 +08:00] [INFO] [reorg.go:284] ["[ddl] run reorg job wait timeout"] [waitTime=5s] [elementType=idx] [elementID=11] [totalAddedRowCount=3966492] [doneKey=1168558586.next] []
[2022/08/24 09:07:20.336 +08:00] [INFO] [ddl_worker.go:886] ["[ddl] schema version doesn’t change"] [worker=“worker 2, tp add index”]
[2022/08/24 09:07:20.337 +08:00] [INFO] [ddl_worker.go:727] ["[ddl] run DDL job"] [worker=“worker 2, tp add index”] [job=“ID:5160, Type:add index, State:running, SchemaState:write reorganization, SchemaID:53, TableID:216, RowCount:3966492, ArgLen:0, start time: 2022-08-23 20:34:43.531 +0800 CST, Err:, ErrCount:0, SnapshotVersion:435488839088472086”]
[2022/08/24 09:07:25.401 +08:00] [INFO] [reorg.go:284] ["[ddl] run reorg job wait timeout"] [waitTime=5s] [elementType=idx] [elementID=11] [totalAddedRowCount=3966492] [doneKey=1168558586.next] []
[2022/08/24 09:07:25.404 +08:00] [INFO] [ddl_worker.go:886] ["[ddl] schema version doesn’t change"] [worker=“worker 2, tp add index”]
[2022/08/24 09:07:25.405 +08:00] [INFO] [ddl_worker.go:727] ["[ddl] run DDL job"] [worker=“worker 2, tp add index”] [job=“ID:5160, Type:add index, State:running, SchemaState:write reorganization, SchemaID:53, TableID:216, RowCount:3966492, ArgLen:0, start time: 2022-08-23 20:34:43.531 +0800 CST, Err:, ErrCount:0, SnapshotVersion:435488839088472086”]
[2022/08/24 09:07:30.429 +08:00] [INFO] [reorg.go:284] ["[ddl] run reorg job wait timeout"] [waitTime=5s] [elementType=idx] [elementID=11] [totalAddedRowCount=3966492] [doneKey=1168558586.next] []
[2022/08/24 09:07:30.432 +08:00] [INFO] [ddl_worker.go:886] ["[ddl] schema version doesn’t change"] [worker=“worker 2, tp add index”]
[2022/08/24 09:07:30.436 +08:00] [INFO] [ddl_worker.go:727] ["[ddl] run DDL job"] [worker=“worker 2, tp add index”] [job=“ID:5160, Type:add index, State:running, SchemaState:write reorganization, SchemaID:53, TableID:216, RowCount:3966492, ArgLen:0, start time: 2022-08-23 20:34:43.531 +0800 CST, Err:, ErrCount:0, SnapshotVersion:435488839088472086”]
[2022/08/24 09:07:35.467 +08:00] [INFO] [reorg.go:284] ["[ddl] run reorg job wait timeout"] [waitTime=5s] [elementType=idx] [elementID=11] [totalAddedRowCount=3966492] [doneKey=1168558586.next] []
[2022/08/24 09:07:35.470 +08:00] [INFO] [ddl_worker.go:886] ["[ddl] schema version doesn’t change"] [worker=“worker 2, tp add index”]
[2022/08/24 09:07:35.471 +08:00] [INFO] [ddl_worker.go:727] ["[ddl] run DDL job"] [worker=“worker 2, tp add index”] [job=“ID:5160, Type:add index, State:running, SchemaState:write reorganization, SchemaID:53, TableID:216, RowCount:3966492, ArgLen:0, start time: 2022-08-23 20:34:43.531 +0800 CST, Err:, ErrCount:0, SnapshotVersion:435488839088472086”]

【复现路径】执行admin cancel ddl jobs jobid,重新执行添加索引还是上面的现象。
请问如何排查ddl卡在哪个阶段？以及如何解决？

2

你看，可以看下cpu,内存，磁盘空间以及iops等资源情况如何，另外把t卡死时间的tidb,tikv日志脱敏发下，按理说900万应该很快啊

另外看下这两个参数的配置： tidb_ddl_reorg_batch_size 和 tidb_ddl_reorg_worker_cnt

顺便看下，索引回填了多少行，多长时间卡死的

3

看错误，索引回填超时了。检查下系统变量：

  1. tidb_ddl_reorg_worker_cnt（回填并发度，默认为 4.）。
  2. tidb_ddl_reorg_batch_size（回填单位，默认 256）。
  3. tidb_ddl_reorg_priority（回填优先级，默认为 PRIORITY_LOW）。
  4. tidb_ddl_error_count_limit（加索引重试次数，默认为 512）。
    其中，tidb_ddl_reorg_priority 作用域为 SESSION 级。加索引期间，是否有大量 DML 操作。尽量避开业务高峰期加索引。

系统变量查询方式如下：

mysql> show variables like 'tidb_ddl_%';
+----------------------------+--------------+
| Variable_name              | Value        |
+----------------------------+--------------+
| tidb_ddl_error_count_limit | 512          |
| tidb_ddl_reorg_batch_size  | 256          |
| tidb_ddl_reorg_priority    | PRIORITY_LOW |
| tidb_ddl_reorg_worker_cnt  | 4            |
+----------------------------+--------------+
4 rows in set (0.00 sec)
4

1、admin show ddl jobs结果，row_count卡在3966492这里很久了
-----±--------------------±--------------------±--------+
| JOB_ID | DB_NAME | TABLE_NAME | JOB_TYPE | SCHEMA_STATE | SCHEMA_ID | TABLE_ID | ROW_COUNT | START_TIME | END_TIME | STATE |
±-------±---------------------±---------------------------------------------------±---------------±---------------------±----------±---------±----------±--------------------±--------------------±--------+
| 5160 | test | test | add index | write reorganization | 53 | 216 | 3966492 | 2022-08-23 20:34:43 | NULL | running |

2、
| tidb_ddl_reorg_batch_size | 256 |
| tidb_ddl_reorg_worker_cnt | 4

3、资源使用情况

image
image1346×380 81.6 KB

image
image2694×518 96.6 KB

image
image1342×398 36.7 KB

5

加索引期间没有很多的dml操作，都是默认的参数

image
image2722×1020 554 KB

6

若排除 TiKV IO 瓶颈，建议适当调高 show variables like 'tidb_ddl_%';返回的几个系统变量值，注意对业务性能的影响。提升加索引速度的同时，如果数据库业务较忙，可能带来性能抖动。

7

可以grafana ，把{cluster_name}-TiDB -> DDL 这个监控发一下看看。

8

image
image2746×1248 473 KB

image
image2724×1138 184 KB

9

调大后ROW_COUNT也还是不变化
| tidb_ddl_reorg_batch_size | 512 |
| tidb_ddl_reorg_worker_cnt | 8 |

10

curl -X POST http://{TiDBIP}:10080/ddl/owner/resign
试试重新选举一个ddl owner 然后再加索引 可以用 SELECT tidb_is_ddl_owner();查看当前tidb server是否owner

11

我试试

12

表的region拆分一下，tidb_ddl_reorg_worker_cnt，tidb_ddl_reorg_batch_size 调大

13

试了，还是不行，加索引速度还是很慢，row_count很长时间才变化

14

表结构、索引语句能贴下吗

15

表结构：
CREATE TABLE summary (
id bigint(20) NOT NULL AUTO_INCREMENT,
empName varchar(100) DEFAULT NULL,
empUuid varchar(100) DEFAULT NULL,
deptUuid varchar(100) DEFAULT NULL,
deptName varchar(100) DEFAULT NULL,
positionUuid varchar(100) DEFAULT NULL,
positionName varchar(100) DEFAULT NULL,
empGroupUuid varchar(100) DEFAULT NULL,
empGroupName varchar(100) DEFAULT NULL,
versionUuid varchar(100) DEFAULT NULL,
companyUuid varchar(100) DEFAULT NULL,
companyName varchar(100) DEFAULT NULL’,
strokeScore decimal(19,2) DEFAULT NULL,
achieveScore decimal(19,2) DEFAULT NULL,
attendScore decimal(19,2) DEFAULT NULL,
customScore decimal(19,2) DEFAULT NULL,
noReachScore decimal(19,2) DEFAULT NULL,
totalScore decimal(19,2) DEFAULT NULL,
assessDateScore decimal(19,2) DEFAULT NULL,
assessWeekScore decimal(19,2) DEFAULT NULL,
assessMonthScore decimal(19,2) DEFAULT NULL,
cal_dt varchar(50) DEFAULT NULL,
approveScore decimal(19,2) DEFAULT NULL,
PRIMARY KEY (id) /*T![clustered_index] CLUSTERED */,
KEY idx_companyUuid (companyUuid),
KEY idx_empUuid (empUuid),
KEY idx_deptUuid (deptUuid),
KEY idx_positionUuid (positionUuid),
KEY idx_empGroupUuid (empGroupUuid),
KEY idx_versionUuid (versionUuid),
KEY idx_cal_dt (cal_dt)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin;

添加索引语句：
ALTER TABLE summary ADD INDEX idx_cal_dt_companyuuid (cal_dt,companyUuid);

现在的表现是：row_count前350w左右跑的很快，然后涨到480w左右很长时间不动，然后涨到557w左右很长时间又不动了(此时已经过去2天了)，感觉再花个几天也能加完

16

看一下gc 设置的是多长时间，中间是不是有大量更新或者删除数据，然后gc 设置的时间太长了导致有很多旧版本的数据

17

1、gc相关设置
| tidb_gc_life_time | 10m0s |
| tidb_gc_run_interval | 10m0s |

2、如何查看是否有很多版本的数据？

3、mysql> select count() from summary;
±---------+
| count() |
±---------+
| 9113495 |
±---------+
1 row in set (1 min 6.88 sec)

dashboad看慢sql里的“Coprocessor 读取”如下，与这个有关系吗？
可见版本数 9.0 Mil
遇到版本数 2.3 Bil 含已删除或覆盖但未 GC 的版本

18

这张表增加其它字段的索引有无这样的问题？

19

建一个相同表结构的表，把数据插入试一下呢，看看是这个表有问题还是所有的都有问题；

20

这个表除了这个近期没有添加索引，现在这个表已经缓慢加索引到700多万行了，过几天加完再测试下