2024/11/22-21:35:25.223418 140024886109760 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00: fork to child time = 0.009256 sec 2024/11/22-21:35:25.224377 140024886109760 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00 2024/11/22-21:35:25.231702 140024886109760 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00 2024/11/22-21:35:25.232869 140024886109760 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/22-21:35:25.233157 140024886109760 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/22-21:35:25.280325 140024886109760 [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-11668/att-00/MANIFEST-206347 2024/11/22-21:35:25.312297 140024886109760 [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-11668/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 229050, last_sequence is 3579476793, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 228828 2024/11/22-21:35:25.312304 140024886109760 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/22-21:35:25.312371 140024886109760 [version_set.cc:5721] Creating manifest 229050 2024/11/22-21:35:25.341416 140024886109760 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/22-21:35:25.361251 140024886109760 [compaction_job.cc:2437] [default] [JOB 11668] Compacting 1@2 + 7@3 files to L3, score 1.00, subcompactions 1 : 1 2024/11/22-21:35:25.361267 140024886109760 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 8790 Base level 2, inputs: [228969(11MB)], [229037(12MB) 228893(33MB) 228894(37MB) 228925(35MB) 228926(35MB) 228927(35MB) 229038(35MB)] 2024/11/22-21:35:25.365562 140024886109760 [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-21:35:25.365593 140024886109760 [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-21:35:25.365614 140024886109760 [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-21:35:25.365619 140024886109760 [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-21:35:25.365630 140024886109760 [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-21:35:25.543287 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.sst) /dev/shm/ToplingTemp/Topling-299587-KahWWA 2024/11/22-21:35:26.326116 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.sst): first pass time = 0.78's, 171.460'MB/sec 2024/11/22-21:35:27.659914 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.sst): old prealloc_size = 147639500, real_size = 33332480 2024/11/22-21:35:27.660461 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 924419 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1083 GB zip-val = 0.0313 GB avg-val = 117.19 avg-zval = 33.89 2024/11/22-21:35:27.661282 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.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-21:35:28.603019 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229051.sst): second pass time = 1.33's, 81.283'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.94's, 39.682'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3353.196'MB/sec (index lex order gen) rebuild zvType time = 0.81's, 0.285'MB/sec write SST data time = 0.13's, 284.937'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.082'MB, throughput = 32002.722'MB/sec zip my value time = 1.33's, unzip length = 0.108'GB zip my value throughput = 81.283'MB/sec zip pipeline throughput = 81.283'MB/sec entries = 924419 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.19 avg-zval = 33.89 usrkeys = 924419 avg-key = 20.00 avg-zkey = 1.91 avg-val = 124.19 avg-zval = 33.89 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 924419 bytes = 3235488 } seq expand size = 6470933 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0313 GB dict = 1.08 MB all = 0.0374 GB } UnZip/Zip{ index = 10.4451 value = 3.4577 dict = 1.00 all = 3.5864 } Zip/UnZip{ index = 0.0957 value = 0.2892 dict = 1.00 all = 0.2788 } ---------------------------- total value len = 0.114805 GB avg = 0.124 KB (by entry num) total key len = 0.025884 GB avg = 0.028 KB total ukey len = 0.018488 GB avg = 0.020 KB total ukey num = 0.000924419 Billion total entry num = 0.000924419 Billion write speed all = 0.003072778 MB/sec (with seq num) write speed all = 0.002911256 MB/sec (without seq num) 2024/11/22-21:35:28.644661 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229051: 924419 keys, 37424236 bytes, temperature: kWarm 2024/11/22-21:35:28.644761 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282528644704, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229051, "file_size": 37424236, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3376774735, "largest_seqno": 3578827423, "table_properties": {"data_size": 31331120, "index_size": 1770048, "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": 25883732, "raw_average_key_size": 28, "raw_value_size": 108334022, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 924419, "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": 1732282525, "oldest_key_time": 0, "file_creation_time": 1732282525, "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": 229051, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:28.681732 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.sst) /dev/shm/ToplingTemp/Topling-299587-MPYVTA 2024/11/22-21:35:29.525776 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.sst): first pass time = 0.84's, 159.025'MB/sec 2024/11/22-21:35:30.868824 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.sst): old prealloc_size = 147639500, real_size = 33889376 2024/11/22-21:35:30.869347 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 928830 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1082 GB zip-val = 0.0319 GB avg-val = 116.50 avg-zval = 34.33 2024/11/22-21:35:30.870108 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.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-21:35:31.781212 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229052.sst): second pass time = 1.34's, 80.614'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.91's, 41.643'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3525.712'MB/sec (index lex order gen) rebuild zvType time = 0.78's, 0.297'MB/sec write SST data time = 0.13's, 293.115'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 = 23737.678'MB/sec zip my value time = 1.34's, unzip length = 0.108'GB zip my value throughput = 80.614'MB/sec zip pipeline throughput = 80.614'MB/sec entries = 928830 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.50 avg-zval = 34.33 usrkeys = 928830 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.50 avg-zval = 34.33 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 928830 bytes = 3250912 } seq expand size = 6501810 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0319 GB dict = 1.08 MB all = 0.0380 GB } UnZip/Zip{ index = 10.5147 value = 3.3932 dict = 1.00 all = 3.5326 } Zip/UnZip{ index = 0.0951 value = 0.2947 dict = 1.00 all = 0.2831 } ---------------------------- total value len = 0.229517 GB avg = 0.124 KB (by entry num) total key len = 0.051891 GB avg = 0.028 KB total ukey len = 0.037065 GB avg = 0.020 KB total ukey num = 0.001853249 Billion total entry num = 0.001853249 Billion write speed all = 0.006145806 MB/sec (with seq num) write speed all = 0.005822014 MB/sec (without seq num) 2024/11/22-21:35:31.823899 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229052: 928830 keys, 37993604 bytes, temperature: kWarm 2024/11/22-21:35:31.823966 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282531823932, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229052, "file_size": 37993604, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3376774746, "largest_seqno": 3578826794, "table_properties": {"data_size": 31890256, "index_size": 1766720, "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": 26007240, "raw_average_key_size": 28, "raw_value_size": 108210616, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 928830, "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": 1732282528, "oldest_key_time": 0, "file_creation_time": 1732282528, "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": 229052, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:31.861620 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.sst) /dev/shm/ToplingTemp/Topling-299587-Aw5oqy 2024/11/22-21:35:32.789201 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.sst): first pass time = 0.93's, 144.705'MB/sec 2024/11/22-21:35:34.139075 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.sst): old prealloc_size = 147639500, real_size = 34261312 2024/11/22-21:35:34.139589 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925575 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1083 GB zip-val = 0.0323 GB avg-val = 117.01 avg-zval = 34.85 2024/11/22-21:35:34.140323 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.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-21:35:35.044246 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229053.sst): second pass time = 1.35's, 80.267'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.91's, 42.058'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3568.976'MB/sec (index lex order gen) rebuild zvType time = 0.77's, 0.300'MB/sec write SST data time = 0.13's, 285.430'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 35538.376'MB/sec zip my value time = 1.35's, unzip length = 0.108'GB zip my value throughput = 80.267'MB/sec zip pipeline throughput = 80.267'MB/sec entries = 925575 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.01 avg-zval = 34.85 usrkeys = 925575 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.29 avg-zval = 34.85 TagRS{ kinds = RS_Key0_TagN bytes = 144720 } TagArray{ size = 830804 bytes = 2803984 } seq expand size = 5815628 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.0323 GB dict = 1.08 MB all = 0.0381 GB } UnZip/Zip{ index = 10.4469 value = 3.3574 dict = 1.00 all = 3.5257 } Zip/UnZip{ index = 0.0957 value = 0.2979 dict = 1.00 all = 0.2836 } ---------------------------- total value len = 0.343635 GB avg = 0.124 KB (by entry num) total key len = 0.077807 GB avg = 0.028 KB total ukey len = 0.055576 GB avg = 0.020 KB total ukey num = 0.002778824 Billion total entry num = 0.002778824 Billion write speed all = 0.009203402 MB/sec (with seq num) write speed all = 0.008717933 MB/sec (without seq num) 2024/11/22-21:35:35.088737 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229053: 925575 keys, 38068898 bytes, temperature: kWarm 2024/11/22-21:35:35.088804 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282535088767, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229053, "file_size": 38068898, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3578828030, "table_properties": {"data_size": 32257776, "index_size": 1771968, "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": 25916100, "raw_average_key_size": 28, "raw_value_size": 108301630, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 925575, "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": 1732282531, "oldest_key_time": 0, "file_creation_time": 1732282531, "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": 229053, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:35.125699 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst) /dev/shm/ToplingTemp/Topling-299587-OcFxXw 2024/11/22-21:35:36.009281 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst): first pass time = 0.88's, 151.909'MB/sec 2024/11/22-21:35:37.406366 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst): old prealloc_size = 147639500, real_size = 34986848 2024/11/22-21:35:37.407014 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 1081665 prefix = 4 raw-key = 0.0173 GB zip-key = 0.0021 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1039 GB zip-val = 0.0327 GB avg-val = 96.08 avg-zval = 30.19 2024/11/22-21:35:37.407068 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst: sumWaitingMem = 0.003 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0028 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-21:35:38.034516 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229054.sst): second pass time = 1.40's, 74.428'MB/sec, value only(77.4% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.63's, 56.935'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3285.734'MB/sec (index lex order gen) rebuild zvType time = 0.49's, 0.557'MB/sec write SST data time = 0.14's, 251.963'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.036'MB, throughput = 27207.087'MB/sec zip my value time = 1.40's, unzip length = 0.104'GB zip my value throughput = 74.428'MB/sec zip pipeline throughput = 74.428'MB/sec entries = 1081665 avg-key = 28.00 avg-zkey = 1.90 avg-val = 96.08 avg-zval = 30.19 usrkeys = 1081665 avg-key = 20.00 avg-zkey = 1.90 avg-val = 96.08 avg-zval = 30.19 TagRS{ kinds = LegacyZvType bytes = 0 } TagArray{ size = 0 bytes = 0 } seq expand size = 0 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0216 GB value = 0.1039 GB dict = 1.04 MB all = 0.1342 GB } __ZipSize{ index = 0.0021 GB value = 0.0327 GB dict = 1.04 MB all = 0.0358 GB } UnZip/Zip{ index = 10.5155 value = 3.1823 dict = 1.00 all = 3.7530 } Zip/UnZip{ index = 0.0951 value = 0.3142 dict = 1.00 all = 0.2665 } ---------------------------- total value len = 0.447566 GB avg = 0.116 KB (by entry num) total key len = 0.108094 GB avg = 0.028 KB total ukey len = 0.077210 GB avg = 0.020 KB total ukey num = 0.003860489 Billion total entry num = 0.003860489 Billion write speed all = 0.012133644 MB/sec (with seq num) write speed all = 0.011459248 MB/sec (without seq num) 2024/11/22-21:35:38.075150 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229054: 1081665 keys, 35762843 bytes, temperature: kWarm 2024/11/22-21:35:38.075212 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282538075181, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229054, "file_size": 35762843, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 0, "table_properties": {"data_size": 32658960, "index_size": 2057280, "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": 30286620, "raw_average_key_size": 28, "raw_value_size": 103931135, "raw_average_value_size": 96, "num_data_blocks": 1, "num_entries": 1081665, "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": "TooZip", "compression_options": "LegacyZvType-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732282535, "oldest_key_time": 0, "file_creation_time": 1732282535, "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": 229054, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:38.113238 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.sst) /dev/shm/ToplingTemp/Topling-299587-OSbU9A 2024/11/22-21:35:38.981326 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.sst): first pass time = 0.87's, 154.621'MB/sec 2024/11/22-21:35:40.285130 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.sst): old prealloc_size = 147639500, real_size = 33673088 2024/11/22-21:35:40.285660 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921023 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.0317 GB avg-val = 117.73 avg-zval = 34.41 2024/11/22-21:35:40.286315 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.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-21:35:41.164325 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229055.sst): second pass time = 1.30's, 83.209'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.88's, 42.369'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3469.949'MB/sec (index lex order gen) rebuild zvType time = 0.75's, 0.309'MB/sec write SST data time = 0.13's, 279.974'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 = 35048.543'MB/sec zip my value time = 1.30's, unzip length = 0.108'GB zip my value throughput = 83.209'MB/sec zip pipeline throughput = 83.209'MB/sec entries = 921023 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.73 avg-zval = 34.41 usrkeys = 921023 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.12 avg-zval = 34.41 TagRS{ kinds = RS_Key0_TagN bytes = 144000 } TagArray{ size = 709056 bytes = 2570336 } seq expand size = 4963392 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0184 GB value = 0.1084 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0317 GB dict = 1.08 MB all = 0.0373 GB } UnZip/Zip{ index = 10.5136 value = 3.4215 dict = 1.00 all = 3.6031 } Zip/UnZip{ index = 0.0951 value = 0.2923 dict = 1.00 all = 0.2775 } ---------------------------- total value len = 0.560958 GB avg = 0.117 KB (by entry num) total key len = 0.133882 GB avg = 0.028 KB total ukey len = 0.095630 GB avg = 0.020 KB total ukey num = 0.004781512 Billion total entry num = 0.004781512 Billion write speed all = 0.015171833 MB/sec (with seq num) write speed all = 0.014336599 MB/sec (without seq num) 2024/11/22-21:35:41.206080 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229055: 921023 keys, 37250344 bytes, temperature: kWarm 2024/11/22-21:35:41.206144 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282541206113, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229055, "file_size": 37250344, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3569326496, "table_properties": {"data_size": 31690608, "index_size": 1752064, "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": 25788644, "raw_average_key_size": 28, "raw_value_size": 108429146, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921023, "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": 1732282538, "oldest_key_time": 0, "file_creation_time": 1732282538, "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": 229055, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:41.242032 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.sst) /dev/shm/ToplingTemp/Topling-299587-xOCTLy 2024/11/22-21:35:42.034831 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.sst): first pass time = 0.79's, 169.304'MB/sec 2024/11/22-21:35:43.389655 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.sst): old prealloc_size = 147639500, real_size = 33334192 2024/11/22-21:35:43.390187 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927624 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1082 GB zip-val = 0.0313 GB avg-val = 116.69 avg-zval = 33.78 2024/11/22-21:35:43.390949 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.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-21:35:44.306454 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229056.sst): second pass time = 1.35's, 79.936'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.92's, 40.833'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3454.231'MB/sec (index lex order gen) rebuild zvType time = 0.79's, 0.295'MB/sec write SST data time = 0.13's, 289.034'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 = 23508.032'MB/sec zip my value time = 1.35's, unzip length = 0.108'GB zip my value throughput = 79.936'MB/sec zip pipeline throughput = 79.936'MB/sec entries = 927624 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.69 avg-zval = 33.78 usrkeys = 927624 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.69 avg-zval = 33.78 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 927624 bytes = 3246704 } seq expand size = 6493368 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0313 GB dict = 1.08 MB all = 0.0374 GB } UnZip/Zip{ index = 10.5152 value = 3.4541 dict = 1.00 all = 3.5854 } Zip/UnZip{ index = 0.0951 value = 0.2895 dict = 1.00 all = 0.2789 } ---------------------------- total value len = 0.675696 GB avg = 0.118 KB (by entry num) total key len = 0.159856 GB avg = 0.028 KB total ukey len = 0.114183 GB avg = 0.020 KB total ukey num = 0.005709136 Billion total entry num = 0.005709136 Billion write speed all = 0.018243006 MB/sec (with seq num) write speed all = 0.017245804 MB/sec (without seq num) 2024/11/22-21:35:44.350681 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229056: 927624 keys, 37434838 bytes, temperature: kWarm 2024/11/22-21:35:44.350741 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282544350709, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229056, "file_size": 37434838, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3365258144, "largest_seqno": 3578828650, "table_properties": {"data_size": 31337760, "index_size": 1764352, "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": 25973472, "raw_average_key_size": 28, "raw_value_size": 108244288, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927624, "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": 1732282541, "oldest_key_time": 0, "file_creation_time": 1732282541, "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": 229056, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:44.390520 140024886109760 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst) /dev/shm/ToplingTemp/Topling-299587-dCUf9A 2024/11/22-21:35:44.614526 140024886109760 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst): first pass time = 0.22's, 246.498'MB/sec 2024/11/22-21:35:45.137475 140024886109760 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst): old prealloc_size = 147639500, real_size = 14150432 2024/11/22-21:35:45.137742 140024886109760 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 383200 prefix = 4 raw-key = 0.0061 GB zip-key = 0.0007 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0445 GB zip-val = 0.0133 GB avg-val = 116.07 avg-zval = 34.76 2024/11/22-21:35:45.138104 140024886109760 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0009 GB, waited 0.000 sec, Key+Value = 0.055 GB 2024/11/22-21:35:45.530379 140024886109760 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00/229057.sst): second pass time = 0.52's, 85.156'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.39's, 40.340'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3014.731'MB/sec (index lex order gen) rebuild zvType time = 0.34's, 0.282'MB/sec write SST data time = 0.05's, 297.103'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.451'MB, throughput = 14490.031'MB/sec zip my value time = 0.52's, unzip length = 0.044'GB zip my value throughput = 85.156'MB/sec zip pipeline throughput = 85.156'MB/sec entries = 383200 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.07 avg-zval = 34.76 usrkeys = 383200 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.07 avg-zval = 34.76 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 383200 bytes = 1341216 } seq expand size = 2682400 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0077 GB value = 0.0445 GB dict = 0.45 MB all = 0.0552 GB } __ZipSize{ index = 0.0007 GB value = 0.0133 GB dict = 0.45 MB all = 0.0158 GB } UnZip/Zip{ index = 10.4312 value = 3.3393 dict = 1.00 all = 3.4833 } Zip/UnZip{ index = 0.0959 value = 0.2995 dict = 1.00 all = 0.2871 } ---------------------------- total value len = 0.722857 GB avg = 0.119 KB (by entry num) total key len = 0.170585 GB avg = 0.028 KB total ukey len = 0.121847 GB avg = 0.020 KB total ukey num = 0.006092336 Billion total entry num = 0.006092336 Billion write speed all = 0.019506435 MB/sec (with seq num) write speed all = 0.018442329 MB/sec (without seq num) 2024/11/22-21:35:45.552112 140024886109760 [compaction_job.cc:1948] [default] [JOB 11668] Generated table #229057: 383200 keys, 15849515 bytes, temperature: kWarm 2024/11/22-21:35:45.552176 140024886109760 EVENT_LOG_v1 {"time_micros": 1732282545552143, "cf_name": "default", "job": 11668, "event": "table_file_creation", "file_number": 229057, "file_size": 15849515, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3384073716, "largest_seqno": 3578826355, "table_properties": {"data_size": 13319760, "index_size": 734720, "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": 10729600, "raw_average_key_size": 28, "raw_value_size": 44478452, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 383200, "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": 1732282544, "oldest_key_time": 0, "file_creation_time": 1732282544, "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": 229057, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-21:35:45.567058 140024886109760 [compaction_job.cc:703] job-11668: subcompact[0], size: 0.239784 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-11668/att-00 [229051,229052,229053,229054,229055,229056,229057] 2024/11/22-21:35:45.615537 140024886109760 (Original Log Time 2024/11/22-21:35:25.361323) EVENT_LOG_v1 {"time_micros": 1732282525361283, "job": 11668, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [228969], "files_L3": [229037, 228893, 228894, 228925, 228926, 228927, 229038], "score": 0.998823, "input_data_size": 248401500, "oldest_snapshot_seqno": 3579476793} 2024/11/22-21:35:45.615540 140024886109760 (Original Log Time 2024/11/22-21:35:45.612146) [compaction_job.cc:2022] [default] [JOB 11668] Compacted 1@2 + 7@3 files to L3 => 239784278 bytes 2024/11/22-21:35:45.615542 140024886109760 (Original Log Time 2024/11/22-21:35:45.615459) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 7 0 0 0] max score 0.01, MB/sec: 12.3 rd, 11.9 wr, level 3, files in(1, 7) out(7 +0 blob) MB in(11.7, 225.2 +0.0 blob) out(228.7 +0.0 blob), read-write-amplify(39.9) write-amplify(19.6) OK, records in: 6110605, records dropped: 18269 output_compression: Snappy 2024/11/22-21:35:45.615550 140024886109760 (Original Log Time 2024/11/22-21:35:45.615514) EVENT_LOG_v1 {"time_micros": 1732282545615493, "cf": "default", "job": 11668, "event": "compaction_finished", "compaction_time_micros": 20205742, "compaction_time_cpu_micros": 9128306, "output_level": 3, "num_output_files": 7, "total_output_size": 239784278, "num_input_records": 6110605, "num_output_records": 6092336, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 145283730, "file_range_sync_nanos": 0, "file_fsync_nanos": 6764, "file_prepare_write_nanos": 15516, "lsm_state": [0, 0, 0, 7, 0, 0, 0]} 2024/11/22-21:35:45.753890 140024886109760 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":1732282525,"executesMs":20383,"compactionJobId":11668,"attempt":0,"compactionInputRawBytes":863108895,"compactionInputZipBytes":248401500,"compactionOutputRawBytes":0,"compactionOutputZipBytes":239784278,"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-b762092ecb7bb563dc49503cf704614a-9a6148276f0c6795-00"}}, response = 2024/11/22-21:35:45.753965 140024886109760 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-11668/att-00: olev 3, work 20.384 s, result 4.957 ms, install 3.426 ms, input{raw 823.125 MiB zip 236.894 MiB}