2024/11/22-14:43:35.959979 140024701470272 DEBG dcompact_worker.cpp:2214: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00: fork to child time = 0.036041 sec 2024/11/22-14:43:35.961003 140024701470272 DEBG dcompact_worker.cpp:1013: Beg SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00 2024/11/22-14:43:35.967771 140024701470272 DEBG dcompact_worker.cpp:1033: End SerDeRead: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00 2024/11/22-14:43:35.969212 140024701470272 TRAC dcompact_worker.cpp:1083: INFO_LOG_LEVEL: rpc = INFO_LEVEL, env_var = undefined 2024/11/22-14:43:35.969586 140024701470272 [WARN] [column_family.cc:386] multiple cf_paths/db_paths and level_compaction_dynamic_level_bytes can't be used together 2024/11/22-14:43:36.017106 140024701470272 [version_set.cc:6208] Recovering from manifest file: /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-01254/att-00/MANIFEST-206347 2024/11/22-14:43:36.051238 140024701470272 [version_set.cc:6251] Recovered from manifest file:/worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-01254/att-00/MANIFEST-206347 succeeded,manifest_file_number is 206347, next_file_number is 208480, last_sequence is 3297999376, log_number is 0,prev_log_number is 0,max_column_family is 0,min_log_number_to_keep is 208319 2024/11/22-14:43:36.051251 140024701470272 [version_set.cc:6266] Column family [default] (ID 0), log number is 0 2024/11/22-14:43:36.051353 140024701470272 [version_set.cc:5721] Creating manifest 208480 2024/11/22-14:43:36.084110 140024701470272 DEBG dcompact_worker.cpp:1218: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00: bottommost_level: fake = 1, rpc = 0 2024/11/22-14:43:36.104802 140024701470272 [compaction_job.cc:2437] [default] [JOB 1254] Compacting 1@2 + 3@3 files to L3, score 0.86, subcompactions 1 : 1 2024/11/22-14:43:36.104826 140024701470272 [compaction_job.cc:2445] [default]: Compaction start summary: Base version 1033 Base level 2, inputs: [208470(24MB)], [208382(37MB) 208383(38MB) 208384(33MB)] 2024/11/22-14:43:36.112213 140024701470272 [top_zip_table.cc:59] core git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap 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/11/22-14:43:36.112265 140024701470272 [top_zip_table.cc:60] fsa git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap 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/11/22-14:43:36.112293 140024701470272 [top_zip_table.cc:61] zbs git_version_hash_info_is:commit fc4ab4f2fbfdcdfa23a955d69e26d2fc533b902d Author: leipeng Date: 2024-04-16 20:29:43 +0800 test_sso.cpp: test swap 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/11/22-14:43:36.112305 140024701470272 [top_zip_table.cc:62] topling-zip_table_reader: git_version_hash_info_is: commit a4a382006cb82713acf5b3425835f22711877681 Author: leipeng Date: 2024-04-11 19:44:14 +0800 fixed_len_hole_index.cc: Add env bool FixedLenHoleIndexUseAVX512 for ut & debug 1. FixedLenHoleIndexUseAVX512 is only in unit tests or debug 2. In release mode, use avx512 by compile options(-march=) 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/11/22-14:43:36.112318 140024701470272 [top_zip_table.cc:64] topling-rocks git_version_hash_info_is: commit feab587e468621ba0204d47b4ffacc52e7c4290d Author: leipeng Date: 2024-03-22 13:35:06 +0800 ToplingZipTableBuilder::Add: immediately return after error This function returns void, and caller does not check builder->status() after calling this function and graceful abandon. So immediately return after error, and return error status in 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. cpu_flag: -march=native -mbmi -mbmi2 2024/11/22-14:43:36.576366 140024701470272 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst) /dev/shm/ToplingTemp/Topling-151189-jRtXzq 2024/11/22-14:43:37.366957 140024701470272 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst): first pass time = 0.79's, 169.779'MB/sec 2024/11/22-14:43:41.319094 140024701470272 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst): old prealloc_size = 147639500, real_size = 37213664 2024/11/22-14:43:41.319763 140024701470272 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 925761 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0017 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.1083 GB zip-val = 0.0352 GB avg-val = 116.98 avg-zval = 38.06 2024/11/22-14:43:41.320355 140024701470272 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-14:43:42.090379 140024701470272 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208481.sst): second pass time = 3.95's, 27.412'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.77's, 51.483'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2670.782'MB/sec (index lex order gen) rebuild zvType time = 0.63's, 0.370'MB/sec write SST data time = 0.14's, 274.940'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.080'MB, throughput = 37150.413'MB/sec zip my value time = 3.95's, unzip length = 0.108'GB zip my value throughput = 27.412'MB/sec zip pipeline throughput = 111.976'MB/sec entries = 925761 avg-key = 28.00 avg-zkey = 1.89 avg-val = 116.98 avg-zval = 38.06 usrkeys = 925761 avg-key = 20.00 avg-zkey = 1.89 avg-val = 120.59 avg-zval = 38.06 TagRS{ kinds = RS_Key0_TagN bytes = 144760 } TagArray{ size = 477488 bytes = 1492160 } seq expand size = 3342416 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0017 GB value = 0.0352 GB dict = 1.08 MB all = 0.0397 GB } UnZip/Zip{ index = 10.5820 value = 3.0738 dict = 1.00 all = 3.3800 } Zip/UnZip{ index = 0.0945 value = 0.3253 dict = 1.00 all = 0.2959 } ---------------------------- total value len = 0.111639 GB avg = 0.121 KB (by entry num) total key len = 0.025921 GB avg = 0.028 KB total ukey len = 0.018515 GB avg = 0.020 KB total ukey num = 0.000925761 Billion total entry num = 0.000925761 Billion write speed all = 0.006525936 MB/sec (with seq num) write speed all = 0.006174586 MB/sec (without seq num) 2024/11/22-14:43:42.136365 140024701470272 [compaction_job.cc:1948] [default] [JOB 1254] Generated table #208481: 925761 keys, 39709021 bytes, temperature: kWarm 2024/11/22-14:43:42.136479 140024701470272 EVENT_LOG_v1 {"time_micros": 1732257822136406, "cf_name": "default", "job": 1254, "event": "table_file_creation", "file_number": 208481, "file_size": 39709021, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3297954524, "table_properties": {"data_size": 35232336, "index_size": 1749696, "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": 25921308, "raw_average_key_size": 28, "raw_value_size": 108296434, "raw_average_value_size": 116, "num_data_blocks": 1, "num_entries": 925761, "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_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732257816, "oldest_key_time": 0, "file_creation_time": 1732257816, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 208481, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-14:43:42.185057 140024701470272 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst) /dev/shm/ToplingTemp/Topling-151189-0wE1Ln 2024/11/22-14:43:43.229337 140024701470272 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst): first pass time = 1.04's, 128.532'MB/sec 2024/11/22-14:43:45.793323 140024701470272 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst): old prealloc_size = 147639500, real_size = 37456960 2024/11/22-14:43:45.793868 140024701470272 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 924041 prefix = 4 raw-key = 0.0148 GB zip-key = 0.0017 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.1083 GB zip-val = 0.0355 GB avg-val = 117.25 avg-zval = 38.40 2024/11/22-14:43:45.794460 140024701470272 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0023 GB, waited 0.000 sec, Key+Value = 0.134 GB 2024/11/22-14:43:46.582116 140024701470272 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208482.sst): second pass time = 2.56's, 42.270'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 0.79's, 51.449'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 3325.164'MB/sec (index lex order gen) rebuild zvType time = 0.65's, 0.355'MB/sec write SST data time = 0.14's, 294.768'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.082'MB, throughput = 26186.506'MB/sec zip my value time = 2.56's, unzip length = 0.108'GB zip my value throughput = 42.270'MB/sec zip pipeline throughput = 96.012'MB/sec entries = 924041 avg-key = 28.00 avg-zkey = 1.89 avg-val = 117.25 avg-zval = 38.40 usrkeys = 924041 avg-key = 20.00 avg-zkey = 1.89 avg-val = 122.39 avg-zval = 38.40 TagRS{ kinds = RS_Key0_TagN bytes = 144480 } TagArray{ size = 678015 bytes = 2118816 } seq expand size = 4746105 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0185 GB value = 0.1083 GB dict = 1.08 MB all = 0.1342 GB } __ZipSize{ index = 0.0017 GB value = 0.0355 GB dict = 1.08 MB all = 0.0406 GB } UnZip/Zip{ index = 10.5832 value = 3.0537 dict = 1.00 all = 3.3074 } Zip/UnZip{ index = 0.0945 value = 0.3275 dict = 1.00 all = 0.3023 } ---------------------------- total value len = 0.224730 GB avg = 0.121 KB (by entry num) total key len = 0.051794 GB avg = 0.028 KB total ukey len = 0.036996 GB avg = 0.020 KB total ukey num = 0.001849802 Billion total entry num = 0.001849802 Billion write speed all = 0.013115668 MB/sec (with seq num) write speed all = 0.012413772 MB/sec (without seq num) 2024/11/22-14:43:46.620956 140024701470272 [compaction_job.cc:1948] [default] [JOB 1254] Generated table #208482: 924041 keys, 40580518 bytes, temperature: kWarm 2024/11/22-14:43:46.621039 140024701470272 EVENT_LOG_v1 {"time_micros": 1732257826620995, "cf_name": "default", "job": 1254, "event": "table_file_creation", "file_number": 208482, "file_size": 40580518, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3297955019, "table_properties": {"data_size": 35479536, "index_size": 1746240, "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": 25873148, "raw_average_key_size": 28, "raw_value_size": 108344598, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 924041, "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_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732257822, "oldest_key_time": 0, "file_creation_time": 1732257822, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 208482, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-14:43:46.669899 140024701470272 [top_zip_table_builder.cc:934] ToplingZipTableBuilder(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst) /dev/shm/ToplingTemp/Topling-151189-CF8v3m 2024/11/22-14:43:47.969262 140024701470272 [top_zip_table_builder.cc:1352] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst): first pass time = 1.30's, 99.964'MB/sec 2024/11/22-14:43:50.187616 140024701470272 [top_zip_table_builder.cc:2772] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst): old prealloc_size = 147639500, real_size = 36246768 2024/11/22-14:43:50.188206 140024701470272 [top_zip_table_builder.cc:1773] BuildReorderMap(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst): index type = NestLoudsTrieDAWG_Mixed_XL_256_32_FL, store type = DictZipBlobStore usrkeys = 894104 prefix = 4 raw-key = 0.0143 GB zip-key = 0.0017 GB avg-key = 16.00 avg-zkey = 1.89 raw-val = 0.1048 GB zip-val = 0.0343 GB avg-val = 117.27 avg-zval = 38.40 2024/11/22-14:43:50.188937 140024701470272 [top_zip_table_builder.cc:1299] /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst: sumWaitingMem = 0.002 GB, sumWorkingMem = 0.000 GB, reorder workingMem = 0.0022 GB, waited 0.000 sec, Key+Value = 0.130 GB 2024/11/22-14:43:51.405219 140024701470272 [top_zip_table_builder.cc:3100] ToplingZipTableBuilder::Finish(/storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00/208483.sst): second pass time = 2.22's, 47.280'MB/sec, value only(80.7% of KV) wait indexing time = 0.00's, remap KeyValue time = 1.22's, 32.697'MB/sec (all stages of remap) Get OrderMap time = 0.00's, 2980.082'MB/sec (index lex order gen) rebuild zvType time = 1.00's, 0.223'MB/sec write SST data time = 0.21's, 185.599'MB/sec dict compress time = 4356233619.02's, 0.000'MB/sec z-dict build time = 0.00's, sample length = 1.049'MB, throughput = 34086.052'MB/sec zip my value time = 2.22's, unzip length = 0.105'GB zip my value throughput = 47.280'MB/sec zip pipeline throughput = 48.341'MB/sec entries = 894104 avg-key = 28.00 avg-zkey = 1.89 avg-val = 117.27 avg-zval = 38.40 usrkeys = 894104 avg-key = 20.00 avg-zkey = 1.89 avg-val = 123.76 avg-zval = 38.40 TagRS{ kinds = RS_Key0_TagN bytes = 139800 } TagArray{ size = 828945 bytes = 2590464 } seq expand size = 5802615 multi value expand size = 0 cnt WriteAppend = 13 UnZipSize{ index = 0.0179 GB value = 0.1048 GB dict = 1.05 MB all = 0.1299 GB } __ZipSize{ index = 0.0017 GB value = 0.0343 GB dict = 1.05 MB all = 0.0398 GB } UnZip/Zip{ index = 10.5804 value = 3.0539 dict = 1.00 all = 3.2625 } Zip/UnZip{ index = 0.0945 value = 0.3275 dict = 1.00 all = 0.3065 } ---------------------------- total value len = 0.335381 GB avg = 0.122 KB (by entry num) total key len = 0.076829 GB avg = 0.028 KB total ukey len = 0.054878 GB avg = 0.020 KB total ukey num = 0.002743906 Billion total entry num = 0.002743906 Billion write speed all = 0.019546881 MB/sec (with seq num) write speed all = 0.018505961 MB/sec (without seq num) 2024/11/22-14:43:51.442240 140024701470272 [compaction_job.cc:1948] [default] [JOB 1254] Generated table #208483: 894104 keys, 39811664 bytes, temperature: kWarm 2024/11/22-14:43:51.442306 140024701470272 EVENT_LOG_v1 {"time_micros": 1732257831442272, "cf_name": "default", "job": 1254, "event": "table_file_creation", "file_number": 208483, "file_size": 39811664, "file_checksum": "", "file_checksum_func_name": "Unknown", "smallest_seqno": 0, "largest_seqno": 3297955096, "table_properties": {"data_size": 34332960, "index_size": 1690112, "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": 25034912, "raw_average_key_size": 28, "raw_value_size": 104849132, "raw_average_value_size": 117, "num_data_blocks": 1, "num_entries": 894104, "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_TagN-NestLoudsTrieDAWG_Mixed_XL_256_32_FL-DictZipBlobStore", "creation_time": 1732257826, "oldest_key_time": 0, "file_creation_time": 1732257826, "slow_compression_estimated_data_size": 0, "fast_compression_estimated_data_size": 0, "db_id": "d89b4006-2803-486e-b7a2-759bcf348921", "db_session_id": "U1ECJGOXSO4Y1P7ZZXV1", "orig_file_number": 208483, "seqno_to_time_mapping": "N/A", "__indexstats__": "[...1 records...]"}} 2024/11/22-14:43:51.467925 140024701470272 [compaction_job.cc:703] job-01254: subcompact[0], size: 0.120101 G, files: /storage/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/mytopling/.rocksdb/job-01254/att-00 [208481,208482,208483] 2024/11/22-14:43:51.534033 140024701470272 (Original Log Time 2024/11/22-14:43:36.104912) EVENT_LOG_v1 {"time_micros": 1732257816104848, "job": 1254, "event": "compaction_started", "compaction_reason": "FilesMarkedForCompaction", "files_L2": [208470], "files_L3": [208382, 208383, 208384], "score": 0.86219, "input_data_size": 141086663, "oldest_snapshot_seqno": 3297999350} 2024/11/22-14:43:51.534038 140024701470272 (Original Log Time 2024/11/22-14:43:51.533314) [compaction_job.cc:2022] [default] [JOB 1254] Compacted 1@2 + 3@3 files to L3 => 120101203 bytes 2024/11/22-14:43:51.534040 140024701470272 (Original Log Time 2024/11/22-14:43:51.533948) [compaction_job.cc:1224] [default] compacted to: files[0 0 0 3 0 0 0] max score 0.00, MB/sec: 9.2 rd, 7.8 wr, level 3, files in(1, 3) out(3 +0 blob) MB in(24.6, 109.9 +0.0 blob) out(114.5 +0.0 blob), read-write-amplify(10.1) write-amplify(4.7) OK, records in: 2839527, records dropped: 95621 output_compression: Snappy 2024/11/22-14:43:51.534050 140024701470272 (Original Log Time 2024/11/22-14:43:51.534006) EVENT_LOG_v1 {"time_micros": 1732257831533980, "cf": "default", "job": 1254, "event": "compaction_finished", "compaction_time_micros": 15363023, "compaction_time_cpu_micros": 4858671, "output_level": 3, "num_output_files": 3, "total_output_size": 120101203, "num_input_records": 2839527, "num_output_records": 2743906, "num_subcompactions": 1, "output_compression": "Snappy", "num_single_delete_mismatches": 0, "num_single_delete_fallthrough": 0, "file_write_nanos": 79726504, "file_range_sync_nanos": 0, "file_fsync_nanos": 2793, "file_prepare_write_nanos": 6799, "lsm_state": [0, 0, 0, 3, 0, 0, 0]} 2024/11/22-14:43:51.665398 140024701470272 DEBG dcompact_worker.cpp:240: HttpPost: 200 OK: url = http://nlb-7zny4kaa1poal01o64.cn-shenzhen.nlb.aliyuncs.com:8443, body = {"instanceId":"nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137","labourId":"","dbId":"d89b4006-2803-486e-b7a2-759bcf348921","dbStarts":1732256054,"starts":1732257815,"executesMs":15558,"compactionJobId":1254,"attempt":0,"compactionInputRawBytes":411897714,"compactionInputZipBytes":141086663,"compactionOutputRawBytes":0,"compactionOutputZipBytes":120101203,"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-1bcf85e766de775cc0dd65b34225d934-9adb7f35ad495bc6-00"}}, response = 2024/11/22-14:43:51.665600 140024701470272 INFO dcompact_worker.cpp:1459: finish /worker/dcompact-log/nfs/i-wz9deglxdazgiryp6ltb_10.57.5.137/2024-11-22T14.14.14/.rocksdb/job-01254/att-00: olev 3, work 15.558 s, result 14.840 ms, install 0.766 ms, input{raw 392.816 MiB zip 134.551 MiB}