Skip to content
This repository has been archived by the owner on Dec 8, 2021. It is now read-only.

Analyze table timeout in lightning #447

Closed
shuijing198799 opened this issue Nov 4, 2020 · 4 comments
Closed

Analyze table timeout in lightning #447

shuijing198799 opened this issue Nov 4, 2020 · 4 comments
Labels
severity/major type/bug This issue is a bug report

Comments

@shuijing198799
Copy link

Bug Report

Please answer these questions before submitting your issue. Thanks!

  1. What did you do? If possible, provide a recipe for reproducing the error.
    I use lightning to restore 100G data from s3, at the end of restore processing, the lightning repoert analyze timeout error
[2020/11/04 08:56:26.445 +00:00] [WARN] [util.go:125] ["analyze table failed but going to try again"] [table=`test`.`stock`] [query="ANALYZE TABLE `test`.`stock`"] [args=null] [retryCnt=2] [error="Error 9002: TiKV server timeout"]
[2020/11/04 08:56:26.446 +00:00] [ERROR] [restore.go:1639] ["analyze failed"] [table=`test`.`stock`] [takeTime=1h40m8.408848091s] [error="analyze table failed: Error 9002: TiKV server timeout"]
[2020/11/04 08:56:26.449 +00:00] [ERROR] [restore.go:698] ["restore table failed"] [table=`test`.`stock`] [takeTime=5h36m51.176150392s] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"]
[2020/11/04 08:59:17.429 +00:00] [INFO] [restore.go:1639] ["analyze completed"] [table=`test`.`order_line`] [takeTime=1h49m40.679022138s] []
[2020/11/04 08:59:17.429 +00:00] [INFO] [restore.go:698] ["restore table completed"] [table=`test`.`order_line`] [takeTime=6h6m20.93107398s] []
[2020/11/04 08:59:17.430 +00:00] [ERROR] [restore.go:815] ["restore all tables data failed"] [takeTime=6h8m3.509870242s] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"]
[2020/11/04 08:59:17.430 +00:00] [ERROR] [restore.go:301] ["run failed"] [step=3] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"]
Error: restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout
[2020/11/04 08:59:17.430 +00:00] [ERROR] [restore.go:312] ["the whole procedure failed"] [takeTime=6h8m3.546851092s] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"]
[2020/11/04 08:59:17.430 +00:00] [INFO] [restore.go:570] ["everything imported, stopping periodic actions"]
[2020/11/04 08:59:17.430 +00:00] [ERROR] [restore.go:114] ["tables failed to be imported"] [count=1]
[2020/11/04 08:59:17.432 +00:00] [ERROR] [restore.go:116] [-] [table=`test`.`stock`] [status=analyzed] [error="analyze table failed: Error 9002: TiKV server timeout"]
[2020/11/04 08:59:17.433 +00:00] [ERROR] [main.go:83] ["tidb lightning encountered error stack info"] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"] [errorVerbose="Error 9002: TiKV server timeout\ngithub.com/pingcap/errors.AddStack\n\t/root/go/pkg/mod/github.com/pingcap/[email protected]/errors.go:174\ngithub.com/pingcap/errors.Trace\n\t/root/go/pkg/mod/github.com/pingcap/[email protected]/juju_adaptor.go:15\ngithub.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.Exec.func1\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/common/util.go:182\ngithub.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.perform\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/common/util.go:120\ngithub.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.Exec\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/common/util.go:180\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*TableRestore).analyzeTable\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/restore/restore.go:1638\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*TableRestore).postProcess\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/restore/restore.go:1228\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*TableRestore).restoreTable\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/restore/restore.go:870\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*RestoreController).restoreTables.func1\n\t/shared-nvme-disks/disk0/ansible-deploy/gl/tidb-lightning/lightning/restore/restore.go:696\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357\nanalyze table failed\nrestore table `test`.`stock` failed"]
[2020/11/04 08:59:17.433 +00:00] [ERROR] [main.go:84] ["tidb lightning encountered error"] [error="restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout"]
tidb lightning encountered error:  restore table `test`.`stock` failed: analyze table failed: Error 9002: TiKV server timeout

  1. What did you expect to see?
    restore successful

  2. What did you see instead?
    nothing

  3. Versions of the cluster

    • TiDB-Lightning version (run tidb-lightning -V):

      Release Version: v4.0.7-11-g2660ffe
Git Commit Hash: 2660ffe03e85e2c84bce7a5dd4013360fd0f8e57
Git Branch: master
UTC Build Time: 2020-10-21 09:53:58
Go Version: go version go1.13.12 linux/amd64

  4. Operation Log
    lightning (2).log

  5. Configuration of the cluster and the task

    • tidb-lightning.toml for TiDB-Lightning if possible
    • tikv-importer.toml for TiKV-Importer if possible
    • inventory.ini if deployed by Ansible
# lightning Configuration

[lightning]
check-requirements = true
index-concurrency = 4
level = "info"
file=""
pprof-port = 8289
table-concurrency = 4

[checkpoint]
enable = true
driver = "file"
dsn = "/etc/endpoint/cp.pb"

[security]
# Specifies certificates and keys for TLS connections within the cluster.
# Public certificate of the CA. Leave empty to disable TLS.
ca-path = "/var/lib/lightning-tls/ca.crt"
# Public certificate of this service.
cert-path = "/var/lib/lightning-tls/tls.crt"
# Private key of this service.
key-path = "/var/lib/lightning-tls/tls.key"

[tikv-importer]
backend = "local"
sorted-kv-dir = "/etc/endpoint"

[mydumper]
data-source-dir = "s3://tidblightning-cloud-test/data-14k?region=us-west-2"
no-schema = true
strict-format = true
#default-file-rules = false

#[[mydumper.files]]
#pattern = "(?i)^(?:[^/]*/)*([a-z]+)[0-9]*(?:\\.([0-9]+))?\\.(sql|csv)$"
#schema = "test"
#table = "$1"
#type = "$3"

[mydumper.csv]
backslash-escape = true
delimiter = '"'
#delimiter = ''
header = false
not-null = false
null = "NULL"
separator = ","

[tidb]
host = "db-tidb"
log-level = "error"
password = "12345678"
port = 4000
status-port = 10080
user = "root"
pd-addr = "db-pd:2379"
tls = "false"

[post-restore]
analyze = true
checksum = true

[cron]
log-progress = "5m"
switch-mode = "5m"
@glorv
Copy link
Contributor

glorv commented Nov 5, 2020

There are some strage lines in the tikv log that tikv found several extremely large region need to be splited:

[2020/11/04 08:09:41.124 +00:00] [INFO] [size.rs:255] ["region size is too large"] [cf=write] [ssts_size="005297.sst:97086217, 005286.sst:96882728, 005272.sst:96986684, 005263.sst:97082951, 005241.sst:96973619, 005212.sst:96984531, 005192.sst:96295309, 005182.sst:96914192, 005172.sst:96896000, 005163.sst:97133290, 005142.sst:97076869, 005112.sst:96794375, 005100.sst:97074579, 005080.sst:97119746, 005060.sst:96867762, 005050.sst:96860638, 005030.sst:96987937, 005020.sst:97119812, 005010.sst:96494072, 005001.sst:96774180, 004990.sst:96823296, 004970.sst:96981036, 004960.sst:97084208, 004950.sst:96483957, 004923.sst:97099185, 002813.sst:131, 005232.sst:96956781, 005132.sst:96342232, 004902.sst:97088667, 004890.sst:96529397, 004880.sst:96634244, 005279.sst:97090218, 005222.sst:97077702, 004860.sst:97117426, 004553.sst:96808272, 004731.sst:96983936, 004588.sst:97134872, 004800.sst:97086940, 004368.sst:123, 005040.sst:97071280, 004532.sst:96979988, 004599.sst:96999773, 005090.sst:97022103, 004697.sst:96550481, 005122.sst:96848059, 004522.sst:96988726, 005202.sst:97081847, 004498.sst:96377705, 004443.sst:96939968, 004676.sst:97109121, 004487.sst:96986968, 005252.sst:96269071, 004870.sst:96886284, 004566.sst:96430164, 004665.sst:96985626, 004476.sst:96979185, 005070.sst:96402984, 004770.sst:96671022, 004577.sst:96753358, 004980.sst:97086255, 004632.sst:96479954, 004764.sst:96567056, 004396.sst:97009135, 004453.sst:96983608, 004910.sst:96983196, 004326.sst:134, 004720.sst:97082338, 005152.sst:97021387, 004830.sst:96571832, 004428.sst:96334553, 004930.sst:96981611, 004346.sst:134, 004609.sst:97079081, 004643.sst:96712531, 004940.sst:96719410, 004416.sst:97069069, 004511.sst:96929095, 004465.sst:97087753, 004619.sst:96935365, 004685.sst:96946518, 004708.sst:96673747, 004742.sst:97095862, 004376.sst:97084630, 004751.sst:96804125, 004780.sst:97113745, 004790.sst:97019267, 004820.sst:96621977, 004544.sst:97083991, 004810.sst:96845201, 004654.sst:97076448, 004840.sst:97116560, 004850.sst:97028669"] [memtable=0] [total_size=8526206064] [region_id=14444]
[2020/11/04 08:09:41.124 +00:00] [INFO] [size.rs:174] ["approximate size over threshold, need to do split check"] [threshold=150994944] [size=8526206064] [region_id=14444]

Lightning has ingested so much sst files to this region.

> grep "\[ingest\] .* region_id: 14444" tikv0.log | wc -l
87
> grep "link plaintext file.*14444_5_686_write" tikv0.log| wc -l
87

But the ingested ranges has no overlap:

> grep "\[ingest\] .* region_id: 14444" tikv0.log
[2020/11/04 04:31:40.324 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 406EC9578B8E4A2A91B3839C8993238B range { start: 7480000000000000FF545F728000000049FF3A9E090000000000FA end: 7480000000000000FF545F728000000049FF4600900000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:33:08.410 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 65F73EC34DDC441C90D873D57CEC317E range { start: 7480000000000000FF545F728000000049FF4600910000000000FA end: 7480000000000000FF545F72800000004AFFB4881B0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:34:24.483 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: DA473DAB591C4C93A706A4055545E3C3 range { start: 7480000000000000FF545F72800000004AFFB4881C0000000000FA end: 7480000000000000FF545F72800000004BFF1EEDA30000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:35:52.569 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 9A93F876CD464DA88170F23A3AE39649 range { start: 7480000000000000FF545F72800000004BFF1EEDA40000000000FA end: 7480000000000000FF545F72800000004BFF2A531B0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:37:14.649 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 9DB86A3FE9E04997AAA49C76D7FA9F5E range { start: 7480000000000000FF545F72800000004BFF2A531C0000000000FA end: 7480000000000000FF545F72800000004BFF35B5A40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:38:40.733 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: A43366871FD2489B9533EDC82F5D0304 range { start: 7480000000000000FF545F72800000004BFF35B5A50000000000FA end: 7480000000000000FF545F72800000004BFF411B1C0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:40:00.812 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 11A7D4D529384D3AB3BD02FDC28FDA96 range { start: 7480000000000000FF545F72800000004BFF411B1D0000000000FA end: 7480000000000000FF545F72800000004BFF4C7DA40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:41:22.891 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 23D0ACB7F22E45178898616A93C3CC51 range { start: 7480000000000000FF545F72800000004BFF4C7DA50000000000FA end: 7480000000000000FF545F72800000004CFFBB052F0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:43:04.990 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: CB6ACA855A2A4AB0A32DD07EA85ACA30 range { start: 7480000000000000FF545F72800000004CFFBB05300000000000FA end: 7480000000000000FF545F72800000004DFF25C8A40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:44:09.053 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 0018B1C9DA8644F0BC4C855D11816E46 range { start: 7480000000000000FF545F72800000004DFF25C8A50000000000FA end: 7480000000000000FF545F72800000004DFF312E1B0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:45:45.146 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 8E20FAEF99BD4CB2B077A626ADB4560C range { start: 7480000000000000FF545F72800000004DFF312E1C0000000000FA end: 7480000000000000FF545F72800000004DFF3C90A40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:47:09.228 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: C38143B19A1D4DB88381574EAF76660D range { start: 7480000000000000FF545F72800000004DFF3C90A50000000000FA end: 7480000000000000FF545F72800000004DFF47F32D0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:48:31.308 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 7556FBDF0D974882A5472F9F63962353 range { start: 7480000000000000FF545F72800000004DFF47F32E0000000000FA end: 7480000000000000FF545F72800000004DFF5358A50000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:49:47.385 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 70C9BB4D88F640ACA16851E8BFADA6FD range { start: 7480000000000000FF545F72800000004DFF5358A60000000000FA end: 7480000000000000FF545F72800000004EFFC1DA500000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:51:21.474 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6B42555485A04D8A954B74ACC9156501 range { start: 7480000000000000FF545F72800000004EFFC1DA510000000000FA end: 7480000000000000FF545F72800000004FFF2C864A0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:52:41.551 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: C1E7383560AB4F119B6044431A4D0873 range { start: 7480000000000000FF545F72800000004FFF2C864B0000000000FA end: 7480000000000000FF545F72800000004FFF37E8D20000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:54:05.633 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: FBB721E832FB4553B7C49D59633CA18E range { start: 7480000000000000FF545F72800000004FFF37E8D30000000000FA end: 7480000000000000FF545F72800000004FFF434E4A0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:55:33.719 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 64CE3ED3E6A14971B85A31531E70BF30 range { start: 7480000000000000FF545F72800000004FFF434E4B0000000000FA end: 7480000000000000FF545F72800000004FFF4EB0D30000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:56:49.792 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: DB288F3F92174EE4BD1FD1475E84F7F5 range { start: 7480000000000000FF545F72800000004FFF4EB0D40000000000FA end: 7480000000000000FF545F72800000004FFF5A164B0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:58:09.871 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 9EB9C8F180E443E8B2BD4847F94D104E range { start: 7480000000000000FF545F72800000004FFF5A164C0000000000FA end: 7480000000000000FF545F728000000050FFC89AE60000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 04:59:45.965 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: F060B03E68AA4BD1BDDE0AB56E2CB972 range { start: 7480000000000000FF545F728000000050FFC89AE70000000000FA end: 7480000000000000FF545F728000000051FF335B6B0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:00:58.035 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 7F210644FD6D4E68B2E038CBF176616A range { start: 7480000000000000FF545F728000000051FF335B6C0000000000FA end: 7480000000000000FF545F728000000051FF3EBDF40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:02:28.123 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BDE02C40442B4CF7989F481F6B8FDFA5 range { start: 7480000000000000FF545F728000000051FF3EBDF50000000000FA end: 7480000000000000FF545F728000000051FF4A236C0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:03:58.210 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: EE849964617E4C1E8AB9D1C924F7607A range { start: 7480000000000000FF545F728000000051FF4A236D0000000000FA end: 7480000000000000FF545F728000000051FF5585F40000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:05:30.300 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 4DC00974C769427D9F022B719C2889A5 range { start: 7480000000000000FF545F728000000051FF5585F50000000000FA end: 7480000000000000FF545F728000000051FF60EB6C0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:06:30.358 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 34809795B23E477494894EA38EBC5158 range { start: 7480000000000000FF545F728000000051FF60EB6D0000000000FA end: 7480000000000000FF545F728000000052FFCF70070000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:08:06.452 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 70DCDE92649443579074346AAA4B641C range { start: 7480000000000000FF545F728000000052FFCF70080000000000FA end: 7480000000000000FF545F728000000053FF399ADC0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:09:34.537 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 136E3568DB2241DFB0D6C90D0B4C988B range { start: 7480000000000000FF545F728000000053FF399ADD0000000000FA end: 7480000000000000FF545F728000000053FF44FD650000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:11:04.625 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 5D41AA35271A4066A1B2FE34C5242049 range { start: 7480000000000000FF545F728000000053FF44FD660000000000FA end: 7480000000000000FF545F728000000053FF5062DD0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:12:14.693 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 334E4112F174452086B436C7A414F76D range { start: 7480000000000000FF545F728000000053FF5062DE0000000000FA end: 7480000000000000FF545F728000000053FF5BC5650000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:13:52.789 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 7A7258B7D0FC40B48BA224FEBAE7E480 range { start: 7480000000000000FF545F728000000053FF5BC5660000000000FA end: 7480000000000000FF545F728000000053FF672ADD0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:15:06.861 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 9A9B064C8C18411B9F6F9BCAB91FCBF4 range { start: 7480000000000000FF545F728000000053FF672ADE0000000000FA end: 7480000000000000FF545F728000000054FFD5AC890000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:16:34.947 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6F5AABAF315448B393F13B13DB83F8B3 range { start: 7480000000000000FF545F728000000054FFD5AC8A0000000000FA end: 7480000000000000FF545F728000000055FF4020BE0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:17:39.009 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: CE1E779338174F15B9BE309099EB06B2 range { start: 7480000000000000FF545F728000000055FF4020BF0000000000FA end: 7480000000000000FF545F728000000055FF4B83470000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:18:39.068 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6A4BB09BF5ED462BBD2BE3E329A5DE1D range { start: 7480000000000000FF545F728000000055FF4B83480000000000FA end: 7480000000000000FF545F728000000055FF56E8BF0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:20:11.158 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BD9B161EBEB84141B2235B1435F9A94D range { start: 7480000000000000FF545F728000000055FF56E8C00000000000FA end: 7480000000000000FF545F728000000055FF624B470000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:21:29.234 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 7382320A4EC54650ABB55F67F415CB8E range { start: 7480000000000000FF545F728000000055FF624B480000000000FA end: 7480000000000000FF545F728000000055FF6DB0BF0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:22:35.298 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: D0FA39AD333C467EB4A2DBF9A82D3711 range { start: 7480000000000000FF545F728000000055FF6DB0C00000000000FA end: 7480000000000000FF545F728000000056FFDC355A0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:24:05.386 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 9B21B738F0CD4E72AD946227917F6BC0 range { start: 7480000000000000FF545F728000000056FFDC355B0000000000FA end: 7480000000000000FF545F728000000057FF4727C50000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:25:13.452 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 215CCBFEBA694159A26FA3A65332DF6C range { start: 7480000000000000FF545F728000000057FF4727C60000000000FA end: 7480000000000000FF545F728000000057FF528A4E0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:26:35.533 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 0602A6BB78794EB7B9CB1A7047269109 range { start: 7480000000000000FF545F728000000057FF528A4F0000000000FA end: 7480000000000000FF545F728000000057FF5DEFC60000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:27:53.609 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 3BE32A39021D469CBD53732BD219E80F range { start: 7480000000000000FF545F728000000057FF5DEFC70000000000FA end: 7480000000000000FF545F728000000057FF69524E0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:28:51.665 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: FCFB3CA9D1AA4EF49E8F90FA8AF5D659 range { start: 7480000000000000FF545F728000000057FF69524F0000000000FA end: 7480000000000000FF545F728000000057FF74B7C60000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:30:15.747 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: FDB211F936E14479A64C9B4F19A18C69 range { start: 7480000000000000FF545F728000000057FF74B7C70000000000FA end: 7480000000000000FF545F728000000058FFE33C610000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:31:33.823 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: AADA44EF890D457D92D54807EC876252 range { start: 7480000000000000FF545F728000000058FFE33C620000000000FA end: 7480000000000000FF545F728000000059FF4E25FE0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:32:37.886 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 47ECD7A53D9E4944B71871E3D646C9DF range { start: 7480000000000000FF545F728000000059FF4E25FF0000000000FA end: 7480000000000000FF545F728000000059FF5988860000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:34:11.977 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 1E551C32CF0D4815910FA5BB0DF08CA8 range { start: 7480000000000000FF545F728000000059FF5988870000000000FA end: 7480000000000000FF545F728000000059FF64EDFE0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:35:08.031 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 32E789130DA8498C80813229C5BC6716 range { start: 7480000000000000FF545F728000000059FF64EDFF0000000000FA end: 7480000000000000FF545F728000000059FF7050870000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:36:34.115 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 0BB0204A527A468391A230E7ADCE1FF6 range { start: 7480000000000000FF545F728000000059FF7050880000000000FA end: 7480000000000000FF545F728000000059FF7BB5FF0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:37:44.184 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 913BD67E80384632864CDE1328E6E190 range { start: 7480000000000000FF545F728000000059FF7BB6000000000000FA end: 7480000000000000FF545F72800000005AFFEAF0930000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:38:44.242 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 167BA894A14542328D11CCB6514CF623 range { start: 7480000000000000FF545F72800000005AFFEAF0940000000000FA end: 7480000000000000FF545F72800000005BFF5B98AA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:40:14.330 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 4A388203FE8F41C09DF32ADD86B7F9C7 range { start: 7480000000000000FF545F72800000005BFF5B98AB0000000000FA end: 7480000000000000FF545F72800000005BFF66FB320000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:41:26.400 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: FB3681DB568B4B01B35042F98A3F4C2B range { start: 7480000000000000FF545F72800000005BFF66FB330000000000FA end: 7480000000000000FF545F72800000005BFF7260AA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:42:34.466 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 26E1599A53664E878ADBAC49EEDC7DFF range { start: 7480000000000000FF545F72800000005BFF7260AB0000000000FA end: 7480000000000000FF545F72800000005BFF7DC3330000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:44:00.551 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: E650522CCB6B4C4481DE1582CBFC16DB range { start: 7480000000000000FF545F72800000005BFF7DC3340000000000FA end: 7480000000000000FF545F72800000005BFF8928AB0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:45:02.611 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 85ED18B75CF94C27822B0BB457071A8D range { start: 7480000000000000FF545F72800000005BFF8928AC0000000000FA end: 7480000000000000FF545F72800000005CFFF7AA560000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:46:26.693 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: F2013D1CB94249C2A6E79EC6E27D7545 range { start: 7480000000000000FF545F72800000005CFFF7AA570000000000FA end: 7480000000000000FF545F72800000005DFF620A000000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:47:32.757 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 5E6D61EB968C4CCAB390066B4B6102B2 range { start: 7480000000000000FF545F72800000005DFF620A010000000000FA end: 7480000000000000FF545F72800000005DFF6D6C890000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:48:44.828 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 072D280CFA9341DAA5677B08AEC2C1E0 range { start: 7480000000000000FF545F72800000005DFF6D6C8A0000000000FA end: 7480000000000000FF545F72800000005DFF78D2010000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:50:06.907 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BF3D7E37917D4BBD862C55978693AF67 range { start: 7480000000000000FF545F72800000005DFF78D2020000000000FA end: 7480000000000000FF545F72800000005DFF8434890000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:51:22.982 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 3892F2620A9C43749459EFC4F28DAEA1 range { start: 7480000000000000FF545F72800000005DFF84348A0000000000FA end: 7480000000000000FF545F72800000005DFF8F9A010000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:52:25.041 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 53289C3272504027866CEF886E92F252 range { start: 7480000000000000FF545F72800000005DFF8F9A020000000000FA end: 7480000000000000FF545F72800000005EFFFE1E9C0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:53:55.129 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BF7FB97166B54F179D385CFC9011DC6C range { start: 7480000000000000FF545F72800000005EFFFE1E9D0000000000FA end: 7480000000000000FF545F72800000005FFF692B710000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:54:59.192 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: A2A254D53B544D05BF39FCBCCFF2DC9B range { start: 7480000000000000FF545F72800000005FFF692B720000000000FA end: 7480000000000000FF545F72800000005FFF748DFA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:56:17.267 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 0FD4B652810544689536C747A5753883 range { start: 7480000000000000FF545F72800000005FFF748DFB0000000000FA end: 7480000000000000FF545F72800000005FFF7FF3720000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:57:25.334 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 05701DB2360241EB915FE49E2BAB574D range { start: 7480000000000000FF545F72800000005FFF7FF3730000000000FA end: 7480000000000000FF545F72800000005FFF8B55FA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 05:58:37.404 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: E5A017CB4F8C4869B491F240A44A21FA range { start: 7480000000000000FF545F72800000005FFF8B55FB0000000000FA end: 7480000000000000FF545F72800000005FFF96BB720000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:00:03.488 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 743D79A645054229BD5947304A43B883 range { start: 7480000000000000FF545F72800000005FFF96BB730000000000FA end: 7480000000000000FF545F728000000061FF053D1E0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:01:13.556 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 78D8D29B696F4115B4EE4A155693F033 range { start: 7480000000000000FF545F728000000061FF053D1F0000000000FA end: 7480000000000000FF545F728000000061FF7006710000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:02:21.622 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 38E7A290D69B42F79CEA93B5822BBEE8 range { start: 7480000000000000FF545F728000000061FF7006720000000000FA end: 7480000000000000FF545F728000000061FF7B68FA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:03:49.708 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6AE3E27FC4FD4E778CA89DA60A7C540A range { start: 7480000000000000FF545F728000000061FF7B68FB0000000000FA end: 7480000000000000FF545F728000000061FF86CE720000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:04:49.767 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: D12D74AFE9D24C949620FB9A8ABA53C2 range { start: 7480000000000000FF545F728000000061FF86CE730000000000FA end: 7480000000000000FF545F728000000061FF9230FB0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:06:17.852 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 8219F4BF7F7F43B8855B47AFAE76FCAC range { start: 7480000000000000FF545F728000000061FF9230FC0000000000FA end: 7480000000000000FF545F728000000061FF9D96720000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:07:19.913 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: AB3DC5BFBE0549A0BB8F016C99DA9BB5 range { start: 7480000000000000FF545F728000000061FF9D96730000000000FA end: 7480000000000000FF545F728000000063FF0C1B0E0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:08:27.979 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 0EBF2E2D3F1340379DD591C71283520A range { start: 7480000000000000FF545F728000000063FF0C1B0F0000000000FA end: 7480000000000000FF545F728000000063FF76E4610000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:09:56.064 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 429E14F2B0E042D2B337F5B44C0B6519 range { start: 7480000000000000FF545F728000000063FF76E4620000000000FA end: 7480000000000000FF545F728000000063FF8246EA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:11:08.135 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: D31F9F333E5E4525A1E2485306A632C2 range { start: 7480000000000000FF545F728000000063FF8246EB0000000000FA end: 7480000000000000FF545F728000000063FF8DAC610000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:12:18.226 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 4F68B179414E4847ABE83498C81F939A range { start: 7480000000000000FF545F728000000063FF8DAC620000000000FA end: 7480000000000000FF545F728000000063FF990EEA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:13:44.287 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 229797FB81B24EBB9003F09EF881FF85 range { start: 7480000000000000FF545F728000000063FF990EEB0000000000FA end: 7480000000000000FF545F728000000063FFA474620000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:14:46.347 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 5A1CA588F40A4C339C90B77B9FC98A18 range { start: 7480000000000000FF545F728000000063FFA474630000000000FA end: 7480000000000000FF545F728000000065FF12F8FD0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:16:06.425 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6C04760F456A4EBF986AA33FEF6F36ED range { start: 7480000000000000FF545F728000000065FF12F8FE0000000000FA end: 7480000000000000FF545F728000000065FF7DC2500000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:17:10.487 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 2A3CB48C44D24235B8B48D1E51DE787E range { start: 7480000000000000FF545F728000000065FF7DC2510000000000FA end: 7480000000000000FF545F728000000065FF8924D90000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:18:20.555 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: C42001D783B141AA8246AB2F6B89445E range { start: 7480000000000000FF545F728000000065FF8924DA0000000000FA end: 7480000000000000FF545F728000000065FF948A510000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:19:42.635 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BE24898398DF4DBB8CC836364FBF52C8 range { start: 7480000000000000FF545F728000000065FF948A520000000000FA end: 7480000000000000FF545F728000000065FF9FECDA0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:20:24.677 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 948596B6E7E04E3DBF7D9135E3D3B257 range { start: 7480000000000000FF545F728000000065FF9FECDB0000000000FA end: 7480000000000000FF545F728000000065FFAB52510000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:21:40.751 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: BB86B81A757D4850AB9FEADC8FE1C523 range { start: 7480000000000000FF545F728000000065FFAB52520000000000FA end: 7480000000000000FF545F728000000067FF19D6ED0000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]
[2020/11/04 06:22:42.811 +00:00] [INFO] [sst_importer.rs:83] [ingest] [meta="uuid: 6AD091DFDC5F4B35945B109D02E83661 range { start: 7480000000000000FF545F728000000067FF19D6EE0000000000FA end: 7480000000000000FF545F728000000067FF253C640000000000FA } cf_name: \"write\" region_id: 14444 region_epoch { conf_ver: 5 version: 686 }"]

From lightning log, we can see the related engine started import and split regions quite early:

[2020/11/04 03:17:16.309 +00:00] [INFO] [backend.go:328] ["import start"] [engineTag=`test`.`order_line`:1] [engineUUID=c7eb990c-f65b-5cd4-9018-7e964579a723] [retryCnt=0]
[2020/11/04 03:17:16.602 +00:00] [INFO] [local.go:673] [doReadAndSplitIntoRange] [firstKey="dIAAAAAAAABUX3KAAAAANFiZpg=="] [lastKey="dIAAAAAAAABUX3KAAAAAZyU8ZA=="]

And there are no partial ingest finish or ingest failed log for this engine range, And from the tikv log, we can see the region 14444 was created quite late:

[2020/11/04 04:30:40.257 +00:00] [INFO] [apply.rs:1162] ["execute admin command"] [command="cmd_type: BatchSplit splits { requests { split_key: 7480000000000000FF545F728000000067FF84FAAC0000000000FA new_region_id: 14444 new_peer_ids: 14445 new_peer_ids: 14446 new_peer_ids: 14447 } right_derive: true }"] [index=8] [term=6] [peer_id=12985] [region_id=12984]
[2020/11/04 04:30:40.258 +00:00] [INFO] [apply.rs:1742] ["split region"] [keys="key 7480000000000000FF545F728000000067FF84FAAC0000000000FA"] [region="id: 12984 start_key: 7480000000000000FF545F728000000049FF2F38900000000000FA end_key: 7480000000000000FF545F728000000067FF9075B60000000000FA region_epoch { conf_ver: 5 version: 685 } peers { id: 12985 store_id: 1 } peers { id: 12986 store_id: 4 } peers { id: 12987 store_id: 5 }"] [peer_id=12985] [region_id=12984]
[2020/11/04 04:30:40.258 +00:00] [INFO] [peer.rs:1773] ["insert new region"] [region="id: 14444 start_key: 7480000000000000FF545F728000000049FF2F38900000000000FA end_key: 7480000000000000FF545F728000000067FF84FAAC0000000000FA region_epoch { conf_ver: 5 version: 686 } peers { id: 14445 store_id: 1 } peers { id: 14446 store_id: 4 } peers { id: 14447 store_id: 5 }"] [region_id=14444]
[2020/11/04 04:30:40.258 +00:00] [INFO] [peer.rs:159] ["create peer"] [peer_id=14445] [region_id=14444]
[2020/11/04 04:30:40.258 +00:00] [INFO] [raft.rs:783] ["became follower at term 5"] [term=5] [raft_id=14445] [region_id=14444]

So I think the root cause is that because in lightning v4.0.7, we don't support disable schedulers, thus when meets engine import quite slow, after 1 hour, the splited region was automated merge again since they are still empty. Then lightning will ingest all the range to the new merged region.

@glorv
Copy link
Contributor

glorv commented Nov 5, 2020

So I think this issue should be fixed by #408, @shuijing198799 could you please use the newest lightning to retry this test again?

@jebter jebter added type/bug This issue is a bug report severity/major labels Nov 6, 2020
@glorv
Copy link
Contributor

glorv commented Nov 9, 2020

There are two bugs in lightning that together will cause this issue:

  • After 1 hour, some regions still don't finished import, thus pd may merge into one big region since they are all empty. So lightning will ingest a lot of kv into a single big region, which will likely cause tidb cooperator request timeout. In current lightning implementation,

    tidb-lightning/lightning/backend/local.go

    Lines 1395 to 1405 in 25a3711

    for i := sValue; i < eValue; i += step {
    if i <= lastValue {
    continue
    }
    binary.BigEndian.PutUint64(seekKey[offset:], i)
    iter.SeekGE(seekKey)
    copy(valueBuf, iter.Key()[offset:])
    value := binary.BigEndian.Uint64(valueBuf)
    sampleValues = append(sampleValues, value)
    lastValue = value
    }
    this scan may be quite slow in some case. And it will be abandoned in backend/local: use range properties to optimize region range estimate #422, so this can be fixed.
  • pd triggers small region merge after 1 hour. This should be fixed in restore: disable some pd scheduler during restore #408

@shuijing198799
Copy link
Author

shuijing198799 commented Nov 16, 2020 •
edited
Loading

This issue occurs 3 times in 4 use 8C 200G ebs with restore 100G data when we use lightning v4.0.7, Use 4.0.8 with the same data, this problem not occured in next 3 restores. And @glorv gives the root cause for this issue. so we can make sure this issue has been fixed.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
severity/major type/bug This issue is a bug report
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jebter @glorv @shuijing198799