2024/11/22-16:24:36.358951 140024978429504 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00: fork to child time = 0.027700 sec 2024/11/22-16:24:36.359968 140024978429504 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00 2024/11/22-16:24:36.366484 140024978429504 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00 2024/11/22-16:24:36.367649 140024978429504 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/22-16:24:36.368193 140024978429504 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/22-16:24:36.421319 140024978429504 [version_set.cc:6208] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-04458/att-00/MANIFEST-206347 2024/11/22-16:24:36.434532 140024978429504 [version_set.cc:6251] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-04458/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 214351, last_sequence is 3376826952, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 214205 2024/11/22-16:24:36.434539 140024978429504 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/22-16:24:36.434815 140024978429504 [version_set.cc:5721] Creating manifest 214351 2024/11/22-16:24:36.467489 140024978429504 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/22-16:24:36.487355 140024978429504 [compaction_job.cc:2437] [default] [JOB 4458] Compacting 1@2 + 10@3 files to L3, score 0.88, subcompactions 1 : 1 2024/11/22-16:24:36.487373 140024978429504 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 3475 Base level 2, inputs: [214340(23MB)], [214288(36MB) 214289(37MB) 214290(36MB) 214291(36MB) 214292(36MB) 214293(36MB) 214294(8502KB) 214258(36MB) 214259(36MB) 214260(5660KB)] 2024/11/22-16:24:36.492843 140024978429504 [top_zip_table.cc:59] core git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-16:24:36.492876 140024978429504 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-16:24:36.492896 140024978429504 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/11/22-16:24:36.492901 140024978429504 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit a4a382006cb82713acf5b3425835f22711877681 Author: leipeng Date: 2024-04-11 19:44:14 +0800 fixed_len_hole_index.cc: Add env bool FixedLenHoleIndexUseAVX512 for ut & debug 1. FixedLenHoleIndexUseAVX512 is only in unit tests or debug 2. In release mode, use avx512 by compile options(-march=) g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/22-16:24:36.492909 140024978429504 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit feab587e468621ba0204d47b4ffacc52e7c4290d Author: leipeng Date: 2024-03-22 13:35:06 +0800 ToplingZipTableBuilder::Add: immediately return after error This function returns void, and caller does not check builder->status() after calling this function and graceful abandon. So immediately return after error, and return error status in Finish(). g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/22-16:24:36.991414 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst) /dev/shm/ToplingTemp/Topling-197238-UMJPrp 2024/11/22-16:24:38.031428 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst): first pass time = 1.04's, 129.061'MB/sec 2024/11/22-16:24:40.773145 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst): old prealloc_size = 147639500, real_size = 33926624 2024/11/22-16:24:40.773692 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921352 prefix = 4 raw-key = 0.0147 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0319 GB avg-val = 117.67 avg-zval = 34.67 2024/11/22-16:24:40.774484 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:24:41.824191 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214352.sst): second pass time = 2.74's, 39.556'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.05's, 36.056'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3212.369'MB/sec (index lex order gen) rebuild zvType time = 0.82's, 0.280'MB/sec write SST data time = 0.23's, 165.426'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 32620.978'MB/sec zip my value time = 2.74's, unzip length = 0.108'GB zip my value throughput = 39.556'MB/sec zip pipeline throughput = 109.392'MB/sec entries = 921352 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.67 avg-zval = 34.67 usrkeys = 921352 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.67 avg-zval = 34.67 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921352 bytes = 3109584 } seq expand size = 6449464 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0319 GB dict = 1.08 MB all = 0.0379 GB } UnZip/Zip{ index = 10.5135 value = 3.3941 dict = 1.00 all = 3.5418 } Zip/UnZip{ index = 0.0951 value = 0.2946 dict = 1.00 all = 0.2823 } ---------------------------- total value len = 0.114869 GB avg = 0.125 KB (by entry num) total key len = 0.025798 GB avg = 0.028 KB total ukey len = 0.018427 GB avg = 0.020 KB total ukey num = 0.000921352 Billion total entry num = 0.000921352 Billion write speed all = 0.005183266 MB/sec (with seq num) write speed all = 0.004911668 MB/sec (without seq num) 2024/11/22-16:24:41.860047 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214352: 921352 keys, 37895496 bytes, temperature: kWarm 2024/11/22-16:24:41.860158 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263881860089, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214352, "file_size": 37895496, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701203, "largest_seqno": 3376771409, "table_properties": {"data_size": 31943376, "index_size": 1752704, "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": 25797856, "raw_average_key_size": 28, "raw_value_size": 108419924, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921352, "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": 1732263876, "oldest_key_time": 0, "file_creation_time": 1732263876, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214352, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:24:41.930824 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst) /dev/shm/ToplingTemp/Topling-197238-LezPln 2024/11/22-16:24:43.412204 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst): first pass time = 1.48's, 90.606'MB/sec 2024/11/22-16:24:45.981477 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst): old prealloc_size = 147639500, real_size = 37080336 2024/11/22-16:24:45.982058 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927105 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.1083 GB zip-val = 0.0351 GB avg-val = 116.77 avg-zval = 37.83 2024/11/22-16:24:45.982339 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:24:47.219086 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214353.sst): second pass time = 2.57's, 42.145'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.24's, 31.407'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3170.519'MB/sec (index lex order gen) rebuild zvType time = 1.06's, 0.219'MB/sec write SST data time = 0.18's, 218.995'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.080'MB, throughput = 33502.373'MB/sec zip my value time = 2.57's, unzip length = 0.108'GB zip my value throughput = 42.145'MB/sec zip pipeline throughput = 98.940'MB/sec entries = 927105 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.77 avg-zval = 37.83 usrkeys = 927105 avg-key = 20.00 avg-zkey = 1.92 avg-val = 118.53 avg-zval = 37.83 TagRS{ kinds = RS_Key0_TagN bytes = 144960 } TagArray{ size = 232806 bytes = 785728 } seq expand size = 1629642 multi value expand size = 0 cnt WriteAppend = 15 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0351 GB dict = 1.08 MB all = 0.0389 GB } UnZip/Zip{ index = 10.4438 value = 3.0867 dict = 1.00 all = 3.4531 } Zip/UnZip{ index = 0.0958 value = 0.3240 dict = 1.00 all = 0.2896 } ---------------------------- total value len = 0.224758 GB avg = 0.122 KB (by entry num) total key len = 0.051757 GB avg = 0.028 KB total ukey len = 0.036969 GB avg = 0.020 KB total ukey num = 0.001848457 Billion total entry num = 0.001848457 Billion write speed all = 0.010186908 MB/sec (with seq num) write speed all = 0.009642125 MB/sec (without seq num) 2024/11/22-16:24:47.256866 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214353: 927105 keys, 38869029 bytes, temperature: kWarm 2024/11/22-16:24:47.256926 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263887256895, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214353, "file_size": 38869029, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3376772235, "table_properties": {"data_size": 35072960, "index_size": 1775424, "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": 25958940, "raw_average_key_size": 28, "raw_value_size": 108258870, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927105, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732263881, "oldest_key_time": 0, "file_creation_time": 1732263881, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214353, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:24:47.302543 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst) /dev/shm/ToplingTemp/Topling-197238-kCm9pp 2024/11/22-16:24:48.741265 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst): first pass time = 1.44's, 93.292'MB/sec 2024/11/22-16:24:50.536235 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst): old prealloc_size = 147639500, real_size = 33993968 2024/11/22-16:24:50.536764 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921221 prefix = 4 raw-key = 0.0147 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1084 GB zip-val = 0.0320 GB avg-val = 117.70 avg-zval = 34.74 2024/11/22-16:24:50.537736 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:24:51.744500 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214354.sst): second pass time = 1.79's, 60.432'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.21's, 31.420'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3484.884'MB/sec (index lex order gen) rebuild zvType time = 0.97's, 0.237'MB/sec write SST data time = 0.24's, 160.749'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 35407.913'MB/sec zip my value time = 1.79's, unzip length = 0.108'GB zip my value throughput = 60.432'MB/sec zip pipeline throughput = 60.432'MB/sec entries = 921221 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.70 avg-zval = 34.74 usrkeys = 921221 avg-key = 20.00 avg-zkey = 1.91 avg-val = 124.70 avg-zval = 34.74 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921221 bytes = 3109136 } seq expand size = 6448547 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0320 GB dict = 1.08 MB all = 0.0380 GB } UnZip/Zip{ index = 10.4449 value = 3.3883 dict = 1.00 all = 3.5355 } Zip/UnZip{ index = 0.0957 value = 0.2951 dict = 1.00 all = 0.2828 } ---------------------------- total value len = 0.339630 GB avg = 0.123 KB (by entry num) total key len = 0.077551 GB avg = 0.028 KB total ukey len = 0.055394 GB avg = 0.020 KB total ukey num = 0.002769678 Billion total entry num = 0.002769678 Billion write speed all = 0.015366552 MB/sec (with seq num) write speed all = 0.014550400 MB/sec (without seq num) 2024/11/22-16:24:51.783773 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214354: 921221 keys, 37962402 bytes, temperature: kWarm 2024/11/22-16:24:51.783863 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263891783819, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214354, "file_size": 37962402, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701510, "largest_seqno": 3376771994, "table_properties": {"data_size": 31999520, "index_size": 1763968, "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": 25794188, "raw_average_key_size": 28, "raw_value_size": 108423678, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921221, "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": 1732263887, "oldest_key_time": 0, "file_creation_time": 1732263887, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214354, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:24:51.841768 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst) /dev/shm/ToplingTemp/Topling-197238-vTQzgr 2024/11/22-16:24:53.386864 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst): first pass time = 1.55's, 86.870'MB/sec 2024/11/22-16:24:55.141116 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst): old prealloc_size = 147639500, real_size = 34450768 2024/11/22-16:24:55.141659 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 923126 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0325 GB avg-val = 117.39 avg-zval = 35.17 2024/11/22-16:24:55.142412 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:24:56.046310 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214355.sst): second pass time = 1.75's, 61.798'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.91's, 42.449'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3367.607'MB/sec (index lex order gen) rebuild zvType time = 0.78's, 0.297'MB/sec write SST data time = 0.13's, 301.554'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.083'MB, throughput = 39994.754'MB/sec zip my value time = 1.75's, unzip length = 0.108'GB zip my value throughput = 61.798'MB/sec zip pipeline throughput = 97.064'MB/sec entries = 923126 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.39 avg-zval = 35.17 usrkeys = 923126 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.39 avg-zval = 35.17 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 923126 bytes = 3115568 } seq expand size = 6461882 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0325 GB dict = 1.08 MB all = 0.0384 GB } UnZip/Zip{ index = 10.5126 value = 3.3382 dict = 1.00 all = 3.4931 } Zip/UnZip{ index = 0.0951 value = 0.2996 dict = 1.00 all = 0.2863 } ---------------------------- total value len = 0.454462 GB avg = 0.123 KB (by entry num) total key len = 0.103399 GB avg = 0.028 KB total ukey len = 0.073856 GB avg = 0.020 KB total ukey num = 0.003692804 Billion total entry num = 0.003692804 Billion write speed all = 0.020545124 MB/sec (with seq num) write speed all = 0.019457123 MB/sec (without seq num) 2024/11/22-16:24:56.078912 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214355: 923126 keys, 38423986 bytes, temperature: kWarm 2024/11/22-16:24:56.078977 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263896078943, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214355, "file_size": 38423986, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701530, "largest_seqno": 3376772199, "table_properties": {"data_size": 32463552, "index_size": 1756224, "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": 25847528, "raw_average_key_size": 28, "raw_value_size": 108370216, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 923126, "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": 1732263891, "oldest_key_time": 0, "file_creation_time": 1732263891, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214355, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:24:56.116762 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst) /dev/shm/ToplingTemp/Topling-197238-0tkbqo 2024/11/22-16:24:56.950746 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst): first pass time = 0.83's, 160.944'MB/sec 2024/11/22-16:24:58.445406 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst): old prealloc_size = 147639500, real_size = 33890208 2024/11/22-16:24:58.445983 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921177 prefix = 4 raw-key = 0.0147 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0319 GB avg-val = 117.70 avg-zval = 34.64 2024/11/22-16:24:58.446727 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:24:59.374681 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214356.sst): second pass time = 1.49's, 72.572'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.93's, 40.740'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3150.348'MB/sec (index lex order gen) rebuild zvType time = 0.80's, 0.288'MB/sec write SST data time = 0.13's, 290.784'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 37359.835'MB/sec zip my value time = 1.49's, unzip length = 0.108'GB zip my value throughput = 72.572'MB/sec zip pipeline throughput = 76.474'MB/sec entries = 921177 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.70 avg-zval = 34.64 usrkeys = 921177 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.70 avg-zval = 34.64 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921177 bytes = 3108992 } seq expand size = 6448239 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0319 GB dict = 1.08 MB all = 0.0379 GB } UnZip/Zip{ index = 10.5157 value = 3.3981 dict = 1.00 all = 3.5453 } Zip/UnZip{ index = 0.0951 value = 0.2943 dict = 1.00 all = 0.2821 } ---------------------------- total value len = 0.569335 GB avg = 0.123 KB (by entry num) total key len = 0.129191 GB avg = 0.028 KB total ukey len = 0.092280 GB avg = 0.020 KB total ukey num = 0.004613981 Billion total entry num = 0.004613981 Billion write speed all = 0.025722477 MB/sec (with seq num) write speed all = 0.024363239 MB/sec (without seq num) 2024/11/22-16:24:59.407241 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214356: 921177 keys, 37858358 bytes, temperature: kWarm 2024/11/22-16:24:59.407300 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263899407268, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214356, "file_size": 37858358, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701561, "largest_seqno": 3376772436, "table_properties": {"data_size": 31907728, "index_size": 1752000, "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": 25792956, "raw_average_key_size": 28, "raw_value_size": 108424826, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921177, "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": 1732263896, "oldest_key_time": 0, "file_creation_time": 1732263896, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214356, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:24:59.441792 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst) /dev/shm/ToplingTemp/Topling-197238-ImSxRn 2024/11/22-16:25:00.244827 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst): first pass time = 0.80's, 167.145'MB/sec 2024/11/22-16:25:01.795978 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst): old prealloc_size = 147639500, real_size = 34348736 2024/11/22-16:25:01.796521 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 923163 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0324 GB avg-val = 117.39 avg-zval = 35.05 2024/11/22-16:25:01.797255 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:25:02.701699 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214357.sst): second pass time = 1.55's, 69.891'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.91's, 42.312'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3380.687'MB/sec (index lex order gen) rebuild zvType time = 0.78's, 0.298'MB/sec write SST data time = 0.13's, 294.417'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.083'MB, throughput = 35388.769'MB/sec zip my value time = 1.55's, unzip length = 0.108'GB zip my value throughput = 69.891'MB/sec zip pipeline throughput = 109.980'MB/sec entries = 923163 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.39 avg-zval = 35.05 usrkeys = 923163 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.39 avg-zval = 35.05 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 923163 bytes = 3115696 } seq expand size = 6462141 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0324 GB dict = 1.08 MB all = 0.0383 GB } UnZip/Zip{ index = 10.5115 value = 3.3487 dict = 1.00 all = 3.5024 } Zip/UnZip{ index = 0.0951 value = 0.2986 dict = 1.00 all = 0.2855 } ---------------------------- total value len = 0.684167 GB avg = 0.124 KB (by entry num) total key len = 0.155040 GB avg = 0.028 KB total ukey len = 0.110743 GB avg = 0.020 KB total ukey num = 0.005537144 Billion total entry num = 0.005537144 Billion write speed all = 0.030899074 MB/sec (with seq num) write speed all = 0.029268080 MB/sec (without seq num) 2024/11/22-16:25:02.737926 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214357: 923163 keys, 38322124 bytes, temperature: kWarm 2024/11/22-16:25:02.737986 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263902737956, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214357, "file_size": 38322124, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701573, "largest_seqno": 3376772279, "table_properties": {"data_size": 32361264, "index_size": 1756480, "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": 25848564, "raw_average_key_size": 28, "raw_value_size": 108369194, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 923163, "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": 1732263899, "oldest_key_time": 0, "file_creation_time": 1732263899, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214357, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:25:02.775170 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst) /dev/shm/ToplingTemp/Topling-197238-3c2YBr 2024/11/22-16:25:03.652587 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst): first pass time = 0.88's, 152.976'MB/sec 2024/11/22-16:25:05.231925 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst): old prealloc_size = 147639500, real_size = 34009264 2024/11/22-16:25:05.232476 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921157 prefix = 4 raw-key = 0.0147 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0320 GB avg-val = 117.71 avg-zval = 34.77 2024/11/22-16:25:05.233198 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:25:06.157855 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214358.sst): second pass time = 1.58's, 68.699'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.93's, 41.016'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3325.268'MB/sec (index lex order gen) rebuild zvType time = 0.80's, 0.289'MB/sec write SST data time = 0.13's, 292.883'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 33774.758'MB/sec zip my value time = 1.58's, unzip length = 0.108'GB zip my value throughput = 68.699'MB/sec zip pipeline throughput = 112.918'MB/sec entries = 921157 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.71 avg-zval = 34.77 usrkeys = 921157 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.71 avg-zval = 34.77 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921157 bytes = 3108912 } seq expand size = 6448099 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0320 GB dict = 1.08 MB all = 0.0380 GB } UnZip/Zip{ index = 10.5105 value = 3.3855 dict = 1.00 all = 3.5342 } Zip/UnZip{ index = 0.0951 value = 0.2954 dict = 1.00 all = 0.2830 } ---------------------------- total value len = 0.799040 GB avg = 0.124 KB (by entry num) total key len = 0.180832 GB avg = 0.028 KB total ukey len = 0.129166 GB avg = 0.020 KB total ukey num = 0.006458301 Billion total entry num = 0.006458301 Billion write speed all = 0.036073713 MB/sec (with seq num) write speed all = 0.034171630 MB/sec (without seq num) 2024/11/22-16:25:06.202300 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214358: 921157 keys, 37977240 bytes, temperature: kWarm 2024/11/22-16:25:06.202371 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263906202332, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214358, "file_size": 37977240, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701604, "largest_seqno": 3376772091, "table_properties": {"data_size": 32025952, "index_size": 1752832, "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": 25792396, "raw_average_key_size": 28, "raw_value_size": 108425354, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921157, "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": 1732263902, "oldest_key_time": 0, "file_creation_time": 1732263902, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214358, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:25:06.237049 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst) /dev/shm/ToplingTemp/Topling-197238-rcDOVn 2024/11/22-16:25:07.038622 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst): first pass time = 0.80's, 167.451'MB/sec 2024/11/22-16:25:08.661940 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst): old prealloc_size = 147639500, real_size = 34334064 2024/11/22-16:25:08.662466 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 923121 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1084 GB zip-val = 0.0323 GB avg-val = 117.40 avg-zval = 35.04 2024/11/22-16:25:08.663221 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-16:25:09.566770 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214359.sst): second pass time = 1.62's, 66.789'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.90's, 42.337'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3481.069'MB/sec (index lex order gen) rebuild zvType time = 0.77's, 0.298'MB/sec write SST data time = 0.13's, 295.124'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.083'MB, throughput = 38681.029'MB/sec zip my value time = 1.62's, unzip length = 0.108'GB zip my value throughput = 66.789'MB/sec zip pipeline throughput = 114.833'MB/sec entries = 923121 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.40 avg-zval = 35.04 usrkeys = 923121 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.40 avg-zval = 35.04 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 923121 bytes = 3115552 } seq expand size = 6461847 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0323 GB dict = 1.08 MB all = 0.0383 GB } UnZip/Zip{ index = 10.5137 value = 3.3502 dict = 1.00 all = 3.5037 } Zip/UnZip{ index = 0.0951 value = 0.2985 dict = 1.00 all = 0.2854 } ---------------------------- total value len = 0.913872 GB avg = 0.124 KB (by entry num) total key len = 0.206680 GB avg = 0.028 KB total ukey len = 0.147628 GB avg = 0.020 KB total ukey num = 0.007381422 Billion total entry num = 0.007381422 Billion write speed all = 0.041247616 MB/sec (with seq num) write speed all = 0.039073930 MB/sec (without seq num) 2024/11/22-16:25:09.599719 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214359: 923121 keys, 38307338 bytes, temperature: kWarm 2024/11/22-16:25:09.599791 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263909599746, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214359, "file_size": 38307338, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3273701615, "largest_seqno": 3376772130, "table_properties": {"data_size": 32347040, "index_size": 1756032, "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": 25847388, "raw_average_key_size": 28, "raw_value_size": 108370422, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 923121, "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": 1732263906, "oldest_key_time": 0, "file_creation_time": 1732263906, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214359, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:25:09.638463 140024978429504 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst) /dev/shm/ToplingTemp/Topling-197238-9sohXo 2024/11/22-16:25:09.934332 140024978429504 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst): first pass time = 0.30's, 207.976'MB/sec 2024/11/22-16:25:10.539174 140024978429504 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst): old prealloc_size = 147639500, real_size = 15980800 2024/11/22-16:25:10.539471 140024978429504 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 423317 prefix = 4 raw-key = 0.0068 GB zip-key = 0.0008 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0497 GB zip-val = 0.0151 GB avg-val = 117.34 avg-zval = 35.58 2024/11/22-16:25:10.539835 140024978429504 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0010 GB, waited 0.000 sec, Key+Value = 0.062 GB 2024/11/22-16:25:10.981733 140024978429504 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00/214360.sst): second pass time = 0.60's, 82.211'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.44's, 40.223'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2942.123'MB/sec (index lex order gen) rebuild zvType time = 0.38's, 0.278'MB/sec write SST data time = 0.06's, 290.000'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.504'MB, throughput = 18420.033'MB/sec zip my value time = 0.60's, unzip length = 0.050'GB zip my value throughput = 82.211'MB/sec zip pipeline throughput = 82.211'MB/sec entries = 423317 avg-key = 28.00 avg-zkey = 1.92 avg-val = 117.34 avg-zval = 35.58 usrkeys = 423317 avg-key = 20.00 avg-zkey = 1.92 avg-val = 124.21 avg-zval = 35.58 TagRS{ kinds = RS_Key0_TagN bytes = 66240 } TagArray{ size = 415508 bytes = 1350416 } seq expand size = 2908556 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0085 GB value = 0.0497 GB dict = 0.50 MB all = 0.0615 GB } __ZipSize{ index = 0.0008 GB value = 0.0151 GB dict = 0.50 MB all = 0.0178 GB } UnZip/Zip{ index = 10.4360 value = 3.2976 dict = 1.00 all = 3.4564 } Zip/UnZip{ index = 0.0958 value = 0.3033 dict = 1.00 all = 0.2893 } ---------------------------- total value len = 0.966454 GB avg = 0.124 KB (by entry num) total key len = 0.218533 GB avg = 0.028 KB total ukey len = 0.156095 GB avg = 0.020 KB total ukey num = 0.007804739 Billion total entry num = 0.007804739 Billion write speed all = 0.043617184 MB/sec (with seq num) write speed all = 0.041318959 MB/sec (without seq num) 2024/11/22-16:25:11.000324 140024978429504 [compaction_job.cc:1948] [default] [JOB 4458] Generated table #214360: 423317 keys, 17800535 bytes, temperature: kWarm 2024/11/22-16:25:11.000383 140024978429504 EVENT_LOG_v1 {"time_micros": 1732263911000353, "cf_name": "default", "job": 4458, "event": "table_file_creation", "file_number": 214360, "file_size": 17800535, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3376772338, "table_properties": {"data_size": 15063536, "index_size": 811264, "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": 11852876, "raw_average_key_size": 28, "raw_value_size": 49673066, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 423317, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732263909, "oldest_key_time": 0, "file_creation_time": 1732263909, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 214360, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-16:25:11.016719 140024978429504 [compaction_job.cc:703] job-04458: subcompact[0], size: 0.323417 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-04458/att-00 [214352,214353,214354,214355,214356,214357,214358,214359,214360] 2024/11/22-16:25:11.080198 140024978429504 (Original Log Time 2024/11/22-16:24:36.487434) EVENT_LOG_v1 {"time_micros": 1732263876487391, "job": 4458, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [214340], "files_L3": [214288, 214289, 214290, 214291, 214292, 214293, 214294, 214258, 214259, 214260], "score": 0.880878, "input_data_size": 343489795, "oldest_snapshot_seqno": 3376826937} 2024/11/22-16:25:11.080201 140024978429504 (Original Log Time 2024/11/22-16:25:11.079620) [compaction_job.cc:2022] [default] [JOB 4458] Compacted 1@2 + 10@3 files to L3 => 323416508 bytes 2024/11/22-16:25:11.080203 140024978429504 (Original Log Time 2024/11/22-16:25:11.080133) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.01, MB/sec: 9.9 rd, 9.4 wr, level 3, files in(1, 10) out(9 +0 blob) MB in(23.0, 304.6 +0.0 blob) out(308.4 +0.0 blob), read-write-amplify(27.6) write-amplify(13.4) OK, records in: 7896789, records dropped: 92050 output_compression: Snappy 2024/11/22-16:25:11.080209 140024978429504 (Original Log Time 2024/11/22-16:25:11.080178) EVENT_LOG_v1 {"time_micros": 1732263911080158, "cf": "default", "job": 4458, "event": "compaction_finished", "compaction_time_micros": 34529293, "compaction_time_cpu_micros": 14446017, "output_level": 3, "num_output_files": 9, "total_output_size": 323416508, "num_input_records": 7896789, "num_output_records": 7804739, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 219442260, "file_range_sync_nanos": 0, "file_fsync_nanos": 8069, "file_prepare_write_nanos": 20180, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/22-16:25:11.209032 140024978429504 DEBG dcompact_worker.cpp:240: HttpPost: 200 OK: url = http://nlb-7zny4kaa1poal01o64.cn-shenzhen.nlb.aliyuncs.com:8443, body = {"instanceId":"nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137","labourId":"","dbId":"d89b4006-2803-486e-b7a2-759bcf348921","dbStarts":1732256054,"starts":1732263876,"executesMs":34714,"compactionJobId":4458,"attempt":0,"compactionInputRawBytes":1148339342,"compactionInputZipBytes":343489795,"compactionOutputRawBytes":0,"compactionOutputZipBytes":323416508,"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-5bd52d7bd3ded525dc3e3d36c5701b26-e5e557d7aab91bd6-00"}}, response = 2024/11/22-16:25:11.209109 140024978429504 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-04458/att-00: olev 3, work 34.714 s, result 6.357 ms, install 0.608 ms, input{raw 1.069 GiB zip 327.577 MiB}