2024/08/20-23:13:02.759820 139856790947392 DEBG dcompact_worker.cpp:2211: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00: fork to child time = 0.019031 sec 2024/08/20-23:13:02.760670 139856790947392 DEBG dcompact_worker.cpp:1011: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00 2024/08/20-23:13:02.765637 139856790947392 DEBG dcompact_worker.cpp:1031: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00 2024/08/20-23:13:02.767051 139856790947392 TRAC dcompact_worker.cpp:1081: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/08/20-23:13:02.767375 139856790947392 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/08/20-23:13:02.802627 139856790947392 [version_set.cc:6139] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-54686/att-00/MANIFEST-14629260 2024/08/20-23:13:02.849194 139856790947392 [version_set.cc:6182] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-54686/att-00/MANIFEST-14629260 succeeded,manifest_file_number is 14629260, next_file_number is 14692241, last_sequence is 191166872387, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 14692110 2024/08/20-23:13:02.849204 139856790947392 [version_set.cc:6197] Column family [default] (ID 0), log number is 0 2024/08/20-23:13:02.849325 139856790947392 [version_set.cc:5652] Creating manifest 14692241 2024/08/20-23:13:02.872464 139856790947392 DEBG dcompact_worker.cpp:1215: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00: bottommost_level: fake = 1, rpc = 0 2024/08/20-23:13:02.885502 139856790947392 [compaction_job.cc:2433] [default] [JOB 54686] Compacting 1@1 + 8@2 files to L2, score 1.00, subcompactions 1 : 1 2024/08/20-23:13:02.885517 139856790947392 [compaction_job.cc:2441] [default]: Compaction start summary: Base version 27657 Base level 1, inputs: [14692226(31MB)], [14692183(19MB) 14692184(19MB) 14692185(20MB) 14692186(19MB) 14692187(20MB) 14692188(19MB) 14692189(19MB) 14692199(20MB)] 2024/08/20-23:13:03.127957 139856790947392 [top_zip_table.cc:59] core git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_finish g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/08/20-23:13:03.127988 139856790947392 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_finish g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/08/20-23:13:03.128009 139856790947392 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit 7517bad5c1a147474c3830831b9a22c996321ae8 Author: leipeng Date: 2024-01-08 19:18:17 +0800 vfork_cmd: call close before wait_finish g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. INCS = -Isrc -I3rdparty/re2 -I3rdparty/zstd -Iboost-include CXXFLAGS = -D TOPLING_IO_WITH_URING=1 -fPIC -time -Wno-class-memaccess -fdiagnostics-color -Wformat=2 -Wcomment -Wall -Wextra -Wno-unused-parameter -Wno-alloc-size-larger-than -mcx16 -Wno-deprecated-declarations -Wstrict-aliasing=3 -DCLIENT_LICENSE_ID="public" -DNO_THREADS -ftls-model=initial-exec -DDIVSUFSORT_API= -fno-stack-protector RLS_FLAGS = -O3 -DNDEBUG -g3 WITH_BMI2 = 1 compile_cpu_flag: -march=haswell -mbmi -mbmi2 2024/08/20-23:13:03.128024 139856790947392 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit 7f80399bfbd2071b6e0f5683e8ab7225b8e6e394 Author: leipeng Date: 2024-01-19 14:52:30 +0800 Change ToplingZipTableOptions::sampleRatio to vector g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/08/20-23:13:03.128053 139856790947392 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit 1240987ca13d0fe562c9b9c037155079f0877840 Author: leipeng Date: 2024-01-19 15:07:04 +0800 Change ToplingZipTableOptions::sampleRatio to vector g++ (GCC) 12.1.0 Copyright (C) 2022 Free Software Foundation, Inc. This is free software; see the source for copying conditions. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. cpu_flag: -march=native -mbmi -mbmi2 2024/08/20-23:13:03.279379 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst) /dev/shm/ToplingTemp/Topling-54916-RKlQTI 2024/08/20-23:13:03.544389 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst): first pass time = 0.26's, 253.278'MB/sec 2024/08/20-23:13:04.329811 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst): old prealloc_size = 73819750, real_size = 18724656 2024/08/20-23:13:04.330175 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466276 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0177 GB avg-val = 115.93 avg-zval = 38.00 2024/08/20-23:13:04.330613 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:04.841789 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692242.sst): second pass time = 0.78's, 68.901'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.51's, 40.486'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2632.453'MB/sec (index lex order gen) rebuild zvType time = 0.44's, 0.265'MB/sec write SST data time = 0.07's, 287.856'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 14458.643'MB/sec zip my value time = 0.78's, unzip length = 0.054'GB zip my value throughput = 68.901'MB/sec zip pipeline throughput = 68.901'MB/sec entries = 466276 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.93 avg-zval = 38.00 usrkeys = 466276 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.93 avg-zval = 38.00 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466276 bytes = 1573696 } seq expand size = 3263932 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0177 GB dict = 0.54 MB all = 0.0207 GB } UnZip/Zip{ index = 10.5017 value = 3.0504 dict = 1.00 all = 3.2375 } Zip/UnZip{ index = 0.0952 value = 0.3278 dict = 1.00 all = 0.3089 } ---------------------------- total value len = 0.057317 GB avg = 0.123 KB (by entry num) total key len = 0.013056 GB avg = 0.028 KB total ukey len = 0.009326 GB avg = 0.020 KB total ukey num = 0.000466276 Billion total entry num = 0.000466276 Billion write speed all = 0.006441594 MB/sec (with seq num) write speed all = 0.006100148 MB/sec (without seq num) 2024/08/20-23:13:04.874594 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692242: 466276 keys, 20728470 bytes, temperature: kWarm 2024/08/20-23:13:04.874679 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166784874632, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692242, "file_size": 20728470, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191073220730, "largest_seqno": 191166857807, "table_properties": {"data_size": 17719904, "index_size": 888000, "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": 13055728, "raw_average_key_size": 28, "raw_value_size": 54053188, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466276, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166783, "oldest_key_time": 0, "file_creation_time": 1724166783, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692242, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:04.910994 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst) /dev/shm/ToplingTemp/Topling-54916-TTf9aJ 2024/08/20-23:13:05.369696 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst): first pass time = 0.46's, 146.318'MB/sec 2024/08/20-23:13:06.222736 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst): old prealloc_size = 73819750, real_size = 18613248 2024/08/20-23:13:06.223089 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 467457 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0540 GB zip-val = 0.0176 GB avg-val = 115.56 avg-zval = 37.65 2024/08/20-23:13:06.223541 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:06.832488 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692243.sst): second pass time = 0.85's, 63.494'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.61's, 33.818'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2716.169'MB/sec (index lex order gen) rebuild zvType time = 0.48's, 0.245'MB/sec write SST data time = 0.13's, 154.891'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 11604.796'MB/sec zip my value time = 0.85's, unzip length = 0.054'GB zip my value throughput = 63.494'MB/sec zip pipeline throughput = 68.253'MB/sec entries = 467457 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.56 avg-zval = 37.65 usrkeys = 467457 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.56 avg-zval = 37.65 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 467457 bytes = 1577680 } seq expand size = 3272199 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0176 GB dict = 0.54 MB all = 0.0206 GB } UnZip/Zip{ index = 10.4388 value = 3.0692 dict = 1.00 all = 3.2546 } Zip/UnZip{ index = 0.0958 value = 0.3258 dict = 1.00 all = 0.3073 } ---------------------------- total value len = 0.114609 GB avg = 0.123 KB (by entry num) total key len = 0.026145 GB avg = 0.028 KB total ukey len = 0.018675 GB avg = 0.020 KB total ukey num = 0.000933733 Billion total entry num = 0.000933733 Billion write speed all = 0.012881594 MB/sec (with seq num) write speed all = 0.012197962 MB/sec (without seq num) 2024/08/20-23:13:06.867301 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692243: 467457 keys, 20619586 bytes, temperature: kWarm 2024/08/20-23:13:06.867388 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166786867345, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692243, "file_size": 20619586, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191073226245, "largest_seqno": 191166857661, "table_properties": {"data_size": 17600560, "index_size": 895616, "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": 13088796, "raw_average_key_size": 28, "raw_value_size": 54020082, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 467457, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166784, "oldest_key_time": 0, "file_creation_time": 1724166784, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692243, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:06.906899 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst) /dev/shm/ToplingTemp/Topling-54916-V5AD0I 2024/08/20-23:13:07.622515 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst): first pass time = 0.72's, 93.785'MB/sec 2024/08/20-23:13:11.452617 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst): old prealloc_size = 73819750, real_size = 19433472 2024/08/20-23:13:11.453035 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466379 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0184 GB avg-val = 115.89 avg-zval = 39.51 2024/08/20-23:13:11.453495 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:12.276863 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692244.sst): second pass time = 3.82's, 14.143'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.82's, 26.011'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2280.128'MB/sec (index lex order gen) rebuild zvType time = 0.68's, 0.172'MB/sec write SST data time = 0.14's, 148.675'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 14651.315'MB/sec zip my value time = 3.82's, unzip length = 0.054'GB zip my value throughput = 14.143'MB/sec zip pipeline throughput = 147.193'MB/sec entries = 466379 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.89 avg-zval = 39.51 usrkeys = 466379 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.89 avg-zval = 39.51 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466379 bytes = 1574048 } seq expand size = 3264653 multi value expand size = 0 cnt WriteAppend = 15 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0184 GB dict = 0.54 MB all = 0.0214 GB } UnZip/Zip{ index = 10.5018 value = 2.9330 dict = 1.00 all = 3.1302 } Zip/UnZip{ index = 0.0952 value = 0.3410 dict = 1.00 all = 0.3195 } ---------------------------- total value len = 0.171924 GB avg = 0.123 KB (by entry num) total key len = 0.039203 GB avg = 0.028 KB total ukey len = 0.028002 GB avg = 0.020 KB total ukey num = 0.001400112 Billion total entry num = 0.001400112 Billion write speed all = 0.019312462 MB/sec (with seq num) write speed all = 0.018287883 MB/sec (without seq num) 2024/08/20-23:13:12.309151 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692244: 466379 keys, 21439050 bytes, temperature: kWarm 2024/08/20-23:13:12.309243 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166792309194, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692244, "file_size": 21439050, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191052376133, "largest_seqno": 191166858221, "table_properties": {"data_size": 18428528, "index_size": 888192, "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": 13058612, "raw_average_key_size": 28, "raw_value_size": 54050354, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466379, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166786, "oldest_key_time": 0, "file_creation_time": 1724166786, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692244, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:12.343372 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst) /dev/shm/ToplingTemp/Topling-54916-x2TgHG 2024/08/20-23:13:13.255052 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst): first pass time = 0.91's, 73.614'MB/sec 2024/08/20-23:13:14.063920 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst): old prealloc_size = 73819750, real_size = 18772400 2024/08/20-23:13:14.064306 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465768 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0178 GB avg-val = 116.08 avg-zval = 38.15 2024/08/20-23:13:14.064763 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:14.484644 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692245.sst): second pass time = 0.81's, 66.918'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.42's, 49.799'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2445.353'MB/sec (index lex order gen) rebuild zvType time = 0.35's, 0.335'MB/sec write SST data time = 0.07's, 287.575'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.544'MB, throughput = 14744.920'MB/sec zip my value time = 0.81's, unzip length = 0.054'GB zip my value throughput = 66.918'MB/sec zip pipeline throughput = 66.918'MB/sec entries = 465768 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.08 avg-zval = 38.15 usrkeys = 465768 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.08 avg-zval = 38.15 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465768 bytes = 1746640 } seq expand size = 3260376 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0178 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.5024 value = 3.0428 dict = 1.00 all = 3.2030 } Zip/UnZip{ index = 0.0952 value = 0.3286 dict = 1.00 all = 0.3122 } ---------------------------- total value len = 0.229252 GB avg = 0.123 KB (by entry num) total key len = 0.052245 GB avg = 0.028 KB total ukey len = 0.037318 GB avg = 0.020 KB total ukey num = 0.001865880 Billion total entry num = 0.001865880 Billion write speed all = 0.025744146 MB/sec (with seq num) write speed all = 0.024379001 MB/sec (without seq num) 2024/08/20-23:13:14.513403 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692245: 465768 keys, 20951558 bytes, temperature: kWarm 2024/08/20-23:13:14.513457 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166794513429, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692245, "file_size": 20951558, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190586022308, "largest_seqno": 191166855804, "table_properties": {"data_size": 17768800, "index_size": 886976, "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": 13041504, "raw_average_key_size": 28, "raw_value_size": 54067372, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465768, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166792, "oldest_key_time": 0, "file_creation_time": 1724166792, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692245, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:14.600012 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst) /dev/shm/ToplingTemp/Topling-54916-meNKkH 2024/08/20-23:13:15.463291 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst): first pass time = 0.86's, 77.744'MB/sec 2024/08/20-23:13:17.086148 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst): old prealloc_size = 73819750, real_size = 18813376 2024/08/20-23:13:17.086571 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466598 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0540 GB zip-val = 0.0178 GB avg-val = 115.83 avg-zval = 38.15 2024/08/20-23:13:17.087050 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:17.843957 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692246.sst): second pass time = 1.62's, 33.323'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.76's, 27.471'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2259.821'MB/sec (index lex order gen) rebuild zvType time = 0.52's, 0.226'MB/sec write SST data time = 0.24's, 86.023'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 11257.047'MB/sec zip my value time = 1.62's, unzip length = 0.054'GB zip my value throughput = 33.323'MB/sec zip pipeline throughput = 95.765'MB/sec entries = 466598 avg-key = 28.00 avg-zkey = 1.92 avg-val = 115.83 avg-zval = 38.15 usrkeys = 466598 avg-key = 20.00 avg-zkey = 1.92 avg-val = 122.83 avg-zval = 38.15 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466598 bytes = 1574784 } seq expand size = 3266186 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0178 GB dict = 0.54 MB all = 0.0208 GB } UnZip/Zip{ index = 10.4353 value = 3.0358 dict = 1.00 all = 3.2237 } Zip/UnZip{ index = 0.0958 value = 0.3294 dict = 1.00 all = 0.3102 } ---------------------------- total value len = 0.286562 GB avg = 0.123 KB (by entry num) total key len = 0.065309 GB avg = 0.028 KB total ukey len = 0.046650 GB avg = 0.020 KB total ukey num = 0.002332478 Billion total entry num = 0.002332478 Billion write speed all = 0.032170379 MB/sec (with seq num) write speed all = 0.030464378 MB/sec (without seq num) 2024/08/20-23:13:17.897922 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692246: 466598 keys, 20817430 bytes, temperature: kWarm 2024/08/20-23:13:17.898009 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166797897963, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692246, "file_size": 20817430, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191037662625, "largest_seqno": 191166856130, "table_properties": {"data_size": 17802288, "index_size": 894272, "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": 13064744, "raw_average_key_size": 28, "raw_value_size": 54044136, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466598, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166794, "oldest_key_time": 0, "file_creation_time": 1724166794, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692246, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:17.935677 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst) /dev/shm/ToplingTemp/Topling-54916-lYOo6H 2024/08/20-23:13:18.697358 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst): first pass time = 0.76's, 88.114'MB/sec 2024/08/20-23:13:19.590420 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst): old prealloc_size = 73819750, real_size = 19226896 2024/08/20-23:13:19.590779 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465729 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0182 GB avg-val = 116.09 avg-zval = 39.12 2024/08/20-23:13:19.591216 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:20.192750 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692247.sst): second pass time = 0.89's, 60.605'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.60's, 35.250'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2656.858'MB/sec (index lex order gen) rebuild zvType time = 0.36's, 0.323'MB/sec write SST data time = 0.24's, 88.006'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.544'MB, throughput = 14966.905'MB/sec zip my value time = 0.89's, unzip length = 0.054'GB zip my value throughput = 60.605'MB/sec zip pipeline throughput = 78.556'MB/sec entries = 465729 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.09 avg-zval = 39.12 usrkeys = 465729 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.09 avg-zval = 39.12 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465729 bytes = 1571856 } seq expand size = 3260103 multi value expand size = 0 cnt WriteAppend = 16 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0182 GB dict = 0.54 MB all = 0.0212 GB } UnZip/Zip{ index = 10.4330 value = 2.9679 dict = 1.00 all = 3.1609 } Zip/UnZip{ index = 0.0958 value = 0.3369 dict = 1.00 all = 0.3164 } ---------------------------- total value len = 0.343891 GB avg = 0.123 KB (by entry num) total key len = 0.078350 GB avg = 0.028 KB total ukey len = 0.055964 GB avg = 0.020 KB total ukey num = 0.002798207 Billion total entry num = 0.002798207 Billion write speed all = 0.038595680 MB/sec (with seq num) write speed all = 0.036549479 MB/sec (without seq num) 2024/08/20-23:13:20.225719 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692247: 465729 keys, 21231294 bytes, temperature: kWarm 2024/08/20-23:13:20.225812 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166800225767, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692247, "file_size": 21231294, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191087667001, "largest_seqno": 191166857477, "table_properties": {"data_size": 18217472, "index_size": 892800, "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": 13040412, "raw_average_key_size": 28, "raw_value_size": 54068534, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465729, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166797, "oldest_key_time": 0, "file_creation_time": 1724166797, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692247, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:20.260863 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst) /dev/shm/ToplingTemp/Topling-54916-5gDMpF 2024/08/20-23:13:20.892108 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst): first pass time = 0.63's, 106.321'MB/sec 2024/08/20-23:13:21.604479 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst): old prealloc_size = 73819750, real_size = 19014944 2024/08/20-23:13:21.604821 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466691 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0540 GB zip-val = 0.0180 GB avg-val = 115.80 avg-zval = 38.59 2024/08/20-23:13:21.605236 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:21.980290 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692248.sst): second pass time = 0.71's, 76.013'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.38's, 55.780'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2819.790'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.381'MB/sec write SST data time = 0.07's, 302.012'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.542'MB, throughput = 15045.041'MB/sec zip my value time = 0.71's, unzip length = 0.054'GB zip my value throughput = 76.013'MB/sec zip pipeline throughput = 76.013'MB/sec entries = 466691 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.80 avg-zval = 38.59 usrkeys = 466691 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.80 avg-zval = 38.59 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466691 bytes = 1516768 } seq expand size = 3266837 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0093 GB value = 0.0540 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0180 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.5035 value = 3.0007 dict = 1.00 all = 3.2016 } Zip/UnZip{ index = 0.0952 value = 0.3333 dict = 1.00 all = 0.3123 } ---------------------------- total value len = 0.401200 GB avg = 0.123 KB (by entry num) total key len = 0.091417 GB avg = 0.028 KB total ukey len = 0.065298 GB avg = 0.020 KB total ukey num = 0.003264898 Billion total entry num = 0.003264898 Billion write speed all = 0.045021151 MB/sec (with seq num) write speed all = 0.042634071 MB/sec (without seq num) 2024/08/20-23:13:22.009647 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692248: 466691 keys, 20960976 bytes, temperature: kWarm 2024/08/20-23:13:22.009718 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166802009683, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692248, "file_size": 20960976, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191102102469, "largest_seqno": 191166857570, "table_properties": {"data_size": 18009424, "index_size": 888640, "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": 13067348, "raw_average_key_size": 28, "raw_value_size": 54041646, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466691, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166800, "oldest_key_time": 0, "file_creation_time": 1724166800, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692248, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:22.034297 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst) /dev/shm/ToplingTemp/Topling-54916-zfiEZI 2024/08/20-23:13:22.442800 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst): first pass time = 0.41's, 164.301'MB/sec 2024/08/20-23:13:23.265257 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst): old prealloc_size = 73819750, real_size = 18961792 2024/08/20-23:13:23.265593 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466241 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0180 GB avg-val = 115.94 avg-zval = 38.51 2024/08/20-23:13:23.266010 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0011 GB, waited 0.000 sec, Key+Value = 0.067 GB 2024/08/20-23:13:23.642131 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692249.sst): second pass time = 0.82's, 65.781'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.38's, 55.789'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2980.102'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.378'MB/sec write SST data time = 0.07's, 309.573'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.543'MB, throughput = 13616.999'MB/sec zip my value time = 0.82's, unzip length = 0.054'GB zip my value throughput = 65.781'MB/sec zip pipeline throughput = 83.031'MB/sec entries = 466241 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.94 avg-zval = 38.51 usrkeys = 466241 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.94 avg-zval = 38.51 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466241 bytes = 1631856 } seq expand size = 3263687 multi value expand size = 0 cnt WriteAppend = 14 UnZipSize{ index = 0.0093 GB value = 0.0541 GB dict = 0.54 MB all = 0.0671 GB } __ZipSize{ index = 0.0009 GB value = 0.0180 GB dict = 0.54 MB all = 0.0210 GB } UnZip/Zip{ index = 10.5032 value = 3.0102 dict = 1.00 all = 3.1918 } Zip/UnZip{ index = 0.0952 value = 0.3322 dict = 1.00 all = 0.3133 } ---------------------------- total value len = 0.458517 GB avg = 0.123 KB (by entry num) total key len = 0.104472 GB avg = 0.028 KB total ukey len = 0.074623 GB avg = 0.020 KB total ukey num = 0.003731139 Billion total entry num = 0.003731139 Billion write speed all = 0.051444821 MB/sec (with seq num) write speed all = 0.048717270 MB/sec (without seq num) 2024/08/20-23:13:23.674168 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692249: 466241 keys, 21025498 bytes, temperature: kWarm 2024/08/20-23:13:23.674233 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166803674199, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692249, "file_size": 21025498, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191031976588, "largest_seqno": 191166857709, "table_properties": {"data_size": 17957232, "index_size": 887808, "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": 13054748, "raw_average_key_size": 28, "raw_value_size": 54054186, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466241, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166802, "oldest_key_time": 0, "file_creation_time": 1724166802, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692249, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:23.697073 139856790947392 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst) /dev/shm/ToplingTemp/Topling-54916-RwLuxG 2024/08/20-23:13:23.822105 139856790947392 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst): first pass time = 0.12's, 268.010'MB/sec 2024/08/20-23:13:24.146257 139856790947392 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst): old prealloc_size = 73819750, real_size = 9617152 2024/08/20-23:13:24.146489 139856790947392 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 231831 prefix = 4 raw-key = 0.0037 GB zip-key = 0.0004 GB avg-key = 16.00 avg-zkey = 1.91 raw-val = 0.0270 GB zip-val = 0.0091 GB avg-val = 116.50 avg-zval = 39.33 2024/08/20-23:13:24.146724 139856790947392 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst: sumWaitingMem = 0.001 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0005 GB, waited 0.000 sec, Key+Value = 0.033 GB 2024/08/20-23:13:24.333759 139856790947392 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00/14692250.sst): second pass time = 0.32's, 83.509'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.19's, 56.650'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2537.623'MB/sec (index lex order gen) rebuild zvType time = 0.15's, 0.380'MB/sec write SST data time = 0.03's, 305.337'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.278'MB, throughput = 7127.702'MB/sec zip my value time = 0.32's, unzip length = 0.027'GB zip my value throughput = 83.509'MB/sec zip pipeline throughput = 83.509'MB/sec entries = 231831 avg-key = 28.00 avg-zkey = 1.91 avg-val = 116.50 avg-zval = 39.33 usrkeys = 231831 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.50 avg-zval = 39.33 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 231831 bytes = 782448 } seq expand size = 1622817 multi value expand size = 0 cnt WriteAppend = 12 UnZipSize{ index = 0.0046 GB value = 0.0270 GB dict = 0.28 MB all = 0.0335 GB } __ZipSize{ index = 0.0004 GB value = 0.0091 GB dict = 0.28 MB all = 0.0106 GB } UnZip/Zip{ index = 10.4935 value = 2.9623 dict = 1.00 all = 3.1537 } Zip/UnZip{ index = 0.0953 value = 0.3376 dict = 1.00 all = 0.3171 } ---------------------------- total value len = 0.487148 GB avg = 0.123 KB (by entry num) total key len = 0.110963 GB avg = 0.028 KB total ukey len = 0.079259 GB avg = 0.020 KB total ukey num = 0.003962970 Billion total entry num = 0.003962970 Billion write speed all = 0.054650733 MB/sec (with seq num) write speed all = 0.051753892 MB/sec (without seq num) 2024/08/20-23:13:24.351282 139856790947392 [compaction_job.cc:1944] [default] [JOB 54686] Generated table #14692250: 231831 keys, 10622032 bytes, temperature: kWarm 2024/08/20-23:13:24.351346 139856790947392 EVENT_LOG_v1 {"time_micros": 1724166804351312, "cf_name": "default", "job": 54686, "event": "table_file_creation", "file_number": 14692250, "file_size": 10622032, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191080442604, "largest_seqno": 191165048176, "table_properties": {"data_size": 9117168, "index_size": 441856, "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": 6491268, "raw_average_key_size": 28, "raw_value_size": 27007798, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 231831, "num_filter_entries": 0, "num_deletions": 0, "num_merge_operands": 0, "num_range_deletions": 0, "format_version": 0, "fixed_key_len": 28, "fixed_value_len": 18446744073709551615, "filter_policy": "", "column_family_name": "default", "column_family_id": 0, "comparator": "leveldb.BytewiseComparator", "merge_operator": "nullptr", "prefix_extractor_name": "nullptr", "property_collectors": "[Rdb_tbl_prop_coll_factory]", "compression": "FlatZip", "compression_options": "RS_Key0_Tag1-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1724166803, "oldest_key_time": 0, "file_creation_time": 1724166803, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "a007a635-5c0a-4b4a-be96-b9c695cb016b", "db_session_id": "90ZT1ZM5QNL093I8HHQG", "orig_file_number": 14692250, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-23:13:24.365375 139856790947392 [compaction_job.cc:699] job-54686: subcompact[0], size: 0.178396 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-54686/att-00 [14692242,14692243,14692244,14692245,14692246,14692247,14692248,14692249,14692250] 2024/08/20-23:13:24.415768 139856790947392 (Original Log Time 2024/08/20-23:13:02.885562) EVENT_LOG_v1 {"time_micros": 1724166782885529, "job": 54686, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L1": [14692226], "files_L2": [14692183, 14692184, 14692185, 14692186, 14692187, 14692188, 14692189, 14692199], "score": 0.998992, "input_data_size": 200970857, "oldest_snapshot_seqno": 191166871068} 2024/08/20-23:13:24.415772 139856790947392 (Original Log Time 2024/08/20-23:13:24.414920) [compaction_job.cc:2018] [default] [JOB 54686] Compacted 1@1 + 8@2 files to L2 => 178395894 bytes 2024/08/20-23:13:24.415773 139856790947392 (Original Log Time 2024/08/20-23:13:24.415695) [compaction_job.cc:1220] [default] compacted to: files[0 0 9 0 0 0 0] max score 0.07, MB/sec: 9.4 rd, 8.3 wr, level 2, files in(1, 8) out(9 +0 blob) MB in(31.8, 159.9 +0.0 blob) out(170.1 +0.0 blob), read-write-amplify(11.4) write-amplify(5.4) OK, records in: 3962970, records dropped: 0 output_compression: Snappy 2024/08/20-23:13:24.415804 139856790947392 (Original Log Time 2024/08/20-23:13:24.415744) EVENT_LOG_v1 {"time_micros": 1724166804415721, "cf": "default", "job": 54686, "event": "compaction_finished", "compaction_time_micros": 21479822, "compaction_time_cpu_micros": 7514378, "output_level": 2, "num_output_files": 9, "total_output_size": 178395894, "num_input_records": 3962970, "num_output_records": 3962970, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 195421920, "file_range_sync_nanos": 0, "file_fsync_nanos": 7782, "file_prepare_write_nanos": 39985, "lsm_state": [0, 0, 9, 0, 0, 0, 0]} 2024/08/20-23:13:24.522524 139856790947392 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":"a007a635-5c0a-4b4a-be96-b9c695cb016b","dbStarts":1724092920,"starts":1724166782,"executesMs":21648,"compactionJobId":54686,"attempt":0,"compactionInputRawBytes":570370456,"compactionInputZipBytes":200970857,"compactionOutputRawBytes":0,"compactionOutputZipBytes":178395894,"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-9736505ba7b2813083c0bd696f4fc81a-a014a3d462b3fa0f-00"}}, response = 2024/08/20-23:13:24.522634 139856790947392 INFO dcompact_worker.cpp:1456: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-54686/att-00: olev 2, work 21.648 s, result 6.711 ms, install 0.925 ms, input{raw 543.948 MiB zip 191.661 MiB}