2024/11/20-20:49:33.966100 140008501057088 DEBG dcompact_worker.cpp:2219: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00: fork to child time = 0.009568 sec 2024/11/20-20:49:33.966676 140008501057088 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00 2024/11/20-20:49:33.973485 140008501057088 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00 2024/11/20-20:49:33.975291 140008501057088 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/20-20:49:33.975644 140008501057088 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/20-20:49:34.042927 140008501057088 [version_set.cc:6211] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-12031/att-00/MANIFEST-049091 2024/11/20-20:49:34.102637 140008501057088 [version_set.cc:6254] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-12031/att-00/MANIFEST-049091 succeeded,manifest_file_number is 49091, next_file_number is 69156, last_sequence is 1113416350, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 69016 2024/11/20-20:49:34.102646 140008501057088 [version_set.cc:6269] Column family [default] (ID 0), log number is 0 2024/11/20-20:49:34.102755 140008501057088 [version_set.cc:5724] Creating manifest 69156 2024/11/20-20:49:34.136683 140008501057088 DEBG dcompact_worker.cpp:1225: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/20-20:49:34.157565 140008501057088 [compaction_job.cc:2437] [default] [JOB 12031] Compacting 1@2 + 9@3 files to L3, score 0.88, subcompactions 1 : 1 2024/11/20-20:49:34.157586 140008501057088 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 9913 Base level 2, inputs: [69154(28MB)], [69110(124MB) 69111(124MB) 69112(124MB) 69113(124MB) 69114(124MB) 69115(124MB) 69116(124MB) 69117(124MB) 69118(120MB)] 2024/11/20-20:49:34.166014 140008501057088 [top_zip_table.cc:59] core git_version_hash_info_is:commit 81964c21ebbcc178d8e99dae0fbf61bded2729cc Author: rockeet Date: Mon Nov 11 21:28:46 2024 +0800 Makefile: fix gen git-version-*.cpp GIT_PATH_ARG = :!src/terark/fsa :!tools/fsa :!src/terark/zbs :!tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:49:34.166059 140008501057088 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit 5dfecb7d107196f044ff5bf78dc39d2e725b9d9b Author: leipeng Date: Thu Nov 7 15:22:45 2024 +0800 Makefile: fix for x86_64 CPU older than haswell GIT_PATH_ARG = src/terark/fsa tools/fsa g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:49:34.166090 140008501057088 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit d44dd5ff72707128fe3c916077b43d2093c01f7c Author: leipeng Date: Sun Oct 27 23:38:26 2024 +0800 Fix for msvc, when toplingdb on msvc GIT_PATH_ARG = src/terark/zbs tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-20:49:34.166101 140008501057088 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit 79614a7e7dc27362fc5151b0797eb7d83c674c7b Author: rockeet Date: Sun Nov 10 15:02:21 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-20:49:34.166114 140008501057088 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit c46b65a52d9c74aa8b87aeb8438620ff2dbc669c Author: rockeet Date: Sun Nov 10 15:02:42 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-20:49:35.463871 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst) /dev/shm/ToplingTemp/Topling-968609-2OCCCR 2024/11/20-20:49:35.794877 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst): first pass time = 0.33's, 405.573'MB/sec 2024/11/20-20:49:37.029918 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst): part-0: reject ZipStore ratio = 0.807 2024/11/20-20:49:37.353108 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst): old prealloc_size = 147639500, real_size = 130035616 2024/11/20-20:49:37.353264 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199764 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.75 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.88 avg-zval = 648.94 2024/11/20-20:49:37.353489 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:37.658915 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069157.sst): second pass time = 1.23's, 104.858'MB/sec, value only(96.4% of KV) wait indexing time = 0.32's, remap KeyValue time = 0.31's, 427.360'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2524.359'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.199'MB/sec write SST data time = 0.06's, 2371.702'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.23's, unzip length = 0.129'GB zip my value throughput = 104.858'MB/sec zip pipeline throughput = 104.858'MB/sec entries = 199764 avg-key = 24.00 avg-zkey = 1.75 avg-val = 647.88 avg-zval = 648.94 usrkeys = 199764 avg-key = 16.00 avg-zkey = 1.75 avg-val = 654.88 avg-zval = 648.94 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 199764 bytes = 699184 } seq expand size = 1398348 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1307 GB } UnZip/Zip{ index = 9.1383 value = 0.9984 dict = 0.00 all = 1.0270 } Zip/UnZip{ index = 0.1094 value = 1.0016 dict = 0.00 all = 0.9737 } ---------------------------- total value len = 563.196554 GB avg = 0.331 KB (by entry num) total key len = 44.319201 GB avg = 0.026 KB total ukey len = 32.797338 GB avg = 0.014 KB total ukey num = 2.321214340 Billion total entry num = 1.700716362 Billion write speed all = 61.024290810 MB/sec (with seq num) write speed all = 59.657610075 MB/sec (without seq num) 2024/11/20-20:49:37.836302 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69157: 199764 keys, 130687647 bytes, temperature: kWarm 2024/11/20-20:49:37.836381 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106977836340, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69157, "file_size": 130687647, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 856426320, "largest_seqno": 1113307008, "table_properties": {"data_size": 129635728, "index_size": 349760, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 0, "raw_key_size": 4794336, "raw_average_key_size": 24, "raw_value_size": 129423743, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199764, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106975, "oldest_key_time": 0, "file_creation_time": 1732106975, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69157, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:37.895415 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst) /dev/shm/ToplingTemp/Topling-968609-MEbARP 2024/11/20-20:49:39.159627 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst): first pass time = 1.26's, 106.171'MB/sec 2024/11/20-20:49:40.428521 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst): part-0: reject ZipStore ratio = 0.807 2024/11/20-20:49:40.810859 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst): old prealloc_size = 147639500, real_size = 130033072 2024/11/20-20:49:40.811079 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199951 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0004 GB avg-key = 12.00 avg-zkey = 1.76 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.26 avg-zval = 648.32 2024/11/20-20:49:40.811333 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:41.165477 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069158.sst): second pass time = 1.27's, 102.061'MB/sec, value only(96.4% of KV) wait indexing time = 0.38's, remap KeyValue time = 0.35's, 368.381'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1753.027'MB/sec (index lex order gen) rebuild zvType time = 0.29's, 0.171'MB/sec write SST data time = 0.06's, 2120.623'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.27's, unzip length = 0.129'GB zip my value throughput = 102.061'MB/sec zip pipeline throughput = 133.143'MB/sec entries = 199951 avg-key = 24.00 avg-zkey = 1.76 avg-val = 647.26 avg-zval = 648.32 usrkeys = 199951 avg-key = 16.00 avg-zkey = 1.76 avg-val = 653.44 avg-zval = 648.32 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 176744 bytes = 618624 } seq expand size = 1237208 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0004 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.1036 value = 0.9984 dict = 0.00 all = 1.0274 } Zip/UnZip{ index = 0.1098 value = 1.0016 dict = 0.00 all = 0.9733 } ---------------------------- total value len = 563.327211 GB avg = 0.331 KB (by entry num) total key len = 44.323999 GB avg = 0.026 KB total ukey len = 32.800537 GB avg = 0.014 KB total ukey num = 2.321414291 Billion total entry num = 1.700916313 Billion write speed all = 61.016405289 MB/sec (with seq num) write speed all = 59.650045149 MB/sec (without seq num) 2024/11/20-20:49:41.345608 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69158: 199951 keys, 130635871 bytes, temperature: kWarm 2024/11/20-20:49:41.345675 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106981345643, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69158, "file_size": 130635871, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113306179, "table_properties": {"data_size": 129631456, "index_size": 351424, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 0, "raw_key_size": 4798824, "raw_average_key_size": 24, "raw_value_size": 129419322, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199951, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106977, "oldest_key_time": 0, "file_creation_time": 1732106977, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69158, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:41.404307 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst) /dev/shm/ToplingTemp/Topling-968609-7dJMVS 2024/11/20-20:49:42.574881 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst): first pass time = 1.17's, 114.664'MB/sec 2024/11/20-20:49:43.614138 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst): part-0: reject ZipStore ratio = 0.804 2024/11/20-20:49:43.926558 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst): old prealloc_size = 147639500, real_size = 130025008 2024/11/20-20:49:43.926713 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199825 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 647.68 avg-zval = 648.74 2024/11/20-20:49:43.926904 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:44.233892 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069159.sst): second pass time = 1.04's, 124.622'MB/sec, value only(96.4% of KV) wait indexing time = 0.31's, remap KeyValue time = 0.31's, 424.917'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2461.343'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.200'MB/sec write SST data time = 0.06's, 2272.874'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.04's, unzip length = 0.129'GB zip my value throughput = 124.622'MB/sec zip pipeline throughput = 125.922'MB/sec entries = 199825 avg-key = 24.00 avg-zkey = 1.70 avg-val = 647.68 avg-zval = 648.74 usrkeys = 199825 avg-key = 16.00 avg-zkey = 1.70 avg-val = 653.43 avg-zval = 648.74 TagRS{ kinds = RS_Key0_TagN bytes = 31320 } TagArray{ size = 164219 bytes = 574784 } seq expand size = 1149533 multi value expand size = 0 cnt WriteAppend = 15810 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.3850 value = 0.9984 dict = 0.00 all = 1.0278 } Zip/UnZip{ index = 0.1066 value = 1.0016 dict = 0.00 all = 0.9729 } ---------------------------- total value len = 563.457783 GB avg = 0.331 KB (by entry num) total key len = 44.328795 GB avg = 0.026 KB total ukey len = 32.803734 GB avg = 0.014 KB total ukey num = 2.321614116 Billion total entry num = 1.701116138 Billion write speed all = 61.011199903 MB/sec (with seq num) write speed all = 59.645100150 MB/sec (without seq num) 2024/11/20-20:49:44.375392 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69159: 199825 keys, 130583967 bytes, temperature: kWarm 2024/11/20-20:49:44.375458 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106984375428, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69159, "file_size": 130583967, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113306939, "table_properties": {"data_size": 129634208, "index_size": 340672, "index_partitions": 0, "top_level_index_size": 0, "index_key_is_user_key": 0, "index_value_is_delta_encoded": 0, "filter_size": 0, "raw_key_size": 4795800, "raw_average_key_size": 24, "raw_value_size": 129422213, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199825, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106981, "oldest_key_time": 0, "file_creation_time": 1732106981, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69159, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:44.431406 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst) /dev/shm/ToplingTemp/Topling-968609-GyGtRP 2024/11/20-20:49:45.760403 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst): first pass time = 1.33's, 100.995'MB/sec 2024/11/20-20:49:47.015791 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst): part-0: reject ZipStore ratio = 0.801 2024/11/20-20:49:47.361573 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst): old prealloc_size = 147639500, real_size = 130032928 2024/11/20-20:49:47.361766 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199506 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 648.75 avg-zval = 649.81 2024/11/20-20:49:47.361988 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:47.845508 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069160.sst): second pass time = 1.25's, 103.155'MB/sec, value only(96.4% of KV) wait indexing time = 0.35's, remap KeyValue time = 0.48's, 269.896'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1934.576'MB/sec (index lex order gen) rebuild zvType time = 0.41's, 0.122'MB/sec write SST data time = 0.08's, 1712.339'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.25's, unzip length = 0.129'GB zip my value throughput = 103.155'MB/sec zip pipeline throughput = 132.528'MB/sec entries = 199506 avg-key = 24.00 avg-zkey = 1.71 avg-val = 648.75 avg-zval = 649.81 usrkeys = 199506 avg-key = 16.00 avg-zkey = 1.71 avg-val = 654.76 avg-zval = 649.81 TagRS{ kinds = RS_Key0_TagN bytes = 31280 } TagArray{ size = 171095 bytes = 598848 } seq expand size = 1197665 multi value expand size = 0 cnt WriteAppend = 15810 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.3577 value = 0.9984 dict = 0.00 all = 1.0276 } Zip/UnZip{ index = 0.1069 value = 1.0016 dict = 0.00 all = 0.9732 } ---------------------------- total value len = 563.588410 GB avg = 0.331 KB (by entry num) total key len = 44.333583 GB avg = 0.026 KB total ukey len = 32.806927 GB avg = 0.014 KB total ukey num = 2.321813622 Billion total entry num = 1.701315644 Billion write speed all = 61.002677117 MB/sec (with seq num) write speed all = 59.636912299 MB/sec (without seq num) 2024/11/20-20:49:48.043740 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69160: 199506 keys, 130615967 bytes, temperature: kWarm 2024/11/20-20:49:48.043842 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106988043794, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69160, "file_size": 130615967, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113307195, "table_properties": {"data_size": 129641744, "index_size": 341120, "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": 4788144, "raw_average_key_size": 24, "raw_value_size": 129430033, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 199506, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106984, "oldest_key_time": 0, "file_creation_time": 1732106984, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69160, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:48.112577 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst) /dev/shm/ToplingTemp/Topling-968609-IlJfoT 2024/11/20-20:49:49.333189 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst): first pass time = 1.22's, 109.963'MB/sec 2024/11/20-20:49:50.554297 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:49:50.924877 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst): old prealloc_size = 147639500, real_size = 130017552 2024/11/20-20:49:50.925076 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200273 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.17 avg-zval = 647.24 2024/11/20-20:49:50.925288 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:51.283968 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069161.sst): second pass time = 1.22's, 106.055'MB/sec, value only(96.4% of KV) wait indexing time = 0.37's, remap KeyValue time = 0.36's, 363.590'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1916.499'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.169'MB/sec write SST data time = 0.06's, 2105.281'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.22's, unzip length = 0.129'GB zip my value throughput = 106.055'MB/sec zip pipeline throughput = 106.055'MB/sec entries = 200273 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.17 avg-zval = 647.24 usrkeys = 200273 avg-key = 16.00 avg-zkey = 1.71 avg-val = 651.74 avg-zval = 647.24 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 159146 bytes = 557024 } seq expand size = 1114022 multi value expand size = 0 cnt WriteAppend = 15808 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.3324 value = 0.9984 dict = 0.00 all = 1.0280 } Zip/UnZip{ index = 0.1072 value = 1.0016 dict = 0.00 all = 0.9727 } ---------------------------- total value len = 563.718936 GB avg = 0.331 KB (by entry num) total key len = 44.338390 GB avg = 0.026 KB total ukey len = 32.810131 GB avg = 0.014 KB total ukey num = 2.322013895 Billion total entry num = 1.701515917 Billion write speed all = 60.995211659 MB/sec (with seq num) write speed all = 59.629757198 MB/sec (without seq num) 2024/11/20-20:49:51.465223 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69161: 200273 keys, 130558687 bytes, temperature: kWarm 2024/11/20-20:49:51.465280 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106991465251, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69161, "file_size": 130558687, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113305930, "table_properties": {"data_size": 129623936, "index_size": 343360, "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": 4806552, "raw_average_key_size": 24, "raw_value_size": 129411404, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200273, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106988, "oldest_key_time": 0, "file_creation_time": 1732106988, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69161, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:51.523423 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst) /dev/shm/ToplingTemp/Topling-968609-Zj1thR 2024/11/20-20:49:52.714689 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst): first pass time = 1.19's, 112.672'MB/sec 2024/11/20-20:49:53.993283 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:49:54.268556 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst): old prealloc_size = 147639500, real_size = 130016080 2024/11/20-20:49:54.268702 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200303 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.08 avg-zval = 647.14 2024/11/20-20:49:54.268875 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:54.591345 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069162.sst): second pass time = 1.28's, 101.267'MB/sec, value only(96.4% of KV) wait indexing time = 0.28's, remap KeyValue time = 0.32's, 404.368'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2549.782'MB/sec (index lex order gen) rebuild zvType time = 0.26's, 0.190'MB/sec write SST data time = 0.06's, 2191.696'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.28's, unzip length = 0.129'GB zip my value throughput = 101.267'MB/sec zip pipeline throughput = 124.992'MB/sec entries = 200303 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.08 avg-zval = 647.14 usrkeys = 200303 avg-key = 16.00 avg-zkey = 1.71 avg-val = 651.29 avg-zval = 647.14 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 149324 bytes = 522656 } seq expand size = 1045268 multi value expand size = 0 cnt WriteAppend = 15808 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.3600 value = 0.9984 dict = 0.00 all = 1.0283 } Zip/UnZip{ index = 0.1068 value = 1.0016 dict = 0.00 all = 0.9725 } ---------------------------- total value len = 563.849392 GB avg = 0.331 KB (by entry num) total key len = 44.343197 GB avg = 0.026 KB total ukey len = 32.813336 GB avg = 0.014 KB total ukey num = 2.322214198 Billion total entry num = 1.701716220 Billion write speed all = 60.988546021 MB/sec (with seq num) write speed all = 59.623383737 MB/sec (without seq num) 2024/11/20-20:49:54.734818 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69162: 200303 keys, 130522847 bytes, temperature: kWarm 2024/11/20-20:49:54.734878 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106994734847, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69162, "file_size": 130522847, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113306277, "table_properties": {"data_size": 129623424, "index_size": 342400, "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": 4807272, "raw_average_key_size": 24, "raw_value_size": 129410904, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200303, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106991, "oldest_key_time": 0, "file_creation_time": 1732106991, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69162, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:54.795386 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst) /dev/shm/ToplingTemp/Topling-968609-5KfIDP 2024/11/20-20:49:56.069573 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst): first pass time = 1.27's, 105.340'MB/sec 2024/11/20-20:49:57.449339 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-20:49:57.752285 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst): old prealloc_size = 147639500, real_size = 130018432 2024/11/20-20:49:57.752489 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200274 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.72 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.17 avg-zval = 647.24 2024/11/20-20:49:57.752660 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:49:58.093467 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069163.sst): second pass time = 1.38's, 93.837'MB/sec, value only(96.4% of KV) wait indexing time = 0.30's, remap KeyValue time = 0.34's, 381.894'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1873.429'MB/sec (index lex order gen) rebuild zvType time = 0.28's, 0.180'MB/sec write SST data time = 0.06's, 2056.573'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.38's, unzip length = 0.129'GB zip my value throughput = 93.837'MB/sec zip pipeline throughput = 150.696'MB/sec entries = 200274 avg-key = 24.00 avg-zkey = 1.72 avg-val = 646.17 avg-zval = 647.24 usrkeys = 200274 avg-key = 16.00 avg-zkey = 1.72 avg-val = 649.08 avg-zval = 647.24 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 83177 bytes = 291136 } seq expand size = 582239 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1303 GB } UnZip/Zip{ index = 9.3203 value = 0.9984 dict = 0.00 all = 1.0301 } Zip/UnZip{ index = 0.1073 value = 1.0016 dict = 0.00 all = 0.9708 } ---------------------------- total value len = 563.979386 GB avg = 0.331 KB (by entry num) total key len = 44.348004 GB avg = 0.026 KB total ukey len = 32.816540 GB avg = 0.014 KB total ukey num = 2.322414472 Billion total entry num = 1.701916494 Billion write speed all = 60.980648067 MB/sec (with seq num) write speed all = 59.615804432 MB/sec (without seq num) 2024/11/20-20:49:58.301543 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69163: 200274 keys, 130293663 bytes, temperature: kWarm 2024/11/20-20:49:58.301606 140008501057088 EVENT_LOG_v1 {"time_micros": 1732106998301575, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69163, "file_size": 130293663, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113304712, "table_properties": {"data_size": 129624368, "index_size": 343808, "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": 4806576, "raw_average_key_size": 24, "raw_value_size": 129411837, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200274, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106994, "oldest_key_time": 0, "file_creation_time": 1732106994, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69163, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:49:58.365298 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst) /dev/shm/ToplingTemp/Topling-968609-5shShT 2024/11/20-20:49:59.547653 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst): first pass time = 1.18's, 113.523'MB/sec 2024/11/20-20:50:00.565617 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst): part-0: reject ZipStore ratio = 0.801 2024/11/20-20:50:00.833265 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst): old prealloc_size = 147639500, real_size = 130018640 2024/11/20-20:50:00.833424 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200120 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.69 avg-zval = 647.75 2024/11/20-20:50:00.833620 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-20:50:01.203770 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069164.sst): second pass time = 1.02's, 127.232'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.37's, 352.369'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2441.214'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.161'MB/sec write SST data time = 0.06's, 2158.919'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.02's, unzip length = 0.129'GB zip my value throughput = 127.232'MB/sec zip pipeline throughput = 127.232'MB/sec entries = 200120 avg-key = 24.00 avg-zkey = 1.70 avg-val = 646.69 avg-zval = 647.75 usrkeys = 200120 avg-key = 16.00 avg-zkey = 1.70 avg-val = 652.15 avg-zval = 647.75 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 156068 bytes = 546256 } seq expand size = 1092476 multi value expand size = 0 cnt WriteAppend = 15807 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.4006 value = 0.9984 dict = 0.00 all = 1.0281 } Zip/UnZip{ index = 0.1064 value = 1.0016 dict = 0.00 all = 0.9727 } ---------------------------- total value len = 564.109894 GB avg = 0.331 KB (by entry num) total key len = 44.352807 GB avg = 0.026 KB total ukey len = 32.819742 GB avg = 0.014 KB total ukey num = 2.322614592 Billion total entry num = 1.702116614 Billion write speed all = 60.975200812 MB/sec (with seq num) write speed all = 59.610622149 MB/sec (without seq num) 2024/11/20-20:50:01.346784 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69164: 200120 keys, 130549215 bytes, temperature: kWarm 2024/11/20-20:50:01.346855 140008501057088 EVENT_LOG_v1 {"time_micros": 1732107001346823, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69164, "file_size": 130549215, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113306483, "table_properties": {"data_size": 129627840, "index_size": 340608, "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": 4802880, "raw_average_key_size": 24, "raw_value_size": 129415531, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200120, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732106998, "oldest_key_time": 0, "file_creation_time": 1732106998, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69164, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:50:01.403112 140008501057088 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst) /dev/shm/ToplingTemp/Topling-968609-UyAUjR 2024/11/20-20:50:02.529564 140008501057088 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst): first pass time = 1.13's, 117.766'MB/sec 2024/11/20-20:50:03.547374 140008501057088 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst): part-0: reject ZipStore ratio = 0.804 2024/11/20-20:50:03.808125 140008501057088 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst): old prealloc_size = 147639500, real_size = 128510608 2024/11/20-20:50:03.808287 140008501057088 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 197681 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.73 raw-val = 0.1279 GB zip-val = 0.1281 GB avg-val = 647.05 avg-zval = 648.11 2024/11/20-20:50:03.808455 140008501057088 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.133 GB 2024/11/20-20:50:04.119700 140008501057088 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00/069165.sst): second pass time = 1.02's, 125.752'MB/sec, value only(96.4% of KV) wait indexing time = 0.26's, remap KeyValue time = 0.31's, 413.918'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2361.207'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.200'MB/sec write SST data time = 0.06's, 2021.285'MB/sec dict compress time = 3472328330.67's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.02's, unzip length = 0.128'GB zip my value throughput = 125.752'MB/sec zip pipeline throughput = 125.752'MB/sec entries = 197681 avg-key = 24.00 avg-zkey = 1.73 avg-val = 647.05 avg-zval = 648.11 usrkeys = 197681 avg-key = 16.00 avg-zkey = 1.73 avg-val = 651.61 avg-zval = 648.11 TagRS{ kinds = RS_Key0_TagN bytes = 31000 } TagArray{ size = 128734 bytes = 450576 } seq expand size = 901138 multi value expand size = 0 cnt WriteAppend = 15625 UnZipSize{ index = 0.0032 GB value = 0.1279 GB dict = 0.00 MB all = 0.1327 GB } __ZipSize{ index = 0.0003 GB value = 0.1281 GB dict = 0.00 MB all = 0.1289 GB } UnZip/Zip{ index = 9.2634 value = 0.9984 dict = 0.00 all = 1.0288 } Zip/UnZip{ index = 0.1080 value = 1.0016 dict = 0.00 all = 0.9720 } ---------------------------- total value len = 564.238705 GB avg = 0.331 KB (by entry num) total key len = 44.357551 GB avg = 0.026 KB total ukey len = 32.822905 GB avg = 0.014 KB total ukey num = 2.322812273 Billion total entry num = 1.702314295 Billion write speed all = 60.970768519 MB/sec (with seq num) write speed all = 59.606430046 MB/sec (without seq num) 2024/11/20-20:50:04.264867 140008501057088 [compaction_job.cc:1948] [default] [JOB 12031] Generated table #69165: 197681 keys, 128945439 bytes, temperature: kWarm 2024/11/20-20:50:04.264963 140008501057088 EVENT_LOG_v1 {"time_micros": 1732107004264913, "cf_name": "default", "job": 12031, "event": "table_file_creation", "file_number": 69165, "file_size": 128945439, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1113306857, "table_properties": {"data_size": 128119552, "index_size": 341440, "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": 4744344, "raw_average_key_size": 24, "raw_value_size": 127909809, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 197681, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732107001, "oldest_key_time": 0, "file_creation_time": 1732107001, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 69165, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-20:50:04.348299 140008501057088 [compaction_job.cc:703] job-12031: subcompact[0], size: 1.173393 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-12031/att-00 [069157,069158,069159,069160,069161,069162,069163,069164,069165] 2024/11/20-20:50:04.472701 140008501057088 (Original Log Time 2024/11/20-20:49:34.157665) EVENT_LOG_v1 {"time_micros": 1732106974157608, "job": 12031, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [69154], "files_L3": [69110, 69111, 69112, 69113, 69114, 69115, 69116, 69117, 69118], "score": 0.883643, "input_data_size": 1200263281, "oldest_snapshot_seqno": 1113415767} 2024/11/20-20:50:04.472704 140008501057088 (Original Log Time 2024/11/20-20:50:04.471867) [compaction_job.cc:2022] [default] [JOB 12031] Compacted 1@2 + 9@3 files to L3 => 1173393303 bytes 2024/11/20-20:50:04.472705 140008501057088 (Original Log Time 2024/11/20-20:50:04.472634) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.04, MB/sec: 39.8 rd, 38.9 wr, level 3, files in(1, 9) out(9 +0 blob) MB in(28.4, 1116.3 +0.0 blob) out(1119.0 +0.0 blob), read-write-amplify(79.8) write-amplify(39.4) OK, records in: 1838279, records dropped: 40582 output_compression: Snappy 2024/11/20-20:50:04.472710 140008501057088 (Original Log Time 2024/11/20-20:50:04.472680) EVENT_LOG_v1 {"time_micros": 1732107004472656, "cf": "default", "job": 12031, "event": "compaction_finished", "compaction_time_micros": 30190642, "compaction_time_cpu_micros": 8006180, "output_level": 3, "num_output_files": 9, "total_output_size": 1173393303, "num_input_records": 1838279, "num_output_records": 1797697, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 815564453, "file_range_sync_nanos": 0, "file_fsync_nanos": 7462, "file_prepare_write_nanos": 5898612, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/20-20:50:04.606031 140008501057088 DEBG dcompact_worker.cpp:240: HttpPost: 200 OK: url = http://nlb-7zny4kaa1poal01o64.cn-shenzhen.nlb.aliyuncs.com:8443, body = {"instanceId":"nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137","labourId":"","dbId":"d89b4006-2803-486e-b7a2-759bcf348921","dbStarts":1732096383,"starts":1732106973,"executesMs":30497,"compactionJobId":12031,"attempt":0,"compactionInputRawBytes":1233914547,"compactionInputZipBytes":1200263281,"compactionOutputRawBytes":0,"compactionOutputZipBytes":1173393303,"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-a86ac9e729fa56dd8fce152d9c29b453-40af63c4e950f6b0-00"}}, response = 2024/11/20-20:50:04.606093 140008501057088 INFO dcompact_worker.cpp:1464: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-12031/att-00: olev 3, work 30.498 s, result 7.656 ms, install 0.857 ms, input{raw 1.149 GiB zip 1.118 GiB}