2024/08/20-15:59:15.363478 140500372350528 DEBG dcompact_worker.cpp:2211: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00: fork to child time = 0.027193 sec 2024/08/20-15:59:15.364772 140500372350528 DEBG dcompact_worker.cpp:1011: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00 2024/08/20-15:59:15.370908 140500372350528 DEBG dcompact_worker.cpp:1031: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00 2024/08/20-15:59:15.372901 140500372350528 TRAC dcompact_worker.cpp:1081: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/08/20-15:59:15.373319 140500372350528 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/08/20-15:59:15.411677 140500372350528 [version_set.cc:6139] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-38451/att-00/MANIFEST-14629260 2024/08/20-15:59:15.464209 140500372350528 [version_set.cc:6182] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-38451/att-00/MANIFEST-14629260 succeeded,manifest_file_number is 14629260, next_file_number is 14673515, last_sequence is 190753219707, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 14673354 2024/08/20-15:59:15.464219 140500372350528 [version_set.cc:6197] Column family [default] (ID 0), log number is 0 2024/08/20-15:59:15.464312 140500372350528 [version_set.cc:5652] Creating manifest 14673515 2024/08/20-15:59:15.487791 140500372350528 DEBG dcompact_worker.cpp:1215: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00: bottommost_level: fake = 1, rpc = 0 2024/08/20-15:59:15.509019 140500372350528 [compaction_job.cc:2433] [default] [JOB 38451] Compacting 1@1 + 7@2 files to L2, score 1.00, subcompactions 1 : 1 2024/08/20-15:59:15.509045 140500372350528 [compaction_job.cc:2441] [default]: Compaction start summary: Base version 19645 Base level 1, inputs: [14673479(31MB)], [14673443(19MB) 14673444(19MB) 14673445(19MB) 14673446(19MB) 14673447(20MB) 14673448(20MB) 14673505(20MB)] 2024/08/20-15:59:15.741420 140500372350528 [top_zip_table.cc:59] core git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_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. 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/08/20-15:59:15.741456 140500372350528 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_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. 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/08/20-15:59:15.741479 140500372350528 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_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. 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/08/20-15:59:15.741494 140500372350528 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit 7f80399bfbd2071b6e0f5683e8ab7225b8e6e394 Author: leipeng Date: 2024-01-19 14:52:30 +0800 Change ToplingZipTableOptions::sampleRatio to vector 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/08/20-15:59:15.741509 140500372350528 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit 1240987ca13d0fe562c9b9c037155079f0877840 Author: leipeng Date: 2024-01-19 15:07:04 +0800 Change ToplingZipTableOptions::sampleRatio to vector 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/08/20-15:59:15.892263 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst) /dev/shm/ToplingTemp/Topling-416142-dR3uMU 2024/08/20-15:59:16.313199 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst): first pass time = 0.42's, 159.448'MB/sec 2024/08/20-15:59:17.096718 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst): old prealloc_size = 73819750, real_size = 18644992 2024/08/20-15:59:17.097120 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466820 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0540 GB zip-val = 0.0176 GB avg-val = 115.76 avg-zval = 37.79 2024/08/20-15:59:17.097581 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:17.497769 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673516.sst): second pass time = 0.78's, 69.059'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.40's, 51.486'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2359.038'MB/sec (index lex order gen) rebuild zvType time = 0.32's, 0.364'MB/sec write SST data time = 0.08's, 257.411'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 15928.693'MB/sec zip my value time = 0.78's, unzip length = 0.054'GB zip my value throughput = 69.059'MB/sec zip pipeline throughput = 69.083'MB/sec entries = 466820 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.76 avg-zval = 37.79 usrkeys = 466820 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.76 avg-zval = 37.79 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466820 bytes = 1575536 } seq expand size = 3267740 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0176 GB dict = 0.54 MB all = 0.0206 GB } UnZip/Zip{ index = 10.5003 value = 3.0636 dict = 1.00 all = 3.2499 } Zip/UnZip{ index = 0.0952 value = 0.3264 dict = 1.00 all = 0.3077 } ---------------------------- total value len = 62.354055 GB avg = 0.180 KB (by entry num) total key len = 6.801829 GB avg = 0.020 KB total ukey len = 3.198844 GB avg = 0.008 KB total ukey num = 0.389800381 Billion total entry num = 0.346678389 Billion write speed all = 0.856777232 MB/sec (with seq num) write speed all = 0.822417043 MB/sec (without seq num) 2024/08/20-15:59:17.526267 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673516: 466820 keys, 20649716 bytes, temperature: kWarm 2024/08/20-15:59:17.526342 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140757526299, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673516, "file_size": 20649716, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190683488808, "largest_seqno": 190753012254, "table_properties": {"data_size": 17638960, "index_size": 889152, "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": 13070960, "raw_average_key_size": 28, "raw_value_size": 54037920, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466820, "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": 1724140755, "oldest_key_time": 0, "file_creation_time": 1724140755, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673516, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:17.559869 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst) /dev/shm/ToplingTemp/Topling-416142-BCmaYS 2024/08/20-15:59:18.001051 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst): first pass time = 0.44's, 152.125'MB/sec 2024/08/20-15:59:18.785524 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst): old prealloc_size = 73819750, real_size = 18374688 2024/08/20-15:59:18.785911 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465990 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0174 GB avg-val = 116.01 avg-zval = 37.26 2024/08/20-15:59:18.786776 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:19.348101 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673517.sst): second pass time = 0.78's, 68.988'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.56's, 36.222'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2460.000'MB/sec (index lex order gen) rebuild zvType time = 0.48's, 0.242'MB/sec write SST data time = 0.08's, 250.437'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 16344.413'MB/sec zip my value time = 0.78's, unzip length = 0.054'GB zip my value throughput = 68.988'MB/sec zip pipeline throughput = 68.988'MB/sec entries = 465990 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.01 avg-zval = 37.26 usrkeys = 465990 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.01 avg-zval = 37.26 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465990 bytes = 1572736 } seq expand size = 3261930 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0174 GB dict = 0.54 MB all = 0.0204 GB } UnZip/Zip{ index = 10.4344 value = 3.1133 dict = 1.00 all = 3.2932 } Zip/UnZip{ index = 0.0958 value = 0.3212 dict = 1.00 all = 0.3037 } ---------------------------- total value len = 62.411379 GB avg = 0.180 KB (by entry num) total key len = 6.814876 GB avg = 0.020 KB total ukey len = 3.208164 GB avg = 0.008 KB total ukey num = 0.390266371 Billion total entry num = 0.347144379 Billion write speed all = 0.857629401 MB/sec (with seq num) write speed all = 0.823223815 MB/sec (without seq num) 2024/08/20-15:59:19.399442 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673517: 465990 keys, 20377818 bytes, temperature: kWarm 2024/08/20-15:59:19.399514 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140759399480, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673517, "file_size": 20377818, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190683488841, "largest_seqno": 190753011836, "table_properties": {"data_size": 17364816, "index_size": 893184, "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": 13047720, "raw_average_key_size": 28, "raw_value_size": 54061144, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465990, "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": 1724140757, "oldest_key_time": 0, "file_creation_time": 1724140757, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673517, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:19.428794 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst) /dev/shm/ToplingTemp/Topling-416142-d2EzFU 2024/08/20-15:59:19.830565 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst): first pass time = 0.40's, 167.050'MB/sec 2024/08/20-15:59:20.726494 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst): old prealloc_size = 73819750, real_size = 18844288 2024/08/20-15:59:20.726877 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466215 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0178 GB avg-val = 115.94 avg-zval = 38.27 2024/08/20-15:59:20.727327 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:21.125430 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673518.sst): second pass time = 0.90's, 60.396'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.40's, 52.262'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2573.211'MB/sec (index lex order gen) rebuild zvType time = 0.32's, 0.365'MB/sec write SST data time = 0.08's, 261.790'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 13525.791'MB/sec zip my value time = 0.90's, unzip length = 0.054'GB zip my value throughput = 60.396'MB/sec zip pipeline throughput = 85.803'MB/sec entries = 466215 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.94 avg-zval = 38.27 usrkeys = 466215 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.94 avg-zval = 38.27 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466215 bytes = 1573488 } seq expand size = 3263505 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0178 GB dict = 0.54 MB all = 0.0208 GB } UnZip/Zip{ index = 10.5056 value = 3.0300 dict = 1.00 all = 3.2187 } Zip/UnZip{ index = 0.0952 value = 0.3300 dict = 1.00 all = 0.3107 } ---------------------------- total value len = 62.468697 GB avg = 0.180 KB (by entry num) total key len = 6.827930 GB avg = 0.020 KB total ukey len = 3.217488 GB avg = 0.008 KB total ukey num = 0.390732586 Billion total entry num = 0.347610594 Billion write speed all = 0.858482326 MB/sec (with seq num) write speed all = 0.824031293 MB/sec (without seq num) 2024/08/20-15:59:21.152638 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673518: 466215 keys, 20849366 bytes, temperature: kWarm 2024/08/20-15:59:21.152703 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140761152670, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673518, "file_size": 20849366, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190683492754, "largest_seqno": 190753010834, "table_properties": {"data_size": 17839984, "index_size": 887552, "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": 13054020, "raw_average_key_size": 28, "raw_value_size": 54054874, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466215, "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": 1724140759, "oldest_key_time": 0, "file_creation_time": 1724140759, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673518, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:21.181666 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst) /dev/shm/ToplingTemp/Topling-416142-JsmqTT 2024/08/20-15:59:21.564753 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst): first pass time = 0.38's, 175.198'MB/sec 2024/08/20-15:59:22.262583 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst): old prealloc_size = 73819750, real_size = 18844048 2024/08/20-15:59:22.262911 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 467250 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0540 GB zip-val = 0.0178 GB avg-val = 115.63 avg-zval = 38.16 2024/08/20-15:59:22.263347 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:22.632347 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673519.sst): second pass time = 0.70's, 77.517'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 56.387'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2829.107'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.387'MB/sec write SST data time = 0.07's, 309.705'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 12901.171'MB/sec zip my value time = 0.70's, unzip length = 0.054'GB zip my value throughput = 77.517'MB/sec zip pipeline throughput = 77.517'MB/sec entries = 467250 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.63 avg-zval = 38.16 usrkeys = 467250 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.63 avg-zval = 38.16 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 467250 bytes = 1576976 } seq expand size = 3270750 multi value expand size = 0 cnt WriteAppend = 16 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0178 GB dict = 0.54 MB all = 0.0209 GB } UnZip/Zip{ index = 10.4342 value = 3.0298 dict = 1.00 all = 3.2186 } Zip/UnZip{ index = 0.0958 value = 0.3301 dict = 1.00 all = 0.3107 } ---------------------------- total value len = 62.525994 GB avg = 0.180 KB (by entry num) total key len = 6.841013 GB avg = 0.020 KB total ukey len = 3.226833 GB avg = 0.008 KB total ukey num = 0.391199836 Billion total entry num = 0.348077844 Billion write speed all = 0.859338184 MB/sec (with seq num) write speed all = 0.824841486 MB/sec (without seq num) 2024/08/20-15:59:22.660042 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673519: 467250 keys, 20850054 bytes, temperature: kWarm 2024/08/20-15:59:22.660109 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140762660076, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673519, "file_size": 20850054, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190682563575, "largest_seqno": 190753011882, "table_properties": {"data_size": 17831424, "index_size": 895616, "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": 13083000, "raw_average_key_size": 28, "raw_value_size": 54025964, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 467250, "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": 1724140761, "oldest_key_time": 0, "file_creation_time": 1724140761, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673519, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:22.684937 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst) /dev/shm/ToplingTemp/Topling-416142-y9ZE6V 2024/08/20-15:59:23.067685 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst): first pass time = 0.38's, 175.355'MB/sec 2024/08/20-15:59:23.769323 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst): old prealloc_size = 73819750, real_size = 19680432 2024/08/20-15:59:23.769661 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466244 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0187 GB avg-val = 115.94 avg-zval = 40.06 2024/08/20-15:59:23.770109 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:24.131402 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673520.sst): second pass time = 0.70's, 77.152'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.36's, 60.054'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2856.450'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.395'MB/sec write SST data time = 0.07's, 327.229'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 11122.416'MB/sec zip my value time = 0.70's, unzip length = 0.054'GB zip my value throughput = 77.152'MB/sec zip pipeline throughput = 77.152'MB/sec entries = 466244 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.94 avg-zval = 40.06 usrkeys = 466244 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.94 avg-zval = 40.06 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466244 bytes = 1631872 } seq expand size = 3263708 multi value expand size = 0 cnt WriteAppend = 16 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0187 GB dict = 0.54 MB all = 0.0217 GB } UnZip/Zip{ index = 10.5017 value = 2.8943 dict = 1.00 all = 3.0863 } Zip/UnZip{ index = 0.0952 value = 0.3455 dict = 1.00 all = 0.3240 } ---------------------------- total value len = 62.583311 GB avg = 0.180 KB (by entry num) total key len = 6.854068 GB avg = 0.020 KB total ukey len = 3.236158 GB avg = 0.008 KB total ukey num = 0.391666080 Billion total entry num = 0.348544088 Billion write speed all = 0.860194006 MB/sec (with seq num) write speed all = 0.825651742 MB/sec (without seq num) 2024/08/20-15:59:24.164237 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673520: 466244 keys, 21743978 bytes, temperature: kWarm 2024/08/20-15:59:24.164306 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140764164271, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673520, "file_size": 21743978, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190586022308, "largest_seqno": 190753012465, "table_properties": {"data_size": 18675744, "index_size": 887936, "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": 13054832, "raw_average_key_size": 28, "raw_value_size": 54054080, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466244, "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": 1724140762, "oldest_key_time": 0, "file_creation_time": 1724140762, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673520, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:24.188712 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst) /dev/shm/ToplingTemp/Topling-416142-FsAoAV 2024/08/20-15:59:24.574312 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst): first pass time = 0.39's, 174.057'MB/sec 2024/08/20-15:59:25.265744 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst): old prealloc_size = 73819750, real_size = 18949296 2024/08/20-15:59:25.266085 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 467039 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.93 raw-val = 0.0540 GB zip-val = 0.0179 GB avg-val = 115.69 avg-zval = 38.39 2024/08/20-15:59:25.266473 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:25.633511 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673521.sst): second pass time = 0.69's, 78.235'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 56.821'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2876.714'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.389'MB/sec write SST data time = 0.07's, 309.263'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 12611.448'MB/sec zip my value time = 0.69's, unzip length = 0.054'GB zip my value throughput = 78.235'MB/sec zip pipeline throughput = 78.235'MB/sec entries = 467039 avg-key = 28.00 avg-zkey = 1.93 avg-val = 115.69 avg-zval = 38.39 usrkeys = 467039 avg-key = 20.00 avg-zkey = 1.93 avg-val = 122.69 avg-zval = 38.39 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 467039 bytes = 1517888 } seq expand size = 3269273 multi value expand size = 0 cnt WriteAppend = 16 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0179 GB dict = 0.54 MB all = 0.0209 GB } UnZip/Zip{ index = 10.3665 value = 3.0133 dict = 1.00 all = 3.2115 } Zip/UnZip{ index = 0.0965 value = 0.3319 dict = 1.00 all = 0.3114 } ---------------------------- total value len = 62.640612 GB avg = 0.179 KB (by entry num) total key len = 6.867145 GB avg = 0.020 KB total ukey len = 3.245499 GB avg = 0.008 KB total ukey num = 0.392133119 Billion total entry num = 0.349011127 Billion write speed all = 0.861049831 MB/sec (with seq num) write speed all = 0.826461926 MB/sec (without seq num) 2024/08/20-15:59:25.664694 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673521: 467039 keys, 20896204 bytes, temperature: kWarm 2024/08/20-15:59:25.664763 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140765664729, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673521, "file_size": 20896204, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190699518179, "largest_seqno": 190753011227, "table_properties": {"data_size": 17931296, "index_size": 901056, "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": 13077092, "raw_average_key_size": 28, "raw_value_size": 54031786, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 467039, "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": 1724140764, "oldest_key_time": 0, "file_creation_time": 1724140764, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673521, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:25.686208 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst) /dev/shm/ToplingTemp/Topling-416142-KlL5PV 2024/08/20-15:59:26.074588 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst): first pass time = 0.39's, 172.811'MB/sec 2024/08/20-15:59:26.770204 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst): old prealloc_size = 73819750, real_size = 19658896 2024/08/20-15:59:26.770547 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466220 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0186 GB avg-val = 115.94 avg-zval = 40.00 2024/08/20-15:59:26.770957 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-15:59:27.129779 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673522.sst): second pass time = 0.69's, 77.805'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.36's, 60.090'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2852.047'MB/sec (index lex order gen) rebuild zvType time = 0.29's, 0.398'MB/sec write SST data time = 0.07's, 325.162'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 13709.879'MB/sec zip my value time = 0.69's, unzip length = 0.054'GB zip my value throughput = 77.805'MB/sec zip pipeline throughput = 77.805'MB/sec entries = 466220 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.94 avg-zval = 40.00 usrkeys = 466220 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.94 avg-zval = 40.00 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466220 bytes = 1515232 } seq expand size = 3263540 multi value expand size = 0 cnt WriteAppend = 27 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0186 GB dict = 0.54 MB all = 0.0216 GB } UnZip/Zip{ index = 10.4343 value = 2.8986 dict = 1.00 all = 3.1060 } Zip/UnZip{ index = 0.0958 value = 0.3450 dict = 1.00 all = 0.3220 } ---------------------------- total value len = 62.697931 GB avg = 0.179 KB (by entry num) total key len = 6.880199 GB avg = 0.020 KB total ukey len = 3.254823 GB avg = 0.008 KB total ukey num = 0.392599339 Billion total entry num = 0.349477347 Billion write speed all = 0.861905618 MB/sec (with seq num) write speed all = 0.827272150 MB/sec (without seq num) 2024/08/20-15:59:27.158805 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673522: 466220 keys, 21606086 bytes, temperature: kWarm 2024/08/20-15:59:27.158874 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140767158837, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673522, "file_size": 21606086, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190694182453, "largest_seqno": 190753012531, "table_properties": {"data_size": 18648512, "index_size": 893632, "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": 13054160, "raw_average_key_size": 28, "raw_value_size": 54054804, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466220, "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": 1724140765, "oldest_key_time": 0, "file_creation_time": 1724140765, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673522, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:27.181724 140500372350528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst) /dev/shm/ToplingTemp/Topling-416142-DNNvVV 2024/08/20-15:59:27.304315 140500372350528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst): first pass time = 0.12's, 273.324'MB/sec 2024/08/20-15:59:27.615954 140500372350528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst): old prealloc_size = 73819750, real_size = 9754128 2024/08/20-15:59:27.616166 140500372350528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 233398 prefix = 4 raw-key = 0.0037 GB zip-key = 0.0005 GB avg-key = 16.00 avg-zkey = 1.93 raw-val = 0.0270 GB zip-val = 0.0092 GB avg-val = 115.51 avg-zval = 39.61 2024/08/20-15:59:27.616392 140500372350528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.020 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.033 GB 2024/08/20-15:59:27.800319 140500372350528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00/14673523.sst): second pass time = 0.31's, 86.725'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.18's, 58.219'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2495.397'MB/sec (index lex order gen) rebuild zvType time = 0.15's, 0.389'MB/sec write SST data time = 0.03's, 312.214'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.277'MB, throughput = 5877.986'MB/sec zip my value time = 0.31's, unzip length = 0.027'GB zip my value throughput = 86.725'MB/sec zip pipeline throughput = 86.725'MB/sec entries = 233398 avg-key = 28.00 avg-zkey = 1.93 avg-val = 115.51 avg-zval = 39.61 usrkeys = 233398 avg-key = 20.00 avg-zkey = 1.93 avg-val = 122.51 avg-zval = 39.61 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 233398 bytes = 758560 } seq expand size = 1633786 multi value expand size = 0 cnt WriteAppend = 21 UnZipSize{ index = 0.0047 GB value = 0.0270 GB dict = 0.28 MB all = 0.0335 GB } __ZipSize{ index = 0.0005 GB value = 0.0092 GB dict = 0.28 MB all = 0.0107 GB } UnZip/Zip{ index = 10.3501 value = 2.9162 dict = 1.00 all = 3.1205 } Zip/UnZip{ index = 0.0966 value = 0.3429 dict = 1.00 all = 0.3205 } ---------------------------- total value len = 62.726524 GB avg = 0.179 KB (by entry num) total key len = 6.886735 GB avg = 0.020 KB total ukey len = 3.259491 GB avg = 0.008 KB total ukey num = 0.392832737 Billion total entry num = 0.349710745 Billion write speed all = 0.862333612 MB/sec (with seq num) write speed all = 0.827677302 MB/sec (without seq num) 2024/08/20-15:59:27.817397 140500372350528 [compaction_job.cc:1944] [default] [JOB 38451] Generated table #14673523: 233398 keys, 10733884 bytes, temperature: kWarm 2024/08/20-15:59:27.817461 140500372350528 EVENT_LOG_v1 {"time_micros": 1724140767817429, "cf_name": "default", "job": 38451, "event": "table_file_creation", "file_number": 14673523, "file_size": 10733884, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190706755556, "largest_seqno": 190753009386, "table_properties": {"data_size": 9244608, "index_size": 451008, "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": 6535144, "raw_average_key_size": 28, "raw_value_size": 26959520, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 233398, "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": 1724140767, "oldest_key_time": 0, "file_creation_time": 1724140767, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14673523, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-15:59:27.826672 140500372350528 [compaction_job.cc:699] job-38451: subcompact[0], size: 0.157707 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-38451/att-00 [14673516,14673517,14673518,14673519,14673520,14673521,14673522,14673523] 2024/08/20-15:59:27.885233 140500372350528 (Original Log Time 2024/08/20-15:59:15.509140) EVENT_LOG_v1 {"time_micros": 1724140755509069, "job": 38451, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L1": [14673479], "files_L2": [14673443, 14673444, 14673445, 14673446, 14673447, 14673448, 14673505], "score": 0.996462, "input_data_size": 180626433, "oldest_snapshot_seqno": 190753218996} 2024/08/20-15:59:27.885237 140500372350528 (Original Log Time 2024/08/20-15:59:27.870716) [compaction_job.cc:2018] [default] [JOB 38451] Compacted 1@1 + 7@2 files to L2 => 157707106 bytes 2024/08/20-15:59:27.885239 140500372350528 (Original Log Time 2024/08/20-15:59:27.885154) [compaction_job.cc:1220] [default] compacted to: files[0 0 8 0 0 0 0] max score 0.06, MB/sec: 14.7 rd, 12.8 wr, level 2, files in(1, 7) out(8 +0 blob) MB in(31.8, 140.5 +0.0 blob) out(150.4 +0.0 blob), read-write-amplify(10.2) write-amplify(4.7) OK, records in: 3499176, records dropped: 0 output_compression: Snappy 2024/08/20-15:59:27.885247 140500372350528 (Original Log Time 2024/08/20-15:59:27.885206) EVENT_LOG_v1 {"time_micros": 1724140767885181, "cf": "default", "job": 38451, "event": "compaction_finished", "compaction_time_micros": 12317540, "compaction_time_cpu_micros": 5031479, "output_level": 2, "num_output_files": 8, "total_output_size": 157707106, "num_input_records": 3499176, "num_output_records": 3499176, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 115006337, "file_range_sync_nanos": 0, "file_fsync_nanos": 5687, "file_prepare_write_nanos": 25006, "lsm_state": [0, 0, 8, 0, 0, 0, 0]} 2024/08/20-15:59:28.006718 140500372350528 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":"a007a635-5c0a-4b4a-be96-b9c695cb016b","dbStarts":1724092920,"starts":1724140755,"executesMs":12502,"compactionJobId":38451,"attempt":0,"compactionInputRawBytes":503257020,"compactionInputZipBytes":180626433,"compactionOutputRawBytes":0,"compactionOutputZipBytes":157707106,"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-60e9fe06818569f23223c40836e36756-598a1c87ed570aa7-00"}}, response = 2024/08/20-15:59:28.006827 140500372350528 INFO dcompact_worker.cpp:1456: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-38451/att-00: olev 2, work 12.502 s, result 4.727 ms, install 14.556 ms, input{raw 479.943 MiB zip 172.259 MiB}