2024/11/23-02:42:17.016827 140025037178432 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00: fork to child time = 0.009459 sec 2024/11/23-02:42:17.017646 140025037178432 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00 2024/11/23-02:42:17.024411 140025037178432 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00 2024/11/23-02:42:17.025499 140025037178432 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/23-02:42:17.025794 140025037178432 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/23-02:42:17.078680 140025037178432 [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-17595/att-00/MANIFEST-206347 2024/11/23-02:42:17.093558 140025037178432 [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-17595/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 241189, last_sequence is 3739862456, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 241049 2024/11/23-02:42:17.093565 140025037178432 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/23-02:42:17.093747 140025037178432 [version_set.cc:5721] Creating manifest 241189 2024/11/23-02:42:17.126760 140025037178432 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/23-02:42:17.149424 140025037178432 [compaction_job.cc:2437] [default] [JOB 17595] Compacting 1@2 + 10@3 files to L3, score 0.99, subcompactions 1 : 1 2024/11/23-02:42:17.149441 140025037178432 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 13147 Base level 2, inputs: [241183(24MB)], [241137(36MB) 241138(37MB) 241139(35MB) 241140(33MB) 241141(34MB) 241142(34MB) 241143(36MB) 241144(35MB) 241145(11MB) 241093(7217KB)] 2024/11/23-02:42:17.155413 140025037178432 [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/23-02:42:17.155450 140025037178432 [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/23-02:42:17.155470 140025037178432 [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/23-02:42:17.155475 140025037178432 [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/23-02:42:17.155485 140025037178432 [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/23-02:42:17.687026 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.sst) /dev/shm/ToplingTemp/Topling-384276-zfajTn 2024/11/23-02:42:18.782674 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.sst): first pass time = 1.10's, 122.506'MB/sec 2024/11/23-02:42:21.053172 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.sst): old prealloc_size = 147639500, real_size = 34268016 2024/11/23-02:42:21.053760 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 933811 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.1081 GB zip-val = 0.0322 GB avg-val = 115.73 avg-zval = 34.53 2024/11/23-02:42:21.054587 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.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/23-02:42:22.393878 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241190.sst): second pass time = 2.27's, 47.612'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.34's, 28.720'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3147.870'MB/sec (index lex order gen) rebuild zvType time = 1.09's, 0.215'MB/sec write SST data time = 0.25's, 152.144'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.078'MB, throughput = 35697.427'MB/sec zip my value time = 2.27's, unzip length = 0.108'GB zip my value throughput = 47.612'MB/sec zip pipeline throughput = 144.296'MB/sec entries = 933811 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.73 avg-zval = 34.53 usrkeys = 933811 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.73 avg-zval = 34.53 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 933811 bytes = 3385072 } seq expand size = 6536677 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0187 GB value = 0.1081 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0322 GB dict = 1.08 MB all = 0.0385 GB } UnZip/Zip{ index = 10.4421 value = 3.3515 dict = 1.00 all = 3.4858 } Zip/UnZip{ index = 0.0958 value = 0.2984 dict = 1.00 all = 0.2869 } ---------------------------- total value len = 0.114608 GB avg = 0.123 KB (by entry num) total key len = 0.026147 GB avg = 0.028 KB total ukey len = 0.018676 GB avg = 0.020 KB total ukey num = 0.000933811 Billion total entry num = 0.000933811 Billion write speed all = 0.002192460 MB/sec (with seq num) write speed all = 0.002076096 MB/sec (without seq num) 2024/11/23-02:42:22.440961 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241190: 933811 keys, 38503650 bytes, temperature: kWarm 2024/11/23-02:42:22.441074 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300942441004, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241190, "file_size": 38503650, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3369353416, "largest_seqno": 3739845226, "table_properties": {"data_size": 32245856, "index_size": 1788544, "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": 26146708, "raw_average_key_size": 28, "raw_value_size": 108071030, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 933811, "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": 1732300937, "oldest_key_time": 0, "file_creation_time": 1732300937, "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": 241190, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:22.509720 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.sst) /dev/shm/ToplingTemp/Topling-384276-w7FTjk 2024/11/23-02:42:23.807868 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.sst): first pass time = 1.30's, 103.396'MB/sec 2024/11/23-02:42:25.623974 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.sst): old prealloc_size = 147639500, real_size = 35580528 2024/11/23-02:42:25.624643 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 927755 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.0336 GB avg-val = 116.67 avg-zval = 36.20 2024/11/23-02:42:25.625361 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.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/23-02:42:26.909189 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241191.sst): second pass time = 1.81's, 59.645'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.29's, 30.566'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2718.978'MB/sec (index lex order gen) rebuild zvType time = 1.02's, 0.228'MB/sec write SST data time = 0.27's, 147.180'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 = 35206.779'MB/sec zip my value time = 1.81's, unzip length = 0.108'GB zip my value throughput = 59.645'MB/sec zip pipeline throughput = 64.601'MB/sec entries = 927755 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.67 avg-zval = 36.20 usrkeys = 927755 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.29 avg-zval = 36.20 TagRS{ kinds = RS_Key0_TagN bytes = 145080 } TagArray{ size = 744758 bytes = 2699760 } seq expand size = 5213306 multi value expand size = 0 cnt WriteAppend = 15 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0336 GB dict = 1.08 MB all = 0.0393 GB } UnZip/Zip{ index = 10.5136 value = 3.2230 dict = 1.00 all = 3.4167 } Zip/UnZip{ index = 0.0951 value = 0.3103 dict = 1.00 all = 0.2927 } ---------------------------- total value len = 0.228062 GB avg = 0.123 KB (by entry num) total key len = 0.052124 GB avg = 0.028 KB total ukey len = 0.037231 GB avg = 0.020 KB total ukey num = 0.001861566 Billion total entry num = 0.001861566 Billion write speed all = 0.004364000 MB/sec (with seq num) write speed all = 0.004132043 MB/sec (without seq num) 2024/11/23-02:42:26.953973 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241191: 927755 keys, 39283088 bytes, temperature: kWarm 2024/11/23-02:42:26.954055 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300946954010, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241191, "file_size": 39283088, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3739844013, "table_properties": {"data_size": 33583520, "index_size": 1764864, "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": 25977140, "raw_average_key_size": 28, "raw_value_size": 108240610, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 927755, "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": 1732300942, "oldest_key_time": 0, "file_creation_time": 1732300942, "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": 241191, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:27.024310 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.sst) /dev/shm/ToplingTemp/Topling-384276-nAB2tm 2024/11/23-02:42:28.145371 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.sst): first pass time = 1.12's, 119.729'MB/sec 2024/11/23-02:42:29.715817 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.sst): old prealloc_size = 147639500, real_size = 32921904 2024/11/23-02:42:29.716510 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 929005 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.0309 GB avg-val = 116.47 avg-zval = 33.29 2024/11/23-02:42:29.717318 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.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/23-02:42:30.955922 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241192.sst): second pass time = 1.57's, 68.940'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.24's, 29.858'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2640.755'MB/sec (index lex order gen) rebuild zvType time = 1.08's, 0.214'MB/sec write SST data time = 0.16's, 237.639'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 = 34525.101'MB/sec zip my value time = 1.57's, unzip length = 0.108'GB zip my value throughput = 68.940'MB/sec zip pipeline throughput = 68.940'MB/sec entries = 929005 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.47 avg-zval = 33.29 usrkeys = 929005 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.47 avg-zval = 33.29 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 929005 bytes = 3251536 } seq expand size = 6503035 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.0309 GB dict = 1.08 MB all = 0.0370 GB } UnZip/Zip{ index = 10.5148 value = 3.4993 dict = 1.00 all = 3.6249 } Zip/UnZip{ index = 0.0951 value = 0.2858 dict = 1.00 all = 0.2759 } ---------------------------- total value len = 0.342770 GB avg = 0.123 KB (by entry num) total key len = 0.078136 GB avg = 0.028 KB total ukey len = 0.055811 GB avg = 0.020 KB total ukey num = 0.002790571 Billion total entry num = 0.002790571 Billion write speed all = 0.006555370 MB/sec (with seq num) write speed all = 0.006207677 MB/sec (without seq num) 2024/11/23-02:42:30.991535 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241192: 929005 keys, 37026762 bytes, temperature: kWarm 2024/11/23-02:42:30.991595 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300950991563, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241192, "file_size": 37026762, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3512539342, "largest_seqno": 3739844340, "table_properties": {"data_size": 30922400, "index_size": 1767040, "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": 26012140, "raw_average_key_size": 28, "raw_value_size": 108205602, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 929005, "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": 1732300947, "oldest_key_time": 0, "file_creation_time": 1732300947, "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": 241192, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:31.031209 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.sst) /dev/shm/ToplingTemp/Topling-384276-pImfSk 2024/11/23-02:42:32.220571 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.sst): first pass time = 1.18's, 113.468'MB/sec 2024/11/23-02:42:33.966845 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.sst): old prealloc_size = 147639500, real_size = 32358960 2024/11/23-02:42:33.967531 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925425 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.0304 GB avg-val = 117.03 avg-zval = 32.81 2024/11/23-02:42:33.968323 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.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/23-02:42:35.233919 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241193.sst): second pass time = 1.75's, 62.047'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.27's, 28.769'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2657.899'MB/sec (index lex order gen) rebuild zvType time = 1.10's, 0.209'MB/sec write SST data time = 0.16's, 225.152'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 = 33056.268'MB/sec zip my value time = 1.75's, unzip length = 0.108'GB zip my value throughput = 62.047'MB/sec zip pipeline throughput = 62.047'MB/sec entries = 925425 avg-key = 28.00 avg-zkey = 1.90 avg-val = 117.03 avg-zval = 32.81 usrkeys = 925425 avg-key = 20.00 avg-zkey = 1.90 avg-val = 124.03 avg-zval = 32.81 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 925425 bytes = 3239008 } seq expand size = 6477975 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.0304 GB dict = 1.08 MB all = 0.0365 GB } UnZip/Zip{ index = 10.5124 value = 3.5666 dict = 1.00 all = 3.6820 } Zip/UnZip{ index = 0.0951 value = 0.2804 dict = 1.00 all = 0.2716 } ---------------------------- total value len = 0.457554 GB avg = 0.123 KB (by entry num) total key len = 0.104048 GB avg = 0.028 KB total ukey len = 0.074320 GB avg = 0.020 KB total ukey num = 0.003715996 Billion total entry num = 0.003715996 Billion write speed all = 0.008746041 MB/sec (with seq num) write speed all = 0.008283076 MB/sec (without seq num) 2024/11/23-02:42:35.266278 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241193: 925425 keys, 36452810 bytes, temperature: kWarm 2024/11/23-02:42:35.266338 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300955266307, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241193, "file_size": 36452810, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3604582272, "largest_seqno": 3739843829, "table_properties": {"data_size": 30366752, "index_size": 1760640, "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": 25911900, "raw_average_key_size": 28, "raw_value_size": 108305882, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 925425, "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": 1732300951, "oldest_key_time": 0, "file_creation_time": 1732300951, "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": 241193, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:35.302979 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.sst) /dev/shm/ToplingTemp/Topling-384276-lu0UAm 2024/11/23-02:42:36.371137 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.sst): first pass time = 1.07's, 125.658'MB/sec 2024/11/23-02:42:38.247621 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.sst): old prealloc_size = 147639500, real_size = 32252016 2024/11/23-02:42:38.248302 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 929445 prefix = 4 raw-key = 0.0149 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.1082 GB zip-val = 0.0302 GB avg-val = 116.41 avg-zval = 32.54 2024/11/23-02:42:38.249116 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.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/23-02:42:39.365895 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241194.sst): second pass time = 1.88's, 57.679'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.12's, 32.513'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2685.104'MB/sec (index lex order gen) rebuild zvType time = 0.91's, 0.254'MB/sec write SST data time = 0.20's, 178.795'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.079'MB, throughput = 32185.522'MB/sec zip my value time = 1.88's, unzip length = 0.108'GB zip my value throughput = 57.679'MB/sec zip pipeline throughput = 78.724'MB/sec entries = 929445 avg-key = 28.00 avg-zkey = 1.91 avg-val = 116.41 avg-zval = 32.54 usrkeys = 929445 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.41 avg-zval = 32.54 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 929445 bytes = 3253072 } seq expand size = 6506115 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0186 GB value = 0.1082 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0018 GB value = 0.0302 GB dict = 1.08 MB all = 0.0364 GB } UnZip/Zip{ index = 10.4441 value = 3.5779 dict = 1.00 all = 3.6916 } Zip/UnZip{ index = 0.0957 value = 0.2795 dict = 1.00 all = 0.2709 } ---------------------------- total value len = 0.572254 GB avg = 0.123 KB (by entry num) total key len = 0.130072 GB avg = 0.028 KB total ukey len = 0.092909 GB avg = 0.020 KB total ukey num = 0.004645441 Billion total entry num = 0.004645441 Billion write speed all = 0.010936884 MB/sec (with seq num) write speed all = 0.010358159 MB/sec (without seq num) 2024/11/23-02:42:39.399190 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241194: 929445 keys, 36357820 bytes, temperature: kWarm 2024/11/23-02:42:39.399271 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300959399225, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241194, "file_size": 36357820, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3485447251, "largest_seqno": 3739844615, "table_properties": {"data_size": 30239648, "index_size": 1779840, "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": 26024460, "raw_average_key_size": 28, "raw_value_size": 108193298, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 929445, "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": 1732300955, "oldest_key_time": 0, "file_creation_time": 1732300955, "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": 241194, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:39.447167 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.sst) /dev/shm/ToplingTemp/Topling-384276-kLzCdm 2024/11/23-02:42:40.431255 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.sst): first pass time = 0.98's, 136.394'MB/sec 2024/11/23-02:42:42.309775 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.sst): old prealloc_size = 147639500, real_size = 31685072 2024/11/23-02:42:42.310399 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 928533 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.0297 GB avg-val = 116.55 avg-zval = 31.97 2024/11/23-02:42:42.311182 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.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/23-02:42:43.318764 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241195.sst): second pass time = 1.88's, 57.627'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.01's, 35.585'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2955.236'MB/sec (index lex order gen) rebuild zvType time = 0.86's, 0.270'MB/sec write SST data time = 0.15's, 243.496'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 = 32150.548'MB/sec zip my value time = 1.88's, unzip length = 0.108'GB zip my value throughput = 57.627'MB/sec zip pipeline throughput = 122.627'MB/sec entries = 928533 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.55 avg-zval = 31.97 usrkeys = 928533 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.55 avg-zval = 31.97 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 928533 bytes = 3365952 } seq expand size = 6499731 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.0297 GB dict = 1.08 MB all = 0.0359 GB } UnZip/Zip{ index = 10.5125 value = 3.6454 dict = 1.00 all = 3.7382 } Zip/UnZip{ index = 0.0951 value = 0.2743 dict = 1.00 all = 0.2675 } ---------------------------- total value len = 0.686972 GB avg = 0.123 KB (by entry num) total key len = 0.156071 GB avg = 0.028 KB total ukey len = 0.111479 GB avg = 0.020 KB total ukey num = 0.005573974 Billion total entry num = 0.005573974 Billion write speed all = 0.013127381 MB/sec (with seq num) write speed all = 0.012433024 MB/sec (without seq num) 2024/11/23-02:42:43.353941 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241195: 928533 keys, 35904464 bytes, temperature: kWarm 2024/11/23-02:42:43.354002 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300963353970, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241195, "file_size": 35904464, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3405268533, "largest_seqno": 3739843863, "table_properties": {"data_size": 29686208, "index_size": 1766528, "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": 25998924, "raw_average_key_size": 28, "raw_value_size": 108218826, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 928533, "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": 1732300959, "oldest_key_time": 0, "file_creation_time": 1732300959, "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": 241195, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:43.390406 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.sst) /dev/shm/ToplingTemp/Topling-384276-Pr1wDk 2024/11/23-02:42:44.221676 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.sst): first pass time = 0.83's, 161.467'MB/sec 2024/11/23-02:42:45.608552 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.sst): old prealloc_size = 147639500, real_size = 34778992 2024/11/23-02:42:45.609125 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 926393 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.1083 GB zip-val = 0.0328 GB avg-val = 116.88 avg-zval = 35.38 2024/11/23-02:42:45.609934 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.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/23-02:42:46.613470 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241196.sst): second pass time = 1.39's, 78.139'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.00's, 38.802'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3223.098'MB/sec (index lex order gen) rebuild zvType time = 0.87's, 0.265'MB/sec write SST data time = 0.13's, 297.914'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 = 30600.425'MB/sec zip my value time = 1.39's, unzip length = 0.108'GB zip my value throughput = 78.139'MB/sec zip pipeline throughput = 78.139'MB/sec entries = 926393 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.88 avg-zval = 35.38 usrkeys = 926393 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.88 avg-zval = 35.38 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 926393 bytes = 3358192 } seq expand size = 6484751 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.0328 GB dict = 1.08 MB all = 0.0390 GB } UnZip/Zip{ index = 10.4436 value = 3.3039 dict = 1.00 all = 3.4422 } Zip/UnZip{ index = 0.0958 value = 0.3027 dict = 1.00 all = 0.2905 } ---------------------------- total value len = 0.801736 GB avg = 0.123 KB (by entry num) total key len = 0.182010 GB avg = 0.028 KB total ukey len = 0.130007 GB avg = 0.020 KB total ukey num = 0.006500367 Billion total entry num = 0.006500367 Billion write speed all = 0.015317534 MB/sec (with seq num) write speed all = 0.014507816 MB/sec (without seq num) 2024/11/23-02:42:46.648326 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241196: 926393 keys, 38992094 bytes, temperature: kWarm 2024/11/23-02:42:46.648389 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300966648358, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241196, "file_size": 38992094, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3405268578, "largest_seqno": 3739844863, "table_properties": {"data_size": 32773152, "index_size": 1774080, "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": 25939004, "raw_average_key_size": 28, "raw_value_size": 108278822, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 926393, "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": 1732300963, "oldest_key_time": 0, "file_creation_time": 1732300963, "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": 241196, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:46.683531 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.sst) /dev/shm/ToplingTemp/Topling-384276-WDWnpk 2024/11/23-02:42:47.514089 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.sst): first pass time = 0.83's, 161.606'MB/sec 2024/11/23-02:42:48.880030 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.sst): old prealloc_size = 147639500, real_size = 33178912 2024/11/23-02:42:48.880609 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 926746 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0018 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.1083 GB zip-val = 0.0312 GB avg-val = 116.83 avg-zval = 33.64 2024/11/23-02:42:48.881388 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.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/23-02:42:49.916973 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241197.sst): second pass time = 1.37's, 79.305'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.04's, 35.949'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3176.987'MB/sec (index lex order gen) rebuild zvType time = 0.91's, 0.255'MB/sec write SST data time = 0.13's, 290.765'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 = 33546.462'MB/sec zip my value time = 1.37's, unzip length = 0.108'GB zip my value throughput = 79.305'MB/sec zip pipeline throughput = 79.305'MB/sec entries = 926746 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.83 avg-zval = 33.64 usrkeys = 926746 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.83 avg-zval = 33.64 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 926746 bytes = 3243632 } seq expand size = 6487222 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.4420 value = 3.4733 dict = 1.00 all = 3.6006 } Zip/UnZip{ index = 0.0958 value = 0.2879 dict = 1.00 all = 0.2777 } ---------------------------- total value len = 0.916492 GB avg = 0.123 KB (by entry num) total key len = 0.207959 GB avg = 0.028 KB total ukey len = 0.148542 GB avg = 0.020 KB total ukey num = 0.007427113 Billion total entry num = 0.007427113 Billion write speed all = 0.017507498 MB/sec (with seq num) write speed all = 0.016582388 MB/sec (without seq num) 2024/11/23-02:42:49.947544 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241197: 926746 keys, 37276930 bytes, temperature: kWarm 2024/11/23-02:42:49.947608 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300969947572, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241197, "file_size": 37276930, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3471845708, "largest_seqno": 3739845199, "table_properties": {"data_size": 31171984, "index_size": 1775040, "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": 25948888, "raw_average_key_size": 28, "raw_value_size": 108268908, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 926746, "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": 1732300966, "oldest_key_time": 0, "file_creation_time": 1732300966, "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": 241197, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:50.070456 140025037178432 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst) /dev/shm/ToplingTemp/Topling-384276-DOMAIk 2024/11/23-02:42:50.566881 140025037178432 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst): first pass time = 0.50's, 178.346'MB/sec 2024/11/23-02:42:51.465102 140025037178432 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst): old prealloc_size = 147639500, real_size = 21262080 2024/11/23-02:42:51.465515 140025037178432 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 614172 prefix = 4 raw-key = 0.0098 GB zip-key = 0.0012 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0713 GB zip-val = 0.0199 GB avg-val = 116.14 avg-zval = 32.45 2024/11/23-02:42:51.466018 140025037178432 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0015 GB, waited 0.000 sec, Key+Value = 0.089 GB 2024/11/23-02:42:52.111368 140025037178432 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00/241198.sst): second pass time = 0.90's, 79.482'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.65's, 36.863'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3029.125'MB/sec (index lex order gen) rebuild zvType time = 0.56's, 0.274'MB/sec write SST data time = 0.09's, 279.813'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.715'MB, throughput = 22055.492'MB/sec zip my value time = 0.90's, unzip length = 0.071'GB zip my value throughput = 79.482'MB/sec zip pipeline throughput = 79.482'MB/sec entries = 614172 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.14 avg-zval = 32.45 usrkeys = 614172 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.14 avg-zval = 32.45 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 614172 bytes = 1996080 } seq expand size = 4299204 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0123 GB value = 0.0713 GB dict = 0.72 MB all = 0.0885 GB } __ZipSize{ index = 0.0012 GB value = 0.0199 GB dict = 0.72 MB all = 0.0238 GB } UnZip/Zip{ index = 10.4406 value = 3.5788 dict = 1.00 all = 3.7161 } Zip/UnZip{ index = 0.0958 value = 0.2794 dict = 1.00 all = 0.2691 } ---------------------------- total value len = 0.992124 GB avg = 0.123 KB (by entry num) total key len = 0.225156 GB avg = 0.028 KB total ukey len = 0.160826 GB avg = 0.020 KB total ukey num = 0.008041285 Billion total entry num = 0.008041285 Billion write speed all = 0.018952175 MB/sec (with seq num) write speed all = 0.017950599 MB/sec (without seq num) 2024/11/23-02:42:52.137863 140025037178432 [compaction_job.cc:1948] [default] [JOB 17595] Generated table #241198: 614172 keys, 23823013 bytes, temperature: kWarm 2024/11/23-02:42:52.137924 140025037178432 EVENT_LOG_v1 {"time_micros": 1732300972137893, "cf_name": "default", "job": 17595, "event": "table_file_creation", "file_number": 241198, "file_size": 23823013, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 3676315627, "largest_seqno": 3739845010, "table_properties": {"data_size": 19931824, "index_size": 1176512, "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": 17196816, "raw_average_key_size": 28, "raw_value_size": 71332596, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 614172, "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": 1732300970, "oldest_key_time": 0, "file_creation_time": 1732300970, "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": 241198, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/23-02:42:52.158715 140025037178432 [compaction_job.cc:703] job-17595: subcompact[0], size: 0.323621 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-17595/att-00 [241190,241191,241192,241193,241194,241195,241196,241197,241198] 2024/11/23-02:42:52.229442 140025037178432 (Original Log Time 2024/11/23-02:42:17.149498) EVENT_LOG_v1 {"time_micros": 1732300937149456, "job": 17595, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [241183], "files_L3": [241137, 241138, 241139, 241140, 241141, 241142, 241143, 241144, 241145, 241093], "score": 0.990945, "input_data_size": 343115232, "oldest_snapshot_seqno": 3739862422} 2024/11/23-02:42:52.229446 140025037178432 (Original Log Time 2024/11/23-02:42:52.228881) [compaction_job.cc:2022] [default] [JOB 17595] Compacted 1@2 + 10@3 files to L3 => 323620631 bytes 2024/11/23-02:42:52.229447 140025037178432 (Original Log Time 2024/11/23-02:42:52.229382) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.01, MB/sec: 9.8 rd, 9.2 wr, level 3, files in(1, 10) out(9 +0 blob) MB in(24.7, 302.6 +0.0 blob) out(308.6 +0.0 blob), read-write-amplify(25.8) write-amplify(12.5) OK, records in: 8089183, records dropped: 47898 output_compression: Snappy 2024/11/23-02:42:52.229454 140025037178432 (Original Log Time 2024/11/23-02:42:52.229423) EVENT_LOG_v1 {"time_micros": 1732300972229404, "cf": "default", "job": 17595, "event": "compaction_finished", "compaction_time_micros": 35009225, "compaction_time_cpu_micros": 15998236, "output_level": 3, "num_output_files": 9, "total_output_size": 323620631, "num_input_records": 8089183, "num_output_records": 8041285, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 249393668, "file_range_sync_nanos": 0, "file_fsync_nanos": 8636, "file_prepare_write_nanos": 21691, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/23-02:42:52.364860 140025037178432 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":1732300936,"executesMs":35206,"compactionJobId":17595,"attempt":0,"compactionInputRawBytes":1169073070,"compactionInputZipBytes":343115232,"compactionOutputRawBytes":0,"compactionOutputZipBytes":323620631,"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-8aa7e38b562d913e05b0bed01f285609-4837ec80d3664e2e-00"}}, response = 2024/11/23-02:42:52.364923 140025037178432 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-17595/att-00: olev 3, work 35.207 s, result 4.868 ms, install 0.591 ms, input{raw 1.089 GiB zip 327.220 MiB}