tiflash 同步数据异常

信仰在空中飘扬 · 2020 年12 月 25 日 09:38

v4.0.1
在已有集群上新增加了tiflash

添加一张表到tiflash 中,日志输出如下:
tail -f tiflash.log

tail -f tiflash_cluster_manager.log

并没有同步进度

查看了几个帖子，未找到好的解决方案。
请问该如何处理，需要将集群升级到新版本么？

不懂就问 · 2020 年12 月 28 日 08:07

根据 tiflash_cluster_manager.log 里面的信息，看着 tidb-server 部分有问题，辛苦看下 tidb.log 里面是否有异常或者提供下tiflash_cluster_manager.log & tidb.log 完整日志信息。

信仰在空中飘扬 · 2020 年12 月 29 日 06:52

看过一个帖子说是有个bug。我直接升级到4.0.8 了。问题解决。

信仰在空中飘扬 · 2020 年12 月 29 日 07:37

补充个问题：创建副本的时候，速度比较慢如何优化？
我调整了下面的参数没啥效果
» config set replica-schedule-limit 1024

数据量如下：

不懂就问 · 2020 年12 月 30 日 02:57

具体是哪个帖子，辛苦给下信息。

不懂就问 · 2020 年12 月 30 日 02:57

尝试按照这个思路调整下参数看看：TiFlash从KV导数据很慢

信仰在空中飘扬 · 2020 年12 月 30 日 06:31

根据上面的帖子进行了各种调整，但是效果并不明显。
我现在是同时同步了两个表，其中一个一直停在了那个进度，另外一个缓慢增长。

概要

» config show
{
  "replication": {
    "enable-placement-rules": "true",
    "location-labels": "host",
    "max-replicas": 3,
    "strictly-match-label": "false"
  },
  "schedule": {
    "enable-cross-table-merge": "false",
    "enable-debug-metrics": "false",
    "enable-location-replacement": "true",
    "enable-make-up-replica": "true",
    "enable-one-way-merge": "false",
    "enable-remove-down-replica": "true",
    "enable-remove-extra-replica": "true",
    "enable-replace-offline-replica": "true",
    "high-space-ratio": 0.7,
    "hot-region-cache-hits-threshold": 3,
    "hot-region-schedule-limit": 4,
    "leader-schedule-limit": 64,
    "leader-schedule-policy": "count",
    "low-space-ratio": 0.8,
    "max-merge-region-keys": 200000,
    "max-merge-region-size": 15,
    "max-pending-peer-count": 16,
    "max-snapshot-count": 3,
    "max-store-down-time": "30m0s",
    "merge-schedule-limit": 64,
    "patrol-region-interval": "10ms",
    "region-schedule-limit": 4096,
    "replica-schedule-limit": 2048,
    "scheduler-max-waiting-operator": 5,
    "split-merge-interval": "1h0m0s",
    "store-limit-mode": "manual",
    "tolerant-size-ratio": 0
  }
}

集群的空region 较多，我调整后合并效果明显
screencapture-tidb-zuoyebang-cc-d-eDbRZpnWk-zyb-tidb-overview-2020-12-30-14_26_41.pdf (5.1 MB)

请问是否有其他办法能解决同步数据到tiflash 慢的问题。我们后期可能要大量业务接入使用这种方式
目前的状态还达不到我们的要求

不懂就问 · 2020 年12 月 30 日 08:52

按照上面提到的帖子调整完还是很慢吗？帮忙提供下 PD 的监控信息。

信仰在空中飘扬 · 2020 年12 月 30 日 12:05

嗯，各种姿势都试过了。但是效果甚微。
我在一个准备上线的新集群，同步2亿的一张表数据还是蛮快的。
但是这个集群就特别慢。而且有一个大表的同步已经停止了，一直卡在0.59 的进度

screencapture-tidb-zuoyebang-cc-d-Q6RuHYIWk-zyb-tidb-pd-2020-12-30-20_01_32.pdf (9.3 MB)

今天在测试时又发现如下异常: 使用手动指定的tikv 引擎并未生效

经过与官方人员沟通，再次补充tiflash 相关日志
tail -100f tiflash_error.log

tail -100f tiflash_cluster_manager.log

概要

2020-12-31 17:14:12,586 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 423
2020-12-31 17:14:17,568 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 423
2020-12-31 17:14:22,525 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:27,545 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:32,527 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:37,530 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:42,644 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:47,525 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:52,571 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:14:57,528 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:02,548 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:07,557 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:12,516 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:17,520 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:22,528 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:27,531 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:32,515 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 425
2020-12-31 17:15:37,572 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:15:52,567 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:15:57,525 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:03,799 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:07,534 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:12,536 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:17,551 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:22,529 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:27,536 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:32,545 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427
2020-12-31 17:16:37,566 TiFlashManager: report to tidb: id 193399, region_count 1931, flash_region_count 427

tail -100f tiflash.log

概要

[2020/12/31 17:17:03.500 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 17 packs, 24214 rows, 1 unsaved_rows, 0 deletes, 0 unsaved_deletes} Compact start”] [thread_id=52]
[2020/12/31 17:17:03.514 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Successfully compacted 11 packs into 1 packs, total 2816 rows.”] [thread_id=52]
[2020/12/31 17:17:04.228 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.meta gcApply remove 4 invalid snapshots.”] [thread_id=59]
[2020/12/31 17:17:04.229 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.data gcApply remove 4 invalid snapshots.”] [thread_id=59]
[2020/12/31 17:17:04.328 +08:00] [DEBUG] [] [“DeltaMergeStore[db_192987.t_193399]: GC removed useless dmfile: /data/tidb/data/tiflash-9000//data/t_193399/stable/.del.dmf_480”] [thread_id=59]
[2020/12/31 17:17:04.441 +08:00] [DEBUG] [] [“DeltaMergeStore[db_192987.t_193399]: GC removed useless dmfile: /data/tidb/data/tiflash-9000//data/t_193399/stable/.del.dmf_481”] [thread_id=59]
[2020/12/31 17:17:04.443 +08:00] [INFO] [] [“PageStorage: db_192987.t_193399.log restore 0 puts and 25 refs and 0 deletes and 25 upserts from checkpoint PageFile_27_0 sequence: 3777”] [thread_id=59]
[2020/12/31 17:17:04.443 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.log collectPageFilesToCompact stop on PageFile_27_1, type: Formal, sequence: 3777 last sequence: 3777”] [thread_id=59]
[2020/12/31 17:17:04.443 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.log LegacyCompactor::tryCompact exit without compaction, candidates size: 0, compact_legacy_min_num: 3”] [thread_id=59]
[2020/12/31 17:17:04.443 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.log DataCompactor::tryMigrate exit without compaction, candidates size: 5, total byte size: 47607557, low_used_file_num: 10, low_use_file_total_size: 134217728”] [thread_id=59]
[2020/12/31 17:17:04.443 +08:00] [DEBUG] [] [“PageStorage: db_192987.t_193399.log gcApply remove 7 invalid snapshots.”] [thread_id=59]
[2020/12/31 17:17:04.444 +08:00] [INFO] [] [“PageStorage: db_192987.t_193399.log GC exit within 0.00 sec. PageFiles from [27,0,Checkpoint] to [54,0,Legacy], size: 30, compact legacy archive files: 0, remove data files: 0, gc apply: 0 puts and 0 refs and 0 deletes and 0 upserts”] [thread_id=59]
[2020/12/31 17:17:04.592 +08:00] [INFO] [] [“KVStore: [region 83365483] handle useless admin command CompactLog at [term: 6, index: 761543]”] [thread_id=81]
[2020/12/31 17:17:04.592 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 7 packs, 24219 rows, 6 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=81]
[2020/12/31 17:17:04.592 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=81]
[2020/12/31 17:17:04.592 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=81]
[2020/12/31 17:17:04.593 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 6 rows and 0 deletes.”] [thread_id=81]
[2020/12/31 17:17:04.593 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365483, applied: term 6 index 761543], cache size: 0 bytes”] [thread_id=81]
[2020/12/31 17:17:04.593 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365483] done”] [thread_id=81]
[2020/12/31 17:17:11.980 +08:00] [INFO] [] [“KVStore: [region 83365394] handle useless admin command CompactLog at [term: 10, index: 2490132]”] [thread_id=81]
[2020/12/31 17:17:11.980 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [189]: 5 packs, 3433 rows, 472 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=81]
[2020/12/31 17:17:11.981 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index start”] [thread_id=81]
[2020/12/31 17:17:11.981 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index done”] [thread_id=81]
[2020/12/31 17:17:11.981 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Flush end. Flushed 1 packs, 472 rows and 0 deletes.”] [thread_id=81]
[2020/12/31 17:17:11.981 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365394, applied: term 10 index 2490132], cache size: 0 bytes”] [thread_id=81]
[2020/12/31 17:17:11.982 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365394] done”] [thread_id=81]
[2020/12/31 17:17:15.994 +08:00] [INFO] [] [“KVStore: [region 83398126] handle useless admin command CompactLog at [term: 6, index: 27483]”] [thread_id=83]
[2020/12/31 17:17:15.994 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 8 packs, 24285 rows, 66 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=83]
[2020/12/31 17:17:15.995 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=83]
[2020/12/31 17:17:15.995 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=83]
[2020/12/31 17:17:15.997 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 66 rows and 0 deletes.”] [thread_id=83]
[2020/12/31 17:17:15.997 +08:00] [INFO] [] [“KVStore: Start to persist [region 83398126, applied: term 6 index 27483], cache size: 0 bytes”] [thread_id=83]
[2020/12/31 17:17:15.997 +08:00] [DEBUG] [] [“KVStore: Persist [region 83398126] done”] [thread_id=83]
[2020/12/31 17:17:22.042 +08:00] [INFO] [] [“KVStore: [region 83365394] handle useless admin command CompactLog at [term: 10, index: 2491384]”] [thread_id=81]
[2020/12/31 17:17:22.042 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [189]: 6 packs, 4007 rows, 574 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=81]
[2020/12/31 17:17:22.043 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index start”] [thread_id=81]
[2020/12/31 17:17:22.043 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index done”] [thread_id=81]
[2020/12/31 17:17:22.043 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Flush end. Flushed 1 packs, 574 rows and 0 deletes.”] [thread_id=81]
[2020/12/31 17:17:22.043 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365394, applied: term 10 index 2491384], cache size: 0 bytes”] [thread_id=81]
[2020/12/31 17:17:22.043 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365394] done”] [thread_id=81]
[2020/12/31 17:17:23.631 +08:00] [INFO] [] [“KVStore: [region 77880342] handle useless admin command CompactLog at [term: 9, index: 351416]”] [thread_id=82]
[2020/12/31 17:17:23.631 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 9 packs, 24304 rows, 19 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=82]
[2020/12/31 17:17:23.631 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=82]
[2020/12/31 17:17:23.632 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=82]
[2020/12/31 17:17:23.632 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 19 rows and 0 deletes.”] [thread_id=82]
[2020/12/31 17:17:23.632 +08:00] [INFO] [] [“KVStore: Start to persist [region 77880342, applied: term 9 index 351416], cache size: 0 bytes”] [thread_id=82]
[2020/12/31 17:17:23.632 +08:00] [DEBUG] [] [“KVStore: Persist [region 77880342] done”] [thread_id=82]
[2020/12/31 17:17:23.653 +08:00] [INFO] [] [“KVStore: [region 83399934] handle useless admin command CompactLog at [term: 6, index: 55145]”] [thread_id=82]
[2020/12/31 17:17:23.653 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 9 packs, 24304 rows, 0 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=82]
[2020/12/31 17:17:23.653 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Nothing to flush”] [thread_id=82]
[2020/12/31 17:17:23.654 +08:00] [INFO] [] [“KVStore: Start to persist [region 83399934, applied: term 6 index 55145], cache size: 0 bytes”] [thread_id=82]
[2020/12/31 17:17:23.654 +08:00] [DEBUG] [] [“KVStore: Persist [region 83399934] done”] [thread_id=82]
[2020/12/31 17:17:24.474 +08:00] [INFO] [] [“KVStore: [region 83365483] handle useless admin command CompactLog at [term: 6, index: 761619]”] [thread_id=79]
[2020/12/31 17:17:24.474 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 10 packs, 24307 rows, 3 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=79]
[2020/12/31 17:17:24.475 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=79]
[2020/12/31 17:17:24.475 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=79]
[2020/12/31 17:17:24.475 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 3 rows and 0 deletes.”] [thread_id=79]
[2020/12/31 17:17:24.475 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365483, applied: term 6 index 761619], cache size: 0 bytes”] [thread_id=79]
[2020/12/31 17:17:24.476 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365483] done”] [thread_id=79]
[2020/12/31 17:17:31.981 +08:00] [INFO] [] [“KVStore: [region 83365394] handle useless admin command CompactLog at [term: 10, index: 2492312]”] [thread_id=81]
[2020/12/31 17:17:31.981 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [189]: 7 packs, 4438 rows, 431 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=81]
[2020/12/31 17:17:31.982 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index start”] [thread_id=81]
[2020/12/31 17:17:31.982 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index done”] [thread_id=81]
[2020/12/31 17:17:31.982 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Flush end. Flushed 1 packs, 431 rows and 0 deletes.”] [thread_id=81]
[2020/12/31 17:17:31.982 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365394, applied: term 10 index 2492312], cache size: 0 bytes”] [thread_id=81]
[2020/12/31 17:17:31.983 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365394] done”] [thread_id=81]
[2020/12/31 17:17:34.664 +08:00] [INFO] [] [“KVStore: [region 77880342] handle useless admin command CompactLog at [term: 9, index: 351530]”] [thread_id=83]
[2020/12/31 17:17:34.664 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 11 packs, 24382 rows, 75 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=83]
[2020/12/31 17:17:34.665 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=83]
[2020/12/31 17:17:34.665 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=83]
[2020/12/31 17:17:34.666 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 75 rows and 0 deletes.”] [thread_id=83]
[2020/12/31 17:17:34.666 +08:00] [INFO] [] [“KVStore: Start to persist [region 77880342, applied: term 9 index 351530], cache size: 0 bytes”] [thread_id=83]
[2020/12/31 17:17:34.666 +08:00] [DEBUG] [] [“KVStore: Persist [region 77880342] done”] [thread_id=83]
[2020/12/31 17:17:35.587 +08:00] [INFO] [] [“KVStore: [region 83398126] handle useless admin command CompactLog at [term: 6, index: 27561]”] [thread_id=79]
[2020/12/31 17:17:35.588 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 12 packs, 24385 rows, 3 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=79]
[2020/12/31 17:17:35.588 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=79]
[2020/12/31 17:17:35.588 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=79]
[2020/12/31 17:17:35.589 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 3 rows and 0 deletes.”] [thread_id=79]
[2020/12/31 17:17:35.589 +08:00] [INFO] [] [“KVStore: Start to persist [region 83398126, applied: term 6 index 27561], cache size: 0 bytes”] [thread_id=79]
[2020/12/31 17:17:35.589 +08:00] [DEBUG] [] [“KVStore: Persist [region 83398126] done”] [thread_id=79]
[2020/12/31 17:17:42.013 +08:00] [INFO] [] [“KVStore: [region 83365394] handle useless admin command CompactLog at [term: 10, index: 2493599]”] [thread_id=79]
[2020/12/31 17:17:42.013 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [189]: 8 packs, 5146 rows, 708 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=79]
[2020/12/31 17:17:42.014 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index start”] [thread_id=79]
[2020/12/31 17:17:42.014 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Update index done”] [thread_id=79]
[2020/12/31 17:17:42.015 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [189] Flush end. Flushed 1 packs, 708 rows and 0 deletes.”] [thread_id=79]
[2020/12/31 17:17:42.015 +08:00] [INFO] [] [“KVStore: Start to persist [region 83365394, applied: term 10 index 2493599], cache size: 0 bytes”] [thread_id=79]
[2020/12/31 17:17:42.015 +08:00] [DEBUG] [] [“KVStore: Persist [region 83365394] done”] [thread_id=79]
[2020/12/31 17:17:42.447 +08:00] [INFO] [] [“KVStore: [region 83369106] handle useless admin command CompactLog at [term: 7, index: 94825]”] [thread_id=81]
[2020/12/31 17:17:42.447 +08:00] [DEBUG] [] [“DeltaValueSpace: {Delta [105]: 13 packs, 24466 rows, 81 unsaved_rows, 0 deletes, 0 unsaved_deletes}, Flush start”] [thread_id=81]
[2020/12/31 17:17:42.448 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index start”] [thread_id=81]
[2020/12/31 17:17:42.448 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Update index done”] [thread_id=81]
[2020/12/31 17:17:42.448 +08:00] [DEBUG] [] [“DeltaValueSpace: Delta [105] Flush end. Flushed 1 packs, 81 rows and 0 deletes.”] [thread_id=81]
[2020/12/31 17:17:42.448 +08:00] [INFO] [] [“KVStore: Start to persist [region 83369106, applied: term 7 index 94825], cache size: 0 bytes”] [thread_id=81]
[2020/12/31 17:17:42.449 +08:00] [DEBUG] [] [“KVStore: Persist [region 83369106] done”] [thread_id=81]

tail -100f tiflash_tikv.log

概要

[2020/12/31 17:16:45.837 +08:00] [INFO] [peer.rs:2409] [“snapshot is applied”] [region=“id: 40435986 start_key: 74800000000002F3FF775F728000000002FF59EB870000000000FA end_key: 74800000000002F3FF775F728000000002FF5B99E80000000000FA region_epoch { conf_ver: 14436 version: 92560 } peers { id: 40435988 store_id: 8 } peers { id: 40435989 store_id: 32033477 } peers { id: 40733823 store_id: 40419021 } peers { id: 83403057 store_id: 79448782 is_learner: true }”] [peer_id=83403057] [region_id=40435986]
[2020/12/31 17:16:45.849 +08:00] [INFO] [region.rs:364] [“begin apply snap data”] [region_id=40159199]
[2020/12/31 17:16:45.860 +08:00] [INFO] [region.rs:393] [“apply data with pre handled snap”] [region_id=40159199]
[2020/12/31 17:16:46.266 +08:00] [INFO] [region.rs:420] [“apply new data”] [time_takes=405.893929ms] [region_id=40159199]
[2020/12/31 17:16:46.821 +08:00] [INFO] [region.rs:318] [“pre handle snapshot”] [time_takes=984.485848ms] [state=“applied_index: 14 truncated_state { index: 14 term: 10 }”] [peer_id=83403057] [region_id=40435986]
[2020/12/31 17:16:46.827 +08:00] [INFO] [region.rs:364] [“begin apply snap data”] [region_id=40435986]
[2020/12/31 17:16:46.828 +08:00] [INFO] [region.rs:393] [“apply data with pre handled snap”] [region_id=40435986]
[2020/12/31 17:16:47.320 +08:00] [INFO] [region.rs:420] [“apply new data”] [time_takes=492.469477ms] [region_id=40435986]
[2020/12/31 17:16:51.982 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2487310 last_commit_index: 2487309 commit_index: 2487311 commit_term: 10 truncated_state { index: 2487308 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:16:55.216 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 87439 last_commit_index: 87438 commit_index: 87439 commit_term: 6 truncated_state { index: 87437 term: 6 }”] [peer_id=83392497] [region_id=83392493]
[2020/12/31 17:16:56.017 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 27425 last_commit_index: 27424 commit_index: 27425 commit_term: 6 truncated_state { index: 27423 term: 6 }”] [peer_id=83398130] [region_id=83398126]
[2020/12/31 17:17:01.980 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2489160 last_commit_index: 2489159 commit_index: 2489160 commit_term: 10 truncated_state { index: 2489157 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:03.397 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 351362 last_commit_index: 351361 commit_index: 351362 commit_term: 9 truncated_state { index: 351360 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:17:04.593 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761543 last_commit_index: 761542 commit_index: 761543 commit_term: 6 truncated_state { index: 761541 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:17:11.982 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2490132 last_commit_index: 2490131 commit_index: 2490133 commit_term: 10 truncated_state { index: 2490128 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:15.997 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 27483 last_commit_index: 27482 commit_index: 27483 commit_term: 6 truncated_state { index: 27481 term: 6 }”] [peer_id=83398130] [region_id=83398126]
[2020/12/31 17:17:19.968 +08:00] [INFO] [peer.rs:639] [“deleting applied snap file”] [snap_file=40159199_13_1790] [peer_id=83403058] [region_id=40159199]
[2020/12/31 17:17:19.968 +08:00] [INFO] [peer.rs:639] [“deleting applied snap file”] [snap_file=40435986_10_14] [peer_id=83403057] [region_id=40435986]
[2020/12/31 17:17:22.043 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2491384 last_commit_index: 2491383 commit_index: 2491384 commit_term: 10 truncated_state { index: 2491382 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:23.632 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 351416 last_commit_index: 351415 commit_index: 351416 commit_term: 9 truncated_state { index: 351414 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:17:23.654 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 55145 last_commit_index: 55144 commit_index: 55145 commit_term: 6 truncated_state { index: 55143 term: 6 }”] [peer_id=83399938] [region_id=83399934]
[2020/12/31 17:17:24.476 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761619 last_commit_index: 761618 commit_index: 761619 commit_term: 6 truncated_state { index: 761617 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:17:28.626 +08:00] [INFO] [raft.rs:1003] [“received a message with higher term from 56712359”] [“msg type”=MsgAppend] [message_term=25] [term=24] [from=56712359] [raft_id=82853541] [region_id=7076741]
[2020/12/31 17:17:28.626 +08:00] [INFO] [raft.rs:783] [“became follower at term 25”] [term=25] [raft_id=82853541] [region_id=7076741]
[2020/12/31 17:17:31.983 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2492312 last_commit_index: 2492310 commit_index: 2492313 commit_term: 10 truncated_state { index: 2492309 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:34.666 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 351530 last_commit_index: 351529 commit_index: 351530 commit_term: 9 truncated_state { index: 351528 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:17:35.589 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 27561 last_commit_index: 27560 commit_index: 27561 commit_term: 6 truncated_state { index: 27559 term: 6 }”] [peer_id=83398130] [region_id=83398126]
[2020/12/31 17:17:42.015 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2493599 last_commit_index: 2493598 commit_index: 2493599 commit_term: 10 truncated_state { index: 2493597 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:44.556 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761694 last_commit_index: 761693 commit_index: 761694 commit_term: 6 truncated_state { index: 761692 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:17:51.986 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2495007 last_commit_index: 2495006 commit_index: 2495007 commit_term: 10 truncated_state { index: 2495005 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:17:54.700 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 351824 last_commit_index: 351823 commit_index: 351824 commit_term: 9 truncated_state { index: 351822 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:17:55.979 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 94684 last_commit_index: 94683 commit_index: 94684 commit_term: 6 truncated_state { index: 94682 term: 6 }”] [peer_id=83381549] [region_id=83381544]
[2020/12/31 17:17:55.980 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 27652 last_commit_index: 27651 commit_index: 27652 commit_term: 6 truncated_state { index: 27650 term: 6 }”] [peer_id=83398130] [region_id=83398126]
[2020/12/31 17:17:57.996 +08:00] [INFO] [peer.rs:197] [“replicate peer”] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:783] [“became follower at term 0”] [term=0] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:285] [newRaft] [peers=“[]”] [“last term”=0] [“last index”=0] [applied=0] [commit=0] [term=0] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raw_node.rs:222] [“RawNode created with id 83403126.”] [id=83403126] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:1003] [“received a message with higher term from 40008019”] [“msg type”=MsgHeartbeat] [message_term=11] [term=0] [from=40008019] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:783] [“became follower at term 11”] [term=11] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:57.997 +08:00] [INFO] [peer.rs:197] [“replicate peer”] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:783] [“became follower at term 0”] [term=0] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:285] [newRaft] [peers=“[]”] [“last term”=0] [“last index”=0] [applied=0] [commit=0] [term=0] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raw_node.rs:222] [“RawNode created with id 83403127.”] [id=83403127] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:1003] [“received a message with higher term from 40431741”] [“msg type”=MsgHeartbeat] [message_term=8] [term=0] [from=40431741] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:57.997 +08:00] [INFO] [raft.rs:783] [“became follower at term 8”] [term=8] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:58.889 +08:00] [INFO] [snap.rs:223] [“saving snapshot file”] [file=/data/tidb/data/tiflash-9000/flash/snap/rev_40008016_11_4250_(default|lock|write).sst] [snap_key=40008016_11_4250]
[2020/12/31 17:17:58.907 +08:00] [INFO] [raft.rs:1957] [“[commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 4250, term: 11]”] [snapshot_term=11] [snapshot_index=4250] [last_term=0] [last_index=0] [commit=0] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:58.907 +08:00] [INFO] [raft_log.rs:487] [“log [committed=0, applied=0, unstable.offset=1, unstable.entries.len()=0] starts to restore snapshot [index: 4250, term: 11]”] [snapshot_term=11] [snapshot_index=4250] [log=“committed=0, applied=0, unstable.offset=1, unstable.entries.len()=0”] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:58.907 +08:00] [INFO] [raft.rs:1893] [“[commit: 4250, term: 11] restored snapshot [index: 4250, term: 11]”] [snapshot_term=11] [snapshot_index=4250] [commit=4250] [term=11] [raft_id=83403126] [region_id=40008016]
[2020/12/31 17:17:58.907 +08:00] [INFO] [peer_storage.rs:985] [“begin to apply snapshot”] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:17:58.907 +08:00] [INFO] [peer_storage.rs:1025] [“apply snapshot with state ok”] [state=“applied_index: 4250 truncated_state { index: 4250 term: 11 }”] [region=“id: 40008016 start_key: 74800000000002F3FF775F728000000002FF5CA7FA0000000000FA end_key: 74800000000002F3FF775F728000000002FF5E152C0000000000FA region_epoch { conf_ver: 14436 version: 92559 } peers { id: 40008018 store_id: 8 } peers { id: 40008019 store_id: 32033477 } peers { id: 46688713 store_id: 46494231 } peers { id: 83403126 store_id: 79448782 is_learner: true }”] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:17:58.908 +08:00] [INFO] [peer.rs:2409] [“snapshot is applied”] [region=“id: 40008016 start_key: 74800000000002F3FF775F728000000002FF5CA7FA0000000000FA end_key: 74800000000002F3FF775F728000000002FF5E152C0000000000FA region_epoch { conf_ver: 14436 version: 92559 } peers { id: 40008018 store_id: 8 } peers { id: 40008019 store_id: 32033477 } peers { id: 46688713 store_id: 46494231 } peers { id: 83403126 store_id: 79448782 is_learner: true }”] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:17:59.309 +08:00] [INFO] [snap.rs:223] [“saving snapshot file”] [file=/data/tidb/data/tiflash-9000/flash/snap/rev_40431739_8_632_(default|lock|write).sst] [snap_key=40431739_8_632]
[2020/12/31 17:17:59.339 +08:00] [INFO] [raft.rs:1957] [“[commit: 0, lastindex: 0, lastterm: 0] starts to restore snapshot [index: 632, term: 8]”] [snapshot_term=8] [snapshot_index=632] [last_term=0] [last_index=0] [commit=0] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.339 +08:00] [INFO] [raft_log.rs:487] [“log [committed=0, applied=0, unstable.offset=1, unstable.entries.len()=0] starts to restore snapshot [index: 632, term: 8]”] [snapshot_term=8] [snapshot_index=632] [log=“committed=0, applied=0, unstable.offset=1, unstable.entries.len()=0”] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.339 +08:00] [INFO] [raft.rs:1893] [“[commit: 632, term: 8] restored snapshot [index: 632, term: 8]”] [snapshot_term=8] [snapshot_index=632] [commit=632] [term=8] [raft_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.339 +08:00] [INFO] [peer_storage.rs:985] [“begin to apply snapshot”] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.339 +08:00] [INFO] [peer_storage.rs:1025] [“apply snapshot with state ok”] [state=“applied_index: 632 truncated_state { index: 632 term: 8 }”] [region=“id: 40431739 start_key: 74800000000002F3FF775F728000000002FF5E152C0000000000FA end_key: 74800000000002F3FF775F728000000002FF5FFBA20000000000FA region_epoch { conf_ver: 14433 version: 92558 } peers { id: 40431740 store_id: 3268897 } peers { id: 40431741 store_id: 8 } peers { id: 40431742 store_id: 32033477 } peers { id: 83403127 store_id: 79448782 is_learner: true }”] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.339 +08:00] [INFO] [peer.rs:2409] [“snapshot is applied”] [region=“id: 40431739 start_key: 74800000000002F3FF775F728000000002FF5E152C0000000000FA end_key: 74800000000002F3FF775F728000000002FF5FFBA20000000000FA region_epoch { conf_ver: 14433 version: 92558 } peers { id: 40431740 store_id: 3268897 } peers { id: 40431741 store_id: 8 } peers { id: 40431742 store_id: 32033477 } peers { id: 83403127 store_id: 79448782 is_learner: true }”] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:17:59.525 +08:00] [INFO] [region.rs:318] [“pre handle snapshot”] [time_takes=616.015027ms] [state=“applied_index: 4250 truncated_state { index: 4250 term: 11 }”] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:17:59.537 +08:00] [INFO] [region.rs:364] [“begin apply snap data”] [region_id=40008016]
[2020/12/31 17:17:59.592 +08:00] [INFO] [region.rs:393] [“apply data with pre handled snap”] [region_id=40008016]
[2020/12/31 17:18:00.063 +08:00] [INFO] [region.rs:420] [“apply new data”] [time_takes=470.627261ms] [region_id=40008016]
[2020/12/31 17:18:00.457 +08:00] [INFO] [region.rs:318] [“pre handle snapshot”] [time_takes=1.117887635s] [state=“applied_index: 632 truncated_state { index: 632 term: 8 }”] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:18:00.464 +08:00] [INFO] [region.rs:364] [“begin apply snap data”] [region_id=40431739]
[2020/12/31 17:18:00.466 +08:00] [INFO] [region.rs:393] [“apply data with pre handled snap”] [region_id=40431739]
[2020/12/31 17:18:01.066 +08:00] [INFO] [region.rs:420] [“apply new data”] [time_takes=599.382823ms] [region_id=40431739]
[2020/12/31 17:18:01.990 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2496590 last_commit_index: 2496588 commit_index: 2496591 commit_term: 10 truncated_state { index: 2496584 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:18:03.728 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 55464 last_commit_index: 55463 commit_index: 55464 commit_term: 6 truncated_state { index: 55462 term: 6 }”] [peer_id=83399938] [region_id=83399934]
[2020/12/31 17:18:03.776 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 351934 last_commit_index: 351933 commit_index: 351934 commit_term: 9 truncated_state { index: 351932 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:18:05.354 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761812 last_commit_index: 761811 commit_index: 761812 commit_term: 6 truncated_state { index: 761810 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:18:05.573 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 27709 last_commit_index: 27708 commit_index: 27709 commit_term: 6 truncated_state { index: 27707 term: 6 }”] [peer_id=83398130] [region_id=83398126]
[2020/12/31 17:18:11.989 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2497462 last_commit_index: 2497461 commit_index: 2497463 commit_term: 10 truncated_state { index: 2497457 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:18:13.652 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 55558 last_commit_index: 55557 commit_index: 55558 commit_term: 6 truncated_state { index: 55556 term: 6 }”] [peer_id=83399938] [region_id=83399934]
[2020/12/31 17:18:13.716 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 352133 last_commit_index: 352132 commit_index: 352133 commit_term: 9 truncated_state { index: 352131 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:18:15.494 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 25695 last_commit_index: 25694 commit_index: 25695 commit_term: 6 truncated_state { index: 25693 term: 6 }”] [peer_id=83396762] [region_id=83396758]
[2020/12/31 17:18:15.739 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 94797 last_commit_index: 94796 commit_index: 94797 commit_term: 6 truncated_state { index: 94795 term: 6 }”] [peer_id=83381549] [region_id=83381544]
[2020/12/31 17:18:15.956 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761888 last_commit_index: 761887 commit_index: 761888 commit_term: 6 truncated_state { index: 761886 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:18:19.970 +08:00] [INFO] [peer.rs:639] [“deleting applied snap file”] [snap_file=40008016_11_4250] [peer_id=83403126] [region_id=40008016]
[2020/12/31 17:18:19.970 +08:00] [INFO] [peer.rs:639] [“deleting applied snap file”] [snap_file=40431739_8_632] [peer_id=83403127] [region_id=40431739]
[2020/12/31 17:18:21.991 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2498501 last_commit_index: 2498500 commit_index: 2498502 commit_term: 10 truncated_state { index: 2498497 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:18:23.491 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 352475 last_commit_index: 352474 commit_index: 352475 commit_term: 9 truncated_state { index: 352473 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:18:23.557 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 55668 last_commit_index: 55667 commit_index: 55668 commit_term: 6 truncated_state { index: 55666 term: 6 }”] [peer_id=83399938] [region_id=83399934]
[2020/12/31 17:18:25.900 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 94882 last_commit_index: 94881 commit_index: 94882 commit_term: 6 truncated_state { index: 94880 term: 6 }”] [peer_id=83381549] [region_id=83381544]
[2020/12/31 17:18:28.522 +08:00] [INFO] [util.rs:419] [“connecting to PD endpoint”] [endpoints=http://172.29.238.36:2379]
[2020/12/31 17:18:28.535 +08:00] [INFO] [] [“New connected subchannel at 0x7f16adc3a660 for subchannel 0x7f16adca3000”]
[2020/12/31 17:18:28.537 +08:00] [INFO] [util.rs:419] [“connecting to PD endpoint”] [endpoints=http://172.29.238.23:2379]
[2020/12/31 17:18:28.537 +08:00] [INFO] [util.rs:484] [“connected to PD leader”] [endpoints=http://172.29.238.23:2379]
[2020/12/31 17:18:28.537 +08:00] [INFO] [util.rs:190] [“heartbeat sender and receiver are stale, refreshing …”]
[2020/12/31 17:18:28.540 +08:00] [WARN] [util.rs:209] [“updating PD client done”] [spend=18.44494ms]
[2020/12/31 17:18:32.001 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2499572 last_commit_index: 2499571 commit_index: 2499572 commit_term: 10 truncated_state { index: 2499570 term: 10 }”] [peer_id=83392605] [region_id=83365394]
[2020/12/31 17:18:33.463 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 352909 last_commit_index: 352908 commit_index: 352909 commit_term: 9 truncated_state { index: 352907 term: 9 }”] [peer_id=83399939] [region_id=77880342]
[2020/12/31 17:18:34.626 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 761994 last_commit_index: 761993 commit_index: 761994 commit_term: 6 truncated_state { index: 761992 term: 6 }”] [peer_id=83381548] [region_id=83365483]
[2020/12/31 17:18:35.586 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 87508 last_commit_index: 87507 commit_index: 87508 commit_term: 6 truncated_state { index: 87506 term: 6 }”] [peer_id=83392497] [region_id=83392493]
[2020/12/31 17:18:36.210 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 94936 last_commit_index: 94935 commit_index: 94936 commit_term: 6 truncated_state { index: 94934 term: 6 }”] [peer_id=83381549] [region_id=83381544]

[2020/12/31 17:18:42.010 +08:00] [INFO] [apply.rs:1118] [“persist apply state”] [state=“applied_index: 2500996 last_commit_index: 2500995 commit_index: 2500996 commit_term: 10 truncated_state { index: 2500994 term: 10 }”] [peer_id=83392605] [region_id=83365394]

信仰在空中飘扬 · 2020 年12 月 31 日 09:55

上传详细的日志
tiflash_cluster_manager.log (8.3 MB) tiflash_error.log (209.2 KB) tiflash_tikv.log (4.5 MB)

flow-PingCAP · 2020 年12 月 31 日 10:26

你好，可以试试调整 PD 的配置，加快 TiFlash 副本同步的速度
https://docs.pingcap.com/zh/tidb/stable/tiflash-configuration#pd-调度参数

信仰在空中飘扬 · 2020 年12 月 31 日 11:10

在上面我发的pd 的相关配置中, 我已经调整过相关的参数了。效果不明显

信仰在空中飘扬 · 2020 年12 月 31 日 11:18

刚看到你的问题:rofl:

这道题我不会 · 2021 年1 月 4 日 02:09

请问下目前 tiflash 同步慢的问题得到解决了吗？

信仰在空中飘扬 · 2021 年1 月 4 日 02:43

===> 目前手动hint 不生效的问题得到解决，在连接tidb的时候加上—coments 参数就可以了。
mysql -uroot -pxxxxxx -h172.29.xxxxx -P4000 --comments

===> 同步慢的问题pingcap 的其他老师正在分析排查中

不懂就问 · 2021 年1 月 6 日 04:17

请问调整完 store limit 之后同步速度怎么样？

信仰在空中飘扬 · 2021 年1 月 6 日 07:25

昨晚试了一个两亿的表:
开始时间:2021-01-05 18:56:51
结束时间:2021-01-05 22:18:21
TiFlashManager: report to tidb: id 21885, region_count 835, flash_region_count 835
这个表region 数比较多。请问这个速度算正常么？

已经调整的参数有
“patrol-region-interval”: “10ms”
“replica-schedule-limit”: 2048
store limit 60 add-peer

====分割线====
又在两个集群分别同步了两个大表速度都在每分钟5个 region 左右，感觉效果一般
table-1

table-2

不懂就问 · 2021 年1 月 6 日 09:06

“replica-schedule-limit”: 2048 & store limit 60 add-peer 这两参数再调大看看效果，目前看还是偏慢。

信仰在空中飘扬 · 2021 年1 月 6 日 09:52

经过实测，replica-schedule-limit 加大没啥用。
我将 store limit 60 add-peer 增加到240 或者360 明显加快。

不懂就问 · 2021 年1 月 7 日 02:12

好的