2024/07/09-08:10:21.338549 140099009918528 DEBG dcompact_worker.cpp:2211: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00: fork to child time = 0.008542 sec 2024/07/09-08:10:21.339304 140099009918528 DEBG dcompact_worker.cpp:1011: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00 2024/07/09-08:10:21.344040 140099009918528 DEBG dcompact_worker.cpp:1031: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00 2024/07/09-08:10:21.345447 140099009918528 TRAC dcompact_worker.cpp:1081: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/07/09-08:10:21.345768 140099009918528 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/07/09-08:10:21.382883 140099009918528 [version_set.cc:6139] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-07-08T14.41.36/.rocksdb/job-36964/att-00/MANIFEST-12625661 2024/07/09-08:10:21.427092 140099009918528 [version_set.cc:6182] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-07-08T14.41.36/.rocksdb/job-36964/att-00/MANIFEST-12625661 succeeded,manifest_file_number is 12625661, next_file_number is 12668096, last_sequence is 148130124444, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 12667931 2024/07/09-08:10:21.427099 140099009918528 [version_set.cc:6197] Column family [default] (ID 0), log number is 0 2024/07/09-08:10:21.427200 140099009918528 [version_set.cc:5652] Creating manifest 12668096 2024/07/09-08:10:21.452479 140099009918528 DEBG dcompact_worker.cpp:1215: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00: bottommost_level: fake = 1, rpc = 0 2024/07/09-08:10:21.465929 140099009918528 [compaction_job.cc:2433] [default] [JOB 36964] Compacting 1@1 + 8@2 files to L2, score 1.00, subcompactions 1 : 1 2024/07/09-08:10:21.465942 140099009918528 [compaction_job.cc:2441] [default]: Compaction start summary: Base version 19248 Base level 1, inputs: [12668079(31MB)], [12668011(20MB) 12668012(20MB) 12668013(20MB) 12668044(19MB) 12668045(20MB) 12668047(20MB) 12668048(19MB) 12668036(21MB)] 2024/07/09-08:10:21.694405 140099009918528 [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/07/09-08:10:21.694432 140099009918528 [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/07/09-08:10:21.694449 140099009918528 [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/07/09-08:10:21.694461 140099009918528 [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/07/09-08:10:21.694470 140099009918528 [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/07/09-08:10:21.865401 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst) /dev/shm/ToplingTemp/Topling-16171-mwzmwZ 2024/07/09-08:10:22.124296 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst): first pass time = 0.26's, 259.267'MB/sec 2024/07/09-08:10:23.516231 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst): old prealloc_size = 73819750, real_size = 19000720 2024/07/09-08:10:23.516597 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466981 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.0180 GB avg-val = 115.71 avg-zval = 38.53 2024/07/09-08:10:23.517157 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:23.895264 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668097.sst): second pass time = 1.39's, 38.844'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.38's, 55.418'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2609.202'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.382'MB/sec write SST data time = 0.07's, 286.696'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 = 12062.955'MB/sec zip my value time = 1.39's, unzip length = 0.054'GB zip my value throughput = 38.844'MB/sec zip pipeline throughput = 176.392'MB/sec entries = 466981 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.71 avg-zval = 38.53 usrkeys = 466981 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.71 avg-zval = 38.53 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466981 bytes = 1576080 } seq expand size = 3268867 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.0180 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.5017 value = 3.0028 dict = 1.00 all = 3.1948 } Zip/UnZip{ index = 0.0952 value = 0.3330 dict = 1.00 all = 0.3130 } ---------------------------- total value len = 0.057302 GB avg = 0.123 KB (by entry num) total key len = 0.013075 GB avg = 0.028 KB total ukey len = 0.009340 GB avg = 0.020 KB total ukey num = 0.000466981 Billion total entry num = 0.000466981 Billion write speed all = 0.024320263 MB/sec (with seq num) write speed all = 0.023029276 MB/sec (without seq num) 2024/07/09-08:10:23.928979 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668097: 466981 keys, 21005834 bytes, temperature: kWarm 2024/07/09-08:10:23.929092 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483823929033, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668097, "file_size": 21005834, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148052501011, "largest_seqno": 148130106969, "table_properties": {"data_size": 17994432, "index_size": 889344, "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": 13075468, "raw_average_key_size": 28, "raw_value_size": 54033486, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466981, "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": 1720483821, "oldest_key_time": 0, "file_creation_time": 1720483821, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668097, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:23.957723 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst) /dev/shm/ToplingTemp/Topling-16171-nVspPX 2024/07/09-08:10:24.362201 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst): first pass time = 0.40's, 165.934'MB/sec 2024/07/09-08:10:25.529063 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst): old prealloc_size = 73819750, real_size = 19589856 2024/07/09-08:10:25.529416 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466629 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.0186 GB avg-val = 115.82 avg-zval = 39.83 2024/07/09-08:10:25.529857 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:25.961324 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668098.sst): second pass time = 1.17's, 46.344'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.43's, 49.824'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2690.289'MB/sec (index lex order gen) rebuild zvType time = 0.36's, 0.326'MB/sec write SST data time = 0.07's, 288.844'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 = 13965.282'MB/sec zip my value time = 1.17's, unzip length = 0.054'GB zip my value throughput = 46.344'MB/sec zip pipeline throughput = 117.819'MB/sec entries = 466629 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.82 avg-zval = 39.83 usrkeys = 466629 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.82 avg-zval = 39.83 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466629 bytes = 1516560 } seq expand size = 3266403 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0186 GB dict = 0.54 MB all = 0.0215 GB } UnZip/Zip{ index = 10.5021 value = 2.9080 dict = 1.00 all = 3.1159 } Zip/UnZip{ index = 0.0952 value = 0.3439 dict = 1.00 all = 0.3209 } ---------------------------- total value len = 0.114612 GB avg = 0.123 KB (by entry num) total key len = 0.026141 GB avg = 0.028 KB total ukey len = 0.018672 GB avg = 0.020 KB total ukey num = 0.000933610 Billion total entry num = 0.000933610 Billion write speed all = 0.048604974 MB/sec (with seq num) write speed all = 0.046025816 MB/sec (without seq num) 2024/07/09-08:10:25.989561 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668098: 466629 keys, 21537446 bytes, temperature: kWarm 2024/07/09-08:10:25.989630 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483825989591, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668098, "file_size": 21537446, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148088759897, "largest_seqno": 148130107096, "table_properties": {"data_size": 18584400, "index_size": 888640, "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": 13065612, "raw_average_key_size": 28, "raw_value_size": 54043350, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466629, "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": 1720483823, "oldest_key_time": 0, "file_creation_time": 1720483823, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668098, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:26.020255 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst) /dev/shm/ToplingTemp/Topling-16171-6FG6h0 2024/07/09-08:10:26.715309 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst): first pass time = 0.70's, 96.558'MB/sec 2024/07/09-08:10:29.271042 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst): old prealloc_size = 73819750, real_size = 19441328 2024/07/09-08:10:29.271387 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465578 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.0541 GB zip-val = 0.0184 GB avg-val = 116.14 avg-zval = 39.61 2024/07/09-08:10:29.271816 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:29.715765 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668099.sst): second pass time = 2.55's, 21.164'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.44's, 48.089'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2703.155'MB/sec (index lex order gen) rebuild zvType time = 0.37's, 0.311'MB/sec write SST data time = 0.07's, 302.334'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 = 13723.828'MB/sec zip my value time = 2.55's, unzip length = 0.054'GB zip my value throughput = 21.164'MB/sec zip pipeline throughput = 117.475'MB/sec entries = 465578 avg-key = 28.00 avg-zkey = 1.89 avg-val = 116.14 avg-zval = 39.61 usrkeys = 465578 avg-key = 20.00 avg-zkey = 1.89 avg-val = 123.14 avg-zval = 39.61 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465578 bytes = 1513136 } seq expand size = 3259046 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.0184 GB dict = 0.54 MB all = 0.0214 GB } UnZip/Zip{ index = 10.5706 value = 2.9318 dict = 1.00 all = 3.1379 } Zip/UnZip{ index = 0.0946 value = 0.3411 dict = 1.00 all = 0.3187 } ---------------------------- total value len = 0.171944 GB avg = 0.123 KB (by entry num) total key len = 0.039177 GB avg = 0.028 KB total ukey len = 0.027984 GB avg = 0.020 KB total ukey num = 0.001399188 Billion total entry num = 0.001399188 Billion write speed all = 0.072810115 MB/sec (with seq num) write speed all = 0.068949773 MB/sec (without seq num) 2024/07/09-08:10:29.749938 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668099: 465578 keys, 21386716 bytes, temperature: kWarm 2024/07/09-08:10:29.750010 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483829749971, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668099, "file_size": 21386716, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148065965859, "largest_seqno": 148130106898, "table_properties": {"data_size": 18443872, "index_size": 880896, "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": 13036184, "raw_average_key_size": 28, "raw_value_size": 54072824, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465578, "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": 1720483826, "oldest_key_time": 0, "file_creation_time": 1720483826, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668099, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:29.792106 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst) /dev/shm/ToplingTemp/Topling-16171-fP4ucY 2024/07/09-08:10:30.307230 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst): first pass time = 0.52's, 130.287'MB/sec 2024/07/09-08:10:31.736210 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst): old prealloc_size = 73819750, real_size = 18667296 2024/07/09-08:10:31.736548 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466376 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.0177 GB avg-val = 115.89 avg-zval = 37.86 2024/07/09-08:10:31.736969 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:32.146638 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668100.sst): second pass time = 1.43's, 37.843'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.41's, 50.223'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2795.205'MB/sec (index lex order gen) rebuild zvType time = 0.32's, 0.368'MB/sec write SST data time = 0.09's, 220.452'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 = 16506.416'MB/sec zip my value time = 1.43's, unzip length = 0.054'GB zip my value throughput = 37.843'MB/sec zip pipeline throughput = 135.792'MB/sec entries = 466376 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.89 avg-zval = 37.86 usrkeys = 466376 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.89 avg-zval = 37.86 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466376 bytes = 1515744 } seq expand size = 3264632 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.0206 GB } UnZip/Zip{ index = 10.4318 value = 3.0612 dict = 1.00 all = 3.2557 } Zip/UnZip{ index = 0.0959 value = 0.3267 dict = 1.00 all = 0.3072 } ---------------------------- total value len = 0.229259 GB avg = 0.123 KB (by entry num) total key len = 0.052236 GB avg = 0.028 KB total ukey len = 0.037311 GB avg = 0.020 KB total ukey num = 0.001865564 Billion total entry num = 0.001865564 Billion write speed all = 0.096998768 MB/sec (with seq num) write speed all = 0.091856011 MB/sec (without seq num) 2024/07/09-08:10:32.184805 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668100: 466376 keys, 20612798 bytes, temperature: kWarm 2024/07/09-08:10:32.184885 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483832184840, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668100, "file_size": 20612798, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148074523019, "largest_seqno": 148130105983, "table_properties": {"data_size": 17656400, "index_size": 894144, "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": 13058528, "raw_average_key_size": 28, "raw_value_size": 54050392, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466376, "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": 1720483829, "oldest_key_time": 0, "file_creation_time": 1720483829, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668100, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:32.215531 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst) /dev/shm/ToplingTemp/Topling-16171-EqactX 2024/07/09-08:10:32.608283 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst): first pass time = 0.39's, 170.886'MB/sec 2024/07/09-08:10:33.302352 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst): old prealloc_size = 73819750, real_size = 19137952 2024/07/09-08:10:33.302683 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466600 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.0181 GB avg-val = 115.83 avg-zval = 38.87 2024/07/09-08:10:33.303084 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:33.820794 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668101.sst): second pass time = 0.69's, 77.953'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.52's, 40.560'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2899.286'MB/sec (index lex order gen) rebuild zvType time = 0.37's, 0.319'MB/sec write SST data time = 0.15's, 138.454'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 = 14852.768'MB/sec zip my value time = 0.69's, unzip length = 0.054'GB zip my value throughput = 77.953'MB/sec zip pipeline throughput = 77.953'MB/sec entries = 466600 avg-key = 28.00 avg-zkey = 1.89 avg-val = 115.83 avg-zval = 38.87 usrkeys = 466600 avg-key = 20.00 avg-zkey = 1.89 avg-val = 122.83 avg-zval = 38.87 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466600 bytes = 1458144 } seq expand size = 3266200 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.0181 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.5738 value = 2.9795 dict = 1.00 all = 3.1916 } Zip/UnZip{ index = 0.0946 value = 0.3356 dict = 1.00 all = 0.3133 } ---------------------------- total value len = 0.286569 GB avg = 0.123 KB (by entry num) total key len = 0.065301 GB avg = 0.028 KB total ukey len = 0.046643 GB avg = 0.020 KB total ukey num = 0.002332164 Billion total entry num = 0.002332164 Billion write speed all = 0.121179040 MB/sec (with seq num) write speed all = 0.114753725 MB/sec (without seq num) 2024/07/09-08:10:33.851779 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668101: 466600 keys, 21027046 bytes, temperature: kWarm 2024/07/09-08:10:33.851862 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483833851816, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668101, "file_size": 21027046, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148097871607, "largest_seqno": 148130106042, "table_properties": {"data_size": 18138576, "index_size": 882560, "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": 13064800, "raw_average_key_size": 28, "raw_value_size": 54044108, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466600, "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": 1720483832, "oldest_key_time": 0, "file_creation_time": 1720483832, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668101, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:33.885947 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst) /dev/shm/ToplingTemp/Topling-16171-HY6nQZ 2024/07/09-08:10:34.553524 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst): first pass time = 0.67's, 100.535'MB/sec 2024/07/09-08:10:35.560731 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst): old prealloc_size = 73819750, real_size = 19375488 2024/07/09-08:10:35.561071 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465792 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.0184 GB avg-val = 116.07 avg-zval = 39.43 2024/07/09-08:10:35.561464 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:35.924953 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668102.sst): second pass time = 1.01's, 53.714'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.36's, 58.536'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2886.325'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.388'MB/sec write SST data time = 0.06's, 332.686'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 = 15523.543'MB/sec zip my value time = 1.01's, unzip length = 0.054'GB zip my value throughput = 53.714'MB/sec zip pipeline throughput = 104.866'MB/sec entries = 465792 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.07 avg-zval = 39.43 usrkeys = 465792 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.07 avg-zval = 39.43 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465792 bytes = 1513840 } seq expand size = 3260544 multi value expand size = 0 cnt WriteAppend = 15 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0184 GB dict = 0.54 MB all = 0.0213 GB } UnZip/Zip{ index = 10.4329 value = 2.9439 dict = 1.00 all = 3.1477 } Zip/UnZip{ index = 0.0959 value = 0.3397 dict = 1.00 all = 0.3177 } ---------------------------- total value len = 0.343897 GB avg = 0.123 KB (by entry num) total key len = 0.078343 GB avg = 0.028 KB total ukey len = 0.055959 GB avg = 0.020 KB total ukey num = 0.002797956 Billion total entry num = 0.002797956 Billion write speed all = 0.145308011 MB/sec (with seq num) write speed all = 0.137604979 MB/sec (without seq num) 2024/07/09-08:10:35.953446 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668102: 465792 keys, 21319724 bytes, temperature: kWarm 2024/07/09-08:10:35.953519 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483835953479, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668102, "file_size": 21319724, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148080406386, "largest_seqno": 148130105132, "table_properties": {"data_size": 18365936, "index_size": 892928, "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": 13042176, "raw_average_key_size": 28, "raw_value_size": 54066788, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465792, "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": 1720483833, "oldest_key_time": 0, "file_creation_time": 1720483833, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668102, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:35.981435 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst) /dev/shm/ToplingTemp/Topling-16171-BhkGsZ 2024/07/09-08:10:36.366726 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst): first pass time = 0.39's, 174.197'MB/sec 2024/07/09-08:10:37.064387 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst): old prealloc_size = 73819750, real_size = 18492096 2024/07/09-08:10:37.064719 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466002 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.0175 GB avg-val = 116.01 avg-zval = 37.53 2024/07/09-08:10:37.065144 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:37.438674 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668103.sst): second pass time = 0.70's, 77.578'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 54.765'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2904.015'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.378'MB/sec write SST data time = 0.07's, 312.982'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 = 15267.268'MB/sec zip my value time = 0.70's, unzip length = 0.054'GB zip my value throughput = 77.578'MB/sec zip pipeline throughput = 77.578'MB/sec entries = 466002 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.01 avg-zval = 37.53 usrkeys = 466002 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.01 avg-zval = 37.53 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466002 bytes = 1572768 } seq expand size = 3262014 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.0175 GB dict = 0.54 MB all = 0.0205 GB } UnZip/Zip{ index = 10.5061 value = 3.0913 dict = 1.00 all = 3.2740 } Zip/UnZip{ index = 0.0952 value = 0.3235 dict = 1.00 all = 0.3054 } ---------------------------- total value len = 0.401220 GB avg = 0.123 KB (by entry num) total key len = 0.091391 GB avg = 0.028 KB total ukey len = 0.065279 GB avg = 0.020 KB total ukey num = 0.003263958 Billion total entry num = 0.003263958 Billion write speed all = 0.169436983 MB/sec (with seq num) write speed all = 0.160455684 MB/sec (without seq num) 2024/07/09-08:10:37.471102 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668103: 466002 keys, 20497274 bytes, temperature: kWarm 2024/07/09-08:10:37.471167 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483837471133, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668103, "file_size": 20497274, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148035373019, "largest_seqno": 148130107290, "table_properties": {"data_size": 17488304, "index_size": 887104, "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": 13048056, "raw_average_key_size": 28, "raw_value_size": 54060940, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 466002, "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": 1720483835, "oldest_key_time": 0, "file_creation_time": 1720483835, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668103, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:37.495321 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst) /dev/shm/ToplingTemp/Topling-16171-mgjpQW 2024/07/09-08:10:37.930698 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst): first pass time = 0.44's, 154.154'MB/sec 2024/07/09-08:10:38.605857 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst): old prealloc_size = 73819750, real_size = 19481056 2024/07/09-08:10:38.606202 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466737 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.0185 GB avg-val = 115.78 avg-zval = 39.58 2024/07/09-08:10:38.606602 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/07/09-08:10:38.968663 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668104.sst): second pass time = 0.67's, 80.136'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.36's, 59.066'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2794.717'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.393'MB/sec write SST data time = 0.07's, 325.518'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 = 15225.216'MB/sec zip my value time = 0.67's, unzip length = 0.054'GB zip my value throughput = 80.136'MB/sec zip pipeline throughput = 80.136'MB/sec entries = 466737 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.78 avg-zval = 39.58 usrkeys = 466737 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.78 avg-zval = 39.58 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466737 bytes = 1516912 } seq expand size = 3267159 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.0185 GB dict = 0.54 MB all = 0.0214 GB } UnZip/Zip{ index = 10.5015 value = 2.9250 dict = 1.00 all = 3.1317 } Zip/UnZip{ index = 0.0952 value = 0.3419 dict = 1.00 all = 0.3193 } ---------------------------- total value len = 0.458527 GB avg = 0.123 KB (by entry num) total key len = 0.104459 GB avg = 0.028 KB total ukey len = 0.074614 GB avg = 0.020 KB total ukey num = 0.003730695 Billion total entry num = 0.003730695 Billion write speed all = 0.193541517 MB/sec (with seq num) write speed all = 0.183281316 MB/sec (without seq num) 2024/07/09-08:10:39.004072 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668104: 466737 keys, 21429052 bytes, temperature: kWarm 2024/07/09-08:10:39.004138 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483839004104, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668104, "file_size": 21429052, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148072385311, "largest_seqno": 148130107340, "table_properties": {"data_size": 18475280, "index_size": 888896, "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": 13068636, "raw_average_key_size": 28, "raw_value_size": 54040326, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466737, "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": 1720483837, "oldest_key_time": 0, "file_creation_time": 1720483837, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668104, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:39.027935 140099009918528 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst) /dev/shm/ToplingTemp/Topling-16171-KI6ri0 2024/07/09-08:10:39.149877 140099009918528 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst): first pass time = 0.12's, 272.683'MB/sec 2024/07/09-08:10:39.491895 140099009918528 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst): old prealloc_size = 73819750, real_size = 10120976 2024/07/09-08:10:39.492097 140099009918528 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 231092 prefix = 4 raw-key = 0.0037 GB zip-key = 0.0004 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0268 GB zip-val = 0.0096 GB avg-val = 115.84 avg-zval = 41.65 2024/07/09-08:10:39.492318 140099009918528 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.033 GB 2024/07/09-08:10:39.669313 140099009918528 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00/12668105.sst): second pass time = 0.34's, 78.435'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.18's, 62.689'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2443.274'MB/sec (index lex order gen) rebuild zvType time = 0.14's, 0.401'MB/sec write SST data time = 0.03's, 335.013'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.275'MB, throughput = 7397.802'MB/sec zip my value time = 0.34's, unzip length = 0.027'GB zip my value throughput = 78.435'MB/sec zip pipeline throughput = 78.435'MB/sec entries = 231092 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.84 avg-zval = 41.65 usrkeys = 231092 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.84 avg-zval = 41.65 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 231092 bytes = 779952 } seq expand size = 1617644 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0046 GB value = 0.0268 GB dict = 0.28 MB all = 0.0332 GB } __ZipSize{ index = 0.0004 GB value = 0.0096 GB dict = 0.28 MB all = 0.0111 GB } UnZip/Zip{ index = 10.5533 value = 2.7812 dict = 1.00 all = 2.9888 } Zip/UnZip{ index = 0.0948 value = 0.3596 dict = 1.00 all = 0.3346 } ---------------------------- total value len = 0.486914 GB avg = 0.123 KB (by entry num) total key len = 0.110930 GB avg = 0.028 KB total ukey len = 0.079236 GB avg = 0.020 KB total ukey num = 0.003961787 Billion total entry num = 0.003961787 Billion write speed all = 0.205475306 MB/sec (with seq num) write speed all = 0.194582177 MB/sec (without seq num) 2024/07/09-08:10:39.688336 140099009918528 [compaction_job.cc:1944] [default] [JOB 36964] Generated table #12668105: 231092 keys, 11121740 bytes, temperature: kWarm 2024/07/09-08:10:39.688400 140099009918528 EVENT_LOG_v1 {"time_micros": 1720483839688369, "cf_name": "default", "job": 36964, "event": "table_file_creation", "file_number": 12668105, "file_size": 11121740, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 148023719064, "largest_seqno": 148128466665, "table_properties": {"data_size": 9625088, "index_size": 437952, "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": 6470576, "raw_average_key_size": 28, "raw_value_size": 26769552, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 231092, "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": 1720483839, "oldest_key_time": 0, "file_creation_time": 1720483839, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "465QC0QPK7Q93426EREI", "orig_file_number": 12668105, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/07/09-08:10:39.701322 140099009918528 [compaction_job.cc:699] job-36964: subcompact[0], size: 0.179938 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-36964/att-00 [12668097,12668098,12668099,12668100,12668101,12668102,12668103,12668104,12668105] 2024/07/09-08:10:39.746014 140099009918528 (Original Log Time 2024/07/09-08:10:21.465980) EVENT_LOG_v1 {"time_micros": 1720483821465952, "job": 36964, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L1": [12668079], "files_L2": [12668011, 12668012, 12668013, 12668044, 12668045, 12668047, 12668048, 12668036], "score": 0.998635, "input_data_size": 203107949, "oldest_snapshot_seqno": 148130123928} 2024/07/09-08:10:39.746031 140099009918528 (Original Log Time 2024/07/09-08:10:39.742366) [compaction_job.cc:2018] [default] [JOB 36964] Compacted 1@1 + 8@2 files to L2 => 179937630 bytes 2024/07/09-08:10:39.746035 140099009918528 (Original Log Time 2024/07/09-08:10:39.745946) [compaction_job.cc:1220] [default] compacted to: files[0 0 9 0 0 0 0] max score 0.07, MB/sec: 11.1 rd, 9.9 wr, level 2, files in(1, 8) out(9 +0 blob) MB in(31.8, 161.9 +0.0 blob) out(171.6 +0.0 blob), read-write-amplify(11.5) write-amplify(5.4) OK, records in: 3961787, records dropped: 0 output_compression: Snappy 2024/07/09-08:10:39.746043 140099009918528 (Original Log Time 2024/07/09-08:10:39.745991) EVENT_LOG_v1 {"time_micros": 1720483839745971, "cf": "default", "job": 36964, "event": "compaction_finished", "compaction_time_micros": 18235351, "compaction_time_cpu_micros": 5986094, "output_level": 2, "num_output_files": 9, "total_output_size": 179937630, "num_input_records": 3961787, "num_output_records": 3961787, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 168102356, "file_range_sync_nanos": 0, "file_fsync_nanos": 7016, "file_prepare_write_nanos": 24616, "lsm_state": [0, 0, 9, 0, 0, 0, 0]} 2024/07/09-08:10:39.882075 140099009918528 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":1720420896,"starts":1720483821,"executesMs":18398,"compactionJobId":36964,"attempt":0,"compactionInputRawBytes":570111802,"compactionInputZipBytes":203107949,"compactionOutputRawBytes":0,"compactionOutputZipBytes":179937630,"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-45875b7214bd489c7cc34d7943136556-0638d3e951154476-00"}}, response = 2024/07/09-08:10:39.882170 140099009918528 INFO dcompact_worker.cpp:1456: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-07-08T14.41.36/.rocksdb/job-36964/att-00: olev 2, work 18.399 s, result 4.931 ms, install 3.699 ms, input{raw 543.701 MiB zip 193.699 MiB}