2024/11/22-22:35:08.111579 140024860931648 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00: fork to child time = 0.009233 sec 2024/11/22-22:35:08.112507 140024860931648 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00 2024/11/22-22:35:08.119746 140024860931648 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00 2024/11/22-22:35:08.121040 140024860931648 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/22-22:35:08.121303 140024860931648 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/22-22:35:08.173397 140024860931648 [version_set.cc:6208] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-12899/att-00/MANIFEST-206347 2024/11/22-22:35:08.207840 140024860931648 [version_set.cc:6251] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-12899/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 231603, last_sequence is 3613606614, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 231463 2024/11/22-22:35:08.207848 140024860931648 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/22-22:35:08.207939 140024860931648 [version_set.cc:5721] Creating manifest 231603 2024/11/22-22:35:08.242866 140024860931648 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/22-22:35:08.263912 140024860931648 [compaction_job.cc:2437] [default] [JOB 12899] Compacting 1@2 + 8@3 files to L3, score 1.00, subcompactions 1 : 1 2024/11/22-22:35:08.263929 140024860931648 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 9701 Base level 2, inputs: [231597(25MB)], [231553(36MB) 231554(37MB) 231555(35MB) 231556(36MB) 231557(35MB) 231558(37MB) 231559(33MB) 231560(28MB)] 2024/11/22-22:35:08.271474 140024860931648 [top_zip_table.cc:59] core git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 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/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-22:35:08.271512 140024860931648 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 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/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-22:35:08.271534 140024860931648 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 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/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-22:35:08.271540 140024860931648 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit a4a382006cb82713acf5b3425835f22711877681 Author: leipeng Date: 2024-04-11 19:44:14 +0800 fixed_len_hole_index.cc: Add env bool FixedLenHoleIndexUseAVX512 for ut & debug 1. FixedLenHoleIndexUseAVX512 is only in unit tests or debug 2. In release mode, use avx512 by compile options(-march=) g++ (GCC) 12.1.0 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/22-22:35:08.271550 140024860931648 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit feab587e468621ba0204d47b4ffacc52e7c4290d Author: leipeng Date: 2024-03-22 13:35:06 +0800 ToplingZipTableBuilder::Add: immediately return after error This function returns void, and caller does not check builder->status() after calling this function and graceful abandon. So immediately return after error, and return error status in Finish(). g++ (GCC) 12.1.0 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/22-22:35:08.749271 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst) /dev/shm/ToplingTemp/Topling-317240-BXA2Uq 2024/11/22-22:35:09.341468 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst): first pass time = 0.59's, 226.658'MB/sec 2024/11/22-22:35:13.927629 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst): old prealloc_size = 147639500, real_size = 34693664 2024/11/22-22:35:13.928221 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 926717 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0327 GB avg-val = 116.83 avg-zval = 35.28 2024/11/22-22:35:13.929025 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:15.279727 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231604.sst): second pass time = 4.59's, 23.612'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.35's, 28.691'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3127.749'MB/sec (index lex order gen) rebuild zvType time = 1.12's, 0.208'MB/sec write SST data time = 0.24's, 164.531'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.080'MB, throughput = 32565.822'MB/sec zip my value time = 4.59's, unzip length = 0.108'GB zip my value throughput = 23.612'MB/sec zip pipeline throughput = 124.992'MB/sec entries = 926717 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.83 avg-zval = 35.28 usrkeys = 926717 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.83 avg-zval = 35.28 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 926717 bytes = 3243520 } seq expand size = 6487019 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0327 GB dict = 1.08 MB all = 0.0388 GB } UnZip/Zip{ index = 10.5152 value = 3.3111 dict = 1.00 all = 3.4600 } Zip/UnZip{ index = 0.0951 value = 0.3020 dict = 1.00 all = 0.2890 } ---------------------------- total value len = 0.114757 GB avg = 0.124 KB (by entry num) total key len = 0.025948 GB avg = 0.028 KB total ukey len = 0.018534 GB avg = 0.020 KB total ukey num = 0.000926717 Billion total entry num = 0.000926717 Billion write speed all = 0.002849882 MB/sec (with seq num) write speed all = 0.002699721 MB/sec (without seq num) 2024/11/22-22:35:15.318662 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231604: 926717 keys, 38791618 bytes, temperature: kWarm 2024/11/22-22:35:15.318792 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286115318699, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231604, "file_size": 38791618, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3369353416, "largest_seqno": 3613582928, "table_properties": {"data_size": 32699152, "index_size": 1762624, "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": 25948076, "raw_average_key_size": 28, "raw_value_size": 108269778, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 926717, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286108, "oldest_key_time": 0, "file_creation_time": 1732286108, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231604, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:15.370994 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst) /dev/shm/ToplingTemp/Topling-317240-SFRdio 2024/11/22-22:35:16.629317 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst): first pass time = 1.26's, 106.668'MB/sec 2024/11/22-22:35:19.444078 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst): old prealloc_size = 147639500, real_size = 35029808 2024/11/22-22:35:19.444689 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 932578 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1081 GB zip-val = 0.0330 GB avg-val = 115.92 avg-zval = 35.40 2024/11/22-22:35:19.445368 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:20.561294 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231605.sst): second pass time = 2.81's, 38.415'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.12's, 34.683'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3011.894'MB/sec (index lex order gen) rebuild zvType time = 0.94's, 0.248'MB/sec write SST data time = 0.18's, 219.709'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.078'MB, throughput = 25563.590'MB/sec zip my value time = 2.81's, unzip length = 0.108'GB zip my value throughput = 38.415'MB/sec zip pipeline throughput = 98.306'MB/sec entries = 932578 avg-key = 28.00 avg-zkey = 1.91 avg-val = 115.92 avg-zval = 35.40 usrkeys = 932578 avg-key = 20.00 avg-zkey = 1.91 avg-val = 121.55 avg-zval = 35.40 TagRS{ kinds = RS_Key0_TagN bytes = 145800 } TagArray{ size = 749581 bytes = 2717248 } seq expand size = 5247067 multi value expand size = 0 cnt WriteAppend = 18 UnZipSize{ index = 0.0187 GB value = 0.1081 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0330 GB dict = 1.08 MB all = 0.0387 GB } UnZip/Zip{ index = 10.4463 value = 3.2748 dict = 1.00 all = 3.4640 } Zip/UnZip{ index = 0.0957 value = 0.3054 dict = 1.00 all = 0.2887 } ---------------------------- total value len = 0.228110 GB avg = 0.123 KB (by entry num) total key len = 0.052060 GB avg = 0.028 KB total ukey len = 0.037186 GB avg = 0.020 KB total ukey num = 0.001859295 Billion total entry num = 0.001859295 Billion write speed all = 0.005674042 MB/sec (with seq num) write speed all = 0.005372804 MB/sec (without seq num) 2024/11/22-22:35:20.602880 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231605: 932578 keys, 38746782 bytes, temperature: kWarm 2024/11/22-22:35:20.602958 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286120602915, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231605, "file_size": 38746782, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3613583386, "table_properties": {"data_size": 33010976, "index_size": 1785472, "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": 26112184, "raw_average_key_size": 28, "raw_value_size": 108105684, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 932578, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286115, "oldest_key_time": 0, "file_creation_time": 1732286115, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231605, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:20.677516 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst) /dev/shm/ToplingTemp/Topling-317240-BgF9oq 2024/11/22-22:35:22.055178 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst): first pass time = 1.38's, 97.428'MB/sec 2024/11/22-22:35:23.767845 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst): old prealloc_size = 147639500, real_size = 32902528 2024/11/22-22:35:23.768573 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925027 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0309 GB avg-val = 117.10 avg-zval = 33.42 2024/11/22-22:35:23.769562 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:25.245830 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231606.sst): second pass time = 1.71's, 63.291'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.48's, 24.953'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2498.581'MB/sec (index lex order gen) rebuild zvType time = 1.22's, 0.189'MB/sec write SST data time = 0.25's, 146.146'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 28410.662'MB/sec zip my value time = 1.71's, unzip length = 0.108'GB zip my value throughput = 63.291'MB/sec zip pipeline throughput = 63.291'MB/sec entries = 925027 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.10 avg-zval = 33.42 usrkeys = 925027 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.10 avg-zval = 33.42 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 925027 bytes = 3121984 } seq expand size = 6475189 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0309 GB dict = 1.08 MB all = 0.0369 GB } UnZip/Zip{ index = 10.5128 value = 3.5041 dict = 1.00 all = 3.6393 } Zip/UnZip{ index = 0.0951 value = 0.2854 dict = 1.00 all = 0.2748 } ---------------------------- total value len = 0.342902 GB avg = 0.123 KB (by entry num) total key len = 0.077961 GB avg = 0.028 KB total ukey len = 0.055686 GB avg = 0.020 KB total ukey num = 0.002784322 Billion total entry num = 0.002784322 Billion write speed all = 0.008522570 MB/sec (with seq num) write speed all = 0.008071504 MB/sec (without seq num) 2024/11/22-22:35:25.283102 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231606: 925027 keys, 36879890 bytes, temperature: kWarm 2024/11/22-22:35:25.283181 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286125283139, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231606, "file_size": 36879890, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3512539342, "largest_seqno": 3613583416, "table_properties": {"data_size": 30911280, "index_size": 1759808, "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": 25900756, "raw_average_key_size": 28, "raw_value_size": 108317066, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 925027, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286120, "oldest_key_time": 0, "file_creation_time": 1732286120, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231606, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:25.355350 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst) /dev/shm/ToplingTemp/Topling-317240-qMQrnn 2024/11/22-22:35:26.667810 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst): first pass time = 1.31's, 102.268'MB/sec 2024/11/22-22:35:28.533097 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst): old prealloc_size = 147639500, real_size = 34408640 2024/11/22-22:35:28.533793 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925118 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0324 GB avg-val = 117.08 avg-zval = 35.04 2024/11/22-22:35:28.534570 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:30.147448 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231607.sst): second pass time = 1.86's, 58.137'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.61's, 23.779'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2603.102'MB/sec (index lex order gen) rebuild zvType time = 1.31's, 0.176'MB/sec write SST data time = 0.30's, 127.701'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 29853.497'MB/sec zip my value time = 1.86's, unzip length = 0.108'GB zip my value throughput = 58.137'MB/sec zip pipeline throughput = 58.137'MB/sec entries = 925118 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.08 avg-zval = 35.04 usrkeys = 925118 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.08 avg-zval = 35.04 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 925118 bytes = 3122288 } seq expand size = 6475826 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0324 GB dict = 1.08 MB all = 0.0384 GB } UnZip/Zip{ index = 10.5142 value = 3.3412 dict = 1.00 all = 3.4965 } Zip/UnZip{ index = 0.0951 value = 0.2993 dict = 1.00 all = 0.2860 } ---------------------------- total value len = 0.457692 GB avg = 0.123 KB (by entry num) total key len = 0.103864 GB avg = 0.028 KB total ukey len = 0.074189 GB avg = 0.020 KB total ukey num = 0.003709440 Billion total entry num = 0.003709440 Billion write speed all = 0.011370521 MB/sec (with seq num) write speed all = 0.010769644 MB/sec (without seq num) 2024/11/22-22:35:30.220881 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231607: 925118 keys, 38386304 bytes, temperature: kWarm 2024/11/22-22:35:30.221036 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286130220938, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231607, "file_size": 38386304, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3485447251, "largest_seqno": 3613582961, "table_properties": {"data_size": 32417456, "index_size": 1759744, "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": 25903304, "raw_average_key_size": 28, "raw_value_size": 108314540, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 925118, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286125, "oldest_key_time": 0, "file_creation_time": 1732286125, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231607, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:30.294655 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst) /dev/shm/ToplingTemp/Topling-317240-iv00uq 2024/11/22-22:35:31.390729 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst): first pass time = 1.10's, 122.459'MB/sec 2024/11/22-22:35:33.293112 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst): old prealloc_size = 147639500, real_size = 33374720 2024/11/22-22:35:33.293737 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 924917 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0314 GB avg-val = 117.11 avg-zval = 33.93 2024/11/22-22:35:33.294531 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:34.412991 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231608.sst): second pass time = 1.90's, 56.959'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.12's, 33.457'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2923.796'MB/sec (index lex order gen) rebuild zvType time = 0.98's, 0.236'MB/sec write SST data time = 0.14's, 268.237'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 40460.323'MB/sec zip my value time = 1.90's, unzip length = 0.108'GB zip my value throughput = 56.959'MB/sec zip pipeline throughput = 56.959'MB/sec entries = 924917 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.11 avg-zval = 33.93 usrkeys = 924917 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.11 avg-zval = 33.93 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 924917 bytes = 3237232 } seq expand size = 6474419 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0314 GB dict = 1.08 MB all = 0.0375 GB } UnZip/Zip{ index = 10.5131 value = 3.4515 dict = 1.00 all = 3.5823 } Zip/UnZip{ index = 0.0951 value = 0.2897 dict = 1.00 all = 0.2792 } ---------------------------- total value len = 0.572487 GB avg = 0.124 KB (by entry num) total key len = 0.129762 GB avg = 0.028 KB total ukey len = 0.092687 GB avg = 0.020 KB total ukey num = 0.004634357 Billion total entry num = 0.004634357 Billion write speed all = 0.014218060 MB/sec (with seq num) write speed all = 0.013467425 MB/sec (without seq num) 2024/11/22-22:35:34.447865 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231608: 924917 keys, 37467450 bytes, temperature: kWarm 2024/11/22-22:35:34.447937 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286134447894, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231608, "file_size": 37467450, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3405268533, "largest_seqno": 3613582778, "table_properties": {"data_size": 31383728, "index_size": 1759552, "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": 25897676, "raw_average_key_size": 28, "raw_value_size": 108320130, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 924917, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286130, "oldest_key_time": 0, "file_creation_time": 1732286130, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231608, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:34.487008 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst) /dev/shm/ToplingTemp/Topling-317240-Zw8eUn 2024/11/22-22:35:35.542063 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst): first pass time = 1.06's, 127.219'MB/sec 2024/11/22-22:35:37.014734 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst): old prealloc_size = 147639500, real_size = 34123344 2024/11/22-22:35:37.015283 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 930484 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1082 GB zip-val = 0.0321 GB avg-val = 116.25 avg-zval = 34.51 2024/11/22-22:35:37.016032 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:37.931173 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231609.sst): second pass time = 1.47's, 73.488'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.92's, 41.591'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3394.832'MB/sec (index lex order gen) rebuild zvType time = 0.79's, 0.296'MB/sec write SST data time = 0.13's, 296.171'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.079'MB, throughput = 37127.819'MB/sec zip my value time = 1.47's, unzip length = 0.108'GB zip my value throughput = 73.488'MB/sec zip pipeline throughput = 73.488'MB/sec entries = 930484 avg-key = 28.00 avg-zkey = 1.91 avg-val = 116.25 avg-zval = 34.51 usrkeys = 930484 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.25 avg-zval = 34.51 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 930484 bytes = 3140400 } seq expand size = 6513388 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0321 GB dict = 1.08 MB all = 0.0381 GB } UnZip/Zip{ index = 10.4449 value = 3.3687 dict = 1.00 all = 3.5213 } Zip/UnZip{ index = 0.0957 value = 0.2969 dict = 1.00 all = 0.2840 } ---------------------------- total value len = 0.687164 GB avg = 0.123 KB (by entry num) total key len = 0.155816 GB avg = 0.028 KB total ukey len = 0.111297 GB avg = 0.020 KB total ukey num = 0.005564841 Billion total entry num = 0.005564841 Billion write speed all = 0.017066155 MB/sec (with seq num) write speed all = 0.016164872 MB/sec (without seq num) 2024/11/22-22:35:37.970236 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231609: 930484 keys, 38115470 bytes, temperature: kWarm 2024/11/22-22:35:37.970297 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286137970266, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231609, "file_size": 38115470, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3525889795, "largest_seqno": 3613583212, "table_properties": {"data_size": 32108864, "index_size": 1781696, "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": 26053552, "raw_average_key_size": 28, "raw_value_size": 108164252, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 930484, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286134, "oldest_key_time": 0, "file_creation_time": 1732286134, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231609, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:38.013212 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst) /dev/shm/ToplingTemp/Topling-317240-6Rg6Xn 2024/11/22-22:35:38.839609 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst): first pass time = 0.83's, 162.421'MB/sec 2024/11/22-22:35:40.281803 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst): old prealloc_size = 147639500, real_size = 32117392 2024/11/22-22:35:40.282323 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921286 prefix = 4 raw-key = 0.0147 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0301 GB avg-val = 117.69 avg-zval = 32.71 2024/11/22-22:35:40.283095 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:41.158650 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231610.sst): second pass time = 1.44's, 75.213'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.88's, 41.286'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3515.343'MB/sec (index lex order gen) rebuild zvType time = 0.75's, 0.308'MB/sec write SST data time = 0.13's, 282.669'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 36372.894'MB/sec zip my value time = 1.44's, unzip length = 0.108'GB zip my value throughput = 75.213'MB/sec zip pipeline throughput = 75.213'MB/sec entries = 921286 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.69 avg-zval = 32.71 usrkeys = 921286 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.69 avg-zval = 32.71 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921286 bytes = 3224512 } seq expand size = 6449002 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0301 GB dict = 1.08 MB all = 0.0362 GB } UnZip/Zip{ index = 10.5108 value = 3.5980 dict = 1.00 all = 3.7076 } Zip/UnZip{ index = 0.0951 value = 0.2779 dict = 1.00 all = 0.2697 } ---------------------------- total value len = 0.802035 GB avg = 0.124 KB (by entry num) total key len = 0.181612 GB avg = 0.028 KB total ukey len = 0.129723 GB avg = 0.020 KB total ukey num = 0.006486127 Billion total entry num = 0.006486127 Billion write speed all = 0.019912657 MB/sec (with seq num) write speed all = 0.018862231 MB/sec (without seq num) 2024/11/22-22:35:41.192162 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231610: 921286 keys, 36201150 bytes, temperature: kWarm 2024/11/22-22:35:41.192225 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286141192192, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231610, "file_size": 36201150, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3405268578, "largest_seqno": 3613581573, "table_properties": {"data_size": 30133888, "index_size": 1753024, "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": 25796008, "raw_average_key_size": 28, "raw_value_size": 108421776, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921286, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286137, "oldest_key_time": 0, "file_creation_time": 1732286137, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231610, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:41.236140 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst) /dev/shm/ToplingTemp/Topling-317240-n6sNBn 2024/11/22-22:35:42.029897 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst): first pass time = 0.79's, 169.100'MB/sec 2024/11/22-22:35:43.452465 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst): old prealloc_size = 147639500, real_size = 32484560 2024/11/22-22:35:43.453145 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 930606 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1082 GB zip-val = 0.0305 GB avg-val = 116.23 avg-zval = 32.75 2024/11/22-22:35:43.453991 140024860931648 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-22:35:44.436888 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231611.sst): second pass time = 1.42's, 76.104'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.98's, 37.172'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2682.932'MB/sec (index lex order gen) rebuild zvType time = 0.83's, 0.281'MB/sec write SST data time = 0.16's, 233.421'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.078'MB, throughput = 36221.408'MB/sec zip my value time = 1.42's, unzip length = 0.108'GB zip my value throughput = 76.104'MB/sec zip pipeline throughput = 76.104'MB/sec entries = 930606 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.23 avg-zval = 32.75 usrkeys = 930606 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.23 avg-zval = 32.75 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 930606 bytes = 3257136 } seq expand size = 6514242 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0305 GB dict = 1.08 MB all = 0.0366 GB } UnZip/Zip{ index = 10.5128 value = 3.5484 dict = 1.00 all = 3.6679 } Zip/UnZip{ index = 0.0951 value = 0.2818 dict = 1.00 all = 0.2726 } ---------------------------- total value len = 0.916710 GB avg = 0.124 KB (by entry num) total key len = 0.207669 GB avg = 0.028 KB total ukey len = 0.148335 GB avg = 0.020 KB total ukey num = 0.007416733 Billion total entry num = 0.007416733 Billion write speed all = 0.022760086 MB/sec (with seq num) write speed all = 0.021559028 MB/sec (without seq num) 2024/11/22-22:35:44.471431 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231611: 930606 keys, 36592926 bytes, temperature: kWarm 2024/11/22-22:35:44.471496 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286144471461, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231611, "file_size": 36592926, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3471845708, "largest_seqno": 3613582403, "table_properties": {"data_size": 30481280, "index_size": 1770432, "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": 26056968, "raw_average_key_size": 28, "raw_value_size": 108160848, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 930606, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "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-DictZipBlobStore", "creation_time": 1732286141, "oldest_key_time": 0, "file_creation_time": 1732286141, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231611, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:44.507513 140024860931648 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231612.sst) /dev/shm/ToplingTemp/Topling-317240-z6OsGm 2024/11/22-22:35:44.511044 140024860931648 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231612.sst): first pass time = 0.00's, 37.307'MB/sec 2024/11/22-22:35:44.532904 140024860931648 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231612.sst): old prealloc_size = 147639500, real_size = 56912 2024/11/22-22:35:44.532957 140024860931648 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231612.sst): index type = FixedLenKeyIndex , store type = DictZipBlobStore usrkeys = 917 prefix = 4 raw-key = 0.0000 GB zip-key = 0.0000 GB avg-key = 16.00 avg-zkey = 16.68 raw-val = 0.0001 GB zip-val = 0.0000 GB avg-val = 114.00 avg-zval = 44.95 2024/11/22-22:35:44.533891 140024860931648 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00/231612.sst): second pass time = 0.02's, 4.877'MB/sec, value only(80.3% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.00's, 62.503'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 376.285'MB/sec (index lex order gen) rebuild zvType time = 0.00's, 0.395'MB/sec write SST data time = 0.00's, 170.263'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.001'MB, throughput = 81.500'MB/sec zip my value time = 0.02's, unzip length = 0.000'GB zip my value throughput = 4.877'MB/sec zip pipeline throughput = 4.877'MB/sec entries = 917 avg-key = 28.00 avg-zkey = 16.68 avg-val = 114.00 avg-zval = 44.95 usrkeys = 917 avg-key = 20.00 avg-zkey = 16.68 avg-val = 121.00 avg-zval = 44.95 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 917 bytes = 2080 } seq expand size = 6419 multi value expand size = 0 cnt WriteAppend = 11 UnZipSize{ index = 0.0000 GB value = 0.0001 GB dict = 0.00 MB all = 0.0001 GB } __ZipSize{ index = 0.0000 GB value = 0.0000 GB dict = 0.00 MB all = 0.0001 GB } UnZip/Zip{ index = 1.1990 value = 2.5363 dict = 1.00 all = 2.1247 } Zip/UnZip{ index = 0.8340 value = 0.3943 dict = 1.00 all = 0.4707 } ---------------------------- total value len = 0.916821 GB avg = 0.124 KB (by entry num) total key len = 0.207694 GB avg = 0.028 KB total ukey len = 0.148353 GB avg = 0.020 KB total ukey num = 0.007417650 Billion total entry num = 0.007417650 Billion write speed all = 0.022762807 MB/sec (with seq num) write speed all = 0.021561603 MB/sec (without seq num) 2024/11/22-22:35:44.538588 140024860931648 [compaction_job.cc:1948] [default] [JOB 12899] Generated table #231612: 917 keys, 61286 bytes, temperature: kWarm 2024/11/22-22:35:44.538634 140024860931648 EVENT_LOG_v1 {"time_micros": 1732286144538608, "cf_name": "default", "job": 12899, "event": "table_file_creation", "file_number": 231612, "file_size": 61286, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3613444189, "largest_seqno": 3613582574, "table_properties": {"data_size": 41216, "index_size": 15296, "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": 25676, "raw_average_key_size": 28, "raw_value_size": 104538, "raw_average_value_size": 114, "num_data_blocks": 1, "num_entries": 917, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 114, "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-FixedLenKeyIndex-DictZipBlobStore", "creation_time": 1732286144, "oldest_key_time": 0, "file_creation_time": 1732286144, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 231612, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-22:35:44.548097 140024860931648 [compaction_job.cc:703] job-12899: subcompact[0], size: 0.301243 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12899/att-00 [231604,231605,231606,231607,231608,231609,231610,231611,231612] 2024/11/22-22:35:44.608400 140024860931648 (Original Log Time 2024/11/22-22:35:08.263986) EVENT_LOG_v1 {"time_micros": 1732286108263943, "job": 12899, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [231597], "files_L3": [231553, 231554, 231555, 231556, 231557, 231558, 231559, 231560], "score": 0.998735, "input_data_size": 320708130, "oldest_snapshot_seqno": 3613606609} 2024/11/22-22:35:44.608403 140024860931648 (Original Log Time 2024/11/22-22:35:44.607822) [compaction_job.cc:2022] [default] [JOB 12899] Compacted 1@2 + 8@3 files to L3 => 301242876 bytes 2024/11/22-22:35:44.608405 140024860931648 (Original Log Time 2024/11/22-22:35:44.608321) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.01, MB/sec: 8.8 rd, 8.3 wr, level 3, files in(1, 8) out(9 +0 blob) MB in(25.8, 280.0 +0.0 blob) out(287.3 +0.0 blob), read-write-amplify(23.0) write-amplify(11.1) OK, records in: 7471539, records dropped: 53889 output_compression: Snappy 2024/11/22-22:35:44.608411 140024860931648 (Original Log Time 2024/11/22-22:35:44.608380) EVENT_LOG_v1 {"time_micros": 1732286144608359, "cf": "default", "job": 12899, "event": "compaction_finished", "compaction_time_micros": 36284116, "compaction_time_cpu_micros": 14891323, "output_level": 3, "num_output_files": 9, "total_output_size": 301242876, "num_input_records": 7471539, "num_output_records": 7417650, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 264843889, "file_range_sync_nanos": 0, "file_fsync_nanos": 10287, "file_prepare_write_nanos": 20186, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/22-22:35:44.737392 140024860931648 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":1732256054,"starts":1732286108,"executesMs":36491,"compactionJobId":12899,"attempt":0,"compactionInputRawBytes":1081525050,"compactionInputZipBytes":320708130,"compactionOutputRawBytes":0,"compactionOutputZipBytes":301242876,"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-c429c296c5cfcbddd5841f7b5afbd9cf-7969079fb74c4377-00"}}, response = 2024/11/22-22:35:44.737462 140024860931648 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-12899/att-00: olev 3, work 36.491 s, result 4.902 ms, install 0.607 ms, input{raw 1.007 GiB zip 305.851 MiB}