2024/11/20-22:06:39.895712 140008727660096 DEBG dcompact_worker.cpp:2219: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00: fork to child time = 0.011783 sec 2024/11/20-22:06:39.896282 140008727660096 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00 2024/11/20-22:06:39.902990 140008727660096 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00 2024/11/20-22:06:39.909828 140008727660096 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/20-22:06:39.910112 140008727660096 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/20-22:06:39.965374 140008727660096 [version_set.cc:6211] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-16458/att-00/MANIFEST-049091 2024/11/20-22:06:40.036494 140008727660096 [version_set.cc:6254] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-16458/att-00/MANIFEST-049091 succeeded,manifest_file_number is 49091, next_file_number is 77270, last_sequence is 1213539863, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 77083 2024/11/20-22:06:40.036508 140008727660096 [version_set.cc:6269] Column family [default] (ID 0), log number is 0 2024/11/20-22:06:40.036598 140008727660096 [version_set.cc:5724] Creating manifest 77270 2024/11/20-22:06:40.066750 140008727660096 DEBG dcompact_worker.cpp:1225: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/20-22:06:40.085122 140008727660096 [compaction_job.cc:2437] [default] [JOB 16458] Compacting 1@2 + 9@3 files to L3, score 0.97, subcompactions 1 : 1 2024/11/20-22:06:40.085142 140008727660096 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 12792 Base level 2, inputs: [77252(28MB)], [77196(124MB) 77197(124MB) 77198(124MB) 77199(124MB) 77200(124MB) 77201(124MB) 77202(124MB) 77203(124MB) 77204(52MB)] 2024/11/20-22:06:40.093744 140008727660096 [top_zip_table.cc:59] core git_version_hash_info_is:commit 81964c21ebbcc178d8e99dae0fbf61bded2729cc Author: rockeet Date: Mon Nov 11 21:28:46 2024 +0800 Makefile: fix gen git-version-*.cpp GIT_PATH_ARG = :!src/terark/fsa :!tools/fsa :!src/terark/zbs :!tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-22:06:40.093785 140008727660096 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit 5dfecb7d107196f044ff5bf78dc39d2e725b9d9b Author: leipeng Date: Thu Nov 7 15:22:45 2024 +0800 Makefile: fix for x86_64 CPU older than haswell GIT_PATH_ARG = src/terark/fsa tools/fsa g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-22:06:40.093809 140008727660096 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit d44dd5ff72707128fe3c916077b43d2093c01f7c Author: leipeng Date: Sun Oct 27 23:38:26 2024 +0800 Fix for msvc, when toplingdb on msvc GIT_PATH_ARG = src/terark/zbs tools/zbs g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/zstd -Iboost-include DEFS = -DTOPLING_IO_WITH_URING=1 -DDIVSUFSORT_API= CXXFLAGS = -fPIC -time -fdiagnostics-color -mcx16 -fno-stack-protector WARNINGS = -Wno-class-memaccess -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -Wno-deprecated-declarations -Wstrict-aliasing=3 RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 LDFLAGS = -fPIC -rdynamic 2024/11/20-22:06:40.093819 140008727660096 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit 79614a7e7dc27362fc5151b0797eb7d83c674c7b Author: rockeet Date: Sun Nov 10 15:02:21 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-22:06:40.093832 140008727660096 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit c46b65a52d9c74aa8b87aeb8438620ff2dbc669c Author: rockeet Date: Sun Nov 10 15:02:42 2024 +0800 cpu_has_bmi2.sh: detect by compile c++ code check __BMI2__ g++ (GCC) 12.2.1 20221121 (Red Hat 12.2.1-7) Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/11/20-22:06:41.438023 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst) /dev/shm/ToplingTemp/Topling-1058344-8iPesb 2024/11/20-22:06:41.611539 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst): first pass time = 0.17's, 773.803'MB/sec 2024/11/20-22:06:43.262127 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst): part-0: reject ZipStore ratio = 0.809 2024/11/20-22:06:43.560371 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst): old prealloc_size = 147639500, real_size = 130044752 2024/11/20-22:06:43.560583 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199308 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.75 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 649.42 avg-zval = 650.48 2024/11/20-22:06:43.560857 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:06:44.045157 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077271.sst): second pass time = 1.65's, 78.453'MB/sec, value only(96.4% of KV) wait indexing time = 0.30's, remap KeyValue time = 0.48's, 269.663'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1840.924'MB/sec (index lex order gen) rebuild zvType time = 0.39's, 0.127'MB/sec write SST data time = 0.09's, 1407.022'MB/sec dict compress time = 8314045560.10's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.65's, unzip length = 0.129'GB zip my value throughput = 78.453'MB/sec zip pipeline throughput = 167.483'MB/sec entries = 199308 avg-key = 24.00 avg-zkey = 1.75 avg-val = 649.42 avg-zval = 650.48 usrkeys = 199308 avg-key = 16.00 avg-zkey = 1.75 avg-val = 656.42 avg-zval = 650.48 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 199308 bytes = 722512 } seq expand size = 1395156 multi value expand size = 0 cnt WriteAppend = 15810 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1307 GB } UnZip/Zip{ index = 9.1560 value = 0.9984 dict = 0.00 all = 1.0268 } Zip/UnZip{ index = 0.1092 value = 1.0016 dict = 0.00 all = 0.9739 } ---------------------------- total value len = 563.196562 GB avg = 0.331 KB (by entry num) total key len = 44.319190 GB avg = 0.026 KB total ukey len = 32.797331 GB avg = 0.014 KB total ukey num = 2.321213884 Billion total entry num = 1.700715906 Billion write speed all = 41.662899048 MB/sec (with seq num) write speed all = 40.729830171 MB/sec (without seq num) 2024/11/20-22:06:44.201380 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77271: 199308 keys, 130720223 bytes, temperature: kWarm 2024/11/20-22:06:44.201471 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111604201428, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77271, "file_size": 130720223, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 856426320, "largest_seqno": 1213401182, "table_properties": {"data_size": 129646464, "index_size": 348288, "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": 4783392, "raw_average_key_size": 24, "raw_value_size": 129435015, "raw_average_value_size": 649, "num_data_blocks": 1, "num_entries": 199308, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111601, "oldest_key_time": 0, "file_creation_time": 1732111601, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77271, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:06:44.294755 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst) /dev/shm/ToplingTemp/Topling-1058344-Uj7dbd 2024/11/20-22:06:45.551289 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst): first pass time = 1.26's, 106.823'MB/sec 2024/11/20-22:06:46.993964 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst): part-0: reject ZipStore ratio = 0.805 2024/11/20-22:06:47.265512 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst): old prealloc_size = 147639500, real_size = 130022352 2024/11/20-22:06:47.265660 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200084 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.72 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.81 avg-zval = 647.87 2024/11/20-22:06:47.265875 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:06:47.641078 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077272.sst): second pass time = 1.44's, 89.749'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.38's, 348.078'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2614.719'MB/sec (index lex order gen) rebuild zvType time = 0.29's, 0.173'MB/sec write SST data time = 0.09's, 1528.940'MB/sec dict compress time = 8314045560.10's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.44's, unzip length = 0.129'GB zip my value throughput = 89.749'MB/sec zip pipeline throughput = 252.196'MB/sec entries = 200084 avg-key = 24.00 avg-zkey = 1.72 avg-val = 646.81 avg-zval = 647.87 usrkeys = 200084 avg-key = 16.00 avg-zkey = 1.72 avg-val = 653.54 avg-zval = 647.87 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 192363 bytes = 697328 } seq expand size = 1346541 multi value expand size = 0 cnt WriteAppend = 15807 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1307 GB } UnZip/Zip{ index = 9.3132 value = 0.9984 dict = 0.00 all = 1.0269 } Zip/UnZip{ index = 0.1074 value = 1.0016 dict = 0.00 all = 0.9738 } ---------------------------- total value len = 563.327325 GB avg = 0.331 KB (by entry num) total key len = 44.323992 GB avg = 0.026 KB total ukey len = 32.800532 GB avg = 0.014 KB total ukey num = 2.321413968 Billion total entry num = 1.700915990 Billion write speed all = 41.661921944 MB/sec (with seq num) write speed all = 40.728973363 MB/sec (without seq num) 2024/11/20-22:06:47.803371 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77272: 200084 keys, 130703775 bytes, temperature: kWarm 2024/11/20-22:06:47.803465 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111607803420, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77272, "file_size": 130703775, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213400847, "table_properties": {"data_size": 129628416, "index_size": 343744, "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": 4802016, "raw_average_key_size": 24, "raw_value_size": 129416141, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200084, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111604, "oldest_key_time": 0, "file_creation_time": 1732111604, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77272, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:06:47.907008 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst) /dev/shm/ToplingTemp/Topling-1058344-fyRkfb 2024/11/20-22:06:49.092677 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst): first pass time = 1.19's, 113.207'MB/sec 2024/11/20-22:06:50.356357 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst): part-0: reject ZipStore ratio = 0.808 2024/11/20-22:06:50.737127 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst): old prealloc_size = 147639500, real_size = 130033872 2024/11/20-22:06:50.737334 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199730 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.74 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 648.00 avg-zval = 649.06 2024/11/20-22:06:50.737554 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:06:51.078078 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077273.sst): second pass time = 1.26's, 102.486'MB/sec, value only(96.4% of KV) wait indexing time = 0.38's, remap KeyValue time = 0.34's, 382.954'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1914.420'MB/sec (index lex order gen) rebuild zvType time = 0.28's, 0.179'MB/sec write SST data time = 0.06's, 2086.594'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.26's, unzip length = 0.129'GB zip my value throughput = 102.486'MB/sec zip pipeline throughput = 102.486'MB/sec entries = 199730 avg-key = 24.00 avg-zkey = 1.74 avg-val = 648.00 avg-zval = 649.06 usrkeys = 199730 avg-key = 16.00 avg-zkey = 1.74 avg-val = 653.27 avg-zval = 649.06 TagRS{ kinds = RS_Key0_TagN bytes = 31320 } TagArray{ size = 150338 bytes = 544992 } seq expand size = 1052366 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.2058 value = 0.9984 dict = 0.00 all = 1.0280 } Zip/UnZip{ index = 0.1086 value = 1.0016 dict = 0.00 all = 0.9728 } ---------------------------- total value len = 563.457802 GB avg = 0.331 KB (by entry num) total key len = 44.328785 GB avg = 0.026 KB total ukey len = 32.803728 GB avg = 0.014 KB total ukey num = 2.321613698 Billion total entry num = 1.701115720 Billion write speed all = 41.661378858 MB/sec (with seq num) write speed all = 40.728540550 MB/sec (without seq num) 2024/11/20-22:06:51.246648 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77273: 199730 keys, 130563039 bytes, temperature: kWarm 2024/11/20-22:06:51.246716 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111611246683, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77273, "file_size": 130563039, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213401506, "table_properties": {"data_size": 129636608, "index_size": 347136, "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": 4793520, "raw_average_key_size": 24, "raw_value_size": 129424696, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199730, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111607, "oldest_key_time": 0, "file_creation_time": 1732111607, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77273, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:06:51.307569 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst) /dev/shm/ToplingTemp/Topling-1058344-irZmge 2024/11/20-22:06:52.510608 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst): first pass time = 1.20's, 111.570'MB/sec 2024/11/20-22:06:53.660464 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst): part-0: reject ZipStore ratio = 0.800 2024/11/20-22:06:54.026972 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst): old prealloc_size = 147639500, real_size = 130037248 2024/11/20-22:06:54.027200 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199225 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 649.70 avg-zval = 650.76 2024/11/20-22:06:54.027448 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:06:54.389256 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077274.sst): second pass time = 1.15's, 112.636'MB/sec, value only(96.4% of KV) wait indexing time = 0.37's, remap KeyValue time = 0.36's, 360.806'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1638.919'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.166'MB/sec write SST data time = 0.06's, 2100.822'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.15's, unzip length = 0.129'GB zip my value throughput = 112.636'MB/sec zip pipeline throughput = 152.445'MB/sec entries = 199225 avg-key = 24.00 avg-zkey = 1.70 avg-val = 649.70 avg-zval = 650.76 usrkeys = 199225 avg-key = 16.00 avg-zkey = 1.70 avg-val = 656.70 avg-zval = 650.76 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 199225 bytes = 722208 } seq expand size = 1394575 multi value expand size = 0 cnt WriteAppend = 15811 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1307 GB } UnZip/Zip{ index = 9.3885 value = 0.9984 dict = 0.00 all = 1.0268 } Zip/UnZip{ index = 0.1065 value = 1.0016 dict = 0.00 all = 0.9739 } ---------------------------- total value len = 563.588633 GB avg = 0.331 KB (by entry num) total key len = 44.333567 GB avg = 0.026 KB total ukey len = 32.806915 GB avg = 0.014 KB total ukey num = 2.321812923 Billion total entry num = 1.701314945 Billion write speed all = 41.661218751 MB/sec (with seq num) write speed all = 40.728482896 MB/sec (without seq num) 2024/11/20-22:06:54.573298 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77274: 199225 keys, 130712415 bytes, temperature: kWarm 2024/11/20-22:06:54.573365 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111614573335, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77274, "file_size": 130712415, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 895334416, "largest_seqno": 1213401629, "table_properties": {"data_size": 129647728, "index_size": 339520, "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": 4781400, "raw_average_key_size": 24, "raw_value_size": 129436355, "raw_average_value_size": 649, "num_data_blocks": 1, "num_entries": 199225, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111611, "oldest_key_time": 0, "file_creation_time": 1732111611, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77274, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:06:54.631285 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst) /dev/shm/ToplingTemp/Topling-1058344-5lKtPa 2024/11/20-22:06:55.889787 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst): first pass time = 1.26's, 106.653'MB/sec 2024/11/20-22:06:57.052755 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst): part-0: reject ZipStore ratio = 0.801 2024/11/20-22:06:57.381645 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst): old prealloc_size = 147639500, real_size = 130030064 2024/11/20-22:06:57.381807 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199566 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 648.55 avg-zval = 649.61 2024/11/20-22:06:57.381999 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:06:57.685567 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077275.sst): second pass time = 1.16's, 111.354'MB/sec, value only(96.4% of KV) wait indexing time = 0.33's, remap KeyValue time = 0.30's, 429.857'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2360.503'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.200'MB/sec write SST data time = 0.05's, 2386.443'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.16's, unzip length = 0.129'GB zip my value throughput = 111.354'MB/sec zip pipeline throughput = 111.354'MB/sec entries = 199566 avg-key = 24.00 avg-zkey = 1.70 avg-val = 648.55 avg-zval = 649.61 usrkeys = 199566 avg-key = 16.00 avg-zkey = 1.70 avg-val = 654.58 avg-zval = 649.61 TagRS{ kinds = RS_Key0_TagN bytes = 31280 } TagArray{ size = 171973 bytes = 623424 } seq expand size = 1203811 multi value expand size = 0 cnt WriteAppend = 15810 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.4011 value = 0.9984 dict = 0.00 all = 1.0274 } Zip/UnZip{ index = 0.1064 value = 1.0016 dict = 0.00 all = 0.9733 } ---------------------------- total value len = 563.719266 GB avg = 0.331 KB (by entry num) total key len = 44.338356 GB avg = 0.026 KB total ukey len = 32.810108 GB avg = 0.014 KB total ukey num = 2.322012489 Billion total entry num = 1.701514511 Billion write speed all = 41.661088121 MB/sec (with seq num) write speed all = 40.728453536 MB/sec (without seq num) 2024/11/20-22:06:57.824925 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77275: 199566 keys, 130637663 bytes, temperature: kWarm 2024/11/20-22:06:57.824993 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111617824961, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77275, "file_size": 130637663, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213402029, "table_properties": {"data_size": 129640352, "index_size": 339648, "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": 4789584, "raw_average_key_size": 24, "raw_value_size": 129428625, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 199566, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111614, "oldest_key_time": 0, "file_creation_time": 1732111614, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77275, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:06:57.885961 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst) /dev/shm/ToplingTemp/Topling-1058344-gLo87a 2024/11/20-22:06:59.051135 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst): first pass time = 1.17's, 115.195'MB/sec 2024/11/20-22:07:00.054594 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst): part-0: reject ZipStore ratio = 0.805 2024/11/20-22:07:00.393768 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst): old prealloc_size = 147639500, real_size = 130022160 2024/11/20-22:07:00.393944 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200060 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.72 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.89 avg-zval = 647.95 2024/11/20-22:07:00.394136 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:07:00.703241 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077276.sst): second pass time = 1.00's, 129.687'MB/sec, value only(96.4% of KV) wait indexing time = 0.34's, remap KeyValue time = 0.31's, 421.734'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2288.503'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.198'MB/sec write SST data time = 0.06's, 2324.931'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.00's, unzip length = 0.129'GB zip my value throughput = 129.687'MB/sec zip pipeline throughput = 129.687'MB/sec entries = 200060 avg-key = 24.00 avg-zkey = 1.72 avg-val = 646.89 avg-zval = 647.95 usrkeys = 200060 avg-key = 16.00 avg-zkey = 1.72 avg-val = 651.75 avg-zval = 647.95 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 138843 bytes = 503328 } seq expand size = 971901 multi value expand size = 0 cnt WriteAppend = 15807 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.3242 value = 0.9984 dict = 0.00 all = 1.0284 } Zip/UnZip{ index = 0.1072 value = 1.0016 dict = 0.00 all = 0.9724 } ---------------------------- total value len = 563.849654 GB avg = 0.331 KB (by entry num) total key len = 44.343158 GB avg = 0.026 KB total ukey len = 32.813309 GB avg = 0.014 KB total ukey num = 2.322212549 Billion total entry num = 1.701714571 Billion write speed all = 41.661736848 MB/sec (with seq num) write speed all = 40.729185416 MB/sec (without seq num) 2024/11/20-22:07:00.847655 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77276: 200060 keys, 130509599 bytes, temperature: kWarm 2024/11/20-22:07:00.847728 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111620847696, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77276, "file_size": 130509599, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213395442, "table_properties": {"data_size": 129628672, "index_size": 343296, "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": 4801440, "raw_average_key_size": 24, "raw_value_size": 129416437, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200060, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111617, "oldest_key_time": 0, "file_creation_time": 1732111617, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77276, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:07:00.906944 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst) /dev/shm/ToplingTemp/Topling-1058344-3re6ae 2024/11/20-22:07:02.111496 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst): first pass time = 1.20's, 111.430'MB/sec 2024/11/20-22:07:03.230822 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst): part-0: reject ZipStore ratio = 0.805 2024/11/20-22:07:03.486707 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst): old prealloc_size = 147639500, real_size = 130043664 2024/11/20-22:07:03.486870 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199445 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0004 GB avg-key = 12.00 avg-zkey = 1.76 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 648.96 avg-zval = 650.02 2024/11/20-22:07:03.487077 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0004 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:07:03.792821 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077277.sst): second pass time = 1.12's, 115.705'MB/sec, value only(96.4% of KV) wait indexing time = 0.26's, remap KeyValue time = 0.31's, 426.590'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2340.812'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.198'MB/sec write SST data time = 0.05's, 2384.917'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.12's, unzip length = 0.129'GB zip my value throughput = 115.705'MB/sec zip pipeline throughput = 115.705'MB/sec entries = 199445 avg-key = 24.00 avg-zkey = 1.76 avg-val = 648.96 avg-zval = 650.02 usrkeys = 199445 avg-key = 16.00 avg-zkey = 1.76 avg-val = 654.25 avg-zval = 650.02 TagRS{ kinds = RS_Key0_TagN bytes = 31280 } TagArray{ size = 150844 bytes = 546832 } seq expand size = 1055908 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0004 GB value = 0.1296 GB dict = 0.00 MB all = 0.1306 GB } UnZip/Zip{ index = 9.1004 value = 0.9984 dict = 0.00 all = 1.0279 } Zip/UnZip{ index = 0.1099 value = 1.0016 dict = 0.00 all = 0.9729 } ---------------------------- total value len = 563.980141 GB avg = 0.331 KB (by entry num) total key len = 44.347944 GB avg = 0.026 KB total ukey len = 32.816500 GB avg = 0.014 KB total ukey num = 2.322411994 Billion total entry num = 1.701914016 Billion write speed all = 41.662185924 MB/sec (with seq num) write speed all = 40.729722539 MB/sec (without seq num) 2024/11/20-22:07:03.938929 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77277: 199445 keys, 130574879 bytes, temperature: kWarm 2024/11/20-22:07:03.939002 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111623938968, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77277, "file_size": 130574879, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213401666, "table_properties": {"data_size": 129642944, "index_size": 350656, "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": 4786680, "raw_average_key_size": 24, "raw_value_size": 129431359, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 199445, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111620, "oldest_key_time": 0, "file_creation_time": 1732111620, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77277, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:07:03.990557 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst) /dev/shm/ToplingTemp/Topling-1058344-z39lif 2024/11/20-22:07:05.148021 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst): first pass time = 1.16's, 115.963'MB/sec 2024/11/20-22:07:06.211899 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst): part-0: reject ZipStore ratio = 0.802 2024/11/20-22:07:06.478623 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst): old prealloc_size = 147639500, real_size = 130014688 2024/11/20-22:07:06.478782 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200244 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.70 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.27 avg-zval = 647.33 2024/11/20-22:07:06.478967 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-22:07:06.787395 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077278.sst): second pass time = 1.06's, 121.741'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.31's, 422.553'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2407.545'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.197'MB/sec write SST data time = 0.05's, 2386.713'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 1.06's, unzip length = 0.129'GB zip my value throughput = 121.741'MB/sec zip pipeline throughput = 121.741'MB/sec entries = 200244 avg-key = 24.00 avg-zkey = 1.70 avg-val = 646.27 avg-zval = 647.33 usrkeys = 200244 avg-key = 16.00 avg-zkey = 1.70 avg-val = 650.93 avg-zval = 647.33 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 133363 bytes = 466784 } seq expand size = 933541 multi value expand size = 0 cnt WriteAppend = 15809 UnZipSize{ index = 0.0032 GB value = 0.1294 GB dict = 0.00 MB all = 0.1342 GB } __ZipSize{ index = 0.0003 GB value = 0.1296 GB dict = 0.00 MB all = 0.1305 GB } UnZip/Zip{ index = 9.4224 value = 0.9984 dict = 0.00 all = 1.0288 } Zip/UnZip{ index = 0.1061 value = 1.0016 dict = 0.00 all = 0.9720 } ---------------------------- total value len = 564.110487 GB avg = 0.331 KB (by entry num) total key len = 44.352750 GB avg = 0.026 KB total ukey len = 32.819704 GB avg = 0.014 KB total ukey num = 2.322612238 Billion total entry num = 1.702114260 Billion write speed all = 41.662897386 MB/sec (with seq num) write speed all = 40.730515510 MB/sec (without seq num) 2024/11/20-22:07:06.968184 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77278: 200244 keys, 130465631 bytes, temperature: kWarm 2024/11/20-22:07:06.968245 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111626968214, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77278, "file_size": 130465631, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1213400570, "table_properties": {"data_size": 129624400, "index_size": 340032, "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": 4805856, "raw_average_key_size": 24, "raw_value_size": 129411938, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200244, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111623, "oldest_key_time": 0, "file_creation_time": 1732111623, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77278, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:07:07.024476 140008727660096 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst) /dev/shm/ToplingTemp/Topling-1058344-XGTikc 2024/11/20-22:07:07.528652 140008727660096 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst): first pass time = 0.50's, 118.008'MB/sec 2024/11/20-22:07:08.057739 140008727660096 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst): part-0: reject ZipStore ratio = 0.812 2024/11/20-22:07:08.172680 140008727660096 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst): old prealloc_size = 147639500, real_size = 57645312 2024/11/20-22:07:08.172784 140008727660096 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 88294 prefix = 4 raw-key = 0.0011 GB zip-key = 0.0002 GB avg-key = 12.00 avg-zkey = 1.76 raw-val = 0.0574 GB zip-val = 0.0575 GB avg-val = 649.81 avg-zval = 650.87 2024/11/20-22:07:08.172901 140008727660096 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0002 GB, waited 0.000 sec, Key+Value = 0.059 GB 2024/11/20-22:07:08.307216 140008727660096 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00/077279.sst): second pass time = 0.53's, 108.585'MB/sec, value only(96.4% of KV) wait indexing time = 0.12's, remap KeyValue time = 0.13's, 430.684'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1801.762'MB/sec (index lex order gen) rebuild zvType time = 0.11's, 0.202'MB/sec write SST data time = 0.03's, 2279.263'MB/sec dict compress time = 140029.08's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.000'MB, throughput = 0.000'MB/sec zip my value time = 0.53's, unzip length = 0.057'GB zip my value throughput = 108.585'MB/sec zip pipeline throughput = 108.585'MB/sec entries = 88294 avg-key = 24.00 avg-zkey = 1.76 avg-val = 649.81 avg-zval = 650.87 usrkeys = 88294 avg-key = 16.00 avg-zkey = 1.76 avg-val = 656.81 avg-zval = 650.87 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 88294 bytes = 309040 } seq expand size = 618058 multi value expand size = 0 cnt WriteAppend = 7014 UnZipSize{ index = 0.0014 GB value = 0.0574 GB dict = 0.00 MB all = 0.0595 GB } __ZipSize{ index = 0.0002 GB value = 0.0575 GB dict = 0.00 MB all = 0.0579 GB } UnZip/Zip{ index = 9.0875 value = 0.9984 dict = 0.00 all = 1.0269 } Zip/UnZip{ index = 0.1100 value = 1.0016 dict = 0.00 all = 0.9738 } ---------------------------- total value len = 564.168479 GB avg = 0.331 KB (by entry num) total key len = 44.354869 GB avg = 0.026 KB total ukey len = 32.821117 GB avg = 0.014 KB total ukey num = 2.322700532 Billion total entry num = 1.702202554 Billion write speed all = 41.662677665 MB/sec (with seq num) write speed all = 40.730344448 MB/sec (without seq num) 2024/11/20-22:07:08.374184 140008727660096 [compaction_job.cc:1948] [default] [JOB 16458] Generated table #77279: 88294 keys, 57934111 bytes, temperature: kWarm 2024/11/20-22:07:08.374255 140008727660096 EVENT_LOG_v1 {"time_micros": 1732111628374221, "cf_name": "default", "job": 16458, "event": "table_file_creation", "file_number": 77279, "file_size": 57934111, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 968887379, "largest_seqno": 1213402024, "table_properties": {"data_size": 57467568, "index_size": 155456, "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": 2119056, "raw_average_key_size": 24, "raw_value_size": 57373884, "raw_average_value_size": 649, "num_data_blocks": 1, "num_entries": 88294, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 24, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-ZipOffsetBlobStore", "creation_time": 1732111627, "oldest_key_time": 0, "file_creation_time": 1732111627, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "6MZ3RU376XPAYLWHL32R", "orig_file_number": 77279, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-22:07:08.397940 140008727660096 [compaction_job.cc:703] job-16458: subcompact[0], size: 1.102821 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-16458/att-00 [077271,077272,077273,077274,077275,077276,077277,077278,077279] 2024/11/20-22:07:08.570116 140008727660096 (Original Log Time 2024/11/20-22:06:40.085199) EVENT_LOG_v1 {"time_micros": 1732111600085155, "job": 16458, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [77252], "files_L3": [77196, 77197, 77198, 77199, 77200, 77201, 77202, 77203, 77204], "score": 0.96515, "input_data_size": 1130041840, "oldest_snapshot_seqno": 1213539000} 2024/11/20-22:07:08.570122 140008727660096 (Original Log Time 2024/11/20-22:07:08.564935) [compaction_job.cc:2022] [default] [JOB 16458] Compacted 1@2 + 9@3 files to L3 => 1102821335 bytes 2024/11/20-22:07:08.570125 140008727660096 (Original Log Time 2024/11/20-22:07:08.570006) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.04, MB/sec: 39.9 rd, 39.0 wr, level 3, files in(1, 9) out(9 +0 blob) MB in(28.3, 1049.4 +0.0 blob) out(1051.7 +0.0 blob), read-write-amplify(75.3) write-amplify(37.2) OK, records in: 1727055, records dropped: 41099 output_compression: Snappy 2024/11/20-22:07:08.570132 140008727660096 (Original Log Time 2024/11/20-22:07:08.570089) EVENT_LOG_v1 {"time_micros": 1732111628570040, "cf": "default", "job": 16458, "event": "compaction_finished", "compaction_time_micros": 28312747, "compaction_time_cpu_micros": 7299104, "output_level": 3, "num_output_files": 9, "total_output_size": 1102821335, "num_input_records": 1727055, "num_output_records": 1685956, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 752217513, "file_range_sync_nanos": 0, "file_fsync_nanos": 8674, "file_prepare_write_nanos": 5174994, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/20-22:07:08.698212 140008727660096 DEBG dcompact_worker.cpp:240: HttpPost: 200 OK: url = http://nlb-7zny4kaa1poal01o64.cn-shenzhen.nlb.aliyuncs.com:8443, body = {"instanceId":"nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137","labourId":"","dbId":"d89b4006-2803-486e-b7a2-759bcf348921","dbStarts":1732096383,"starts":1732111599,"executesMs":28659,"compactionJobId":16458,"attempt":0,"compactionInputRawBytes":1161111430,"compactionInputZipBytes":1130041840,"compactionOutputRawBytes":0,"compactionOutputZipBytes":1102821335,"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-d23518ee37519a2fca9268e0ecbc2a20-60275521b5ae5167-00"}}, response = 2024/11/20-22:07:08.698269 140008727660096 INFO dcompact_worker.cpp:1464: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-16458/att-00: olev 3, work 28.659 s, result 9.721 ms, install 5.220 ms, input{raw 1.081 GiB zip 1.052 GiB}