2024/11/20-20:48:36.977132 140008937477696 DEBG dcompact_worker.cpp:2219: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00: fork to child time = 0.008776 sec 2024/11/20-20:48:36.977597 140008937477696 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00 2024/11/20-20:48:36.983868 140008937477696 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00 2024/11/20-20:48:36.985575 140008937477696 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/20-20:48:36.985788 140008937477696 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/20-20:48:37.031822 140008937477696 [version_set.cc:6211] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-11968/att-00/MANIFEST-049091 2024/11/20-20:48:37.096924 140008937477696 [version_set.cc:6254] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-11968/att-00/MANIFEST-049091 succeeded,manifest_file_number is 49091, next_file_number is 69061, last_sequence is 1112105175, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 68903 2024/11/20-20:48:37.096932 140008937477696 [version_set.cc:6269] Column family [default] (ID 0), log number is 0 2024/11/20-20:48:37.096989 140008937477696 [version_set.cc:5724] Creating manifest 69061 2024/11/20-20:48:37.136776 140008937477696 DEBG dcompact_worker.cpp:1225: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/20-20:48:37.162226 140008937477696 [compaction_job.cc:2437] [default] [JOB 11968] Compacting 1@2 + 9@3 files to L3, score 0.88, subcompactions 1 : 1 2024/11/20-20:48:37.162236 140008937477696 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 9877 Base level 2, inputs: [69056(28MB)], [69019(124MB) 69020(124MB) 69021(124MB) 69022(124MB) 69023(124MB) 69024(124MB) 69025(124MB) 69026(124MB) 69027(117MB)] 2024/11/20-20:48:37.169144 140008937477696 [top_zip_table.cc:59] core git_version_hash_info_is:commit 81964c21ebbcc178d8e99dae0fbf61bded2729cc Author: rockeet Date: Mon Nov 11 21:28:46 2024 +0800 Makefile: fix gen git-version-*.cpp GIT_PATH_ARG = :!src/terark/fsa :!tools/fsa :!src/terark/zbs :!tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:48:37.169163 140008937477696 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit 5dfecb7d107196f044ff5bf78dc39d2e725b9d9b Author: leipeng Date: Thu Nov 7 15:22:45 2024 +0800 Makefile: fix for x86_64 CPU older than haswell GIT_PATH_ARG = src/terark/fsa tools/fsa g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:48:37.169178 140008937477696 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit d44dd5ff72707128fe3c916077b43d2093c01f7c Author: leipeng Date: Sun Oct 27 23:38:26 2024 +0800 Fix for msvc, when toplingdb on msvc GIT_PATH_ARG = src/terark/zbs tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:48:37.169184 140008937477696 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit 79614a7e7dc27362fc5151b0797eb7d83c674c7b Author: rockeet Date: Sun Nov 10 15:02:21 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-20:48:37.169192 140008937477696 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit c46b65a52d9c74aa8b87aeb8438620ff2dbc669c Author: rockeet Date: Sun Nov 10 15:02:42 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-20:48:38.463379 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst) /dev/shm/ToplingTemp/Topling-967550-sGi4mM 2024/11/20-20:48:38.624204 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst): first pass time = 0.16's, 834.829'MB/sec 2024/11/20-20:48:40.128978 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst): part-0: reject ZipStore ratio = 0.807 2024/11/20-20:48:40.409813 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst): old prealloc_size = 147639500, real_size = 130035040 2024/11/20-20:48:40.409987 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199774 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.75 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.85 avg-zval = 648.91 2024/11/20-20:48:40.410228 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:40.771820 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069062.sst): second pass time = 1.50's, 86.511'MB/sec, value only(96.4% of KV) wait indexing time = 0.28's, remap KeyValue time = 0.36's, 361.039'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2261.053'MB/sec (index lex order gen) rebuild zvType time = 0.28's, 0.177'MB/sec write SST data time = 0.08's, 1647.471'MB/sec dict compress time = 4495846074.24's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.50's, unzip length = 0.129'GB zip my value throughput = 86.511'MB/sec zip pipeline throughput = 176.067'MB/sec entries = 199774 avg-key = 24.00 avg-zkey = 1.75 avg-val = 647.85 avg-zval = 648.91 usrkeys = 199774 avg-key = 16.00 avg-zkey = 1.75 avg-val = 654.85 avg-zval = 648.91 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 199774 bytes = 699216 } seq expand size = 1398418 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1307 GB } UnZip/Zip{ index = 9.1388 value = 0.9984 dict = 0.00 all = 1.0270 } Zip/UnZip{ index = 0.1094 value = 1.0016 dict = 0.00 all = 0.9737 } ---------------------------- total value len = 563.196554 GB avg = 0.331 KB (by entry num) total key len = 44.319201 GB avg = 0.026 KB total ukey len = 32.797338 GB avg = 0.014 KB total ukey num = 2.321214350 Billion total entry num = 1.700716372 Billion write speed all = 61.375002836 MB/sec (with seq num) write speed all = 60.000467656 MB/sec (without seq num) 2024/11/20-20:48:40.938154 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69062: 199774 keys, 130687135 bytes, temperature: kWarm 2024/11/20-20:48:40.938286 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106920938225, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69062, "file_size": 130687135, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 856426320, "largest_seqno": 1111804725, "table_properties": {"data_size": 129635152, "index_size": 349760, "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": 4794576, "raw_average_key_size": 24, "raw_value_size": 129423161, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199774, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106918, "oldest_key_time": 0, "file_creation_time": 1732106918, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69062, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:41.036080 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst) /dev/shm/ToplingTemp/Topling-967550-X9Gr5K 2024/11/20-20:48:42.383245 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst): first pass time = 1.35's, 99.633'MB/sec 2024/11/20-20:48:43.728563 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst): part-0: reject ZipStore ratio = 0.807 2024/11/20-20:48:44.000058 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst): old prealloc_size = 147639500, real_size = 130032784 2024/11/20-20:48:44.000216 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199952 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0004 GB avg-key = 12.00 avg-zkey = 1.76 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.25 avg-zval = 648.31 2024/11/20-20:48:44.000405 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:44.311682 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069063.sst): second pass time = 1.34's, 96.249'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.31's, 419.196'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2513.421'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.198'MB/sec write SST data time = 0.06's, 2233.828'MB/sec dict compress time = 4495846074.24's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.34's, unzip length = 0.129'GB zip my value throughput = 96.249'MB/sec zip pipeline throughput = 231.900'MB/sec entries = 199952 avg-key = 24.00 avg-zkey = 1.76 avg-val = 647.25 avg-zval = 648.31 usrkeys = 199952 avg-key = 16.00 avg-zkey = 1.76 avg-val = 653.38 avg-zval = 648.31 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 175113 bytes = 612912 } seq expand size = 1225791 multi value expand size = 0 cnt WriteAppend = 15808 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0004 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.1036 value = 0.9984 dict = 0.00 all = 1.0275 } Zip/UnZip{ index = 0.1098 value = 1.0016 dict = 0.00 all = 0.9733 } ---------------------------- total value len = 563.327199 GB avg = 0.331 KB (by entry num) total key len = 44.324000 GB avg = 0.026 KB total ukey len = 32.800537 GB avg = 0.014 KB total ukey num = 2.321414302 Billion total entry num = 1.700916324 Billion write speed all = 61.366740156 MB/sec (with seq num) write speed all = 59.992534818 MB/sec (without seq num) 2024/11/20-20:48:44.452397 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69063: 199952 keys, 130629791 bytes, temperature: kWarm 2024/11/20-20:48:44.452459 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106924452429, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69063, "file_size": 130629791, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111804539, "table_properties": {"data_size": 129631168, "index_size": 351424, "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": 4798848, "raw_average_key_size": 24, "raw_value_size": 129419027, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199952, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106921, "oldest_key_time": 0, "file_creation_time": 1732106921, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69063, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:44.509148 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst) /dev/shm/ToplingTemp/Topling-967550-nwMyDL 2024/11/20-20:48:45.728448 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst): first pass time = 1.22's, 110.082'MB/sec 2024/11/20-20:48:46.866477 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst): part-0: reject ZipStore ratio = 0.804 2024/11/20-20:48:47.139507 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst): old prealloc_size = 147639500, real_size = 130024976 2024/11/20-20:48:47.139677 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199817 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.70 avg-zval = 648.76 2024/11/20-20:48:47.139872 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:47.504325 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069064.sst): second pass time = 1.14's, 113.794'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.36's, 357.996'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2262.429'MB/sec (index lex order gen) rebuild zvType time = 0.29's, 0.175'MB/sec write SST data time = 0.08's, 1657.917'MB/sec dict compress time = 4495846074.24's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.14's, unzip length = 0.129'GB zip my value throughput = 113.794'MB/sec zip pipeline throughput = 134.153'MB/sec entries = 199817 avg-key = 24.00 avg-zkey = 1.70 avg-val = 647.70 avg-zval = 648.76 usrkeys = 199817 avg-key = 16.00 avg-zkey = 1.70 avg-val = 653.51 avg-zval = 648.76 TagRS{ kinds = RS_Key0_TagN bytes = 31320 } TagArray{ size = 165807 bytes = 580336 } seq expand size = 1160649 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.3846 value = 0.9984 dict = 0.00 all = 1.0278 } Zip/UnZip{ index = 0.1066 value = 1.0016 dict = 0.00 all = 0.9730 } ---------------------------- total value len = 563.457781 GB avg = 0.331 KB (by entry num) total key len = 44.328795 GB avg = 0.026 KB total ukey len = 32.803734 GB avg = 0.014 KB total ukey num = 2.321614119 Billion total entry num = 1.701116141 Billion write speed all = 61.360627950 MB/sec (with seq num) write speed all = 59.986704160 MB/sec (without seq num) 2024/11/20-20:48:47.654628 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69064: 199817 keys, 130589471 bytes, temperature: kWarm 2024/11/20-20:48:47.654692 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106927654661, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69064, "file_size": 130589471, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111804804, "table_properties": {"data_size": 129634176, "index_size": 340672, "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": 4795608, "raw_average_key_size": 24, "raw_value_size": 129422201, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199817, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106924, "oldest_key_time": 0, "file_creation_time": 1732106924, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69064, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:47.712889 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst) /dev/shm/ToplingTemp/Topling-967550-5uhOFL 2024/11/20-20:48:49.055622 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst): first pass time = 1.34's, 99.962'MB/sec 2024/11/20-20:48:50.264258 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst): part-0: reject ZipStore ratio = 0.802 2024/11/20-20:48:50.592324 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst): old prealloc_size = 147639500, real_size = 130033712 2024/11/20-20:48:50.592478 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199499 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 648.78 avg-zval = 649.84 2024/11/20-20:48:50.592674 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:50.896524 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069065.sst): second pass time = 1.21's, 107.153'MB/sec, value only(96.4% of KV) wait indexing time = 0.33's, remap KeyValue time = 0.30's, 429.385'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2474.393'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.201'MB/sec write SST data time = 0.06's, 2315.135'MB/sec dict compress time = 4495846074.24's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.21's, unzip length = 0.129'GB zip my value throughput = 107.153'MB/sec zip pipeline throughput = 107.153'MB/sec entries = 199499 avg-key = 24.00 avg-zkey = 1.71 avg-val = 648.78 avg-zval = 649.84 usrkeys = 199499 avg-key = 16.00 avg-zkey = 1.71 avg-val = 654.78 avg-zval = 649.84 TagRS{ kinds = RS_Key0_TagN bytes = 31280 } TagArray{ size = 171068 bytes = 598752 } seq expand size = 1197476 multi value expand size = 0 cnt WriteAppend = 15810 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.3433 value = 0.9984 dict = 0.00 all = 1.0276 } Zip/UnZip{ index = 0.1070 value = 1.0016 dict = 0.00 all = 0.9732 } ---------------------------- total value len = 563.588409 GB avg = 0.331 KB (by entry num) total key len = 44.333583 GB avg = 0.026 KB total ukey len = 32.806926 GB avg = 0.014 KB total ukey num = 2.321813618 Billion total entry num = 1.701315640 Billion write speed all = 61.353287449 MB/sec (with seq num) write speed all = 59.979672955 MB/sec (without seq num) 2024/11/20-20:48:51.036030 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69065: 199499 keys, 130616671 bytes, temperature: kWarm 2024/11/20-20:48:51.036102 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106931036070, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69065, "file_size": 130616671, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111804730, "table_properties": {"data_size": 129642016, "index_size": 341632, "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": 4787976, "raw_average_key_size": 24, "raw_value_size": 129430314, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 199499, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106927, "oldest_key_time": 0, "file_creation_time": 1732106927, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69065, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:51.096598 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst) /dev/shm/ToplingTemp/Topling-967550-7kNXoN 2024/11/20-20:48:52.289903 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst): first pass time = 1.19's, 112.480'MB/sec 2024/11/20-20:48:53.789658 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:48:54.063478 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst): old prealloc_size = 147639500, real_size = 130016720 2024/11/20-20:48:54.063632 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200304 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.07 avg-zval = 647.13 2024/11/20-20:48:54.063801 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:54.478989 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069066.sst): second pass time = 1.50's, 86.331'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.42's, 314.213'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2454.402'MB/sec (index lex order gen) rebuild zvType time = 0.34's, 0.149'MB/sec write SST data time = 0.08's, 1639.253'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.50's, unzip length = 0.129'GB zip my value throughput = 86.331'MB/sec zip pipeline throughput = 158.418'MB/sec entries = 200304 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.07 avg-zval = 647.13 usrkeys = 200304 avg-key = 16.00 avg-zkey = 1.71 avg-val = 651.54 avg-zval = 647.13 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 156305 bytes = 547088 } seq expand size = 1094135 multi value expand size = 0 cnt WriteAppend = 15808 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.3478 value = 0.9984 dict = 0.00 all = 1.0281 } Zip/UnZip{ index = 0.1070 value = 1.0016 dict = 0.00 all = 0.9727 } ---------------------------- total value len = 563.718915 GB avg = 0.331 KB (by entry num) total key len = 44.338391 GB avg = 0.026 KB total ukey len = 32.810131 GB avg = 0.014 KB total ukey num = 2.322013922 Billion total entry num = 1.701515944 Billion write speed all = 61.344764372 MB/sec (with seq num) write speed all = 59.971484666 MB/sec (without seq num) 2024/11/20-20:48:54.631834 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69066: 200304 keys, 130547935 bytes, temperature: kWarm 2024/11/20-20:48:54.631927 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106934631881, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69066, "file_size": 130547935, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111785435, "table_properties": {"data_size": 129623616, "index_size": 342848, "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": 4807296, "raw_average_key_size": 24, "raw_value_size": 129411099, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200304, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106931, "oldest_key_time": 0, "file_creation_time": 1732106931, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69066, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:54.705924 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst) /dev/shm/ToplingTemp/Topling-967550-Fy21QL 2024/11/20-20:48:56.030395 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst): first pass time = 1.32's, 101.340'MB/sec 2024/11/20-20:48:57.290674 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:48:57.553800 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst): old prealloc_size = 147639500, real_size = 130017520 2024/11/20-20:48:57.553950 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200278 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.16 avg-zval = 647.22 2024/11/20-20:48:57.554148 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:48:57.859267 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069067.sst): second pass time = 1.26's, 102.745'MB/sec, value only(96.4% of KV) wait indexing time = 0.26's, remap KeyValue time = 0.31's, 427.352'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2597.329'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.200'MB/sec write SST data time = 0.06's, 2352.991'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.26's, unzip length = 0.129'GB zip my value throughput = 102.745'MB/sec zip pipeline throughput = 137.983'MB/sec entries = 200278 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.16 avg-zval = 647.22 usrkeys = 200278 avg-key = 16.00 avg-zkey = 1.71 avg-val = 651.48 avg-zval = 647.22 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 152126 bytes = 532448 } seq expand size = 1064882 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.3309 value = 0.9984 dict = 0.00 all = 1.0282 } Zip/UnZip{ index = 0.1072 value = 1.0016 dict = 0.00 all = 0.9726 } ---------------------------- total value len = 563.849391 GB avg = 0.331 KB (by entry num) total key len = 44.343197 GB avg = 0.026 KB total ukey len = 32.813336 GB avg = 0.014 KB total ukey num = 2.322214200 Billion total entry num = 1.701716222 Billion write speed all = 61.337494913 MB/sec (with seq num) write speed all = 59.964521783 MB/sec (without seq num) 2024/11/20-20:48:58.003566 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69067: 200278 keys, 130534111 bytes, temperature: kWarm 2024/11/20-20:48:58.003639 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106938003606, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69067, "file_size": 130534111, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111802308, "table_properties": {"data_size": 129623840, "index_size": 343424, "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": 4806672, "raw_average_key_size": 24, "raw_value_size": 129411303, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200278, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106934, "oldest_key_time": 0, "file_creation_time": 1732106934, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69067, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:48:58.064122 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst) /dev/shm/ToplingTemp/Topling-967550-DBH00O 2024/11/20-20:48:59.355618 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst): first pass time = 1.29's, 103.928'MB/sec 2024/11/20-20:49:00.407999 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:49:00.668287 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst): old prealloc_size = 147639500, real_size = 130017024 2024/11/20-20:49:00.668436 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200293 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.11 avg-zval = 647.17 2024/11/20-20:49:00.668567 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:00.969470 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069068.sst): second pass time = 1.05's, 123.058'MB/sec, value only(96.4% of KV) wait indexing time = 0.26's, remap KeyValue time = 0.30's, 432.615'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2592.757'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.203'MB/sec write SST data time = 0.05's, 2394.213'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.05's, unzip length = 0.129'GB zip my value throughput = 123.058'MB/sec zip pipeline throughput = 147.072'MB/sec entries = 200293 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.11 avg-zval = 647.17 usrkeys = 200293 avg-key = 16.00 avg-zkey = 1.71 avg-val = 649.02 avg-zval = 647.17 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 83141 bytes = 291008 } seq expand size = 581987 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1303 GB } UnZip/Zip{ index = 9.3473 value = 0.9984 dict = 0.00 all = 1.0301 } Zip/UnZip{ index = 0.1070 value = 1.0016 dict = 0.00 all = 0.9707 } ---------------------------- total value len = 563.979384 GB avg = 0.331 KB (by entry num) total key len = 44.348004 GB avg = 0.026 KB total ukey len = 32.816540 GB avg = 0.014 KB total ukey num = 2.322414493 Billion total entry num = 1.701916515 Billion write speed all = 61.331851772 MB/sec (with seq num) write speed all = 59.959147621 MB/sec (without seq num) 2024/11/20-20:49:01.108087 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69068: 200293 keys, 130292127 bytes, temperature: kWarm 2024/11/20-20:49:01.108158 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106941108127, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69068, "file_size": 130292127, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111803903, "table_properties": {"data_size": 129623920, "index_size": 342848, "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": 4807032, "raw_average_key_size": 24, "raw_value_size": 129411380, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200293, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106938, "oldest_key_time": 0, "file_creation_time": 1732106938, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69068, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:01.168277 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst) /dev/shm/ToplingTemp/Topling-967550-xkMRWM 2024/11/20-20:49:02.333740 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst): first pass time = 1.17's, 115.168'MB/sec 2024/11/20-20:49:03.434971 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst): part-0: reject ZipStore ratio = 0.800 2024/11/20-20:49:03.714633 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst): old prealloc_size = 147639500, real_size = 130017712 2024/11/20-20:49:03.714803 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200134 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.64 avg-zval = 647.70 2024/11/20-20:49:03.715000 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:04.014306 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069069.sst): second pass time = 1.10's, 117.619'MB/sec, value only(96.4% of KV) wait indexing time = 0.28's, remap KeyValue time = 0.30's, 435.656'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2250.074'MB/sec (index lex order gen) rebuild zvType time = 0.24's, 0.206'MB/sec write SST data time = 0.06's, 2326.408'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.10's, unzip length = 0.129'GB zip my value throughput = 117.619'MB/sec zip pipeline throughput = 117.619'MB/sec entries = 200134 avg-key = 24.00 avg-zkey = 1.70 avg-val = 646.64 avg-zval = 647.70 usrkeys = 200134 avg-key = 16.00 avg-zkey = 1.70 avg-val = 652.10 avg-zval = 647.70 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 156065 bytes = 546240 } seq expand size = 1092455 multi value expand size = 0 cnt WriteAppend = 15808 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.4066 value = 0.9984 dict = 0.00 all = 1.0281 } Zip/UnZip{ index = 0.1063 value = 1.0016 dict = 0.00 all = 0.9727 } ---------------------------- total value len = 564.109891 GB avg = 0.331 KB (by entry num) total key len = 44.352808 GB avg = 0.026 KB total ukey len = 32.819743 GB avg = 0.014 KB total ukey num = 2.322614627 Billion total entry num = 1.702116649 Billion write speed all = 61.326667712 MB/sec (with seq num) write speed all = 59.954223454 MB/sec (without seq num) 2024/11/20-20:49:04.153248 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69069: 200134 keys, 130548319 bytes, temperature: kWarm 2024/11/20-20:49:04.153318 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106944153287, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69069, "file_size": 130548319, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111804799, "table_properties": {"data_size": 129627104, "index_size": 340416, "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": 4803216, "raw_average_key_size": 24, "raw_value_size": 129414719, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200134, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106941, "oldest_key_time": 0, "file_creation_time": 1732106941, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69069, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:04.209366 140008937477696 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst) /dev/shm/ToplingTemp/Topling-967550-2PAPsM 2024/11/20-20:49:05.327199 140008937477696 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst): first pass time = 1.12's, 116.018'MB/sec 2024/11/20-20:49:06.250517 140008937477696 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst): part-0: reject ZipStore ratio = 0.804 2024/11/20-20:49:06.500230 140008937477696 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst): old prealloc_size = 147639500, real_size = 125634400 2024/11/20-20:49:06.500383 140008937477696 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 193254 prefix = 4 raw-key = 0.0023 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.73 raw-val = 0.1250 GB zip-val = 0.1253 GB avg-val = 647.06 avg-zval = 648.12 2024/11/20-20:49:06.500554 140008937477696 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.130 GB 2024/11/20-20:49:06.868291 140008937477696 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00/069070.sst): second pass time = 0.92's, 135.531'MB/sec, value only(96.4% of KV) wait indexing time = 0.25's, remap KeyValue time = 0.37's, 342.495'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2455.114'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.154'MB/sec write SST data time = 0.06's, 2291.453'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 0.92's, unzip length = 0.125'GB zip my value throughput = 135.531'MB/sec zip pipeline throughput = 135.531'MB/sec entries = 193254 avg-key = 24.00 avg-zkey = 1.73 avg-val = 647.06 avg-zval = 648.12 usrkeys = 193254 avg-key = 16.00 avg-zkey = 1.73 avg-val = 651.56 avg-zval = 648.12 TagRS{ kinds = RS_Key0_TagN bytes = 30280 } TagArray{ size = 124281 bytes = 434992 } seq expand size = 869967 multi value expand size = 0 cnt WriteAppend = 15276 UnZipSize{ index = 0.0031 GB value = 0.1250 GB dict = 0.00 MB all = 0.1297 GB } __ZipSize{ index = 0.0003 GB value = 0.1253 GB dict = 0.00 MB all = 0.1261 GB } UnZip/Zip{ index = 9.2590 value = 0.9984 dict = 0.00 all = 1.0288 } Zip/UnZip{ index = 0.1080 value = 1.0016 dict = 0.00 all = 0.9720 } ---------------------------- total value len = 564.235808 GB avg = 0.331 KB (by entry num) total key len = 44.357446 GB avg = 0.026 KB total ukey len = 32.822835 GB avg = 0.014 KB total ukey num = 2.322807881 Billion total entry num = 1.702309903 Billion write speed all = 61.322186831 MB/sec (with seq num) write speed all = 59.949981467 MB/sec (without seq num) 2024/11/20-20:49:07.006306 140008937477696 [compaction_job.cc:1948] [default] [JOB 11968] Generated table #69070: 193254 keys, 126054111 bytes, temperature: kWarm 2024/11/20-20:49:07.006375 140008937477696 EVENT_LOG_v1 {"time_micros": 1732106947006344, "cf_name": "default", "job": 11968, "event": "table_file_creation", "file_number": 69070, "file_size": 126054111, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1111803966, "table_properties": {"data_size": 125251920, "index_size": 333952, "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": 4638096, "raw_average_key_size": 24, "raw_value_size": 125046855, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 193254, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106944, "oldest_key_time": 0, "file_creation_time": 1732106944, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69070, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:07.054944 140008937477696 [compaction_job.cc:703] job-11968: subcompact[0], size: 1.170500 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11968/att-00 [069062,069063,069064,069065,069066,069067,069068,069069,069070] 2024/11/20-20:49:07.174824 140008937477696 (Original Log Time 2024/11/20-20:48:37.162268) EVENT_LOG_v1 {"time_micros": 1732106917162244, "job": 11968, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [69056], "files_L3": [69019, 69020, 69021, 69022, 69023, 69024, 69025, 69026, 69027], "score": 0.883643, "input_data_size": 1197040049, "oldest_snapshot_seqno": 1112105025} 2024/11/20-20:49:07.174827 140008937477696 (Original Log Time 2024/11/20-20:49:07.173887) [compaction_job.cc:2022] [default] [JOB 11968] Compacted 1@2 + 9@3 files to L3 => 1170499671 bytes 2024/11/20-20:49:07.174829 140008937477696 (Original Log Time 2024/11/20-20:49:07.174756) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.04, MB/sec: 40.0 rd, 39.2 wr, level 3, files in(1, 9) out(9 +0 blob) MB in(28.0, 1113.6 +0.0 blob) out(1116.3 +0.0 blob), read-write-amplify(80.6) write-amplify(39.8) OK, records in: 1833399, records dropped: 40094 output_compression: Snappy 2024/11/20-20:49:07.174833 140008937477696 (Original Log Time 2024/11/20-20:49:07.174802) EVENT_LOG_v1 {"time_micros": 1732106947174780, "cf": "default", "job": 11968, "event": "compaction_finished", "compaction_time_micros": 29892685, "compaction_time_cpu_micros": 7556644, "output_level": 3, "num_output_files": 9, "total_output_size": 1170499671, "num_input_records": 1833399, "num_output_records": 1793305, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 808767933, "file_range_sync_nanos": 0, "file_fsync_nanos": 8901, "file_prepare_write_nanos": 6313087, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/20-20:49:07.314431 140008937477696 DEBG dcompact_worker.cpp:240: HttpPost: 200 OK: url = http://nlb-7zny4kaa1poal01o64.cn-shenzhen.nlb.aliyuncs.com:8443, body = {"instanceId":"nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137","labourId":"","dbId":"d89b4006-2803-486e-b7a2-759bcf348921","dbStarts":1732096383,"starts":1732106916,"executesMs":30190,"compactionJobId":11968,"attempt":0,"compactionInputRawBytes":1230606313,"compactionInputZipBytes":1197040049,"compactionOutputRawBytes":0,"compactionOutputZipBytes":1170499671,"headers":{"Accept":"*/*","Connection":"close","Host":"aliyun-topling-saas.topling.cn:18443","RemoteIp":"120.24.192.169","X-Forwarded-For":"120.24.192.169","region":"cn-shenzhen","token":"e6474c481bd4415abc537135cc03626b","instance-token":"e6474c481bd4415abc537135cc03626b","provider":"aliyun","CloudMarketInstanceId":"si-59c0ae5c955845588903","MeteringAssit":"","Transfer-Encoding":"chunked","traceparent":"00-175e93239658c16fe74f1ec5ed71cd10-35dcf91439db95a4-00"}}, response = 2024/11/20-20:49:07.314489 140008937477696 INFO dcompact_worker.cpp:1464: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-11968/att-00: olev 3, work 30.191 s, result 6.007 ms, install 0.962 ms, input{raw 1.146 GiB zip 1.115 GiB}