2024/11/24-04:22:01.908250 139957651584576 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00: fork to child time = 0.007360 sec 2024/11/24-04:22:01.909029 139957651584576 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00 2024/11/24-04:22:01.914511 139957651584576 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00 2024/11/24-04:22:01.915426 139957651584576 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/24-04:22:01.915662 139957651584576 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/24-04:22:01.973354 139957651584576 [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-41457/att-00/MANIFEST-206347 2024/11/24-04:22:01.988785 139957651584576 [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-41457/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 291808, last_sequence is 4437077473, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 291589 2024/11/24-04:22:01.988792 139957651584576 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/24-04:22:01.988882 139957651584576 [version_set.cc:5721] Creating manifest 291808 2024/11/24-04:22:02.023172 139957651584576 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/24-04:22:02.043671 139957651584576 [compaction_job.cc:2437] [default] [JOB 41457] Compacting 1@2 + 9@3 files to L3, score 0.88, subcompactions 1 : 1 2024/11/24-04:22:02.043690 139957651584576 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 31058 Base level 2, inputs: [291734(11MB)], [291781(2029KB) 291649(35MB) 291650(35MB) 291651(33MB) 291652(35MB) 291653(35MB) 291654(33MB) 291655(34MB) 291782(35MB)] 2024/11/24-04:22:02.048754 139957651584576 [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/24-04:22:02.048796 139957651584576 [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/24-04:22:02.048819 139957651584576 [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/24-04:22:02.048825 139957651584576 [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/24-04:22:02.048833 139957651584576 [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/24-04:22:02.187586 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst) /dev/shm/ToplingTemp/Topling-268478-PJh2df 2024/11/24-04:22:03.083086 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst): first pass time = 0.90's, 149.888'MB/sec 2024/11/24-04:22:04.909778 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst): old prealloc_size = 147639500, real_size = 33210592 2024/11/24-04:22:04.910523 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 926934 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.0312 GB avg-val = 116.80 avg-zval = 33.66 2024/11/24-04:22:04.911403 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:05.972654 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291809.sst): second pass time = 1.82's, 59.346'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.06's, 35.102'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2461.132'MB/sec (index lex order gen) rebuild zvType time = 0.91's, 0.255'MB/sec write SST data time = 0.15's, 245.517'MB/sec dict compress time = 0.00's, 1069168.317'MB/sec z-dict build time = 0.00's, sample length = 1.080'MB, throughput = 34086.490'MB/sec zip my value time = 1.82's, unzip length = 0.108'GB zip my value throughput = 59.346'MB/sec zip pipeline throughput = 95.532'MB/sec entries = 926934 avg-key = 28.00 avg-zkey = 1.91 avg-val = 116.80 avg-zval = 33.66 usrkeys = 926934 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.80 avg-zval = 33.66 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 926934 bytes = 3244288 } seq expand size = 6488538 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0312 GB dict = 1.08 MB all = 0.0373 GB } UnZip/Zip{ index = 10.4445 value = 3.4696 dict = 1.00 all = 3.5975 } Zip/UnZip{ index = 0.0957 value = 0.2882 dict = 1.00 all = 0.2780 } ---------------------------- total value len = 2251.440325 GB avg = 0.200 KB (by entry num) total key len = 306.908917 GB avg = 0.027 KB total ukey len = 237.373266 GB avg = 0.015 KB total ukey num = 15.739588097 Billion total entry num = 11.280902045 Billion write speed all = 36.540664505 MB/sec (with seq num) write speed all = 35.251671899 MB/sec (without seq num) 2024/11/24-04:22:06.018660 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291809: 926934 keys, 37308804 bytes, temperature: kWarm 2024/11/24-04:22:06.018751 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393326018695, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291809, "file_size": 37308804, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4261178686, "largest_seqno": 4436635375, "table_properties": {"data_size": 31203728, "index_size": 1774976, "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": 25954152, "raw_average_key_size": 28, "raw_value_size": 108263604, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 926934, "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": 1732393322, "oldest_key_time": 0, "file_creation_time": 1732393322, "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": 291809, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:06.057593 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst) /dev/shm/ToplingTemp/Topling-268478-qpCHaf 2024/11/24-04:22:06.978952 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst): first pass time = 0.92's, 145.679'MB/sec 2024/11/24-04:22:08.640101 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst): old prealloc_size = 147639500, real_size = 32661552 2024/11/24-04:22:08.640692 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927107 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0307 GB avg-val = 116.77 avg-zval = 33.08 2024/11/24-04:22:08.641490 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:09.495910 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291810.sst): second pass time = 1.66's, 65.197'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.86's, 42.956'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3093.172'MB/sec (index lex order gen) rebuild zvType time = 0.72's, 0.321'MB/sec write SST data time = 0.13's, 277.240'MB/sec dict compress time = 0.00's, 1069863.366'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 29280.349'MB/sec zip my value time = 1.66's, unzip length = 0.108'GB zip my value throughput = 65.197'MB/sec zip pipeline throughput = 126.829'MB/sec entries = 927107 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.77 avg-zval = 33.08 usrkeys = 927107 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.77 avg-zval = 33.08 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 927107 bytes = 3244896 } seq expand size = 6489749 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0307 GB dict = 1.08 MB all = 0.0368 GB } UnZip/Zip{ index = 10.5128 value = 3.5303 dict = 1.00 all = 3.6511 } Zip/UnZip{ index = 0.0951 value = 0.2833 dict = 1.00 all = 0.2739 } ---------------------------- total value len = 2251.555074 GB avg = 0.200 KB (by entry num) total key len = 306.934876 GB avg = 0.027 KB total ukey len = 237.391808 GB avg = 0.015 KB total ukey num = 15.740515204 Billion total entry num = 11.281829152 Billion write speed all = 36.540835400 MB/sec (with seq num) write speed all = 35.251801727 MB/sec (without seq num) 2024/11/24-04:22:09.542136 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291810: 927107 keys, 36761090 bytes, temperature: kWarm 2024/11/24-04:22:09.542193 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393329542163, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291810, "file_size": 36761090, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4261178700, "largest_seqno": 4436635392, "table_properties": {"data_size": 30665824, "index_size": 1763776, "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": 25958996, "raw_average_key_size": 28, "raw_value_size": 108258734, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927107, "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": 1732393326, "oldest_key_time": 0, "file_creation_time": 1732393326, "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": 291810, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:09.578810 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst) /dev/shm/ToplingTemp/Topling-268478-I57tud 2024/11/24-04:22:10.470804 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst): first pass time = 0.89's, 150.475'MB/sec 2024/11/24-04:22:12.032866 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst): old prealloc_size = 147639500, real_size = 31209120 2024/11/24-04:22:12.033437 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 921196 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.0292 GB avg-val = 117.70 avg-zval = 31.71 2024/11/24-04:22:12.034233 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:12.847282 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291811.sst): second pass time = 1.56's, 69.446'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.81's, 43.334'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3180.147'MB/sec (index lex order gen) rebuild zvType time = 0.68's, 0.336'MB/sec write SST data time = 0.13's, 272.935'MB/sec dict compress time = 0.00's, 1073011.881'MB/sec z-dict build time = 0.00's, sample length = 1.084'MB, throughput = 17279.050'MB/sec zip my value time = 1.56's, unzip length = 0.108'GB zip my value throughput = 69.446'MB/sec zip pipeline throughput = 136.294'MB/sec entries = 921196 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.70 avg-zval = 31.71 usrkeys = 921196 avg-key = 20.00 avg-zkey = 1.91 avg-val = 124.70 avg-zval = 31.71 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 921196 bytes = 3224208 } seq expand size = 6448372 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.0292 GB dict = 1.08 MB all = 0.0353 GB } UnZip/Zip{ index = 10.4453 value = 3.7113 dict = 1.00 all = 3.8032 } Zip/UnZip{ index = 0.0957 value = 0.2694 dict = 1.00 all = 0.2629 } ---------------------------- total value len = 2251.669947 GB avg = 0.200 KB (by entry num) total key len = 306.960669 GB avg = 0.027 KB total ukey len = 237.410232 GB avg = 0.015 KB total ukey num = 15.741436400 Billion total entry num = 11.282750348 Billion write speed all = 36.541095387 MB/sec (with seq num) write speed all = 35.252018163 MB/sec (without seq num) 2024/11/24-04:22:12.918514 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291811: 921196 keys, 35290734 bytes, temperature: kWarm 2024/11/24-04:22:12.918587 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393332918551, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291811, "file_size": 35290734, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4295837793, "largest_seqno": 4436635404, "table_properties": {"data_size": 29214800, "index_size": 1763840, "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": 25793488, "raw_average_key_size": 28, "raw_value_size": 108424368, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 921196, "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": 1732393329, "oldest_key_time": 0, "file_creation_time": 1732393329, "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": 291811, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:12.954917 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst) /dev/shm/ToplingTemp/Topling-268478-haKJIf 2024/11/24-04:22:13.806146 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst): first pass time = 0.85's, 157.682'MB/sec 2024/11/24-04:22:15.441047 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst): old prealloc_size = 147639500, real_size = 32947280 2024/11/24-04:22:15.441700 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925055 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0310 GB avg-val = 117.09 avg-zval = 33.46 2024/11/24-04:22:15.442530 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:16.303629 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291812.sst): second pass time = 1.63's, 66.290'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.86's, 42.942'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2796.641'MB/sec (index lex order gen) rebuild zvType time = 0.72's, 0.322'MB/sec write SST data time = 0.14's, 256.981'MB/sec dict compress time = 0.00's, 1069839.604'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 36461.549'MB/sec zip my value time = 1.63's, unzip length = 0.108'GB zip my value throughput = 66.290'MB/sec zip pipeline throughput = 129.658'MB/sec entries = 925055 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.09 avg-zval = 33.46 usrkeys = 925055 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.09 avg-zval = 33.46 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 925055 bytes = 3237712 } seq expand size = 6475385 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0310 GB dict = 1.08 MB all = 0.0370 GB } UnZip/Zip{ index = 10.5105 value = 3.4991 dict = 1.00 all = 3.6236 } Zip/UnZip{ index = 0.0951 value = 0.2858 dict = 1.00 all = 0.2760 } ---------------------------- total value len = 2251.784738 GB avg = 0.200 KB (by entry num) total key len = 306.986571 GB avg = 0.027 KB total ukey len = 237.428733 GB avg = 0.015 KB total ukey num = 15.742361455 Billion total entry num = 11.283675403 Billion write speed all = 36.541300949 MB/sec (with seq num) write speed all = 35.252181668 MB/sec (without seq num) 2024/11/24-04:22:16.354842 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291812: 925055 keys, 37040106 bytes, temperature: kWarm 2024/11/24-04:22:16.354922 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393336354881, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291812, "file_size": 37040106, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4261178719, "largest_seqno": 4436631362, "table_properties": {"data_size": 30955584, "index_size": 1760256, "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": 25901540, "raw_average_key_size": 28, "raw_value_size": 108316282, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 925055, "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": 1732393332, "oldest_key_time": 0, "file_creation_time": 1732393332, "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": 291812, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:16.392013 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst) /dev/shm/ToplingTemp/Topling-268478-cWQOle 2024/11/24-04:22:17.325130 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst): first pass time = 0.93's, 143.843'MB/sec 2024/11/24-04:22:18.900920 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst): old prealloc_size = 147639500, real_size = 33109056 2024/11/24-04:22:18.901492 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927339 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0311 GB avg-val = 116.73 avg-zval = 33.55 2024/11/24-04:22:18.902260 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:19.755348 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291813.sst): second pass time = 1.57's, 68.732'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.85's, 43.550'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3191.795'MB/sec (index lex order gen) rebuild zvType time = 0.72's, 0.321'MB/sec write SST data time = 0.13's, 284.907'MB/sec dict compress time = 0.00's, 1069863.366'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 28179.263'MB/sec zip my value time = 1.57's, unzip length = 0.108'GB zip my value throughput = 68.732'MB/sec zip pipeline throughput = 115.458'MB/sec entries = 927339 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.73 avg-zval = 33.55 usrkeys = 927339 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.73 avg-zval = 33.55 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 927339 bytes = 3245696 } seq expand size = 6491373 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0311 GB dict = 1.08 MB all = 0.0372 GB } UnZip/Zip{ index = 10.5142 value = 3.4793 dict = 1.00 all = 3.6071 } Zip/UnZip{ index = 0.0951 value = 0.2874 dict = 1.00 all = 0.2772 } ---------------------------- total value len = 2251.899482 GB avg = 0.200 KB (by entry num) total key len = 307.012536 GB avg = 0.027 KB total ukey len = 237.447280 GB avg = 0.015 KB total ukey num = 15.743288794 Billion total entry num = 11.284602742 Billion write speed all = 36.541509129 MB/sec (with seq num) write speed all = 35.252347451 MB/sec (without seq num) 2024/11/24-04:22:19.801524 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291813: 927339 keys, 37209346 bytes, temperature: kWarm 2024/11/24-04:22:19.801590 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393339801558, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291813, "file_size": 37209346, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4261178730, "largest_seqno": 4436635420, "table_properties": {"data_size": 31113072, "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": 25965492, "raw_average_key_size": 28, "raw_value_size": 108252286, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927339, "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": 1732393336, "oldest_key_time": 0, "file_creation_time": 1732393336, "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": 291813, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:19.837214 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst) /dev/shm/ToplingTemp/Topling-268478-ARmYKf 2024/11/24-04:22:20.841798 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst): first pass time = 1.00's, 133.612'MB/sec 2024/11/24-04:22:22.144260 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst): old prealloc_size = 147639500, real_size = 31042944 2024/11/24-04:22:22.144837 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 923726 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1084 GB zip-val = 0.0290 GB avg-val = 117.30 avg-zval = 31.44 2024/11/24-04:22:22.145645 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:22.954873 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291814.sst): second pass time = 1.30's, 83.247'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.81's, 43.198'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3209.791'MB/sec (index lex order gen) rebuild zvType time = 0.68's, 0.338'MB/sec write SST data time = 0.13's, 274.786'MB/sec dict compress time = 0.00's, 1071879.208'MB/sec z-dict build time = 0.00's, sample length = 1.083'MB, throughput = 34756.581'MB/sec zip my value time = 1.30's, unzip length = 0.108'GB zip my value throughput = 83.247'MB/sec zip pipeline throughput = 83.247'MB/sec entries = 923726 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.30 avg-zval = 31.44 usrkeys = 923726 avg-key = 20.00 avg-zkey = 1.91 avg-val = 124.30 avg-zval = 31.44 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 923726 bytes = 3117584 } seq expand size = 6466082 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.0290 GB dict = 1.08 MB all = 0.0350 GB } UnZip/Zip{ index = 10.4456 value = 3.7308 dict = 1.00 all = 3.8330 } Zip/UnZip{ index = 0.0957 value = 0.2680 dict = 1.00 all = 0.2609 } ---------------------------- total value len = 2252.014301 GB avg = 0.200 KB (by entry num) total key len = 307.038400 GB avg = 0.027 KB total ukey len = 237.465754 GB avg = 0.015 KB total ukey num = 15.744212520 Billion total entry num = 11.285526468 Billion write speed all = 36.541848537 MB/sec (with seq num) write speed all = 35.252640234 MB/sec (without seq num) 2024/11/24-04:22:22.998956 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291814: 923726 keys, 35016182 bytes, temperature: kWarm 2024/11/24-04:22:22.999028 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393342998993, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291814, "file_size": 35016182, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4311151314, "largest_seqno": 4436635433, "table_properties": {"data_size": 29043184, "index_size": 1768640, "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": 25864328, "raw_average_key_size": 28, "raw_value_size": 108353516, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 923726, "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": 1732393339, "oldest_key_time": 0, "file_creation_time": 1732393339, "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": 291814, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:23.037158 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst) /dev/shm/ToplingTemp/Topling-268478-EUFaod 2024/11/24-04:22:24.038258 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst): first pass time = 1.00's, 134.076'MB/sec 2024/11/24-04:22:25.374143 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst): old prealloc_size = 147639500, real_size = 32601168 2024/11/24-04:22:25.374690 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 922551 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1084 GB zip-val = 0.0306 GB avg-val = 117.49 avg-zval = 33.17 2024/11/24-04:22:25.375459 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:26.204232 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291815.sst): second pass time = 1.34's, 81.184'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.83's, 44.200'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3374.798'MB/sec (index lex order gen) rebuild zvType time = 0.70's, 0.329'MB/sec write SST data time = 0.13's, 287.774'MB/sec dict compress time = 0.00's, 1072273.267'MB/sec z-dict build time = 0.00's, sample length = 1.083'MB, throughput = 32228.187'MB/sec zip my value time = 1.34's, unzip length = 0.108'GB zip my value throughput = 81.184'MB/sec zip pipeline throughput = 81.184'MB/sec entries = 922551 avg-key = 28.00 avg-zkey = 1.91 avg-val = 117.49 avg-zval = 33.17 usrkeys = 922551 avg-key = 20.00 avg-zkey = 1.91 avg-val = 124.49 avg-zval = 33.17 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 922551 bytes = 3228944 } seq expand size = 6457857 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.0306 GB dict = 1.08 MB all = 0.0367 GB } UnZip/Zip{ index = 10.4440 value = 3.5416 dict = 1.00 all = 3.6583 } Zip/UnZip{ index = 0.0957 value = 0.2824 dict = 1.00 all = 0.2733 } ---------------------------- total value len = 2252.129146 GB avg = 0.200 KB (by entry num) total key len = 307.064232 GB avg = 0.027 KB total ukey len = 237.484205 GB avg = 0.015 KB total ukey num = 15.745135071 Billion total entry num = 11.286449019 Billion write speed all = 36.542161790 MB/sec (with seq num) write speed all = 35.252907919 MB/sec (without seq num) 2024/11/24-04:22:26.248653 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291815: 922551 keys, 36688388 bytes, temperature: kWarm 2024/11/24-04:22:26.248721 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393346248686, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291815, "file_size": 36688388, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4265680186, "largest_seqno": 4436631014, "table_properties": {"data_size": 30603712, "index_size": 1766656, "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": 25831428, "raw_average_key_size": 28, "raw_value_size": 108386382, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 922551, "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": 1732393343, "oldest_key_time": 0, "file_creation_time": 1732393343, "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": 291815, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:26.290456 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst) /dev/shm/ToplingTemp/Topling-268478-yafeye 2024/11/24-04:22:27.318191 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst): first pass time = 1.03's, 130.601'MB/sec 2024/11/24-04:22:28.674057 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst): old prealloc_size = 147639500, real_size = 33438000 2024/11/24-04:22:28.674617 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927087 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.1083 GB zip-val = 0.0314 GB avg-val = 116.77 avg-zval = 33.92 2024/11/24-04:22:28.675396 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/24-04:22:29.528973 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291816.sst): second pass time = 1.35's, 79.925'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.85's, 43.909'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3329.168'MB/sec (index lex order gen) rebuild zvType time = 0.73's, 0.318'MB/sec write SST data time = 0.13's, 296.654'MB/sec dict compress time = 0.00's, 1069936.634'MB/sec z-dict build time = 0.00's, sample length = 1.081'MB, throughput = 34091.615'MB/sec zip my value time = 1.35's, unzip length = 0.108'GB zip my value throughput = 79.925'MB/sec zip pipeline throughput = 79.925'MB/sec entries = 927087 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.77 avg-zval = 33.92 usrkeys = 927087 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.77 avg-zval = 33.92 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 927087 bytes = 3244816 } seq expand size = 6489609 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0314 GB dict = 1.08 MB all = 0.0375 GB } UnZip/Zip{ index = 10.5141 value = 3.4431 dict = 1.00 all = 3.5756 } Zip/UnZip{ index = 0.0951 value = 0.2904 dict = 1.00 all = 0.2797 } ---------------------------- total value len = 2252.243895 GB avg = 0.200 KB (by entry num) total key len = 307.090190 GB avg = 0.027 KB total ukey len = 237.502747 GB avg = 0.015 KB total ukey num = 15.746062158 Billion total entry num = 11.287376106 Billion write speed all = 36.542436129 MB/sec (with seq num) write speed all = 35.253137564 MB/sec (without seq num) 2024/11/24-04:22:29.574047 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291816: 927087 keys, 37537548 bytes, temperature: kWarm 2024/11/24-04:22:29.574116 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393349574080, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291816, "file_size": 37537548, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4265680199, "largest_seqno": 4436635447, "table_properties": {"data_size": 31442528, "index_size": 1763520, "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": 25958436, "raw_average_key_size": 28, "raw_value_size": 108259406, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927087, "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": 1732393346, "oldest_key_time": 0, "file_creation_time": 1732393346, "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": 291816, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:29.613860 139957651584576 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst) /dev/shm/ToplingTemp/Topling-268478-iQN3hf 2024/11/24-04:22:29.671267 139957651584576 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst): first pass time = 0.06's, 237.456'MB/sec 2024/11/24-04:22:29.794158 139957651584576 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst): old prealloc_size = 147639500, real_size = 4159776 2024/11/24-04:22:29.794275 139957651584576 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 93307 prefix = 4 raw-key = 0.0015 GB zip-key = 0.0002 GB avg-key = 16.00 avg-zkey = 1.93 raw-val = 0.0110 GB zip-val = 0.0040 GB avg-val = 118.00 avg-zval = 42.40 2024/11/24-04:22:29.794382 139957651584576 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.006 GB, reorder workingMem = 0.0002 GB, waited 0.000 sec, Key+Value = 0.014 GB 2024/11/24-04:22:29.875637 139957651584576 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00/291817.sst): second pass time = 0.12's, 90.069'MB/sec, value only(80.8% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.08's, 55.633'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1844.352'MB/sec (index lex order gen) rebuild zvType time = 0.07's, 0.342'MB/sec write SST data time = 0.01's, 343.669'MB/sec dict compress time = 0.00's, 112976.238'MB/sec z-dict build time = 0.00's, sample length = 0.114'MB, throughput = 4598.267'MB/sec zip my value time = 0.12's, unzip length = 0.011'GB zip my value throughput = 90.069'MB/sec zip pipeline throughput = 90.069'MB/sec entries = 93307 avg-key = 28.00 avg-zkey = 1.93 avg-val = 118.00 avg-zval = 42.40 usrkeys = 93307 avg-key = 20.00 avg-zkey = 1.93 avg-val = 125.00 avg-zval = 42.40 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 93307 bytes = 279936 } seq expand size = 653149 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0019 GB value = 0.0110 GB dict = 0.11 MB all = 0.0136 GB } __ZipSize{ index = 0.0002 GB value = 0.0040 GB dict = 0.11 MB all = 0.0045 GB } UnZip/Zip{ index = 10.3582 value = 2.7831 dict = 1.00 all = 3.0060 } Zip/UnZip{ index = 0.0965 value = 0.3593 dict = 1.00 all = 0.3327 } ---------------------------- total value len = 2252.255558 GB avg = 0.200 KB (by entry num) total key len = 307.092803 GB avg = 0.027 KB total ukey len = 237.504613 GB avg = 0.015 KB total ukey num = 15.746155465 Billion total entry num = 11.287469413 Billion write speed all = 36.542459083 MB/sec (with seq num) write speed all = 35.253156242 MB/sec (without seq num) 2024/11/24-04:22:29.888536 139957651584576 [compaction_job.cc:1948] [default] [JOB 41457] Generated table #291817: 93307 keys, 4531865 bytes, temperature: kWarm 2024/11/24-04:22:29.888584 139957651584576 EVENT_LOG_v1 {"time_micros": 1732393349888557, "cf_name": "default", "job": 41457, "event": "table_file_creation", "file_number": 291817, "file_size": 4531865, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 4336153900, "largest_seqno": 4351686826, "table_properties": {"data_size": 3956112, "index_size": 180160, "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": 2612596, "raw_average_key_size": 28, "raw_value_size": 11010226, "raw_average_value_size": 118, "num_data_blocks": 1, "num_entries": 93307, "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": 118, "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": 1732393349, "oldest_key_time": 0, "file_creation_time": 1732393349, "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": 291817, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/24-04:22:29.899409 139957651584576 [compaction_job.cc:703] job-41457: subcompact[0], size: 0.297384 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-41457/att-00 [291809,291810,291811,291812,291813,291814,291815,291816,291817] 2024/11/24-04:22:29.957114 139957651584576 (Original Log Time 2024/11/24-04:22:02.043755) EVENT_LOG_v1 {"time_micros": 1732393322043708, "job": 41457, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [291734], "files_L3": [291781, 291649, 291650, 291651, 291652, 291653, 291654, 291655, 291782], "score": 0.882836, "input_data_size": 305685371, "oldest_snapshot_seqno": 4437077070} 2024/11/24-04:22:29.957118 139957651584576 (Original Log Time 2024/11/24-04:22:29.956300) [compaction_job.cc:2022] [default] [JOB 41457] Compacted 1@2 + 9@3 files to L3 => 297384063 bytes 2024/11/24-04:22:29.957119 139957651584576 (Original Log Time 2024/11/24-04:22:29.957052) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.01, MB/sec: 11.0 rd, 10.7 wr, level 3, files in(1, 9) out(9 +0 blob) MB in(11.4, 280.1 +0.0 blob) out(283.6 +0.0 blob), read-write-amplify(50.4) write-amplify(24.8) OK, records in: 7540415, records dropped: 46113 output_compression: Snappy 2024/11/24-04:22:29.957125 139957651584576 (Original Log Time 2024/11/24-04:22:29.957095) EVENT_LOG_v1 {"time_micros": 1732393349957076, "cf": "default", "job": 41457, "event": "compaction_finished", "compaction_time_micros": 27855657, "compaction_time_cpu_micros": 11412550, "output_level": 3, "num_output_files": 9, "total_output_size": 297384063, "num_input_records": 7540415, "num_output_records": 7494302, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 213457938, "file_range_sync_nanos": 0, "file_fsync_nanos": 7244, "file_prepare_write_nanos": 19930, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/24-04:22:30.105129 139957651584576 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":1732393321,"executesMs":28041,"compactionJobId":41457,"attempt":0,"compactionInputRawBytes":1093913306,"compactionInputZipBytes":305685371,"compactionOutputRawBytes":0,"compactionOutputZipBytes":297384063,"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-4439a06f5974724def7b12f2802a213f-6f4aab781309d63c-00"}}, response = 2024/11/24-04:22:30.105214 139957651584576 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-41457/att-00: olev 3, work 28.042 s, result 5.964 ms, install 0.840 ms, input{raw 1.019 GiB zip 291.524 MiB}