2024/08/20-21:08:00.672051 139857193797184 DEBG dcompact_worker.cpp:2211: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00: fork to child time = 0.018585 sec 2024/08/20-21:08:00.672779 139857193797184 DEBG dcompact_worker.cpp:1011: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00 2024/08/20-21:08:00.677525 139857193797184 DEBG dcompact_worker.cpp:1031: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00 2024/08/20-21:08:00.679391 139857193797184 TRAC dcompact_worker.cpp:1081: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/08/20-21:08:00.679670 139857193797184 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/08/20-21:08:00.725385 139857193797184 [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-50009/att-00/MANIFEST-14629260 2024/08/20-21:08:00.780842 139857193797184 [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-50009/att-00/MANIFEST-14629260 succeeded,manifest_file_number is 14629260, next_file_number is 14686877, last_sequence is 191051936687, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 14686793 2024/08/20-21:08:00.780852 139857193797184 [version_set.cc:6197] Column family [default] (ID 0), log number is 0 2024/08/20-21:08:00.780961 139857193797184 [version_set.cc:5652] Creating manifest 14686877 2024/08/20-21:08:00.805867 139857193797184 DEBG dcompact_worker.cpp:1215: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00: bottommost_level: fake = 1, rpc = 0 2024/08/20-21:08:00.866678 139857193797184 [compaction_job.cc:2433] [default] [JOB 50009] Compacting 1@1 + 8@2 files to L2, score 1.00, subcompactions 1 : 1 2024/08/20-21:08:00.866697 139857193797184 [compaction_job.cc:2441] [default]: Compaction start summary: Base version 25379 Base level 1, inputs: [14686822(24MB)], [14686875(10MB) 14686780(20MB) 14686781(19MB) 14686782(19MB) 14686783(19MB) 14686784(20MB) 14686785(19MB) 14686786(10MB)] 2024/08/20-21:08:01.055078 139857193797184 [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-21:08:01.055109 139857193797184 [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-21:08:01.055132 139857193797184 [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-21:08:01.055152 139857193797184 [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-21:08:01.055166 139857193797184 [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-21:08:01.139293 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst) /dev/shm/ToplingTemp/Topling-20579-nJcAtg 2024/08/20-21:08:01.586858 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst): first pass time = 0.45's, 149.961'MB/sec 2024/08/20-21:08:02.254489 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst): old prealloc_size = 73819750, real_size = 19208240 2024/08/20-21:08:02.254805 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466740 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.0182 GB avg-val = 115.78 avg-zval = 39.00 2024/08/20-21:08:02.255250 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:02.624999 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686878.sst): second pass time = 0.67's, 81.048'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 57.252'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3068.729'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.384'MB/sec write SST data time = 0.07's, 320.244'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 = 13259.348'MB/sec zip my value time = 0.67's, unzip length = 0.054'GB zip my value throughput = 81.048'MB/sec zip pipeline throughput = 81.048'MB/sec entries = 466740 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.78 avg-zval = 39.00 usrkeys = 466740 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.78 avg-zval = 39.00 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466740 bytes = 1575264 } seq expand size = 3267180 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.0182 GB dict = 0.54 MB all = 0.0212 GB } UnZip/Zip{ index = 10.5038 value = 2.9688 dict = 1.00 all = 3.1636 } Zip/UnZip{ index = 0.0952 value = 0.3368 dict = 1.00 all = 0.3161 } ---------------------------- total value len = 0.057307 GB avg = 0.123 KB (by entry num) total key len = 0.013069 GB avg = 0.028 KB total ukey len = 0.009335 GB avg = 0.020 KB total ukey num = 0.000466740 Billion total entry num = 0.000466740 Billion write speed all = 0.020562533 MB/sec (with seq num) write speed all = 0.019471554 MB/sec (without seq num) 2024/08/20-21:08:02.661421 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686878: 466740 keys, 21212540 bytes, temperature: kWarm 2024/08/20-21:08:02.661501 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159282661456, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686878, "file_size": 21212540, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190978417349, "largest_seqno": 191051609079, "table_properties": {"data_size": 18202656, "index_size": 888704, "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": 13068720, "raw_average_key_size": 28, "raw_value_size": 54040200, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466740, "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": 1724159281, "oldest_key_time": 0, "file_creation_time": 1724159281, "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": 14686878, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:02.683245 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst) /dev/shm/ToplingTemp/Topling-20579-0KL45f 2024/08/20-21:08:03.221863 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst): first pass time = 0.54's, 124.607'MB/sec 2024/08/20-21:08:04.226338 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst): old prealloc_size = 73819750, real_size = 19008368 2024/08/20-21:08:04.226662 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465416 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0180 GB avg-val = 116.19 avg-zval = 38.69 2024/08/20-21:08:04.227097 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:04.626682 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686879.sst): second pass time = 1.00's, 53.879'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.40's, 52.486'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2999.993'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.378'MB/sec write SST data time = 0.09's, 228.372'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.544'MB, throughput = 14631.757'MB/sec zip my value time = 1.00's, unzip length = 0.054'GB zip my value throughput = 53.879'MB/sec zip pipeline throughput = 95.688'MB/sec entries = 465416 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.19 avg-zval = 38.69 usrkeys = 465416 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.19 avg-zval = 38.69 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465416 bytes = 1570800 } seq expand size = 3257912 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0180 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.4997 value = 3.0034 dict = 1.00 all = 3.1939 } Zip/UnZip{ index = 0.0952 value = 0.3330 dict = 1.00 all = 0.3131 } ---------------------------- total value len = 0.114643 GB avg = 0.123 KB (by entry num) total key len = 0.026100 GB avg = 0.028 KB total ukey len = 0.018643 GB avg = 0.020 KB total ukey num = 0.000932156 Billion total entry num = 0.000932156 Billion write speed all = 0.041098317 MB/sec (with seq num) write speed all = 0.038920727 MB/sec (without seq num) 2024/08/20-21:08:04.655979 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686879: 465416 keys, 21011872 bytes, temperature: kWarm 2024/08/20-21:08:04.656049 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159284656018, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686879, "file_size": 21011872, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190948638134, "largest_seqno": 191051608233, "table_properties": {"data_size": 18005280, "index_size": 886528, "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": 13031648, "raw_average_key_size": 28, "raw_value_size": 54077256, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465416, "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": 1724159282, "oldest_key_time": 0, "file_creation_time": 1724159282, "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": 14686879, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:04.679745 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst) /dev/shm/ToplingTemp/Topling-20579-U6L14g 2024/08/20-21:08:05.146187 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst): first pass time = 0.47's, 143.887'MB/sec 2024/08/20-21:08:06.008654 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst): old prealloc_size = 73819750, real_size = 18725344 2024/08/20-21:08:06.009034 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465617 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0177 GB avg-val = 116.13 avg-zval = 38.05 2024/08/20-21:08:06.009504 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:06.455288 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686880.sst): second pass time = 0.86's, 62.838'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.45's, 46.539'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2517.479'MB/sec (index lex order gen) rebuild zvType time = 0.37's, 0.317'MB/sec write SST data time = 0.08's, 263.118'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 = 14087.669'MB/sec zip my value time = 0.86's, unzip length = 0.054'GB zip my value throughput = 62.838'MB/sec zip pipeline throughput = 62.838'MB/sec entries = 465617 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.13 avg-zval = 38.05 usrkeys = 465617 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.13 avg-zval = 38.05 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465617 bytes = 1629680 } seq expand size = 3259319 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0177 GB dict = 0.54 MB all = 0.0208 GB } UnZip/Zip{ index = 10.4350 value = 3.0521 dict = 1.00 all = 3.2286 } Zip/UnZip{ index = 0.0958 value = 0.3276 dict = 1.00 all = 0.3097 } ---------------------------- total value len = 0.171973 GB avg = 0.123 KB (by entry num) total key len = 0.039138 GB avg = 0.028 KB total ukey len = 0.027955 GB avg = 0.020 KB total ukey num = 0.001397773 Billion total entry num = 0.001397773 Billion write speed all = 0.061613624 MB/sec (with seq num) write speed all = 0.058350059 MB/sec (without seq num) 2024/08/20-21:08:06.484025 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686880: 465617 keys, 20785588 bytes, temperature: kWarm 2024/08/20-21:08:06.484094 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159286484061, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686880, "file_size": 20785588, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190905335731, "largest_seqno": 191051608343, "table_properties": {"data_size": 17716368, "index_size": 892416, "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": 13037276, "raw_average_key_size": 28, "raw_value_size": 54071606, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465617, "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": 1724159284, "oldest_key_time": 0, "file_creation_time": 1724159284, "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": 14686880, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:06.506449 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst) /dev/shm/ToplingTemp/Topling-20579-WqZpQj 2024/08/20-21:08:06.904466 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst): first pass time = 0.40's, 168.627'MB/sec 2024/08/20-21:08:07.580298 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst): old prealloc_size = 73819750, real_size = 18918240 2024/08/20-21:08:07.580619 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466521 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.0179 GB avg-val = 115.85 avg-zval = 38.40 2024/08/20-21:08:07.581005 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:07.952949 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686881.sst): second pass time = 0.67's, 80.071'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 55.987'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3031.418'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.379'MB/sec write SST data time = 0.06's, 321.753'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 = 13096.883'MB/sec zip my value time = 0.67's, unzip length = 0.054'GB zip my value throughput = 80.071'MB/sec zip pipeline throughput = 80.071'MB/sec entries = 466521 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.85 avg-zval = 38.40 usrkeys = 466521 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.85 avg-zval = 38.40 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466521 bytes = 1516208 } seq expand size = 3265647 multi value expand size = 0 cnt WriteAppend = 12 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.5019 value = 3.0172 dict = 1.00 all = 3.2165 } Zip/UnZip{ index = 0.0952 value = 0.3314 dict = 1.00 all = 0.3109 } ---------------------------- total value len = 0.229285 GB avg = 0.123 KB (by entry num) total key len = 0.052200 GB avg = 0.028 KB total ukey len = 0.037286 GB avg = 0.020 KB total ukey num = 0.001864294 Billion total entry num = 0.001864294 Billion write speed all = 0.082116814 MB/sec (with seq num) write speed all = 0.077765902 MB/sec (without seq num) 2024/08/20-21:08:07.982343 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686881: 466521 keys, 20863782 bytes, temperature: kWarm 2024/08/20-21:08:07.982406 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159287982375, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686881, "file_size": 20863782, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191008529035, "largest_seqno": 191051609012, "table_properties": {"data_size": 17912976, "index_size": 888448, "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": 13062588, "raw_average_key_size": 28, "raw_value_size": 54046278, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466521, "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": 1724159286, "oldest_key_time": 0, "file_creation_time": 1724159286, "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": 14686881, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:08.007960 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst) /dev/shm/ToplingTemp/Topling-20579-HejhSj 2024/08/20-21:08:08.424623 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst): first pass time = 0.42's, 161.082'MB/sec 2024/08/20-21:08:09.081036 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst): old prealloc_size = 73819750, real_size = 18313952 2024/08/20-21:08:09.081400 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 467403 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.0540 GB zip-val = 0.0173 GB avg-val = 115.58 avg-zval = 37.04 2024/08/20-21:08:09.081824 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:09.474003 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686882.sst): second pass time = 0.66's, 82.393'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.39's, 51.861'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2615.474'MB/sec (index lex order gen) rebuild zvType time = 0.32's, 0.365'MB/sec write SST data time = 0.07's, 282.078'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 = 13742.660'MB/sec zip my value time = 0.66's, unzip length = 0.054'GB zip my value throughput = 82.393'MB/sec zip pipeline throughput = 82.393'MB/sec entries = 467403 avg-key = 28.00 avg-zkey = 1.89 avg-val = 115.58 avg-zval = 37.04 usrkeys = 467403 avg-key = 20.00 avg-zkey = 1.89 avg-val = 122.58 avg-zval = 37.04 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 467403 bytes = 1635920 } seq expand size = 3271821 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0173 GB dict = 0.54 MB all = 0.0204 GB } UnZip/Zip{ index = 10.5705 value = 3.1204 dict = 1.00 all = 3.2928 } Zip/UnZip{ index = 0.0946 value = 0.3205 dict = 1.00 all = 0.3037 } ---------------------------- total value len = 0.286579 GB avg = 0.123 KB (by entry num) total key len = 0.065288 GB avg = 0.028 KB total ukey len = 0.046634 GB avg = 0.020 KB total ukey num = 0.002331697 Billion total entry num = 0.002331697 Billion write speed all = 0.102603224 MB/sec (with seq num) write speed all = 0.097163895 MB/sec (without seq num) 2024/08/20-21:08:09.501411 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686882: 467403 keys, 20380454 bytes, temperature: kWarm 2024/08/20-21:08:09.501479 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159289501445, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686882, "file_size": 20380454, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190904945736, "largest_seqno": 191051607283, "table_properties": {"data_size": 17312592, "index_size": 884352, "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": 13087284, "raw_average_key_size": 28, "raw_value_size": 54021678, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 467403, "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": 1724159287, "oldest_key_time": 0, "file_creation_time": 1724159287, "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": 14686882, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:09.524250 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst) /dev/shm/ToplingTemp/Topling-20579-g4Odyj 2024/08/20-21:08:09.921208 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst): first pass time = 0.40's, 169.086'MB/sec 2024/08/20-21:08:10.614327 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst): old prealloc_size = 73819750, real_size = 20109232 2024/08/20-21:08:10.614642 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465094 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0191 GB avg-val = 116.29 avg-zval = 41.07 2024/08/20-21:08:10.615056 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:10.982884 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686883.sst): second pass time = 0.69's, 78.129'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 59.999'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3080.830'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.386'MB/sec write SST data time = 0.07's, 328.884'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.544'MB, throughput = 13791.937'MB/sec zip my value time = 0.69's, unzip length = 0.054'GB zip my value throughput = 78.129'MB/sec zip pipeline throughput = 78.129'MB/sec entries = 465094 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.29 avg-zval = 41.07 usrkeys = 465094 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.29 avg-zval = 41.07 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465094 bytes = 1569712 } seq expand size = 3255658 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.0191 GB dict = 0.54 MB all = 0.0221 GB } UnZip/Zip{ index = 10.4352 value = 2.8315 dict = 1.00 all = 3.0349 } Zip/UnZip{ index = 0.0958 value = 0.3532 dict = 1.00 all = 0.3295 } ---------------------------- total value len = 0.343921 GB avg = 0.123 KB (by entry num) total key len = 0.078310 GB avg = 0.028 KB total ukey len = 0.055936 GB avg = 0.020 KB total ukey num = 0.002796791 Billion total entry num = 0.002796791 Billion write speed all = 0.123067200 MB/sec (with seq num) write speed all = 0.116545781 MB/sec (without seq num) 2024/08/20-21:08:11.012314 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686883: 465094 keys, 22112482 bytes, temperature: kWarm 2024/08/20-21:08:11.012390 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159291012351, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686883, "file_size": 22112482, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190938608776, "largest_seqno": 191051609033, "table_properties": {"data_size": 19101408, "index_size": 891392, "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": 13022632, "raw_average_key_size": 28, "raw_value_size": 54086348, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465094, "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": 1724159289, "oldest_key_time": 0, "file_creation_time": 1724159289, "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": 14686883, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:11.034124 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst) /dev/shm/ToplingTemp/Topling-20579-fIqcOi 2024/08/20-21:08:11.368974 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst): first pass time = 0.33's, 200.445'MB/sec 2024/08/20-21:08:12.030778 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst): old prealloc_size = 73819750, real_size = 18713744 2024/08/20-21:08:12.031124 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466307 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.0177 GB avg-val = 115.92 avg-zval = 37.98 2024/08/20-21:08:12.031557 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-21:08:12.400553 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686884.sst): second pass time = 0.66's, 81.780'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 56.028'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2785.201'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.384'MB/sec write SST data time = 0.07's, 315.264'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 = 13508.313'MB/sec zip my value time = 0.66's, unzip length = 0.054'GB zip my value throughput = 81.780'MB/sec zip pipeline throughput = 81.780'MB/sec entries = 466307 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.92 avg-zval = 37.98 usrkeys = 466307 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.92 avg-zval = 37.98 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466307 bytes = 1573808 } seq expand size = 3264149 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.0177 GB dict = 0.54 MB all = 0.0207 GB } UnZip/Zip{ index = 10.5047 value = 3.0522 dict = 1.00 all = 3.2393 } Zip/UnZip{ index = 0.0952 value = 0.3276 dict = 1.00 all = 0.3087 } ---------------------------- total value len = 0.401237 GB avg = 0.123 KB (by entry num) total key len = 0.091367 GB avg = 0.028 KB total ukey len = 0.065262 GB avg = 0.020 KB total ukey num = 0.003263098 Billion total entry num = 0.003263098 Billion write speed all = 0.143519450 MB/sec (with seq num) write speed all = 0.135913861 MB/sec (without seq num) 2024/08/20-21:08:12.428705 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686884: 466307 keys, 20717190 bytes, temperature: kWarm 2024/08/20-21:08:12.428777 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159292428742, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686884, "file_size": 20717190, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190978176192, "largest_seqno": 191051608046, "table_properties": {"data_size": 17709184, "index_size": 887808, "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": 13056596, "raw_average_key_size": 28, "raw_value_size": 54052306, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466307, "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": 1724159291, "oldest_key_time": 0, "file_creation_time": 1724159291, "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": 14686884, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:12.449687 139857193797184 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst) /dev/shm/ToplingTemp/Topling-20579-rFJYHj 2024/08/20-21:08:12.549819 139857193797184 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst): first pass time = 0.10's, 270.901'MB/sec 2024/08/20-21:08:12.803039 139857193797184 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst): old prealloc_size = 73819750, real_size = 7930592 2024/08/20-21:08:12.803206 139857193797184 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 188641 prefix = 4 raw-key = 0.0030 GB zip-key = 0.0004 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.0218 GB zip-val = 0.0075 GB avg-val = 115.73 avg-zval = 39.88 2024/08/20-21:08:12.803417 139857193797184 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.027 GB 2024/08/20-21:08:12.953442 139857193797184 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00/14686885.sst): second pass time = 0.25's, 86.646'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.15's, 57.866'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2586.346'MB/sec (index lex order gen) rebuild zvType time = 0.12's, 0.384'MB/sec write SST data time = 0.03's, 315.975'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.228'MB, throughput = 5758.977'MB/sec zip my value time = 0.25's, unzip length = 0.022'GB zip my value throughput = 86.646'MB/sec zip pipeline throughput = 86.646'MB/sec entries = 188641 avg-key = 28.00 avg-zkey = 1.91 avg-val = 115.73 avg-zval = 39.88 usrkeys = 188641 avg-key = 20.00 avg-zkey = 1.91 avg-val = 122.73 avg-zval = 39.88 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 188641 bytes = 589520 } seq expand size = 1320487 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0038 GB value = 0.0218 GB dict = 0.23 MB all = 0.0271 GB } __ZipSize{ index = 0.0004 GB value = 0.0075 GB dict = 0.23 MB all = 0.0087 GB } UnZip/Zip{ index = 10.4763 value = 2.9018 dict = 1.00 all = 3.1152 } Zip/UnZip{ index = 0.0955 value = 0.3446 dict = 1.00 all = 0.3210 } ---------------------------- total value len = 0.424389 GB avg = 0.123 KB (by entry num) total key len = 0.096649 GB avg = 0.028 KB total ukey len = 0.069035 GB avg = 0.020 KB total ukey num = 0.003451739 Billion total entry num = 0.003451739 Billion write speed all = 0.151778971 MB/sec (with seq num) write speed all = 0.143734996 MB/sec (without seq num) 2024/08/20-21:08:12.968986 139857193797184 [compaction_job.cc:1944] [default] [JOB 50009] Generated table #14686885: 188641 keys, 8703402 bytes, temperature: kWarm 2024/08/20-21:08:12.969060 139857193797184 EVENT_LOG_v1 {"time_micros": 1724159292969024, "cf_name": "default", "job": 50009, "event": "table_file_creation", "file_number": 14686885, "file_size": 8703402, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191024640758, "largest_seqno": 191051608079, "table_properties": {"data_size": 7523088, "index_size": 360128, "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": 5281948, "raw_average_key_size": 28, "raw_value_size": 21830770, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 188641, "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": 1724159292, "oldest_key_time": 0, "file_creation_time": 1724159292, "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": 14686885, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-21:08:12.977404 139857193797184 [compaction_job.cc:699] job-50009: subcompact[0], size: 0.155787 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-50009/att-00 [14686878,14686879,14686880,14686881,14686882,14686883,14686884,14686885] 2024/08/20-21:08:13.030045 139857193797184 (Original Log Time 2024/08/20-21:08:00.866750) EVENT_LOG_v1 {"time_micros": 1724159280866711, "job": 50009, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L1": [14686822], "files_L2": [14686875, 14686780, 14686781, 14686782, 14686783, 14686784, 14686785, 14686786], "score": 0.997123, "input_data_size": 174096367, "oldest_snapshot_seqno": 191051936322} 2024/08/20-21:08:13.030050 139857193797184 (Original Log Time 2024/08/20-21:08:13.020024) [compaction_job.cc:2018] [default] [JOB 50009] Compacted 1@1 + 8@2 files to L2 => 155787310 bytes 2024/08/20-21:08:13.030051 139857193797184 (Original Log Time 2024/08/20-21:08:13.029958) [compaction_job.cc:1220] [default] compacted to: files[0 0 8 0 0 0 0] max score 0.06, MB/sec: 14.4 rd, 12.9 wr, level 2, files in(1, 8) out(8 +0 blob) MB in(24.8, 141.2 +0.0 blob) out(148.6 +0.0 blob), read-write-amplify(12.7) write-amplify(6.0) OK, records in: 3451739, records dropped: 0 output_compression: Snappy 2024/08/20-21:08:13.030059 139857193797184 (Original Log Time 2024/08/20-21:08:13.030020) EVENT_LOG_v1 {"time_micros": 1724159293029987, "cf": "default", "job": 50009, "event": "compaction_finished", "compaction_time_micros": 12110660, "compaction_time_cpu_micros": 4890044, "output_level": 2, "num_output_files": 8, "total_output_size": 155787310, "num_input_records": 3451739, "num_output_records": 3451739, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 105703021, "file_range_sync_nanos": 0, "file_fsync_nanos": 6215, "file_prepare_write_nanos": 21681, "lsm_state": [0, 0, 8, 0, 0, 0, 0]} 2024/08/20-21:08:13.148532 139857193797184 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":1724159280,"executesMs":12340,"compactionJobId":50009,"attempt":0,"compactionInputRawBytes":496875134,"compactionInputZipBytes":174096367,"compactionOutputRawBytes":0,"compactionOutputZipBytes":155787310,"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-578b0e30bb00efd6daed126338697c17-17b200b7739212a4-00"}}, response = 2024/08/20-21:08:13.148651 139857193797184 INFO dcompact_worker.cpp:1456: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-50009/att-00: olev 2, work 12.341 s, result 6.804 ms, install 10.066 ms, input{raw 473.857 MiB zip 166.031 MiB}