2024/08/20-22:15:38.034453 139857185404480 DEBG dcompact_worker.cpp:2211: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00: fork to child time = 0.032570 sec 2024/08/20-22:15:38.035277 139857185404480 DEBG dcompact_worker.cpp:1011: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00 2024/08/20-22:15:38.040166 139857185404480 DEBG dcompact_worker.cpp:1031: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00 2024/08/20-22:15:38.041991 139857185404480 TRAC dcompact_worker.cpp:1081: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/08/20-22:15:38.042314 139857185404480 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/08/20-22:15:38.089044 139857185404480 [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-52416/att-00/MANIFEST-14629260 2024/08/20-22:15:38.117858 139857185404480 [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-52416/att-00/MANIFEST-14629260 succeeded,manifest_file_number is 14629260, next_file_number is 14689624, last_sequence is 191114518705, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 14689586 2024/08/20-22:15:38.117869 139857185404480 [version_set.cc:6197] Column family [default] (ID 0), log number is 0 2024/08/20-22:15:38.117981 139857185404480 [version_set.cc:5652] Creating manifest 14689624 2024/08/20-22:15:38.152988 139857185404480 DEBG dcompact_worker.cpp:1215: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00: bottommost_level: fake = 1, rpc = 0 2024/08/20-22:15:38.179673 139857185404480 [compaction_job.cc:2433] [default] [JOB 52416] Compacting 1@1 + 6@2 files to L2, score 1.00, subcompactions 1 : 1 2024/08/20-22:15:38.179691 139857185404480 [compaction_job.cc:2441] [default]: Compaction start summary: Base version 26548 Base level 1, inputs: [14689607(31MB)], [14689542(19MB) 14689543(20MB) 14689544(20MB) 14689579(19MB) 14689580(20MB) 14689581(20MB)] 2024/08/20-22:15:38.456388 139857185404480 [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-22:15:38.456420 139857185404480 [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-22:15:38.456437 139857185404480 [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-22:15:38.456447 139857185404480 [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-22:15:38.456457 139857185404480 [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-22:15:38.637588 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.sst) /dev/shm/ToplingTemp/Topling-38112-lsPgI1 2024/08/20-22:15:38.903213 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.sst): first pass time = 0.27's, 252.692'MB/sec 2024/08/20-22:15:42.313519 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.sst): old prealloc_size = 73819750, real_size = 18909392 2024/08/20-22:15:42.313890 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466315 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.0179 GB avg-val = 115.91 avg-zval = 38.40 2024/08/20-22:15:42.314419 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.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-22:15:43.106582 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689625.sst): second pass time = 3.41's, 15.858'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.79's, 26.296'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2595.209'MB/sec (index lex order gen) rebuild zvType time = 0.63's, 0.186'MB/sec write SST data time = 0.16's, 126.805'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 = 13703.786'MB/sec zip my value time = 3.41's, unzip length = 0.054'GB zip my value throughput = 15.858'MB/sec zip pipeline throughput = 162.088'MB/sec entries = 466315 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.91 avg-zval = 38.40 usrkeys = 466315 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.91 avg-zval = 38.40 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466315 bytes = 1515536 } seq expand size = 3264205 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.0179 GB dict = 0.54 MB all = 0.0209 GB } UnZip/Zip{ index = 10.5049 value = 3.0189 dict = 1.00 all = 3.2180 } Zip/UnZip{ index = 0.0952 value = 0.3313 dict = 1.00 all = 0.3108 } ---------------------------- total value len = 0.057316 GB avg = 0.123 KB (by entry num) total key len = 0.013057 GB avg = 0.028 KB total ukey len = 0.009326 GB avg = 0.020 KB total ukey num = 0.000466315 Billion total entry num = 0.000466315 Billion write speed all = 0.009404381 MB/sec (with seq num) write speed all = 0.008905849 MB/sec (without seq num) 2024/08/20-22:15:43.136269 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689625: 466315 keys, 20854462 bytes, temperature: kWarm 2024/08/20-22:15:43.136376 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163343136316, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689625, "file_size": 20854462, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191073220030, "largest_seqno": 191114505100, "table_properties": {"data_size": 17904832, "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": 13056820, "raw_average_key_size": 28, "raw_value_size": 54052162, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466315, "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": 1724163338, "oldest_key_time": 0, "file_creation_time": 1724163338, "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": 14689625, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:43.176034 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.sst) /dev/shm/ToplingTemp/Topling-38112-qrM9n4 2024/08/20-22:15:43.895791 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.sst): first pass time = 0.72's, 93.245'MB/sec 2024/08/20-22:15:45.180606 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.sst): old prealloc_size = 73819750, real_size = 19414320 2024/08/20-22:15:45.180931 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465837 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.0184 GB avg-val = 116.06 avg-zval = 39.51 2024/08/20-22:15:45.181383 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.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-22:15:45.867295 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689626.sst): second pass time = 1.28's, 42.106'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.69's, 31.108'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2958.437'MB/sec (index lex order gen) rebuild zvType time = 0.55's, 0.213'MB/sec write SST data time = 0.14's, 154.174'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 = 17747.705'MB/sec zip my value time = 1.28's, unzip length = 0.054'GB zip my value throughput = 42.106'MB/sec zip pipeline throughput = 81.921'MB/sec entries = 465837 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.06 avg-zval = 39.51 usrkeys = 465837 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.06 avg-zval = 39.51 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465837 bytes = 1513984 } seq expand size = 3260859 multi value expand size = 0 cnt WriteAppend = 19 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.4294 value = 2.9376 dict = 1.00 all = 3.1417 } Zip/UnZip{ index = 0.0959 value = 0.3404 dict = 1.00 all = 0.3183 } ---------------------------- total value len = 0.114643 GB avg = 0.123 KB (by entry num) total key len = 0.026100 GB avg = 0.028 KB total ukey len = 0.018643 GB avg = 0.020 KB total ukey num = 0.000932152 Billion total entry num = 0.000932152 Billion write speed all = 0.018801375 MB/sec (with seq num) write speed all = 0.017805191 MB/sec (without seq num) 2024/08/20-22:15:45.900441 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689626: 465837 keys, 21360436 bytes, temperature: kWarm 2024/08/20-22:15:45.900525 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163345900481, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689626, "file_size": 21360436, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191052376133, "largest_seqno": 191114505496, "table_properties": {"data_size": 18404384, "index_size": 893312, "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": 13043436, "raw_average_key_size": 28, "raw_value_size": 54065522, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465837, "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": 1724163343, "oldest_key_time": 0, "file_creation_time": 1724163343, "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": 14689626, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:45.936831 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.sst) /dev/shm/ToplingTemp/Topling-38112-SHyYP1 2024/08/20-22:15:46.753674 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.sst): first pass time = 0.82's, 82.162'MB/sec 2024/08/20-22:15:48.880094 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.sst): old prealloc_size = 73819750, real_size = 18886640 2024/08/20-22:15:48.880526 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 464565 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.90 raw-val = 0.0541 GB zip-val = 0.0179 GB avg-val = 116.46 avg-zval = 38.50 2024/08/20-22:15:48.880978 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.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-22:15:49.402026 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689627.sst): second pass time = 2.13's, 25.452'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.52's, 40.017'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2235.527'MB/sec (index lex order gen) rebuild zvType time = 0.42's, 0.277'MB/sec write SST data time = 0.10's, 205.450'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 = 15016.061'MB/sec zip my value time = 2.13's, unzip length = 0.054'GB zip my value throughput = 25.452'MB/sec zip pipeline throughput = 107.965'MB/sec entries = 464565 avg-key = 28.00 avg-zkey = 1.90 avg-val = 116.46 avg-zval = 38.50 usrkeys = 464565 avg-key = 20.00 avg-zkey = 1.90 avg-val = 123.46 avg-zval = 38.50 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 464565 bytes = 1567920 } seq expand size = 3251955 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.0179 GB dict = 0.54 MB all = 0.0209 GB } UnZip/Zip{ index = 10.5025 value = 3.0248 dict = 1.00 all = 3.2131 } Zip/UnZip{ index = 0.0952 value = 0.3306 dict = 1.00 all = 0.3112 } ---------------------------- total value len = 0.171996 GB avg = 0.123 KB (by entry num) total key len = 0.039108 GB avg = 0.028 KB total ukey len = 0.027934 GB avg = 0.020 KB total ukey num = 0.001396717 Billion total entry num = 0.001396717 Billion write speed all = 0.028187336 MB/sec (with seq num) write speed all = 0.026695379 MB/sec (without seq num) 2024/08/20-22:15:49.434503 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689627: 464565 keys, 20886090 bytes, temperature: kWarm 2024/08/20-22:15:49.434582 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163349434538, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689627, "file_size": 20886090, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190996031550, "largest_seqno": 191114505559, "table_properties": {"data_size": 17885664, "index_size": 884672, "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": 13007820, "raw_average_key_size": 28, "raw_value_size": 54101126, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 464565, "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": 1724163345, "oldest_key_time": 0, "file_creation_time": 1724163345, "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": 14689627, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:49.490045 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.sst) /dev/shm/ToplingTemp/Topling-38112-T6EwN1 2024/08/20-22:15:50.763346 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.sst): first pass time = 1.27's, 52.707'MB/sec 2024/08/20-22:15:51.704801 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.sst): old prealloc_size = 73819750, real_size = 18966976 2024/08/20-22:15:51.705206 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 465005 prefix = 4 raw-key = 0.0074 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.92 raw-val = 0.0541 GB zip-val = 0.0180 GB avg-val = 116.32 avg-zval = 38.62 2024/08/20-22:15:51.705714 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.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-22:15:52.214775 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689628.sst): second pass time = 0.94's, 57.502'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.51's, 41.348'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2359.075'MB/sec (index lex order gen) rebuild zvType time = 0.43's, 0.271'MB/sec write SST data time = 0.08's, 261.783'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 0.545'MB, throughput = 11736.612'MB/sec zip my value time = 0.94's, unzip length = 0.054'GB zip my value throughput = 57.502'MB/sec zip pipeline throughput = 119.969'MB/sec entries = 465005 avg-key = 28.00 avg-zkey = 1.92 avg-val = 116.32 avg-zval = 38.62 usrkeys = 465005 avg-key = 20.00 avg-zkey = 1.92 avg-val = 123.32 avg-zval = 38.62 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 465005 bytes = 1685664 } seq expand size = 3255035 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.0180 GB dict = 0.54 MB all = 0.0211 GB } UnZip/Zip{ index = 10.4310 value = 3.0118 dict = 1.00 all = 3.1826 } Zip/UnZip{ index = 0.0959 value = 0.3320 dict = 1.00 all = 0.3142 } ---------------------------- total value len = 0.229340 GB avg = 0.123 KB (by entry num) total key len = 0.052128 GB avg = 0.028 KB total ukey len = 0.037234 GB avg = 0.020 KB total ukey num = 0.001861722 Billion total entry num = 0.001861722 Billion write speed all = 0.037568470 MB/sec (with seq num) write speed all = 0.035580547 MB/sec (without seq num) 2024/08/20-22:15:52.244349 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689628: 465005 keys, 21086390 bytes, temperature: kWarm 2024/08/20-22:15:52.244425 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163352244387, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689628, "file_size": 21086390, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 190586022308, "largest_seqno": 191114505569, "table_properties": {"data_size": 17958960, "index_size": 891584, "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": 13020140, "raw_average_key_size": 28, "raw_value_size": 54088786, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 465005, "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": 1724163349, "oldest_key_time": 0, "file_creation_time": 1724163349, "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": 14689628, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:52.285235 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.sst) /dev/shm/ToplingTemp/Topling-38112-3LWzw5 2024/08/20-22:15:53.071169 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.sst): first pass time = 0.79's, 85.397'MB/sec 2024/08/20-22:15:53.868654 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.sst): old prealloc_size = 73819750, real_size = 18884048 2024/08/20-22:15:53.869009 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466346 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.0179 GB avg-val = 115.90 avg-zval = 38.34 2024/08/20-22:15:53.869471 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.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-22:15:54.247221 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689629.sst): second pass time = 0.80's, 67.841'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.38's, 55.176'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2739.937'MB/sec (index lex order gen) rebuild zvType time = 0.31's, 0.375'MB/sec write SST data time = 0.07's, 309.741'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 = 13987.108'MB/sec zip my value time = 0.80's, unzip length = 0.054'GB zip my value throughput = 67.841'MB/sec zip pipeline throughput = 67.841'MB/sec entries = 466346 avg-key = 28.00 avg-zkey = 1.90 avg-val = 115.90 avg-zval = 38.34 usrkeys = 466346 avg-key = 20.00 avg-zkey = 1.90 avg-val = 122.90 avg-zval = 38.34 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466346 bytes = 1573936 } seq expand size = 3264422 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.0179 GB dict = 0.54 MB all = 0.0209 GB } UnZip/Zip{ index = 10.5033 value = 3.0231 dict = 1.00 all = 3.2129 } Zip/UnZip{ index = 0.0952 value = 0.3308 dict = 1.00 all = 0.3112 } ---------------------------- total value len = 0.286655 GB avg = 0.123 KB (by entry num) total key len = 0.065186 GB avg = 0.028 KB total ukey len = 0.046561 GB avg = 0.020 KB total ukey num = 0.002328068 Billion total entry num = 0.002328068 Billion write speed all = 0.046948710 MB/sec (with seq num) write speed all = 0.044463503 MB/sec (without seq num) 2024/08/20-22:15:54.276255 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689629: 466346 keys, 20887402 bytes, temperature: kWarm 2024/08/20-22:15:54.276323 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163354276291, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689629, "file_size": 20887402, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191037270855, "largest_seqno": 191114505057, "table_properties": {"data_size": 17879296, "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": 13057688, "raw_average_key_size": 28, "raw_value_size": 54051292, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466346, "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": 1724163352, "oldest_key_time": 0, "file_creation_time": 1724163352, "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": 14689629, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:54.304018 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.sst) /dev/shm/ToplingTemp/Topling-38112-nizp91 2024/08/20-22:15:54.720729 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.sst): first pass time = 0.42's, 161.065'MB/sec 2024/08/20-22:15:55.417604 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.sst): old prealloc_size = 73819750, real_size = 19418624 2024/08/20-22:15:55.417961 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 466820 prefix = 4 raw-key = 0.0075 GB zip-key = 0.0009 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.0540 GB zip-val = 0.0184 GB avg-val = 115.76 avg-zval = 39.46 2024/08/20-22:15:55.418422 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.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-22:15:55.787782 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689630.sst): second pass time = 0.70's, 77.628'MB/sec, value only(80.5% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.37's, 57.722'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2678.117'MB/sec (index lex order gen) rebuild zvType time = 0.30's, 0.388'MB/sec write SST data time = 0.07's, 308.134'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 = 14751.217'MB/sec zip my value time = 0.70's, unzip length = 0.054'GB zip my value throughput = 77.628'MB/sec zip pipeline throughput = 77.628'MB/sec entries = 466820 avg-key = 28.00 avg-zkey = 1.89 avg-val = 115.76 avg-zval = 39.46 usrkeys = 466820 avg-key = 20.00 avg-zkey = 1.89 avg-val = 122.76 avg-zval = 39.46 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 466820 bytes = 1517184 } seq expand size = 3267740 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.0184 GB dict = 0.54 MB all = 0.0214 GB } UnZip/Zip{ index = 10.5719 value = 2.9339 dict = 1.00 all = 3.1408 } Zip/UnZip{ index = 0.0946 value = 0.3408 dict = 1.00 all = 0.3184 } ---------------------------- total value len = 0.343961 GB avg = 0.123 KB (by entry num) total key len = 0.078257 GB avg = 0.028 KB total ukey len = 0.055898 GB avg = 0.020 KB total ukey num = 0.002794888 Billion total entry num = 0.002794888 Billion write speed all = 0.056327996 MB/sec (with seq num) write speed all = 0.053345073 MB/sec (without seq num) 2024/08/20-22:15:55.819901 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689630: 466820 keys, 21367004 bytes, temperature: kWarm 2024/08/20-22:15:55.819975 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163355819938, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689630, "file_size": 21367004, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191062402356, "largest_seqno": 191114505023, "table_properties": {"data_size": 18418608, "index_size": 883136, "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": 13070960, "raw_average_key_size": 28, "raw_value_size": 54037972, "raw_average_value_size": 115, "num_data_blocks": 1, "num_entries": 466820, "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": 1724163354, "oldest_key_time": 0, "file_creation_time": 1724163354, "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": 14689630, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:55.853043 139857185404480 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.sst) /dev/shm/ToplingTemp/Topling-38112-rHZKe3 2024/08/20-22:15:56.107480 139857185404480 [top_zip_table_builder.cc:1344] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.sst): first pass time = 0.25's, 131.606'MB/sec 2024/08/20-22:15:56.552405 139857185404480 [top_zip_table_builder.cc:2764] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.sst): old prealloc_size = 73819750, real_size = 10136000 2024/08/20-22:15:56.552597 139857185404480 [top_zip_table_builder.cc:1765] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 232184 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.0096 GB avg-val = 116.19 avg-zval = 41.50 2024/08/20-22:15:56.552841 139857185404480 [top_zip_table_builder.cc:1295] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.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-22:15:56.736754 139857185404480 [top_zip_table_builder.cc:3092] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00/14689631.sst): second pass time = 0.44's, 60.747'MB/sec, value only(80.6% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.18's, 60.446'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2704.126'MB/sec (index lex order gen) rebuild zvType time = 0.15's, 0.389'MB/sec write SST data time = 0.03's, 319.200'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 = 7318.323'MB/sec zip my value time = 0.44's, unzip length = 0.027'GB zip my value throughput = 60.747'MB/sec zip pipeline throughput = 60.747'MB/sec entries = 232184 avg-key = 28.00 avg-zkey = 1.91 avg-val = 116.19 avg-zval = 41.50 usrkeys = 232184 avg-key = 20.00 avg-zkey = 1.91 avg-val = 123.19 avg-zval = 41.50 TagRS{ kinds = RS_Key0_Tag1 bytes = 0 } TagArray{ size = 232184 bytes = 783632 } seq expand size = 1625288 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0046 GB value = 0.0270 GB dict = 0.28 MB all = 0.0335 GB } __ZipSize{ index = 0.0004 GB value = 0.0096 GB dict = 0.28 MB all = 0.0111 GB } UnZip/Zip{ index = 10.4837 value = 2.8000 dict = 1.00 all = 3.0046 } Zip/UnZip{ index = 0.0954 value = 0.3571 dict = 1.00 all = 0.3328 } ---------------------------- total value len = 0.372564 GB avg = 0.123 KB (by entry num) total key len = 0.084758 GB avg = 0.028 KB total ukey len = 0.060541 GB avg = 0.020 KB total ukey num = 0.003027072 Billion total entry num = 0.003027072 Billion write speed all = 0.061003501 MB/sec (with seq num) write speed all = 0.057773183 MB/sec (without seq num) 2024/08/20-22:15:56.754452 139857185404480 [compaction_job.cc:1944] [default] [JOB 52416] Generated table #14689631: 232184 keys, 11142432 bytes, temperature: kWarm 2024/08/20-22:15:56.754522 139857185404480 EVENT_LOG_v1 {"time_micros": 1724163356754488, "cf_name": "default", "job": 52416, "event": "table_file_creation", "file_number": 14689631, "file_size": 11142432, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 191031976588, "largest_seqno": 191114505276, "table_properties": {"data_size": 9634800, "index_size": 442944, "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": 6501152, "raw_average_key_size": 28, "raw_value_size": 26977652, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 232184, "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": 1724163355, "oldest_key_time": 0, "file_creation_time": 1724163355, "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": 14689631, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/08/20-22:15:56.764767 139857185404480 [compaction_job.cc:699] job-52416: subcompact[0], size: 0.137584 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-52416/att-00 [14689625,14689626,14689627,14689628,14689629,14689630,14689631] 2024/08/20-22:15:56.802164 139857185404480 (Original Log Time 2024/08/20-22:15:38.179739) EVENT_LOG_v1 {"time_micros": 1724163338179704, "job": 52416, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L1": [14689607], "files_L2": [14689542, 14689543, 14689544, 14689579, 14689580, 14689581], "score": 0.998866, "input_data_size": 161172101, "oldest_snapshot_seqno": 191114518251} 2024/08/20-22:15:56.802168 139857185404480 (Original Log Time 2024/08/20-22:15:56.801418) [compaction_job.cc:2018] [default] [JOB 52416] Compacted 1@1 + 6@2 files to L2 => 137584216 bytes 2024/08/20-22:15:56.802170 139857185404480 (Original Log Time 2024/08/20-22:15:56.802080) [compaction_job.cc:1220] [default] compacted to: files[0 0 7 0 0 0 0] max score 0.05, MB/sec: 8.7 rd, 7.4 wr, level 2, files in(1, 6) out(7 +0 blob) MB in(31.8, 121.9 +0.0 blob) out(131.2 +0.0 blob), read-write-amplify(9.0) write-amplify(4.1) OK, records in: 3027072, records dropped: 0 output_compression: Snappy 2024/08/20-22:15:56.802176 139857185404480 (Original Log Time 2024/08/20-22:15:56.802140) EVENT_LOG_v1 {"time_micros": 1724163356802107, "cf": "default", "job": 52416, "event": "compaction_finished", "compaction_time_micros": 18585039, "compaction_time_cpu_micros": 5973037, "output_level": 2, "num_output_files": 7, "total_output_size": 137584216, "num_input_records": 3027072, "num_output_records": 3027072, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 123269062, "file_range_sync_nanos": 0, "file_fsync_nanos": 6650, "file_prepare_write_nanos": 22456, "lsm_state": [0, 0, 7, 0, 0, 0, 0]} 2024/08/20-22:15:56.925487 139857185404480 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":1724163337,"executesMs":18759,"compactionJobId":52416,"attempt":0,"compactionInputRawBytes":436132528,"compactionInputZipBytes":161172101,"compactionOutputRawBytes":0,"compactionOutputZipBytes":137584216,"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-07dfaedd9f79f740da4a91751dfda98d-0c2b3b0cea0fb6e1-00"}}, response = 2024/08/20-22:15:56.925590 139857185404480 INFO dcompact_worker.cpp:1456: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-08-20T02.42.00/.rocksdb/job-52416/att-00: olev 2, work 18.760 s, result 6.821 ms, install 0.782 ms, input{raw 415.928 MiB zip 153.706 MiB}