【 TiDB 使用环境】生产环境
【 TiDB 版本】6.5.5
【复现路径】做过哪些操作出现的问题
09:22:50执行以下SQL加索引:
alter table wm_xxx add index idx_xxx(c1,c2)
【遇到的问题:问题现象及影响】
执行后一直卡住,job_type为add index /* ingest */,state为write reorganization,row_count始终为0
执行ddl的tidb server 日志:
[2024/04/09 09:22:51.021 +08:00] [Info] [ddl_worker.go:314] ["[ddl] add DDL jobs"] ["batch count"=1] [jobs="ID:37449, Type:add index, State:queueing, SchemaState:none, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0; "] [table=true]
[2024/04/09 09:22:51.022 +08:00] [Info] [ddl.go:1011] ["[ddl] start DDL job"] [job="ID:37449, Type:add index, State:queueing, SchemaState:none, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"] [query="alter table wm_xxx add index idx_xxx(c1,c2)"]
[2024/04/09 09:22:51.077 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39676]
[2024/04/09 09:22:51.177 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39677]
[2024/04/09 09:22:51.227 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39678]
ddl owner的相关日志:
[2024/04/09 09:22:51.047 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 13, tp add index"] [job="ID:37449, Type:add index, State:queueing, SchemaState:none, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.050 +08:00] [Info] [index.go:605] ["[ddl] run add index job"] [job="ID:37449, Type:add index, State:running, SchemaState:none, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"] [indexInfo="{\"id\":7,\"idx_name\":{\"O\":\"idx_xxx\",\"L\":\"idx_xxx\"},\"tbl_name\":{\"O\":\"\",\"L\":\"\"},\"idx_cols\":[{\"name\":{\"O\":\"group_mater_flag\",\"L\":\"group_mater_flag\"},\"offset\":5,\"length\":-1},{\"name\":{\"O\":\"scan_flag\",\"L\":\"scan_flag\"},\"offset\":93,\"length\":-1}],\"state\":0,\"backfill_state\":0,\"comment\":\"\",\"index_type\":1,\"is_unique\":false,\"is_primary\":false,\"is_invisible\":false,\"is_global\":false}"]
[2024/04/09 09:22:51.100 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39676]
[2024/04/09 09:22:51.111 +08:00] [Info] [ddl_worker.go:1395] ["[ddl] wait latest schema version changed(get the metadata lock if tidb_enable_metadata_lock is true)"] [ver=39676] ["take time"=52.592634ms] [job="ID:37449, Type:add index, State:running, SchemaState:delete only, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.120 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:delete only, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.150 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39677]
[2024/04/09 09:22:51.182 +08:00] [Info] [syncer.go:333] ["[ddl] syncer check all versions, someone is not synced"] [info="instance ip 10.0.6.65, port 4002, id 0a414933-16dc-4baa-b762-7a250aae380c"] ["ddl id"=37449] [ver=39677]
[2024/04/09 09:22:51.203 +08:00] [Info] [ddl_worker.go:1395] ["[ddl] wait latest schema version changed(get the metadata lock if tidb_enable_metadata_lock is true)"] [ver=39677] ["take time"=73.441067ms] [job="ID:37449, Type:add index, State:running, SchemaState:write only, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.210 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 6, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write only, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.249 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39678]
[2024/04/09 09:22:51.271 +08:00] [Info] [ddl_worker.go:1395] ["[ddl] wait latest schema version changed(get the metadata lock if tidb_enable_metadata_lock is true)"] [ver=39678] ["take time"=52.152977ms] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.290 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/04/09 09:22:51.292 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:22:51.320 +08:00] [Info] [backend_mgr.go:74] ["[ddl-ingest] create one backend for an DDL job"] ["job ID"=37449] ["current memory usage"=136] ["max memory quota"=2147483648] ["is unique index"=false]
[2024/04/09 09:22:51.336 +08:00] [Info] [reorg.go:621] ["[ddl] job get table range"] [jobID=37449] [physicalTableID=7737] [startKey=748000000000001e395f728000000000000e10] [endKey=748000000000001e395f72800000000d500251]
[2024/04/09 09:22:51.355 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:22:51.358 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:22:51.359 +08:00] [Info] [index.go:1682] ["[ddl] start to add table index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:6, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"] [reorgInfo="CurrElementType:_idx_,CurrElementID:7,StartKey:748000000000001e395f728000000000000e10,EndKey:748000000000001e395f72800000000d500251,First:false,PhysicalTableID:7737,Ingest mode:true"]
[2024/04/09 09:22:51.386 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] open an engine for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=335544600] ["memory limitation"=2147483648] ["current writer count"=1]
[2024/04/09 09:22:51.411 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=0] ["allocate memory"=32] ["current memory usage"=335544632] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.411 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=402653496] ["memory limitation"=2147483648] ["current writer count"=2]
[2024/04/09 09:22:51.436 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=1] ["allocate memory"=32] ["current memory usage"=402653528] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.437 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=469762392] ["memory limitation"=2147483648] ["current writer count"=3]
[2024/04/09 09:22:51.461 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=2] ["allocate memory"=32] ["current memory usage"=469762424] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.461 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=536871288] ["memory limitation"=2147483648] ["current writer count"=4]
[2024/04/09 09:22:51.488 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=3] ["allocate memory"=32] ["current memory usage"=536871320] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.488 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=603980184] ["memory limitation"=2147483648] ["current writer count"=5]
[2024/04/09 09:22:51.514 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=4] ["allocate memory"=32] ["current memory usage"=603980216] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.514 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=671089080] ["memory limitation"=2147483648] ["current writer count"=6]
[2024/04/09 09:22:51.540 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=5] ["allocate memory"=32] ["current memory usage"=671089112] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.540 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=738197976] ["memory limitation"=2147483648] ["current writer count"=7]
[2024/04/09 09:22:51.568 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=6] ["allocate memory"=32] ["current memory usage"=738198008] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.568 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=805306872] ["memory limitation"=2147483648] ["current writer count"=8]
[2024/04/09 09:22:51.595 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=7] ["allocate memory"=32] ["current memory usage"=805306904] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.595 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=872415768] ["memory limitation"=2147483648] ["current writer count"=9]
[2024/04/09 09:22:51.622 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=8] ["allocate memory"=32] ["current memory usage"=872415800] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.622 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=939524664] ["memory limitation"=2147483648] ["current writer count"=10]
[2024/04/09 09:22:51.649 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=9] ["allocate memory"=32] ["current memory usage"=939524696] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.649 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1006633560] ["memory limitation"=2147483648] ["current writer count"=11]
[2024/04/09 09:22:51.677 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=10] ["allocate memory"=32] ["current memory usage"=1006633592] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.677 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1073742456] ["memory limitation"=2147483648] ["current writer count"=12]
[2024/04/09 09:22:51.704 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=11] ["allocate memory"=32] ["current memory usage"=1073742488] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.704 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1140851352] ["memory limitation"=2147483648] ["current writer count"=13]
[2024/04/09 09:22:51.730 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=12] ["allocate memory"=32] ["current memory usage"=1140851384] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.730 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1207960248] ["memory limitation"=2147483648] ["current writer count"=14]
[2024/04/09 09:22:51.757 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=13] ["allocate memory"=32] ["current memory usage"=1207960280] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.757 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1275069144] ["memory limitation"=2147483648] ["current writer count"=15]
[2024/04/09 09:22:51.783 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=14] ["allocate memory"=32] ["current memory usage"=1275069176] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.783 +08:00] [Info] [engine_mgr.go:82] ["[ddl-ingest] reuse engine and add a writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["current memory usage"=1342178040] ["memory limitation"=2147483648] ["current writer count"=16]
[2024/04/09 09:22:51.807 +08:00] [Info] [engine.go:170] ["[ddl-ingest] create one local writer for index reorg task"] ["job ID"=37449] ["index ID"=7] ["worker ID"=15] ["allocate memory"=32] ["current memory usage"=1342178072] ["max memory quota"=2147483648]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:51.808 +08:00] [Warn] [engine_mgr.go:73] ["[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)"] ["job ID"=37449] ["index ID"=7] [concurrency=16]
[2024/04/09 09:22:56.365 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:22:56.367 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:01.378 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:01.394 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:06.402 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:06.404 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:11.415 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:11.417 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:16.426 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:16.428 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:21.435 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:21.437 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:26.445 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:26.447 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:31.455 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:31.457 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:36.465 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:36.468 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:41.475 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:41.477 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:46.485 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:46.488 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:51.501 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:51.503 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:23:56.511 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:23:56.513 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:01.521 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:01.523 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:06.531 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:06.533 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:11.540 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:11.543 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:16.551 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:16.553 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:21.562 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:21.565 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:26.573 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:26.576 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:31.583 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:31.585 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:36.593 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:36.595 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:41.603 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:41.605 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:46.613 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:46.615 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:51.624 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:51.626 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:24:56.635 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:24:56.637 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:01.646 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:01.648 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:06.655 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:06.658 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:11.666 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:11.668 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:16.676 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:16.679 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:21.686 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:21.689 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:26.697 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:26.699 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:31.708 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:31.710 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:36.718 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:36.720 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:41.729 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 11, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:41.731 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:46.740 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 7, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:46.742 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:51.750 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 8, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:51.753 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
[2024/04/09 09:25:56.761 +08:00] [Info] [ddl_worker.go:1186] ["[ddl] run DDL job"] [worker="worker 4, tp add index"] [job="ID:37449, Type:add index, State:running, SchemaState:write reorganization, SchemaID:3642, TableID:7737, RowCount:0, ArgLen:0, start time: 2024-04-09 09:22:50.984 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:448954570187473162, UniqueWarnings:0"]
[2024/04/09 09:25:56.763 +08:00] [Info] [index.go:800] ["[ddl] index backfill state running"] ["job ID"=37449] [table=wm_xxx] ["ingest mode"=true] [index=idx_xxx]
中间出现"[ddl-ingest] the concurrency is greater than lightning limit(tikv-importer.range-concurrency)“]后每隔5s反复打印[”[ddl] run DDL job"]和[“[ddl] index backfill state running”] 。
以上日志是根据job id:37449过滤后的结果。
其他所有tidb server也在相近的时间点打印3条以下信息:
[2024/04/09 09:22:51.100 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39676]
[2024/04/09 09:22:51.150 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39677]
[2024/04/09 09:22:51.250 +08:00] [Info] [domain.go:766] ["mdl gets lock, update to owner"] [jobID=37449] [version=39678]
不清楚什么原因卡住。
【资源配置】进入到 TiDB Dashboard -集群信息 (Cluster Info) -主机(Hosts) 截图此页面
【附件:截图/日志/监控】