tikv 手动compact

田帅萌7 · 2024 年1 月 23 日 09:30

【 TiDB 使用环境】生产环境 /测试/ Poc
【 TiDB 版本】v5.0.6
【复现路径】做过哪些操作出现的问题
【遇到的问题：问题现象及影响】
【资源配置】进入到 TiDB Dashboard -集群信息 (Cluster Info) -主机(Hosts) 截图此页面
【附件：截图/日志/监控】
因为

进行手动 compact
集群规模 3台tikv 总容量1.9T 单台tikv 680G
从今天11点30开始执行
tiup ctl:v5.0.6 tikv --pd compact-cluster -d kv --threads 32
单机容量翻倍

zhanggame1 · 2024 年1 月 23 日 11:59

compact没执行完吧，执行过程会占用巨大的磁盘空间

TiDBer_jYQINSnf · 2024 年1 月 23 日 12:19

看看compact日志，在rocksdb.info中，里面有compact的job，根据jobid看看进度。
compact的流程是：
遍历level0的文件和level1的文件，范围内的sst列为输入，然后读取，合并，输出到level1，然后删除输入sst。
然后level1到level2。。。。
依次类推，直到最后一层
正常来应该是波动下降的，这个翻倍感觉不是特别正常。看看日志什么情况吧。

田帅萌7 · 2024 年1 月 23 日 12:52

我找到jobid ，如果根据jobid进行查询呢

有猫万事足 · 2024 年1 月 23 日 14:18

https://github.com/facebook/rocksdb/wiki/Compaction-Stats-and-DB-Status#compaction-stats

我不太清楚怎么根据jobid查看，不过我在rocksdb的文档中发现了这个。
说是10分钟就会输出一次压缩状态。
我在rocksdb.info文件中找了下，确实能找到类似的日志。不知道是否对你有所帮助。

田帅萌7 · 2024 年1 月 23 日 23:33

compact 执行之后执行计划不稳定
ySQL [(none)]> use hotel_product
Database changed
MySQL [hotel_product]> explain ANALYZE select * from prefetch_key_info limit 100;
±---------------------------±--------±--------±----------±------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| id | estRows | actRows | task | access object | execution info

                 | operator info       | memory  | disk |

±---------------------------±--------±--------±----------±------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| Limit_7 | 100.00 | 100 | root | | time:3m2.9s, loops:2

                 | offset:0, count:100 | N/A     | N/A  |

| └─TableReader_12 | 100.00 | 100 | root | | time:3m2.9s, loops:1, cop_task: {num: 806, max: 742.3ms, min: 922.4µs, avg: 226.8ms, p95: 448.7ms, max_proc_keys: 100, p95_proc_keys: 0, tot_proc: 2m47.9s, tot_wait: 14.2s, rpc_num: 808, rpc_time: 3m2.8s, copr_cache_hit_ratio: 0.00}, backoff{regionMiss: 2ms}
| data:Limit_11 | 18.9 KB | N/A |
| └─Limit_11 | 100.00 | 100 | cop[tikv] | | tikv_task:{proc max:620ms, min:0s, p80:298ms, p95:423ms, iters:808, tasks:806}, scan_detail: {total_process_keys: 100, total_keys: 423330044, rocksdb: {delete_skipped_count: 51187119, key_skipped_count: 474516358, block: {cache_hit_count: 6711, read_count: 294819, read_byte: 829.3 MB}}} | offset:0, count:100 | N/A | N/A |
| └─TableFullScan_10 | 100.00 | 100 | cop[tikv] | table:prefetch_key_info | tikv_task:{proc max:620ms, min:0s, p80:298ms, p95:423ms, iters:808, tasks:806}, scan_detail: {total_process_keys: 0, total_keys: 0, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 0, read_count: 0, read_byte: 0 Bytes}}}
| keep order:false | N/A | N/A |
±---------------------------±--------±--------±----------±------------------------±------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
4 rows in set (3 min 3.78 sec)

MySQL [hotel_product]> ANALYZE table prefetch_key_info;
Query OK, 0 rows affected (20 min 43.13 sec)

MySQL [hotel_product]> explain ANALYZE select * from prefetch_key_info limit 100;
±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| id | estRows | actRows | task | access object | execution info

               | operator info       | memory  | disk |

±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| Limit_7 | 100.00 | 100 | root | | time:2m37s, loops:2

               | offset:0, count:100 | N/A     | N/A  |

| └─TableReader_12 | 100.00 | 100 | root | | time:2m37s, loops:1, cop_task: {num: 802, max: 675.2ms, min: 518.6µs, avg: 195.7ms, p95:
431.4ms, max_proc_keys: 100, p95_proc_keys: 0, tot_proc: 2m24.8s, tot_wait: 11.4s, rpc_num: 802, rpc_time: 2m36.9s, copr_cache_hit_ratio: 0.08}
| data:Limit_11 | 18.9 KB | N/A |
| └─Limit_11 | 100.00 | 100 | cop[tikv] | | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 100, total_keys: 387235317, rocksdb: {delete_skipped_count: 47320693, key_skipped_count: 434555272, block: {cache_hit_count: 276457, read_count: 18, read_byte: 382.9 KB}}} | offset:0, count:100 | N/A | N/A |
| └─TableFullScan_10 | 100.00 | 100 | cop[tikv] | table:prefetch_key_info | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 0, total_keys: 0, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 0, read_count: 0, read_byte: 0 Bytes}}}
| keep order:false | N/A | N/A |
±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
4 rows in set (2 min 37.80 sec)

ySQL [hotel_product]> explain ANALYZE select * from prefetch_key_info limit 100;
±---------------------------±--------±--------±----------±------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| id | estRows | actRows | task | access object | execution info

          | operator info       | memory  | disk |

±---------------------------±--------±--------±----------±------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| Limit_7 | 100.00 | 100 | root | | time:7.7s, loops:2

          | offset:0, count:100 | N/A     | N/A  |

| └─TableReader_12 | 100.00 | 100 | root | | time:7.7s, loops:1, cop_task: {num: 802, max: 433.9ms, min: 393.4µs, avg: 9.55ms, p95: 2.06ms, max_proc_keys: 100, p95_proc_keys: 0, tot_proc: 7.03s, tot_wait: 293ms, rpc_num: 804, rpc_time: 7.65s, copr_cache_hit_ratio: 0.95}, backoff{regionMiss: 2ms}
| data:Limit_11 | 18.9 KB | N/A |
| └─Limit_11 | 100.00 | 100 | cop[tikv] | | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 100, total_keys: 19583148, rocksdb: {delete_skipped_count: 1814115, key_skipped_count: 21397225, block: {cache_hit_count: 13487, read_count: 7, read_byte: 316.2 KB}}} | offset:0, count:100 | N/A | N/A |
| └─TableFullScan_10 | 100.00 | 100 | cop[tikv] | table:prefetch_key_info | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 0, total_keys: 0, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 0, read_count: 0, read_byte: 0 Bytes}}}
| keep order:false | N/A | N/A |
±---------------------------±--------±--------±----------±------------------------±-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
4 rows in set (7.74 sec)

MySQL [hotel_product]> explain ANALYZE select * from prefetch_key_info limit 100;
±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| id | estRows | actRows | task | access object | execution info
| operator
info | memory | disk |
±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
| Limit_7 | 100.00 | 100 | root | | time:709.4ms, loops:2
|
| └─TableReader_12 | 100.00 | 100 | root | | time:709.4ms, loops:1, cop_task: {num: 802, max: 4.63ms, min: 381.5µs, avg: 846.7µs, p95: 1.76ms, tot_proc: 2ms, tot_wait: 366ms, rpc_num: 802, rpc_time: 671.2ms, copr_cache_hit_ratio: 1.00} | data:Limit_11 | 18.9 KB | N/A |
| └─Limit_11 | 100.00 | 100 | cop[tikv] | | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 0, total_keys: 3, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 40, read_count: 3, read_byte: 143.9 KB}}} | offset:0, count:100 | N/A | N/A |
| └─TableFullScan_10 | 100.00 | 100 | cop[tikv] | table:prefetch_key_info | tikv_task:{proc max:574ms, min:0s, p80:280ms, p95:404ms, iters:804, tasks:802}, scan_detail: {total_process_keys: 0, total_keys: 0, rocksdb: {delete_skipped_count: 0, key_skipped_count: 0, block: {cache_hit_count: 0, read_count: 0, read_byte: 0 Bytes}}} | keep order:false | N/A | N/A |
±---------------------------±--------±--------±----------±------------------------±----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±--------------------±--------±-----+
4 rows in set (0.74 sec)

h5n1 · 2024 年1 月 24 日 01:32

这样compact
tikv-ctl --host xxxxx:20160 compact -c write -d kv --bottommost force
tikv-ctl --host xxxx:20160 compact -c default -d kv --bottommost force

TiDBer_jYQINSnf · 2024 年1 月 24 日 02:09

cat rocksdb.info |grep EVENT_LOG_v|grep "job\": 161"

这是过滤所有 job=161的event_log，里面会记录compaction_started table_file_creation table_file_deletion compaction_finished
基本上就能看到你这个compact执行情况了。

cat rocksdb.info |grep EVENT_LOG_v|grep "job\": 161"
[2024/01/24 10:07:21.743 +08:00][4][INFO] EVENT_LOG_v1 {"time_micros": 1706062041741309, "job": 161, "event": "compaction_started", "compaction_reason": "LevelL0FilesNum", "files_L0": [199], "files_L6": [188], "score": 1, "input_data_size": 4344}
[2024/01/24 10:07:21.744 +08:00][4][INFO] EVENT_LOG_v1 {"time_micros": 1706062041743394, "cf_name": "raft", "job": 161, "event": "table_file_creation", "file_number": 229, "file_size": 3323, "table_properties": {"data_size": 2487, "index_size": 38, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 0, "raw_key_size": 912, "raw_average_key_size": 19, "raw_value_size": 1807, "raw_average_value_size": 37, "num_data_blocks": 1, "num_entries": 48, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 0, "filter_policy": "rocksdb.BuiltinBloomFilter", "column_family_name": "raft", "column_family_id": 3, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "NoopSliceTransform", "property_collectors": "[]", "compression": "NoCompression", "compression_options": "window_bits=-14; level=32767; strategy=0; max_dict_bytes=0; zstd_max_train_bytes=0; enabled=0; ", "creation_time": 1706062020, "oldest_key_time": 0, "file_creation_time": 1706062041}}
[2024/01/24 10:07:21.745 +08:00][4][INFO] (Original Log Time 2024/01/24-10:07:21.744843) EVENT_LOG_v1 {"time_micros": 1706062041744822, "job": 161, "event": "compaction_finished", "compaction_time_micros": 2235, "compaction_time_cpu_micros": 1814, "output_level": 6, "num_output_files": 1, "total_output_size": 3323, "num_input_records": 50, "num_output_records": 48, "num_subcompactions": 1, "output_compression": "NoCompression", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "lsm_state": [0, 0, 0, 0, 0, 0, 1]}
[2024/01/24 10:07:21.747 +08:00][4][INFO] EVENT_LOG_v1 {"time_micros": 1706062041745531, "job": 161, "event": "table_file_deletion", "file_number": 199}
[2024/01/24 10:07:21.747 +08:00][4][INFO] EVENT_LOG_v1 {"time_micros": 1706062041745708, "job": 161, "event": "table_file_deletion", "file_number": 188}

举例看看这个，compact 输入的文件是level0的199和level6的188，输入的大小是 4344。
第二条，创建了一个文件，229，文件大小3323
第三条：compact结束，输出到了level6，输出了1个文件，大小是3323，
后面2条就是把输入的文件删掉。这个compact就结束了。
磁盘占用从 4344到 4344+3323到3323
因为一次compact不至于拉入所有cf的所有sst文件，顶多是某一个cf的某2个level,空间翻倍感觉不至于这么夸张吧。具体你还是看看日志，看看db目录下都是什么内容。

dba远航 · 2024 年1 月 25 日 00:45

压缩情况与存储的数据有关

田帅萌7 · 2024 年1 月 25 日 08:47

[2024/01/25 16:46:42.672 +08:00][2][INFO] [db/compaction/compaction_job.cc:1690] [lock] Compaction start summary: Base version 30145 Base level 0, inputs: [7753036(2496KB)], [7753032(412KB)]
[2024/01/25 16:46:42.672 +08:00][2][INFO] EVENT_LOG_v1 {“time_micros”: 1706172402672831, “job”: 44850, “event”: “compaction_started”, “compaction_reason”: “LevelL0FilesNum”, “files_L0”: [7753036], “files_L6”: [7753032], “score”: 1, “input_data_size”: 2979055}
[2024/01/25 16:46:42.702 +08:00][2][INFO] [db/compaction/compaction_job.cc:1373] [lock] [JOB 44850] Generated table #7753037: 2176 keys, 369969 bytes
[2024/01/25 16:46:42.703 +08:00][2][INFO] [db/compaction/compaction_job.cc:1436] [lock] [JOB 44850] Compacted 1@0 + 1@6 files to L6 => 369969 bytes
[2024/01/25 16:46:42.705 +08:00][2][INFO] (Original Log Time 2024/01/25-16:46:42.703281) [db/compaction/compaction_job.cc:767] [lock] compacted to: base level 6 level multiplier 10.00 max bytes base 134217728 files[0 0 0 0 0 0 1] max score 0.00, MB/sec: 100.1 rd, 12.4 wr, level 6, files in(1, 1) out(1) MB in(2.4, 0.4) out(0.4), read-write-amplify(1.3) write-amplify(0.1) OK, records in: 94037, records dropped: 91861 output_compression: NoCompression
[2024/01/25 16:46:42.705 +08:00][2][INFO] (Original Log Time 2024/01/25-16:46:42.703299) EVENT_LOG_v1 {“time_micros”: 1706172402703291, “job”: 44850, “event”: “compaction_finished”, “compaction_time_micros”: 29764, “compaction_time_cpu_micros”: 27119, “output_level”: 6, “num_output_files”: 1, “total_output_size”: 369969, “num_input_records”: 94037, “num_output_records”: 2176, “num_subcompactions”: 1, “output_compression”: “NoCompression”, “num_single_delete_mismatches”: 0, “num_single_delete_fallthrough”: 0, “lsm_state”: [0, 0, 0, 0, 0, 0, 1]}

田帅萌7 · 2024 年1 月 25 日 08:47

tikv:
raftstore.capacity: 1024G
readpool.coprocessor.use-unified-pool: true
readpool.storage.use-unified-pool: false
readpool.unified.max-thread-count: 32
storage.block-cache.capacity: 96G

PINO · 2024 年1 月 25 日 09:27

从日志看确实在compact，但看不出来不确定是自动的还是手动的。以手动执行的进程为准吧。

田帅萌7 · 2024 年1 月 26 日 01:37

手动进程已经关闭

TiDBer_jYQINSnf · 2024 年1 月 26 日 01:49

你发的这个是一个常规的 l0 文件触发的向下compact，你如果想看当时发生了什么，就找你手动触发compact的时候，compactreason: manual_compact 的日志。
如果就想看看现状，可以通过 tikv-ctl ldb manifest_dump --path=./db/MANIFEST-XX --hex 列出当前 rokcsdb每一层有多少sst
还可以通过

tikv-ctl ldb list_file_range_deletes --db=./tikv/db/ 看看多少文件被标记删除

还可以通过

tikv-ctl ldb checkconsistency --db=./tikv/db/ 检查下db目录是不是正常。

不过最好还是别折腾了，空间早晚会缩回去。

江湖故人 · 2024 年1 月 26 日 02:57

可能还有其他的compact没执行完成，等等看

田帅萌7 · 2024 年1 月 31 日 05:42

看日志还在 compact

TiDBer_jYQINSnf · 2024 年1 月 31 日 06:14

compact一直发生的

田帅萌7 · 2024 年1 月 31 日 06:21

影响这么大？

TiDBer_jYQINSnf · 2024 年1 月 31 日 06:36

compact 只要有写入就会发生，你触发的手动compact只是一次范围比较大的compact。

田帅萌7 · 2024 年1 月 31 日 06:39

手动触发的操作早在8天前停止。操作期间影响cpu 我理解，为啥停止这么久还影响cpu