数据迁移操作速度慢

1、硬件,4台(64G内存、16核、阿里云SSD盘)

2、日志 1) tidb_slow_query.log

Time: 2019-08-07T09:50:25.745265227+08:00

Txn_start_ts: 410292748296126475

Query_time: 0.703752069

Prewrite_time: 0.556934552 Commit_time: 0.145204897 Get_commit_ts_time: 0.000285525 Local_latch_wait_time: 5.963e-06 Write_keys: 3 Write_size: 84 Prewrite_region: 1

Is_internal: true

Digest: 8d1c7c8cd6c130cdb23dc1cf1743c3333a8b43d67136d0fa03e69a0d7308cf8c

Num_cop_tasks: 0

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr:

Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr:

delete from mysql.stats_meta where table_id = 550489;

Time: 2019-08-07T09:50:26.287418085+08:00

Txn_start_ts: 410292748479627276

Query_time: 0.530500808

Prewrite_time: 0.327225982 Commit_time: 0.201623181 Get_commit_ts_time: 0.000287689 Local_latch_wait_time: 5e-06 Write_keys: 3 Write_size: 84 Prewrite_region: 1

Is_internal: true

Digest: 8d1c7c8cd6c130cdb23dc1cf1743c3333a8b43d67136d0fa03e69a0d7308cf8c

Num_cop_tasks: 0

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr:

Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr:

delete from mysql.stats_meta where table_id = 550539;

Time: 2019-08-07T09:50:26.642814977+08:00

Txn_start_ts: 410292748374769665

Query_time: 1.3073201669999999

Prewrite_time: 0.723361959 Commit_time: 0.58228445 Get_commit_ts_time: 0.00029737 Local_latch_wait_time: 4.278e-06 Write_keys: 2 Write_size: 56 Prewrite_region: 1

Is_internal: true

Digest: c6cc6600d9e30e2c65d85988b59746e00e0306aced60ded10b7abdea6308b200

Num_cop_tasks: 0

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr:

Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr:

DELETE FROM mysql.gc_delete_range_done WHERE job_id = 520158 AND element_id = 513959;

Time: 2019-08-07T09:50:26.837264282+08:00

Txn_start_ts: 410292748623806468

Query_time: 0.546290999

Prewrite_time: 0.10780567 Commit_time: 0.43682156 Get_commit_ts_time: 0.000319809 Local_latch_wait_time: 3.85e-06 Write_keys: 3 Write_size: 84 Prewrite_region: 1

…skipping…

Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr:

update mysql.stats_meta set version = 410407803483324418, count = count + 0, modify_count = modify_count + 4002 where table_id = 15;

Time: 2019-08-12T11:45:26.450522464+08:00

Txn_start_ts: 410407803588182020

Query_time: 0.306597233

Wait_time: 0.305 Request_count: 1 Total_keys: 1

Is_internal: true

Digest: 16e7ac941a71c9c110e4ef0b2a3be61537fb4e890c78d99a4ccd1fce5d8f240e

Stats: stats_feedback:pseudo

Num_cop_tasks: 1

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr: 10.0.66.74:20160

Cop_wait_avg: 0.305 Cop_wait_p90: 0.305 Cop_wait_max: 0.305 Cop_wait_addr: 10.0.66.74:20160

Mem_max: 116

select table_id, hist_id, is_index, feedback from mysql.stats_feedback order by table_id, hist_id, is_index;

Time: 2019-08-12T11:45:28.205124917+08:00

Txn_start_ts: 410407803968290817

Query_time: 0.594862516

Wait_time: 0.593 Request_count: 2

Index_ids: [1]

Is_internal: true

Digest: ab6d79d3e75abdf0ba1e0fb7161312e07099349d4d14a13968fa9cc7767d66a1

Stats: tidb:pseudo

Num_cop_tasks: 2

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr: 10.0.66.75:20160

Cop_wait_avg: 0.2965 Cop_wait_p90: 0.593 Cop_wait_max: 0.593 Cop_wait_addr: 10.0.66.75:20160

Mem_max: 9605

SELECT HIGH_PRIORITY (variable_value) FROM mysql.tidb WHERE variable_name=‘tikv_gc_leader_uuid’ FOR UPDATE;

Time: 2019-08-12T11:45:28.987246551+08:00

Txn_start_ts: 410407803968290817

Query_time: 0.490320554

Prewrite_time: 0.227371058 Commit_time: 0.262557179 Get_commit_ts_time: 0.000319775 Local_latch_wait_time: 3.181e-06 Write_keys: 1 Write_size: 119 Prewrite_region: 1

Is_internal: true

Digest: 9505cacb7c710ed17125fcc6cb3669e8ddca6c8cd8af6a31f6b3cd64604c3098

Num_cop_tasks: 0

Cop_proc_avg: 0 Cop_proc_p90: 0 Cop_proc_max: 0 Cop_proc_addr:

Cop_wait_avg: 0 Cop_wait_p90: 0 Cop_wait_max: 0 Cop_wait_addr:

COMMIT; 2) tidb.log [2019/08/12 11:45:08.184 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:415.839879ms txnStartTS:410407798764732417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:415"] [2019/08/12 11:45:20.348 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:580.253323ms txnStartTS:410407801910460417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:579"] [2019/08/12 11:45:23.145 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:307.767041ms txnStartTS:410407802709999617 region_id:72 store_addr:10.0.66.74:20160 kv_wait_ms:307"] [2019/08/12 11:45:26.450 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:306.218368ms txnStartTS:410407803588182020 region_id:60 store_addr:10.0.66.74:20160 kv_wait_ms:305"] [2019/08/12 11:45:28.204 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:593.856442ms txnStartTS:410407803968290817 region_id:32 store_addr:10.0.66.75:20160 kv_wait_ms:593"] [2019/08/12 11:45:28.987 +08:00] [INFO] [gc_worker.go:244] ["[gc worker] there’s already a gc job running, skipped"] [“leaderTick on”=5b1d6f5d5d40001] [2019/08/12 11:45:53.199 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:427.567562ms txnStartTS:410407810561212418 region_id:28 store_addr:10.0.66.74:20160 kv_wait_ms:427"] [2019/08/12 11:45:56.166 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:395.938585ms txnStartTS:410407811347644418 region_id:60 store_addr:10.0.66.74:20160 kv_wait_ms:395"] [2019/08/12 11:45:56.361 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:592.610156ms txnStartTS:410407811347644417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:592"] [2019/08/12 11:46:08.420 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:651.9527ms txnStartTS:410407814493372417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:651"] [2019/08/12 11:46:09.476 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:414.087099ms txnStartTS:410407814834159617 region_id:72 store_addr:10.0.66.74:20160 kv_wait_ms:413"] [2019/08/12 11:46:17.209 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:439.179506ms txnStartTS:410407816852668418 region_id:28 store_addr:10.0.66.74:20160 kv_wait_ms:438"] [2019/08/12 11:46:20.270 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:501.600465ms txnStartTS:410407817639100417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:501"] [2019/08/12 11:46:28.302 +08:00] [INFO] [gc_worker.go:244] ["[gc worker] there’s already a gc job running, skipped"] [“leaderTick on”=5b1d6f5d5d40001] [2019/08/12 11:46:32.398 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:630.161982ms txnStartTS:410407820784828417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:629"] [2019/08/12 11:46:44.381 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:613.108838ms txnStartTS:410407823930556417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:612"] [2019/08/12 11:46:56.314 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:545.499854ms txnStartTS:410407827076284417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:545"] [2019/08/12 11:47:05.189 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:556.198081ms txnStartTS:410407829396258817 region_id:72 store_addr:10.0.66.74:20160 kv_wait_ms:556"] [2019/08/12 11:47:08.246 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:476.202059ms txnStartTS:410407830222012418 region_id:28 store_addr:10.0.66.74:20160 kv_wait_ms:469"] [2019/08/12 11:47:08.259 +08:00] [INFO] [coprocessor.go:726] ["[TIME_COP_WAIT] resp_time:490.956018ms txnStartTS:410407830222012417 region_id:40 store_addr:10.0.66.75:20160 kv_wait_ms:490"] 3、SQL explain ANALYZE SELECT version, table_id, modify_count, count FROM mysql.stats_meta WHERE version > 410406893660143619 ORDER BY version; 结果如下:

Projection_18 3333.33 root mysql.stats_meta.version, mysql.stats_meta.table_id, mysql.stats_meta.modify_count, mysql.stats_meta.count time:235.79554ms, loops:2, rows:12
└─IndexLookUp_17 3333.33 root time:235.740265ms, loops:2, rows:12
├─IndexScan_15 3333.33 cop table:stats_meta, index:version, range:(410406893660143619,+inf], keep order:true, stats:pseudo time:0s, loops:1, rows:12
└─TableScan_16 3333.33 cop table:stats_meta, keep order:false, stats:pseudo time:0s, loops:1, rows:12

请将系统的基本运行情况再详细告知一下。比如机器负载,磁盘 IO 性能等。ps:请按照提问标准模板进行有效提问。