2024/11/20-21:19:11.397779 140008459093568 DEBG dcompact_worker.cpp:2219: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00: fork to child time = 0.009316 sec 2024/11/20-21:19:11.398362 140008459093568 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00 2024/11/20-21:19:11.404960 140008459093568 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00 2024/11/20-21:19:11.406662 140008459093568 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/20-21:19:11.406918 140008459093568 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/20-21:19:11.467328 140008459093568 [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-13780/att-00/MANIFEST-049091 2024/11/20-21:19:11.527711 140008459093568 [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-13780/att-00/MANIFEST-049091 succeeded,manifest_file_number is 49091, next_file_number is 72351, last_sequence is 1152847422, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 72166 2024/11/20-21:19:11.527731 140008459093568 [version_set.cc:6269] Column family [default] (ID 0), log number is 0 2024/11/20-21:19:11.527855 140008459093568 [version_set.cc:5724] Creating manifest 72351 2024/11/20-21:19:11.562941 140008459093568 DEBG dcompact_worker.cpp:1225: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/20-21:19:11.585542 140008459093568 [compaction_job.cc:2437] [default] [JOB 13780] Compacting 1@2 + 9@3 files to L3, score 0.92, subcompactions 1 : 1 2024/11/20-21:19:11.585559 140008459093568 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 11044 Base level 2, inputs: [72321(27MB)], [72272(124MB) 72273(124MB) 72274(124MB) 72275(124MB) 72276(124MB) 72277(124MB) 72278(124MB) 72279(124MB) 72280(66MB)] 2024/11/20-21:19:11.595997 140008459093568 [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-21:19:11.596034 140008459093568 [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-21:19:11.596071 140008459093568 [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-21:19:11.596084 140008459093568 [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-21:19:11.596098 140008459093568 [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-21:19:12.925287 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst) /dev/shm/ToplingTemp/Topling-1003849-NlT7nx 2024/11/20-21:19:13.085211 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst): first pass time = 0.16's, 839.442'MB/sec 2024/11/20-21:19:14.420986 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst): part-0: reject ZipStore ratio = 0.808 2024/11/20-21:19:14.692464 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst): old prealloc_size = 147639500, real_size = 130039264 2024/11/20-21:19:14.692631 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199563 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 = 648.56 avg-zval = 649.62 2024/11/20-21:19:14.692865 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.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-21:19:15.038379 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072352.sst): second pass time = 1.34's, 96.946'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.35's, 377.927'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2273.395'MB/sec (index lex order gen) rebuild zvType time = 0.27's, 0.187'MB/sec write SST data time = 0.08's, 1643.776'MB/sec dict compress time = 2333493794.58'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.34's, unzip length = 0.129'GB zip my value throughput = 96.946'MB/sec zip pipeline throughput = 145.305'MB/sec entries = 199563 avg-key = 24.00 avg-zkey = 1.75 avg-val = 648.56 avg-zval = 649.62 usrkeys = 199563 avg-key = 16.00 avg-zkey = 1.75 avg-val = 655.56 avg-zval = 649.62 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 199563 bytes = 723424 } seq expand size = 1396941 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.1425 value = 0.9984 dict = 0.00 all = 1.0268 } Zip/UnZip{ index = 0.1094 value = 1.0016 dict = 0.00 all = 0.9739 } ---------------------------- total value len = 563.196557 GB avg = 0.331 KB (by entry num) total key len = 44.319196 GB avg = 0.026 KB total ukey len = 32.797335 GB avg = 0.014 KB total ukey num = 2.321214139 Billion total entry num = 1.700716161 Billion write speed all = 51.779750720 MB/sec (with seq num) write speed all = 50.620107917 MB/sec (without seq num) 2024/11/20-21:19:15.186080 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72352: 199563 keys, 130715615 bytes, temperature: kWarm 2024/11/20-21:19:15.186170 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108755186128, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72352, "file_size": 130715615, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 856426320, "largest_seqno": 1152384857, "table_properties": {"data_size": 129639952, "index_size": 349248, "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": 4789512, "raw_average_key_size": 24, "raw_value_size": 129428229, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 199563, "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": 1732108752, "oldest_key_time": 0, "file_creation_time": 1732108752, "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": 72352, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:15.247613 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst) /dev/shm/ToplingTemp/Topling-1003849-TaV9Ow 2024/11/20-21:19:16.451842 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst): first pass time = 1.20's, 111.459'MB/sec 2024/11/20-21:19:17.708452 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst): part-0: reject ZipStore ratio = 0.807 2024/11/20-21:19:17.983096 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst): old prealloc_size = 147639500, real_size = 130029120 2024/11/20-21:19:17.983236 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199965 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 = 647.21 avg-zval = 648.27 2024/11/20-21:19:17.983458 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.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-21:19:18.300094 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072353.sst): second pass time = 1.26's, 103.047'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.32's, 412.403'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2722.274'MB/sec (index lex order gen) rebuild zvType time = 0.26's, 0.196'MB/sec write SST data time = 0.06's, 2136.809'MB/sec dict compress time = 2333493794.58'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 = 103.047'MB/sec zip pipeline throughput = 117.824'MB/sec entries = 199965 avg-key = 24.00 avg-zkey = 1.74 avg-val = 647.21 avg-zval = 648.27 usrkeys = 199965 avg-key = 16.00 avg-zkey = 1.74 avg-val = 653.93 avg-zval = 648.27 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 192092 bytes = 696352 } seq expand size = 1344644 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.1307 GB } UnZip/Zip{ index = 9.2031 value = 0.9984 dict = 0.00 all = 1.0268 } Zip/UnZip{ index = 0.1087 value = 1.0016 dict = 0.00 all = 0.9739 } ---------------------------- total value len = 563.327321 GB avg = 0.331 KB (by entry num) total key len = 44.323995 GB avg = 0.026 KB total ukey len = 32.800534 GB avg = 0.014 KB total ukey num = 2.321414104 Billion total entry num = 1.700916126 Billion write speed all = 51.776910920 MB/sec (with seq num) write speed all = 50.617454101 MB/sec (without seq num) 2024/11/20-21:19:18.446844 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72353: 199965 keys, 130709599 bytes, temperature: kWarm 2024/11/20-21:19:18.446930 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108758446883, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72353, "file_size": 130709599, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152383815, "table_properties": {"data_size": 129631280, "index_size": 347648, "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": 4799160, "raw_average_key_size": 24, "raw_value_size": 129419124, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199965, "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": 1732108755, "oldest_key_time": 0, "file_creation_time": 1732108755, "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": 72353, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:18.519027 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst) /dev/shm/ToplingTemp/Topling-1003849-bPtOIx 2024/11/20-21:19:19.669478 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst): first pass time = 1.15's, 116.671'MB/sec 2024/11/20-21:19:20.859919 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst): part-0: reject ZipStore ratio = 0.805 2024/11/20-21:19:21.128052 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst): old prealloc_size = 147639500, real_size = 130026608 2024/11/20-21:19:21.128203 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199914 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 = 647.38 avg-zval = 648.44 2024/11/20-21:19:21.128361 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.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-21:19:21.526239 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072354.sst): second pass time = 1.19's, 108.788'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.40's, 327.827'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2516.557'MB/sec (index lex order gen) rebuild zvType time = 0.34's, 0.145'MB/sec write SST data time = 0.05's, 2402.012'MB/sec dict compress time = 2333493794.58'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.19's, unzip length = 0.129'GB zip my value throughput = 108.788'MB/sec zip pipeline throughput = 144.779'MB/sec entries = 199914 avg-key = 24.00 avg-zkey = 1.72 avg-val = 647.38 avg-zval = 648.44 usrkeys = 199914 avg-key = 16.00 avg-zkey = 1.72 avg-val = 652.62 avg-zval = 648.44 TagRS{ kinds = RS_Key0_TagN bytes = 31320 } TagArray{ size = 149668 bytes = 523856 } seq expand size = 1047676 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.1305 GB } UnZip/Zip{ index = 9.2931 value = 0.9984 dict = 0.00 all = 1.0282 } Zip/UnZip{ index = 0.1076 value = 1.0016 dict = 0.00 all = 0.9726 } ---------------------------- total value len = 563.457789 GB avg = 0.331 KB (by entry num) total key len = 44.328793 GB avg = 0.026 KB total ukey len = 32.803733 GB avg = 0.014 KB total ukey num = 2.321614018 Billion total entry num = 1.701116040 Billion write speed all = 51.774204083 MB/sec (with seq num) write speed all = 50.614929671 MB/sec (without seq num) 2024/11/20-21:19:21.680155 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72354: 199914 keys, 130534559 bytes, temperature: kWarm 2024/11/20-21:19:21.680249 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108761680202, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72354, "file_size": 130534559, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152385109, "table_properties": {"data_size": 129632224, "index_size": 344192, "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": 4797936, "raw_average_key_size": 24, "raw_value_size": 129420118, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199914, "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": 1732108758, "oldest_key_time": 0, "file_creation_time": 1732108758, "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": 72354, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:21.759874 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst) /dev/shm/ToplingTemp/Topling-1003849-G4gOfA 2024/11/20-21:19:22.980797 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst): first pass time = 1.22's, 109.936'MB/sec 2024/11/20-21:19:24.185342 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst): part-0: reject ZipStore ratio = 0.801 2024/11/20-21:19:24.549500 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst): old prealloc_size = 147639500, real_size = 130036416 2024/11/20-21:19:24.549705 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199284 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 649.50 avg-zval = 650.56 2024/11/20-21:19:24.549949 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.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-21:19:24.901752 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072355.sst): second pass time = 1.20's, 107.526'MB/sec, value only(96.4% of KV) wait indexing time = 0.36's, remap KeyValue time = 0.35's, 371.048'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1832.614'MB/sec (index lex order gen) rebuild zvType time = 0.29's, 0.171'MB/sec write SST data time = 0.06's, 2162.106'MB/sec dict compress time = 2333493794.58'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.20's, unzip length = 0.129'GB zip my value throughput = 107.526'MB/sec zip pipeline throughput = 107.526'MB/sec entries = 199284 avg-key = 24.00 avg-zkey = 1.71 avg-val = 649.50 avg-zval = 650.56 usrkeys = 199284 avg-key = 16.00 avg-zkey = 1.71 avg-val = 656.35 avg-zval = 650.56 TagRS{ kinds = RS_Key0_TagN bytes = 31240 } TagArray{ size = 195038 bytes = 682640 } seq expand size = 1365266 multi value expand size = 0 cnt WriteAppend = 15812 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.3825 value = 0.9984 dict = 0.00 all = 1.0269 } Zip/UnZip{ index = 0.1066 value = 1.0016 dict = 0.00 all = 0.9738 } ---------------------------- total value len = 563.588589 GB avg = 0.331 KB (by entry num) total key len = 44.333576 GB avg = 0.026 KB total ukey len = 32.806921 GB avg = 0.014 KB total ukey num = 2.321813302 Billion total entry num = 1.701315324 Billion write speed all = 51.770867413 MB/sec (with seq num) write speed all = 50.611790477 MB/sec (without seq num) 2024/11/20-21:19:25.045969 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72355: 199284 keys, 130703263 bytes, temperature: kWarm 2024/11/20-21:19:25.046034 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108765046004, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72355, "file_size": 130703263, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152384947, "table_properties": {"data_size": 129646576, "index_size": 339840, "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": 4782816, "raw_average_key_size": 24, "raw_value_size": 129435157, "raw_average_value_size": 649, "num_data_blocks": 1, "num_entries": 199284, "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": 1732108761, "oldest_key_time": 0, "file_creation_time": 1732108761, "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": 72355, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:25.107473 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst) /dev/shm/ToplingTemp/Topling-1003849-aw2kbx 2024/11/20-21:19:26.329407 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst): first pass time = 1.22's, 109.844'MB/sec 2024/11/20-21:19:27.313530 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-21:19:27.626289 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst): old prealloc_size = 147639500, real_size = 130025904 2024/11/20-21:19:27.626454 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 199870 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 = 647.53 avg-zval = 648.59 2024/11/20-21:19:27.626670 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.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-21:19:27.956626 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072356.sst): second pass time = 0.98's, 131.997'MB/sec, value only(96.4% of KV) wait indexing time = 0.31's, remap KeyValue time = 0.33's, 395.503'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2328.023'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.196'MB/sec write SST data time = 0.08's, 1734.983'MB/sec dict compress time = 2333493794.58'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.98's, unzip length = 0.129'GB zip my value throughput = 131.997'MB/sec zip pipeline throughput = 131.997'MB/sec entries = 199870 avg-key = 24.00 avg-zkey = 1.72 avg-val = 647.53 avg-zval = 648.59 usrkeys = 199870 avg-key = 16.00 avg-zkey = 1.72 avg-val = 653.69 avg-zval = 648.59 TagRS{ kinds = RS_Key0_TagN bytes = 31320 } TagArray{ size = 176034 bytes = 616128 } seq expand size = 1232238 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.3275 value = 0.9984 dict = 0.00 all = 1.0275 } Zip/UnZip{ index = 0.1072 value = 1.0016 dict = 0.00 all = 0.9732 } ---------------------------- total value len = 563.719243 GB avg = 0.331 KB (by entry num) total key len = 44.338373 GB avg = 0.026 KB total ukey len = 32.810119 GB avg = 0.014 KB total ukey num = 2.322013172 Billion total entry num = 1.701515194 Billion write speed all = 51.768934692 MB/sec (with seq num) write speed all = 50.610023079 MB/sec (without seq num) 2024/11/20-21:19:28.113578 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72356: 199870 keys, 130626207 bytes, temperature: kWarm 2024/11/20-21:19:28.113638 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108768113606, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72356, "file_size": 130626207, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152385037, "table_properties": {"data_size": 129632928, "index_size": 342848, "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": 4796880, "raw_average_key_size": 24, "raw_value_size": 129420876, "raw_average_value_size": 647, "num_data_blocks": 1, "num_entries": 199870, "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": 1732108765, "oldest_key_time": 0, "file_creation_time": 1732108765, "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": 72356, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:28.169153 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst) /dev/shm/ToplingTemp/Topling-1003849-prOOBy 2024/11/20-21:19:29.343201 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst): first pass time = 1.17's, 114.324'MB/sec 2024/11/20-21:19:30.678234 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-21:19:30.945162 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst): old prealloc_size = 147639500, real_size = 130017824 2024/11/20-21:19:30.945309 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200241 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.28 avg-zval = 647.35 2024/11/20-21:19:30.945452 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.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-21:19:31.258466 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072357.sst): second pass time = 1.33's, 96.985'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.31's, 416.187'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2537.992'MB/sec (index lex order gen) rebuild zvType time = 0.26's, 0.196'MB/sec write SST data time = 0.06's, 2256.927'MB/sec dict compress time = 2333493794.58'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.33's, unzip length = 0.129'GB zip my value throughput = 96.985'MB/sec zip pipeline throughput = 114.616'MB/sec entries = 200241 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.28 avg-zval = 647.35 usrkeys = 200241 avg-key = 16.00 avg-zkey = 1.71 avg-val = 650.10 avg-zval = 647.35 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 109222 bytes = 382288 } seq expand size = 764554 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.1304 GB } UnZip/Zip{ index = 9.3553 value = 0.9984 dict = 0.00 all = 1.0294 } Zip/UnZip{ index = 0.1069 value = 1.0016 dict = 0.00 all = 0.9714 } ---------------------------- total value len = 563.849420 GB avg = 0.331 KB (by entry num) total key len = 44.343178 GB avg = 0.026 KB total ukey len = 32.813323 GB avg = 0.014 KB total ukey num = 2.322213413 Billion total entry num = 1.701715435 Billion write speed all = 51.765874676 MB/sec (with seq num) write speed all = 50.607152414 MB/sec (without seq num) 2024/11/20-21:19:31.406723 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72357: 200241 keys, 130384287 bytes, temperature: kWarm 2024/11/20-21:19:31.406812 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108771406767, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72357, "file_size": 130384287, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152383194, "table_properties": {"data_size": 129625104, "index_size": 342464, "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": 4805784, "raw_average_key_size": 24, "raw_value_size": 129412661, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200241, "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": 1732108768, "oldest_key_time": 0, "file_creation_time": 1732108768, "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": 72357, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:31.488473 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst) /dev/shm/ToplingTemp/Topling-1003849-Nqvslx 2024/11/20-21:19:32.708917 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst): first pass time = 1.22's, 109.980'MB/sec 2024/11/20-21:19:33.779401 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst): part-0: reject ZipStore ratio = 0.803 2024/11/20-21:19:34.049149 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst): old prealloc_size = 147639500, real_size = 130018688 2024/11/20-21:19:34.049311 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200272 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.18 avg-zval = 647.24 2024/11/20-21:19:34.049468 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.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-21:19:34.355980 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072358.sst): second pass time = 1.07's, 120.984'MB/sec, value only(96.4% of KV) wait indexing time = 0.27's, remap KeyValue time = 0.31's, 425.084'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2419.148'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.201'MB/sec write SST data time = 0.06's, 2261.942'MB/sec dict compress time = 2333493794.58'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.07's, unzip length = 0.129'GB zip my value throughput = 120.984'MB/sec zip pipeline throughput = 120.984'MB/sec entries = 200272 avg-key = 24.00 avg-zkey = 1.72 avg-val = 646.18 avg-zval = 647.24 usrkeys = 200272 avg-key = 16.00 avg-zkey = 1.72 avg-val = 650.37 avg-zval = 647.24 TagRS{ kinds = RS_Key0_TagN bytes = 31400 } TagArray{ size = 119809 bytes = 419344 } seq expand size = 838663 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.1304 GB } UnZip/Zip{ index = 9.3029 value = 0.9984 dict = 0.00 all = 1.0291 } Zip/UnZip{ index = 0.1075 value = 1.0016 dict = 0.00 all = 0.9717 } ---------------------------- total value len = 563.979670 GB avg = 0.331 KB (by entry num) total key len = 44.347985 GB avg = 0.026 KB total ukey len = 32.816528 GB avg = 0.014 KB total ukey num = 2.322413685 Billion total entry num = 1.701915707 Billion write speed all = 51.763722800 MB/sec (with seq num) write speed all = 50.605169613 MB/sec (without seq num) 2024/11/20-21:19:34.495061 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72358: 200272 keys, 130422175 bytes, temperature: kWarm 2024/11/20-21:19:34.495134 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108774495102, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72358, "file_size": 130422175, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152375537, "table_properties": {"data_size": 129623984, "index_size": 344448, "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": 4806528, "raw_average_key_size": 24, "raw_value_size": 129411445, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200272, "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": 1732108771, "oldest_key_time": 0, "file_creation_time": 1732108771, "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": 72358, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:34.550380 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst) /dev/shm/ToplingTemp/Topling-1003849-aGx1cz 2024/11/20-21:19:35.727551 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst): first pass time = 1.18's, 114.021'MB/sec 2024/11/20-21:19:36.880650 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst): part-0: reject ZipStore ratio = 0.801 2024/11/20-21:19:37.140637 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst): old prealloc_size = 147639500, real_size = 130018368 2024/11/20-21:19:37.140768 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 200180 prefix = 4 raw-key = 0.0024 GB zip-key = 0.0003 GB avg-key = 12.00 avg-zkey = 1.71 raw-val = 0.1294 GB zip-val = 0.1296 GB avg-val = 646.49 avg-zval = 647.55 2024/11/20-21:19:37.140933 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.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-21:19:37.444977 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072359.sst): second pass time = 1.15's, 112.309'MB/sec, value only(96.4% of KV) wait indexing time = 0.26's, remap KeyValue time = 0.30's, 428.830'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2874.326'MB/sec (index lex order gen) rebuild zvType time = 0.25's, 0.200'MB/sec write SST data time = 0.05's, 2435.254'MB/sec dict compress time = 2333493794.58'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.309'MB/sec zip pipeline throughput = 112.309'MB/sec entries = 200180 avg-key = 24.00 avg-zkey = 1.71 avg-val = 646.49 avg-zval = 647.55 usrkeys = 200180 avg-key = 16.00 avg-zkey = 1.71 avg-val = 651.46 avg-zval = 647.55 TagRS{ kinds = RS_Key0_TagN bytes = 31360 } TagArray{ size = 142225 bytes = 497808 } seq expand size = 995575 multi value expand size = 0 cnt WriteAppend = 15808 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.3647 value = 0.9984 dict = 0.00 all = 1.0285 } Zip/UnZip{ index = 0.1068 value = 1.0016 dict = 0.00 all = 0.9723 } ---------------------------- total value len = 564.110079 GB avg = 0.331 KB (by entry num) total key len = 44.352789 GB avg = 0.026 KB total ukey len = 32.819730 GB avg = 0.014 KB total ukey num = 2.322613865 Billion total entry num = 1.702115887 Billion write speed all = 51.761622905 MB/sec (with seq num) write speed all = 50.603237929 MB/sec (without seq num) 2024/11/20-21:19:37.587639 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72359: 200180 keys, 130500447 bytes, temperature: kWarm 2024/11/20-21:19:37.587711 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108777587679, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72359, "file_size": 130500447, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152385042, "table_properties": {"data_size": 129626096, "index_size": 342016, "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": 4804320, "raw_average_key_size": 24, "raw_value_size": 129413713, "raw_average_value_size": 646, "num_data_blocks": 1, "num_entries": 200180, "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": 1732108774, "oldest_key_time": 0, "file_creation_time": 1732108774, "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": 72359, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:37.642148 140008459093568 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst) /dev/shm/ToplingTemp/Topling-1003849-afmTwA 2024/11/20-21:19:38.298470 140008459093568 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst): first pass time = 0.66's, 116.135'MB/sec 2024/11/20-21:19:38.915397 140008459093568 [top_zip_table_builder.cc:2752] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst): part-0: reject ZipStore ratio = 0.809 2024/11/20-21:19:39.058789 140008459093568 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst): old prealloc_size = 147639500, real_size = 73845648 2024/11/20-21:19:39.058899 140008459093568 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = ZipOffsetBlobStore usrkeys = 113312 prefix = 4 raw-key = 0.0014 GB zip-key = 0.0002 GB avg-key = 12.00 avg-zkey = 1.75 raw-val = 0.0735 GB zip-val = 0.0736 GB avg-val = 648.64 avg-zval = 649.70 2024/11/20-21:19:39.059025 140008459093568 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0002 GB, waited 0.000 sec, Key+Value = 0.076 GB 2024/11/20-21:19:39.227820 140008459093568 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00/072360.sst): second pass time = 0.62's, 119.273'MB/sec, value only(96.4% of KV) wait indexing time = 0.14's, remap KeyValue time = 0.17's, 438.885'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2105.504'MB/sec (index lex order gen) rebuild zvType time = 0.14's, 0.205'MB/sec write SST data time = 0.03's, 2434.517'MB/sec dict compress time = 2333493794.58'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.62's, unzip length = 0.073'GB zip my value throughput = 119.273'MB/sec zip pipeline throughput = 119.273'MB/sec entries = 113312 avg-key = 24.00 avg-zkey = 1.75 avg-val = 648.64 avg-zval = 649.70 usrkeys = 113312 avg-key = 16.00 avg-zkey = 1.75 avg-val = 654.64 avg-zval = 649.70 TagRS{ kinds = RS_Key0_TagN bytes = 17800 } TagArray{ size = 97197 bytes = 340208 } seq expand size = 680379 multi value expand size = 0 cnt WriteAppend = 8982 UnZipSize{ index = 0.0018 GB value = 0.0735 GB dict = 0.00 MB all = 0.0762 GB } __ZipSize{ index = 0.0002 GB value = 0.0736 GB dict = 0.00 MB all = 0.0742 GB } UnZip/Zip{ index = 9.1322 value = 0.9984 dict = 0.00 all = 1.0275 } Zip/UnZip{ index = 0.1095 value = 1.0016 dict = 0.00 all = 0.9732 } ---------------------------- total value len = 564.184258 GB avg = 0.331 KB (by entry num) total key len = 44.355509 GB avg = 0.026 KB total ukey len = 32.821543 GB avg = 0.014 KB total ukey num = 2.322727177 Billion total entry num = 1.702229199 Billion write speed all = 51.760314344 MB/sec (with seq num) write speed all = 50.602027925 MB/sec (without seq num) 2024/11/20-21:19:39.308685 140008459093568 [compaction_job.cc:1948] [default] [JOB 13780] Generated table #72360: 113312 keys, 74177439 bytes, temperature: kWarm 2024/11/20-21:19:39.308748 140008459093568 EVENT_LOG_v1 {"time_micros": 1732108779308718, "cf_name": "default", "job": 13780, "event": "table_file_creation", "file_number": 72360, "file_size": 74177439, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1152385160, "table_properties": {"data_size": 73618624, "index_size": 198528, "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": 2719488, "raw_average_key_size": 24, "raw_value_size": 73498401, "raw_average_value_size": 648, "num_data_blocks": 1, "num_entries": 113312, "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": 1732108777, "oldest_key_time": 0, "file_creation_time": 1732108777, "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": 72360, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-21:19:39.335400 140008459093568 [compaction_job.cc:703] job-13780: subcompact[0], size: 1.118774 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-13780/att-00 [072352,072353,072354,072355,072356,072357,072358,072359,072360] 2024/11/20-21:19:39.452743 140008459093568 (Original Log Time 2024/11/20-21:19:11.585636) EVENT_LOG_v1 {"time_micros": 1732108751585586, "job": 13780, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [72321], "files_L3": [72272, 72273, 72274, 72275, 72276, 72277, 72278, 72279, 72280], "score": 0.915509, "input_data_size": 1143646769, "oldest_snapshot_seqno": 1152847163} 2024/11/20-21:19:39.452747 140008459093568 (Original Log Time 2024/11/20-21:19:39.451864) [compaction_job.cc:2022] [default] [JOB 13780] Compacted 1@2 + 9@3 files to L3 => 1118773591 bytes 2024/11/20-21:19:39.452748 140008459093568 (Original Log Time 2024/11/20-21:19:39.452676) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 9 0 0 0] max score 0.04, MB/sec: 41.2 rd, 40.3 wr, level 3, files in(1, 9) out(9 +0 blob) MB in(27.9, 1062.8 +0.0 blob) out(1066.9 +0.0 blob), read-write-amplify(77.4) write-amplify(38.3) OK, records in: 1750154, records dropped: 37553 output_compression: Snappy 2024/11/20-21:19:39.452752 140008459093568 (Original Log Time 2024/11/20-21:19:39.452722) EVENT_LOG_v1 {"time_micros": 1732108779452699, "cf": "default", "job": 13780, "event": "compaction_finished", "compaction_time_micros": 27749773, "compaction_time_cpu_micros": 7028873, "output_level": 3, "num_output_files": 9, "total_output_size": 1118773591, "num_input_records": 1750154, "num_output_records": 1712601, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 743039065, "file_range_sync_nanos": 0, "file_fsync_nanos": 8072, "file_prepare_write_nanos": 5261349, "lsm_state": [0, 0, 0, 9, 0, 0, 0]} 2024/11/20-21:19:39.564141 140008459093568 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":1732108751,"executesMs":28044,"compactionJobId":13780,"attempt":0,"compactionInputRawBytes":1175427755,"compactionInputZipBytes":1143646769,"compactionOutputRawBytes":0,"compactionOutputZipBytes":1118773591,"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-2c3858a8b9f776b955fc1fa5abf4af37-e84d113a8c6edc8d-00"}}, response = 2024/11/20-21:19:39.564212 140008459093568 INFO dcompact_worker.cpp:1464: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-13780/att-00: olev 3, work 28.045 s, result 8.925 ms, install 0.906 ms, input{raw 1.095 GiB zip 1.065 GiB}