Skip to content

Commit 3ea9a0f

Browse files
b41shb41sh
authored
chore(query): vector index add some logs (#18427)
* chore(query): vector index add some logs * increase default vector_index_filter_size * fix
1 parent bca60ae commit 3ea9a0f

File tree

6 files changed

+30
-13
lines changed

6 files changed

+30
-13
lines changed

‎src/query/config/src/config.rs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3304,15 +3304,15 @@ pub struct CacheConfig {
33043304
#[clap(
33053305
long = "cache-vector-index-meta-count",
33063306
value_name = "VALUE",
3307-
default_value = "3000"
3307+
default_value = "30000"
33083308
)]
33093309
pub vector_index_meta_count: u64,
33103310

33113311
/// Max bytes of cached vector index filters used. Set it to 0 to disable it.
33123312
#[clap(
33133313
long = "cache-vector-index-filter-size",
33143314
value_name = "VALUE",
3315-
default_value = "2147483648"
3315+
default_value = "64424509440"
33163316
)]
33173317
pub vector_index_filter_size: u64,
33183318

‎src/query/config/src/inner.rs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -760,8 +760,8 @@ impl Default for CacheConfig {
760760
inverted_index_meta_count: 3000,
761761
inverted_index_filter_size: 2147483648,
762762
inverted_index_filter_memory_ratio: 0,
763-
vector_index_meta_count: 3000,
764-
vector_index_filter_size: 2147483648,
763+
vector_index_meta_count: 30000,
764+
vector_index_filter_size: 64424509440,
765765
vector_index_filter_memory_ratio: 0,
766766
table_prune_partitions_count: 256,
767767
data_cache_storage: Default::default(),

‎src/query/service/tests/it/storages/testdata/configs_table_basic.txt‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,8 +33,8 @@ DB.Table: 'system'.'configs', Table: configs-table_id:1, ver:0, Engine: SystemCo
3333
| 'cache' | 'table_meta_statistic_count' | '256' | '' |
3434
| 'cache' | 'table_prune_partitions_count' | '256' | '' |
3535
| 'cache' | 'vector_index_filter_memory_ratio' | '0' | '' |
36-
| 'cache' | 'vector_index_filter_size' | '2147483648' | '' |
37-
| 'cache' | 'vector_index_meta_count' | '3000' | '' |
36+
| 'cache' | 'vector_index_filter_size' | '64424509440' | '' |
37+
| 'cache' | 'vector_index_meta_count' | '30000' | '' |
3838
| 'log' | 'dir' | './.databend/logs' | '' |
3939
| 'log' | 'file.dir' | './.databend/logs' | '' |
4040
| 'log' | 'file.format' | 'text' | '' |

‎src/query/storages/fuse/src/io/read/vector_index/vector_index_loader.rs‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ use databend_storages_common_index::VectorIndexMeta;
3636
use databend_storages_common_io::MergeIOReader;
3737
use databend_storages_common_io::ReadSettings;
3838
use databend_storages_common_table_meta::table::TableCompression;
39+
use log::info;
3940
use opendal::Operator;
4041
use parquet::arrow::arrow_reader::ParquetRecordBatchReader;
4142
use parquet::arrow::parquet_to_arrow_field_levels;
@@ -156,6 +157,9 @@ pub(crate) async fn load_vector_index_files<'a>(
156157
names_map.insert(*i as u32, (name, cache_key));
157158
}
158159

160+
let not_cached_data = ranges.len();
161+
let cached_data = column_data.len();
162+
159163
if !ranges.is_empty() {
160164
let merge_io_result =
161165
MergeIOReader::merge_io_read(settings, operator.clone(), location, &ranges).await?;
@@ -210,11 +214,15 @@ pub(crate) async fn load_vector_index_files<'a>(
210214
vector_columns.push(column);
211215
}
212216

217+
let elapsed = start.elapsed().as_millis() as u64;
213218
// Perf.
214219
{
215220
metrics_inc_block_vector_index_read_bytes(vector_bytes_len as u64);
216-
metrics_inc_block_vector_index_read_milliseconds(start.elapsed().as_millis() as u64);
221+
metrics_inc_block_vector_index_read_milliseconds(elapsed);
217222
}
223+
info!(
224+
"[FUSE-PRUNER] Vector index read data elapsed: {elapsed} cached_data: {cached_data} not_cached_data: {not_cached_data}"
225+
);
218226

219227
Ok(vector_columns)
220228
}

‎src/query/storages/fuse/src/pruning/vector_index_pruner.rs‎

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,7 @@ use databend_storages_common_io::ReadSettings;
4040
use databend_storages_common_pruner::BlockMetaIndex;
4141
use databend_storages_common_table_meta::meta::BlockMeta;
4242
use futures_util::future;
43+
use log::info;
4344

4445
use crate::io::read::VectorIndexReader;
4546
use crate::pruning::PruningContext;
@@ -147,6 +148,7 @@ impl VectorIndexPruner {
147148
let pruning_runtime = &self.pruning_ctx.pruning_runtime;
148149
let pruning_semaphore = &self.pruning_ctx.pruning_semaphore;
149150

151+
let start = Instant::now();
150152
// Perf.
151153
{
152154
let block_size = metas.iter().map(|(_, m)| m.block_size).sum();
@@ -202,8 +204,6 @@ impl VectorIndexPruner {
202204
})
203205
});
204206

205-
let start = Instant::now();
206-
207207
let join_handlers = pruning_runtime
208208
.try_spawn_batch_with_owned_semaphore(pruning_semaphore.clone(), pruning_tasks)
209209
.await?;
@@ -246,6 +246,7 @@ impl VectorIndexPruner {
246246
pruned_metas.push((block_meta_index, vector_prune_result.block_meta));
247247
}
248248

249+
let elapsed = start.elapsed().as_millis() as u64;
249250
// Perf.
250251
{
251252
let block_size = pruned_metas.iter().map(|(_, m)| m.block_size).sum();
@@ -254,8 +255,9 @@ impl VectorIndexPruner {
254255
self.pruning_ctx
255256
.pruning_stats
256257
.set_blocks_vector_index_pruning_after(pruned_metas.len() as u64);
257-
metrics_inc_block_vector_index_pruning_milliseconds(start.elapsed().as_millis() as u64);
258+
metrics_inc_block_vector_index_pruning_milliseconds(elapsed);
258259
}
260+
info!("[FUSE-PRUNER] Vector index topn prune elapsed: {elapsed}");
259261

260262
Ok(pruned_metas)
261263
}
@@ -269,6 +271,7 @@ impl VectorIndexPruner {
269271
let pruning_runtime = &self.pruning_ctx.pruning_runtime;
270272
let pruning_semaphore = &self.pruning_ctx.pruning_semaphore;
271273

274+
let start = Instant::now();
272275
let mut block_meta_indexes = metas.into_iter().enumerate();
273276
let pruning_tasks = std::iter::from_fn(move || {
274277
block_meta_indexes
@@ -314,8 +317,6 @@ impl VectorIndexPruner {
314317
})
315318
});
316319

317-
let start = Instant::now();
318-
319320
let join_handlers = pruning_runtime
320321
.try_spawn_batch_with_owned_semaphore(pruning_semaphore.clone(), pruning_tasks)
321322
.await?;
@@ -345,10 +346,12 @@ impl VectorIndexPruner {
345346
new_metas.push((block_meta_index, vector_prune_result.block_meta));
346347
}
347348

349+
let elapsed = start.elapsed().as_millis() as u64;
348350
// Perf.
349351
{
350-
metrics_inc_block_vector_index_pruning_milliseconds(start.elapsed().as_millis() as u64);
352+
metrics_inc_block_vector_index_pruning_milliseconds(elapsed);
351353
}
354+
info!("[FUSE-PRUNER] Vector index prune elapsed: {elapsed}");
352355

353356
Ok(new_metas)
354357
}

‎src/query/storages/fuse/src/pruning_pipeline/vector_index_prune_transform.rs‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
// limitations under the License.
1414

1515
use std::sync::Arc;
16+
use std::time::Instant;
1617

1718
use databend_common_exception::ErrorCode;
1819
use databend_common_exception::Result;
@@ -25,6 +26,7 @@ use databend_common_pipeline_transforms::AsyncAccumulatingTransform;
2526
use databend_common_pipeline_transforms::AsyncAccumulatingTransformer;
2627
use databend_storages_common_pruner::BlockMetaIndex;
2728
use databend_storages_common_table_meta::meta::BlockMeta;
29+
use log::info;
2830

2931
use crate::pruning::VectorIndexPruner;
3032
use crate::pruning_pipeline::block_prune_result_meta::BlockPruneResult;
@@ -74,7 +76,11 @@ impl VectorIndexPruneTransform {
7476
}
7577

7678
async fn do_vector_index_prune(&self) -> Result<Option<DataBlock>> {
79+
let start = Instant::now();
7780
let pruned = self.vector_index_pruner.prune(self.metas.clone()).await?;
81+
let elapsed = start.elapsed().as_millis() as u64;
82+
info!("[PROCESSOR-ASYNC-TASK] Vector index prune transform elapsed: {elapsed}");
83+
7884
if pruned.is_empty() {
7985
Ok(None)
8086
} else {

0 commit comments

Comments
 (0)