2024/11/20-23:41:49.237971 140007913567808 DEBG dcompact_worker.cpp:2219: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00: fork to child time = 0.021853 sec 2024/11/20-23:41:49.238747 140007913567808 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00 2024/11/20-23:41:49.246247 140007913567808 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00 2024/11/20-23:41:49.248500 140007913567808 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/20-23:41:49.248832 140007913567808 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/20-23:41:49.293758 140007913567808 [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-21558/att-00/MANIFEST-049091 2024/11/20-23:41:49.310322 140007913567808 [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-21558/att-00/MANIFEST-049091 succeeded,manifest_file_number is 49091, next_file_number is 86689, last_sequence is 1327089724, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 86523 2024/11/20-23:41:49.310332 140007913567808 [version_set.cc:6269] Column family [default] (ID 0), log number is 0 2024/11/20-23:41:49.310426 140007913567808 [version_set.cc:5724] Creating manifest 86689 2024/11/20-23:41:49.341763 140007913567808 DEBG dcompact_worker.cpp:1225: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/20-23:41:49.361536 140007913567808 [compaction_job.cc:2437] [default] [JOB 21558] Compacting 1@2 + 5@3 files to L3, score 1.00, subcompactions 1 : 1 2024/11/20-23:41:49.361560 140007913567808 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 16120 Base level 2, inputs: [86681(18MB)], [86650(38MB) 86601(40MB) 86602(40MB) 86603(39MB) 86604(9790KB)] 2024/11/20-23:41:49.369660 140007913567808 [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-23:41:49.369696 140007913567808 [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-23:41:49.369724 140007913567808 [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-23:41:49.369736 140007913567808 [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-23:41:49.369750 140007913567808 [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-23:41:49.865336 140007913567808 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst) /dev/shm/ToplingTemp/Topling-1161419-dwFeUf 2024/11/20-23:41:50.557375 140007913567808 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst): first pass time = 0.69's, 193.959'MB/sec 2024/11/20-23:41:51.111776 140007913567808 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst): old prealloc_size = 147639500, real_size = 40608000 2024/11/20-23:41:51.111908 140007913567808 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 122353 prefix = 4 raw-key = 0.0010 GB zip-key = 0.0002 GB avg-key = 8.00 avg-zkey = 1.72 raw-val = 0.1316 GB zip-val = 0.0404 GB avg-val =1075.82 avg-zval = 329.92 2024/11/20-23:41:51.112055 140007913567808 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0003 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-23:41:51.309338 140007913567808 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086690.sst): second pass time = 0.55's, 237.751'MB/sec, value only(98.1% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.20's, 213.538'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1950.801'MB/sec (index lex order gen) rebuild zvType time = 0.14's, 0.212'MB/sec write SST data time = 0.05's, 791.749'MB/sec dict compress time = 5433441498.03's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.378'MB, throughput = 41989.667'MB/sec zip my value time = 0.55's, unzip length = 0.132'GB zip my value throughput = 237.751'MB/sec zip pipeline throughput = 241.392'MB/sec entries = 129428 avg-key = 20.00 avg-zkey = 1.63 avg-val = 1017.01 avg-zval = 311.88 usrkeys = 122353 avg-key = 12.00 avg-zkey = 1.72 avg-val = 1079.39 avg-zval = 329.92 TagRS{ kinds = RS_KeyN_TagN bytes = 42496 } TagArray{ size = 52331 bytes = 189712 } seq expand size = 380626 multi value expand size = 56592 cnt WriteAppend = 13 UnZipSize{ index = 0.0015 GB value = 0.1316 GB dict = 1.38 MB all = 0.1342 GB } __ZipSize{ index = 0.0002 GB value = 0.0404 GB dict = 1.38 MB all = 0.0422 GB } UnZip/Zip{ index = 6.9603 value = 3.2609 dict = 1.00 all = 3.1814 } Zip/UnZip{ index = 0.1437 value = 0.3067 dict = 1.00 all = 0.3143 } ---------------------------- total value len = 563.197799 GB avg = 0.331 KB (by entry num) total key len = 44.316995 GB avg = 0.026 KB total ukey len = 32.795610 GB avg = 0.014 KB total ukey num = 2.321136929 Billion total entry num = 1.700646026 Billion write speed all = 29.943120327 MB/sec (with seq num) write speed all = 29.272550338 MB/sec (without seq num) 2024/11/20-23:41:51.361187 140007913567808 [compaction_job.cc:1948] [default] [JOB 21558] Generated table #86690: 129428 keys, 42188776 bytes, temperature: kWarm 2024/11/20-23:41:51.361284 140007913567808 EVENT_LOG_v1 {"time_micros": 1732117311361241, "cf_name": "default", "job": 21558, "event": "table_file_creation", "file_number": 86690, "file_size": 42188776, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1326999793, "table_properties": {"data_size": 40366256, "index_size": 210944, "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": 2588560, "raw_average_key_size": 20, "raw_value_size": 131629586, "raw_average_value_size": 1017, "num_data_blocks": 1, "num_entries": 129428, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 20, "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_KeyN_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732117309, "oldest_key_time": 0, "file_creation_time": 1732117309, "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": 86690, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-23:41:51.400261 140007913567808 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst) /dev/shm/ToplingTemp/Topling-1161419-3AAXQf 2024/11/20-23:41:52.042269 140007913567808 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst): first pass time = 0.64's, 209.069'MB/sec 2024/11/20-23:41:53.245042 140007913567808 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst): old prealloc_size = 147639500, real_size = 40691376 2024/11/20-23:41:53.245222 140007913567808 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 117180 prefix = 4 raw-key = 0.0009 GB zip-key = 0.0002 GB avg-key = 8.00 avg-zkey = 1.80 raw-val = 0.1316 GB zip-val = 0.0405 GB avg-val =1123.31 avg-zval = 345.20 2024/11/20-23:41:53.245405 140007913567808 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0002 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-23:41:53.528678 140007913567808 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086691.sst): second pass time = 1.20's, 109.519'MB/sec, value only(98.1% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.28's, 149.615'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1614.532'MB/sec (index lex order gen) rebuild zvType time = 0.21's, 0.137'MB/sec write SST data time = 0.07's, 613.015'MB/sec dict compress time = 5433441498.03's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.378'MB, throughput = 29075.693'MB/sec zip my value time = 1.20's, unzip length = 0.132'GB zip my value throughput = 109.519'MB/sec zip pipeline throughput = 207.863'MB/sec entries = 129434 avg-key = 20.00 avg-zkey = 1.63 avg-val = 1016.96 avg-zval = 312.52 usrkeys = 117180 avg-key = 12.00 avg-zkey = 1.80 avg-val = 1130.17 avg-zval = 345.20 TagRS{ kinds = RS_KeyN_TagN bytes = 42416 } TagArray{ size = 97282 bytes = 352656 } seq expand size = 705675 multi value expand size = 98020 cnt WriteAppend = 13 UnZipSize{ index = 0.0014 GB value = 0.1316 GB dict = 1.38 MB all = 0.1342 GB } __ZipSize{ index = 0.0002 GB value = 0.0405 GB dict = 1.38 MB all = 0.0424 GB } UnZip/Zip{ index = 6.6640 value = 3.2541 dict = 1.00 all = 3.1628 } Zip/UnZip{ index = 0.1501 value = 0.3073 dict = 1.00 all = 0.3162 } ---------------------------- total value len = 563.330232 GB avg = 0.331 KB (by entry num) total key len = 44.319584 GB avg = 0.026 KB total ukey len = 32.797016 GB avg = 0.014 KB total ukey num = 2.321254109 Billion total entry num = 1.700775460 Billion write speed all = 29.946499513 MB/sec (with seq num) write speed all = 29.275951836 MB/sec (without seq num) 2024/11/20-23:41:53.581163 140007913567808 [compaction_job.cc:1948] [default] [JOB 21558] Generated table #86691: 129434 keys, 42436875 bytes, temperature: kWarm 2024/11/20-23:41:53.581242 140007913567808 EVENT_LOG_v1 {"time_micros": 1732117313581209, "cf_name": "default", "job": 21558, "event": "table_file_creation", "file_number": 86691, "file_size": 42436875, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1326999672, "table_properties": {"data_size": 40450912, "index_size": 211008, "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": 2588680, "raw_average_key_size": 20, "raw_value_size": 131629326, "raw_average_value_size": 1016, "num_data_blocks": 1, "num_entries": 129434, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 20, "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_KeyN_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732117311, "oldest_key_time": 0, "file_creation_time": 1732117311, "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": 86691, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-23:41:53.622743 140007913567808 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst) /dev/shm/ToplingTemp/Topling-1161419-lwHQfi 2024/11/20-23:41:53.807088 140007913567808 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst): first pass time = 0.18's, 728.272'MB/sec 2024/11/20-23:41:54.356525 140007913567808 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst): old prealloc_size = 147639500, real_size = 40716640 2024/11/20-23:41:54.356644 140007913567808 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 111420 prefix = 4 raw-key = 0.0009 GB zip-key = 0.0002 GB avg-key = 8.00 avg-zkey = 1.75 raw-val = 0.1316 GB zip-val = 0.0405 GB avg-val =1181.38 avg-zval = 363.43 2024/11/20-23:41:54.356793 140007913567808 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0002 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-23:41:54.583231 140007913567808 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086692.sst): second pass time = 0.55's, 240.438'MB/sec, value only(98.1% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.23's, 187.324'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2005.816'MB/sec (index lex order gen) rebuild zvType time = 0.15's, 0.180'MB/sec write SST data time = 0.07's, 592.397'MB/sec dict compress time = 5433441498.03's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.378'MB, throughput = 38277.560'MB/sec zip my value time = 0.55's, unzip length = 0.132'GB zip my value throughput = 240.438'MB/sec zip pipeline throughput = 240.438'MB/sec entries = 129432 avg-key = 20.00 avg-zkey = 1.51 avg-val = 1016.98 avg-zval = 312.85 usrkeys = 111420 avg-key = 12.00 avg-zkey = 1.75 avg-val = 1189.00 avg-zval = 363.43 TagRS{ kinds = RS_KeyN_TagN bytes = 42328 } TagArray{ size = 95378 bytes = 345760 } seq expand size = 704044 multi value expand size = 144080 cnt WriteAppend = 13 UnZipSize{ index = 0.0013 GB value = 0.1316 GB dict = 1.38 MB all = 0.1342 GB } __ZipSize{ index = 0.0002 GB value = 0.0405 GB dict = 1.38 MB all = 0.0425 GB } UnZip/Zip{ index = 6.8496 value = 3.2506 dict = 1.00 all = 3.1613 } Zip/UnZip{ index = 0.1460 value = 0.3076 dict = 1.00 all = 0.3163 } ---------------------------- total value len = 563.462710 GB avg = 0.331 KB (by entry num) total key len = 44.322172 GB avg = 0.026 KB total ukey len = 32.798353 GB avg = 0.014 KB total ukey num = 2.321365529 Billion total entry num = 1.700904892 Billion write speed all = 29.951599367 MB/sec (with seq num) write speed all = 29.281035510 MB/sec (without seq num) 2024/11/20-23:41:54.638385 140007913567808 [compaction_job.cc:1948] [default] [JOB 21558] Generated table #86692: 129432 keys, 42456634 bytes, temperature: kWarm 2024/11/20-23:41:54.638454 140007913567808 EVENT_LOG_v1 {"time_micros": 1732117314638422, "cf_name": "default", "job": 21558, "event": "table_file_creation", "file_number": 86692, "file_size": 42456634, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1326999678, "table_properties": {"data_size": 40493392, "index_size": 195200, "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": 2588640, "raw_average_key_size": 20, "raw_value_size": 131629818, "raw_average_value_size": 1016, "num_data_blocks": 1, "num_entries": 129432, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 20, "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_KeyN_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732117313, "oldest_key_time": 0, "file_creation_time": 1732117313, "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": 86692, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-23:41:54.677235 140007913567808 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst) /dev/shm/ToplingTemp/Topling-1161419-mJamsf 2024/11/20-23:41:55.210901 140007913567808 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst): first pass time = 0.53's, 251.517'MB/sec 2024/11/20-23:41:56.511428 140007913567808 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst): old prealloc_size = 147639500, real_size = 40411648 2024/11/20-23:41:56.511584 140007913567808 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 129379 prefix = 4 raw-key = 0.0010 GB zip-key = 0.0002 GB avg-key = 8.00 avg-zkey = 1.72 raw-val = 0.1316 GB zip-val = 0.0402 GB avg-val =1017.39 avg-zval = 310.38 2024/11/20-23:41:56.511686 140007913567808 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0003 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/20-23:41:56.751554 140007913567808 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086693.sst): second pass time = 1.30's, 101.272'MB/sec, value only(98.1% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.24's, 174.298'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1692.083'MB/sec (index lex order gen) rebuild zvType time = 0.19's, 0.171'MB/sec write SST data time = 0.05's, 828.257'MB/sec dict compress time = 5433441498.03's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.378'MB, throughput = 45168.229'MB/sec zip my value time = 1.30's, unzip length = 0.132'GB zip my value throughput = 101.272'MB/sec zip pipeline throughput = 200.871'MB/sec entries = 129430 avg-key = 20.00 avg-zkey = 1.72 avg-val = 1016.99 avg-zval = 310.26 usrkeys = 129379 avg-key = 12.00 avg-zkey = 1.72 avg-val = 1018.14 avg-zval = 310.38 TagRS{ kinds = RS_KeyN_TagN bytes = 42608 } TagArray{ size = 13596 bytes = 49296 } seq expand size = 95463 multi value expand size = 408 cnt WriteAppend = 13 UnZipSize{ index = 0.0016 GB value = 0.1316 GB dict = 1.38 MB all = 0.1342 GB } __ZipSize{ index = 0.0002 GB value = 0.0402 GB dict = 1.38 MB all = 0.0419 GB } UnZip/Zip{ index = 6.9849 value = 3.2779 dict = 1.00 all = 3.2071 } Zip/UnZip{ index = 0.1432 value = 0.3051 dict = 1.00 all = 0.3118 } ---------------------------- total value len = 563.594435 GB avg = 0.331 KB (by entry num) total key len = 44.324761 GB avg = 0.026 KB total ukey len = 32.799906 GB avg = 0.014 KB total ukey num = 2.321494908 Billion total entry num = 1.701034322 Billion write speed all = 29.955017457 MB/sec (with seq num) write speed all = 29.284474226 MB/sec (without seq num) 2024/11/20-23:41:56.801865 140007913567808 [compaction_job.cc:1948] [default] [JOB 21558] Generated table #86693: 129430 keys, 41850861 bytes, temperature: kWarm 2024/11/20-23:41:56.801931 140007913567808 EVENT_LOG_v1 {"time_micros": 1732117316801902, "cf_name": "default", "job": 21558, "event": "table_file_creation", "file_number": 86693, "file_size": 41850861, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1326980070, "table_properties": {"data_size": 40156848, "index_size": 222272, "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": 2588600, "raw_average_key_size": 20, "raw_value_size": 131629436, "raw_average_value_size": 1016, "num_data_blocks": 1, "num_entries": 129430, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 20, "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_KeyN_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732117314, "oldest_key_time": 0, "file_creation_time": 1732117314, "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": 86693, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-23:41:56.838962 140007913567808 [top_zip_table_builder.cc:960] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst) /dev/shm/ToplingTemp/Topling-1161419-1U1O2e 2024/11/20-23:41:56.982087 140007913567808 [top_zip_table_builder.cc:1378] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst): first pass time = 0.14's, 240.585'MB/sec 2024/11/20-23:41:57.225276 140007913567808 [top_zip_table_builder.cc:2798] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst): old prealloc_size = 147639500, real_size = 10513408 2024/11/20-23:41:57.225343 140007913567808 [top_zip_table_builder.cc:1799] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 33179 prefix = 4 raw-key = 0.0003 GB zip-key = 0.0001 GB avg-key = 8.00 avg-zkey = 1.83 raw-val = 0.0338 GB zip-val = 0.0104 GB avg-val =1017.51 avg-zval = 314.78 2024/11/20-23:41:57.225396 140007913567808 [top_zip_table_builder.cc:1325] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst: sumWaitingMem = 0.000 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0001 GB, waited 0.000 sec, Key+Value = 0.034 GB 2024/11/20-23:41:57.273110 140007913567808 [top_zip_table_builder.cc:3129] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00/086694.sst): second pass time = 0.24's, 139.255'MB/sec, value only(98.1% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.05's, 227.788'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 1328.172'MB/sec (index lex order gen) rebuild zvType time = 0.04's, 0.230'MB/sec write SST data time = 0.01's, 929.117'MB/sec dict compress time = 0.00's, 286542.461'MB/sec z-dict build time = 0.00's, sample length = 0.331'MB, throughput = 7639.191'MB/sec zip my value time = 0.24's, unzip length = 0.034'GB zip my value throughput = 139.255'MB/sec zip pipeline throughput = 139.255'MB/sec entries = 33196 avg-key = 20.00 avg-zkey = 1.83 avg-val = 1016.99 avg-zval = 314.62 usrkeys = 33179 avg-key = 12.00 avg-zkey = 1.83 avg-val = 1019.98 avg-zval = 314.78 TagRS{ kinds = RS_KeyN_TagN bytes = 11024 } TagArray{ size = 11649 bytes = 42240 } seq expand size = 81598 multi value expand size = 136 cnt WriteAppend = 13 UnZipSize{ index = 0.0004 GB value = 0.0338 GB dict = 0.33 MB all = 0.0344 GB } __ZipSize{ index = 0.0001 GB value = 0.0104 GB dict = 0.33 MB all = 0.0109 GB } UnZip/Zip{ index = 6.5554 value = 3.2324 dict = 1.00 all = 3.1609 } Zip/UnZip{ index = 0.1525 value = 0.3094 dict = 1.00 all = 0.3164 } ---------------------------- total value len = 563.628277 GB avg = 0.331 KB (by entry num) total key len = 44.325425 GB avg = 0.026 KB total ukey len = 32.800304 GB avg = 0.014 KB total ukey num = 2.321528087 Billion total entry num = 1.701067518 Billion write speed all = 29.955947861 MB/sec (with seq num) write speed all = 29.285408776 MB/sec (without seq num) 2024/11/20-23:41:57.311531 140007913567808 [compaction_job.cc:1948] [default] [JOB 21558] Generated table #86694: 33196 keys, 10890412 bytes, temperature: kWarm 2024/11/20-23:41:57.311595 140007913567808 EVENT_LOG_v1 {"time_micros": 1732117317311566, "cf_name": "default", "job": 21558, "event": "table_file_creation", "file_number": 86694, "file_size": 10890412, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 1326992150, "table_properties": {"data_size": 10444208, "index_size": 60736, "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": 663920, "raw_average_key_size": 20, "raw_value_size": 33760017, "raw_average_value_size": 1016, "num_data_blocks": 1, "num_entries": 33196, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 20, "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_KeyN_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732117316, "oldest_key_time": 0, "file_creation_time": 1732117316, "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": 86694, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/20-23:41:57.324559 140007913567808 [compaction_job.cc:703] job-21558: subcompact[0], size: 0.179824 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-21558/att-00 [086690,086691,086692,086693,086694] 2024/11/20-23:41:57.395563 140007913567808 (Original Log Time 2024/11/20-23:41:49.361646) EVENT_LOG_v1 {"time_micros": 1732117309361583, "job": 21558, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [86681], "files_L3": [86650, 86601, 86602, 86603, 86604], "score": 0.999867, "input_data_size": 197218842, "oldest_snapshot_seqno": 1323177126} 2024/11/20-23:41:57.395567 140007913567808 (Original Log Time 2024/11/20-23:41:57.394883) [compaction_job.cc:2022] [default] [JOB 21558] Compacted 1@2 + 5@3 files to L3 => 179823558 bytes 2024/11/20-23:41:57.395568 140007913567808 (Original Log Time 2024/11/20-23:41:57.395493) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 5 0 0 0] max score 0.01, MB/sec: 24.8 rd, 22.6 wr, level 3, files in(1, 5) out(5 +0 blob) MB in(18.9, 169.2 +0.0 blob) out(171.5 +0.0 blob), read-write-amplify(19.0) write-amplify(9.1) OK, records in: 562687, records dropped: 11767 output_compression: Snappy 2024/11/20-23:41:57.395572 140007913567808 (Original Log Time 2024/11/20-23:41:57.395541) EVENT_LOG_v1 {"time_micros": 1732117317395517, "cf": "default", "job": 21558, "event": "compaction_finished", "compaction_time_micros": 7962919, "compaction_time_cpu_micros": 1877971, "output_level": 3, "num_output_files": 5, "total_output_size": 179823558, "num_input_records": 562687, "num_output_records": 550920, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 186174627, "file_range_sync_nanos": 0, "file_fsync_nanos": 4557, "file_prepare_write_nanos": 11790, "lsm_state": [0, 0, 0, 5, 0, 0, 0]} 2024/11/20-23:41:57.525860 140007913567808 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":1732117309,"executesMs":8148,"compactionJobId":21558,"attempt":0,"compactionInputRawBytes":583498352,"compactionInputZipBytes":197218842,"compactionOutputRawBytes":0,"compactionOutputZipBytes":179823558,"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-c0cb7dd0284d3d1130f8696b9c879b19-968ef8bbca4064ed-00"}}, response = 2024/11/20-23:41:57.525956 140007913567808 INFO dcompact_worker.cpp:1464: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-20T17.53.03/.rocksdb/job-21558/att-00: olev 3, work 8.148 s, result 8.555 ms, install 0.708 ms, input{raw 556.467 MiB zip 188.083 MiB}