[fix](profile) populate inverted index metrics for SEARCH() query path (#62121)

### What problem does this PR solve? Issue Number: close #xxx Related PR: #xxx Problem Summary: SEARCH() function uses the query_v2 engine, which bypasses `InvertedIndexReader::query()`. This causes all inverted index profile metrics to report zero, making it impossible to diagnose SEARCH() performance issues from query profiles. Four independent problems were identified and fixed: **1. Query-level timers not populated (function_search.cpp)** The MATCH path populates `inverted_index_query_timer`, `searcher_open_timer`, `searcher_search_timer`, etc. via `SCOPED_RAW_TIMER` in `inverted_index_reader.cpp`. The SEARCH path bypasses this entirely — `FieldReaderResolver::resolve()` opens the index and `evaluate_inverted_index_with_search_param()` executes the query without any timer instrumentation. Fix: Add `SCOPED_RAW_TIMER` at corresponding points in `function_search.cpp`: - `inverted_index_query_timer` around the entire evaluation (placed before DSL cache lookup so cache-hit path is also timed) - `inverted_index_searcher_open_timer` around searcher cache miss (directory open) - `inverted_index_searcher_search_timer` around query build + execution - `inverted_index_searcher_search_init_timer` around `build_query_recursive()` - `inverted_index_searcher_search_exec_timer` around `collect_multi_segment_doc_set/top_k()` - `inverted_index_searcher_cache_hit/miss` counters in `resolve()` - `inverted_index_lookup_timer` around both DSL cache and searcher cache lookups - `inverted_index_query_cache_hit/miss` counters on DSL cache lookup **2. io_ctx dangling pointer in cached IndexSearcher (function_search.cpp)** `FieldReaderResolver::resolve()` opens the index directory with the caller's `io_ctx`, builds an IndexSearcher, and inserts it into the global `InvertedIndexSearcherCache`. The cached searcher's underlying `DorisCompoundReader` main stream retains a raw pointer to the caller's `io_ctx`. When the originating scan context is destroyed, this pointer dangles — any subsequent cache hit from a different query would read through a stale `io_ctx`, causing use-after-free (caught by ASAN). Fix: After building the IndexSearcher and before inserting into cache, clear the main stream's `io_ctx` via `stream->setIoContext(nullptr)`. Subsequent query-phase reads receive the caller's `io_ctx` through CLucene API parameters (`termDocs`/`termPositions`/`terms`) — the same pattern used by the MATCH path in `InvertedIndexReader::create_index_searcher()`. **3. Profile counters pruned by level (olap_scan_operator.cpp)** All inverted index counters were registered with default `level=2` via `ADD_TIMER`/`ADD_COUNTER`. The profile display system prunes level-2 leaf counters when `profile_level < 2`, making them invisible in query profiles. The FileCache counters used `ADD_CHILD_TIMER_WITH_LEVEL(..., 1)` and were visible. Fix: Register inverted index counters with `level=1` via `ADD_TIMER_WITH_LEVEL`/`ADD_COUNTER_WITH_LEVEL`. **4. Cache control and metric accuracy issues (function_search.cpp)** Code review identified several metric and cache control issues: - DSL query-cache hit path returned early before `inverted_index_query_timer` scope, resulting in `InvertedIndexQueryTime=0` for warm queries. - Searcher cache lookup was unconditional, ignoring `enable_inverted_index_searcher_cache` session variable. A second query with cache disabled could silently hit the cache. - Resolver local `_cache` hit (same field referenced multiple times within one DSL) was incorrectly counted as `inverted_index_searcher_cache_hit`, inflating the metric. - `InvertedIndexLookupTimer` was not instrumented in the SEARCH path. Fix: - Move `inverted_index_query_timer` before DSL cache lookup so cache-hit fast path is also timed. - Gate searcher cache lookup on `enable_inverted_index_searcher_cache` (matching MATCH path in `InvertedIndexReader::handle_searcher_cache`). Insert remains unconditional for consistency. - Remove false `inverted_index_searcher_cache_hit++` from resolver local `_cache` hit. - Add `SCOPED_RAW_TIMER` for `inverted_index_lookup_timer` around both DSL and searcher cache lookups. - Record `inverted_index_query_cache_hit/miss` on DSL cache lookup result. - Add regression tests: DSL query-cache hit path, searcher cache disabled with two runs.
2026-11-04 07:31:17 +00:00 · 2026-04-07 22:02:33 +08:00
1 parent 63654958c6
commit 361bbed335
@@ -238,33 +238,37 @@ Status OlapScanLocalState::_init_profile() {

    _statistics_collect_timer = ADD_TIMER(_scanner_profile, "StatisticsCollectTime");
    _inverted_index_filter_counter =
-            ADD_COUNTER(_segment_profile, "RowsInvertedIndexFiltered", TUnit::UNIT);
-    _inverted_index_filter_timer = ADD_TIMER(_segment_profile, "InvertedIndexFilterTime");
+            ADD_COUNTER_WITH_LEVEL(_segment_profile, "RowsInvertedIndexFiltered", TUnit::UNIT, 1);
+    _inverted_index_filter_timer =
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexFilterTime", 1);
    _inverted_index_query_cache_hit_counter =
-            ADD_COUNTER(_segment_profile, "InvertedIndexQueryCacheHit", TUnit::UNIT);
+            ADD_COUNTER_WITH_LEVEL(_segment_profile, "InvertedIndexQueryCacheHit", TUnit::UNIT, 1);
    _inverted_index_query_cache_miss_counter =
-            ADD_COUNTER(_segment_profile, "InvertedIndexQueryCacheMiss", TUnit::UNIT);
-    _inverted_index_query_timer = ADD_TIMER(_segment_profile, "InvertedIndexQueryTime");
+            ADD_COUNTER_WITH_LEVEL(_segment_profile, "InvertedIndexQueryCacheMiss", TUnit::UNIT, 1);
+    _inverted_index_query_timer =
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexQueryTime", 1);
    _inverted_index_query_null_bitmap_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexQueryNullBitmapTime");
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexQueryNullBitmapTime", 1);
    _inverted_index_query_bitmap_copy_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexQueryBitmapCopyTime");
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexQueryBitmapCopyTime", 1);
    _inverted_index_searcher_open_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexSearcherOpenTime");
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexSearcherOpenTime", 1);
    _inverted_index_searcher_search_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexSearcherSearchTime");
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexSearcherSearchTime", 1);
    _inverted_index_searcher_search_init_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexSearcherSearchInitTime");
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexSearcherSearchInitTime", 1);
    _inverted_index_searcher_search_exec_timer =
-            ADD_TIMER(_segment_profile, "InvertedIndexSearcherSearchExecTime");
-    _inverted_index_searcher_cache_hit_counter =
-            ADD_COUNTER(_segment_profile, "InvertedIndexSearcherCacheHit", TUnit::UNIT);
-    _inverted_index_searcher_cache_miss_counter =
-            ADD_COUNTER(_segment_profile, "InvertedIndexSearcherCacheMiss", TUnit::UNIT);
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexSearcherSearchExecTime", 1);
+    _inverted_index_searcher_cache_hit_counter = ADD_COUNTER_WITH_LEVEL(
+            _segment_profile, "InvertedIndexSearcherCacheHit", TUnit::UNIT, 1);
+    _inverted_index_searcher_cache_miss_counter = ADD_COUNTER_WITH_LEVEL(
+            _segment_profile, "InvertedIndexSearcherCacheMiss", TUnit::UNIT, 1);
    _inverted_index_downgrade_count_counter =
-            ADD_COUNTER(_segment_profile, "InvertedIndexDowngradeCount", TUnit::UNIT);
-    _inverted_index_analyzer_timer = ADD_TIMER(_segment_profile, "InvertedIndexAnalyzerTime");
-    _inverted_index_lookup_timer = ADD_TIMER(_segment_profile, "InvertedIndexLookupTimer");
+            ADD_COUNTER_WITH_LEVEL(_segment_profile, "InvertedIndexDowngradeCount", TUnit::UNIT, 1);
+    _inverted_index_analyzer_timer =
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexAnalyzerTime", 1);
+    _inverted_index_lookup_timer =
+            ADD_TIMER_WITH_LEVEL(_segment_profile, "InvertedIndexLookupTimer", 1);

    _output_index_result_column_timer = ADD_TIMER(_segment_profile, "OutputIndexResultColumnTime");
    _filtered_segment_counter = ADD_COUNTER(_segment_profile, "NumSegmentFiltered", TUnit::UNIT);
@@ -37,9 +37,11 @@
 #include "core/data_type/data_type_string.h"
 #include "exprs/function/simple_function_factory.h"
 #include "exprs/vexpr_context.h"
+#include "runtime/runtime_profile.h"
 #include "storage/index/index_file_reader.h"
 #include "storage/index/index_query_context.h"
 #include "storage/index/inverted/analyzer/analyzer.h"
+#include "storage/index/inverted/inverted_index_compound_reader.h"
 #include "storage/index/inverted/inverted_index_iterator.h"
 #include "storage/index/inverted/inverted_index_parser.h"
 #include "storage/index/inverted/inverted_index_reader.h"
@@ -62,6 +64,7 @@
 #include "storage/segment/variant/nested_group_provider.h"
 #include "storage/segment/variant/variant_column_reader.h"
 #include "storage/types.h"
+#include "util/debug_points.h"
 #include "util/string_util.h"
 #include "util/thrift_util.h"

@@ -265,16 +268,31 @@ Status FieldReaderResolver::resolve(const std::string& field_name,
                "index file reader is null for field '{}'", field_name);
    }

-    // Use InvertedIndexSearcherCache to avoid re-opening index files repeatedly
+    // Use InvertedIndexSearcherCache to avoid re-opening index files repeatedly,
+    // respecting the enable_inverted_index_searcher_cache session variable.
    auto index_file_key =
            index_file_reader->get_index_file_cache_key(&inverted_reader->get_index_meta());
    InvertedIndexSearcherCache::CacheKey searcher_cache_key(index_file_key);
    InvertedIndexCacheHandle searcher_cache_handle;
-    bool cache_hit = InvertedIndexSearcherCache::instance()->lookup(searcher_cache_key,
-                                                                    &searcher_cache_handle);
+
+    bool searcher_cache_enabled =
+            _context->runtime_state != nullptr &&
+            _context->runtime_state->query_options().enable_inverted_index_searcher_cache;
+
+    bool cache_hit = false;
+    if (searcher_cache_enabled) {
+        int64_t lookup_dummy = 0;
+        SCOPED_RAW_TIMER(_context->stats ? &_context->stats->inverted_index_lookup_timer
+                                         : &lookup_dummy);
+        cache_hit = InvertedIndexSearcherCache::instance()->lookup(searcher_cache_key,
+                                                                   &searcher_cache_handle);
+    }

    std::shared_ptr<lucene::index::IndexReader> reader_holder;
    if (cache_hit) {
+        if (_context->stats) {
+            _context->stats->inverted_index_searcher_cache_hit++;
+        }
        auto searcher_variant = searcher_cache_handle.get_index_searcher();
        auto* searcher_ptr = std::get_if<FulltextIndexSearcherPtr>(&searcher_variant);
        if (searcher_ptr != nullptr && *searcher_ptr != nullptr) {
@@ -285,7 +303,13 @@ Status FieldReaderResolver::resolve(const std::string& field_name,
    }

    if (!reader_holder) {
+        if (_context->stats) {
+            _context->stats->inverted_index_searcher_cache_miss++;
+        }
        // Cache miss: open directory, build IndexSearcher, insert into cache
+        int64_t dummy_timer = 0;
+        SCOPED_RAW_TIMER(_context->stats ? &_context->stats->inverted_index_searcher_open_timer
+                                         : &dummy_timer);
        RETURN_IF_ERROR(
                index_file_reader->init(config::inverted_index_read_buffer_size, _context->io_ctx));
        auto directory = DORIS_TRY(
@@ -297,6 +321,26 @@ Status FieldReaderResolver::resolve(const std::string& field_name,
                DORIS_TRY(index_searcher_builder->get_index_searcher(directory.get()));
        auto reader_size = index_searcher_builder->get_reader_size();

+        // Initialization reads are done. Clear io_ctx on the main stream so the
+        // cached searcher does not carry a stale reference. Subsequent query-phase
+        // reads receive the caller's io_ctx through the CLucene API parameters
+        // (termDocs/termPositions/terms) — the same pattern used by the MATCH path
+        // in InvertedIndexReader::create_index_searcher().
+        auto* stream = static_cast<DorisCompoundReader*>(directory.get())->getDorisIndexInput();
+        DBUG_EXECUTE_IF(
+                "FieldReaderResolver.resolve.io_ctx", ({
+                    const auto* cur_io_ctx = (const io::IOContext*)stream->getIoContext();
+                    if (cur_io_ctx->file_cache_stats) {
+                        if (cur_io_ctx->file_cache_stats != &_context->stats->file_cache_stats) {
+                            LOG(FATAL) << "search: io_ctx file_cache_stats mismatch: "
+                                       << cur_io_ctx->file_cache_stats << " vs "
+                                       << &_context->stats->file_cache_stats;
+                        }
+                    }
+                }));
+        stream->setIoContext(nullptr);
+        stream->setIndexFile(false);
+
        auto* cache_value = new InvertedIndexSearcherCache::CacheValue(std::move(searcher_result),
                                                                       reader_size, UnixMillis());
        InvertedIndexSearcherCache::instance()->insert(searcher_cache_key, cache_value,
@@ -395,6 +439,13 @@ Status FunctionSearch::evaluate_inverted_index_with_search_param(
        return Status::OK();
    }

+    // Track overall query time (equivalent to inverted_index_query_timer in MATCH path).
+    // Must be declared before the DSL cache lookup so that cache-hit fast paths are
+    // also covered by the timer.
+    int64_t query_timer_dummy = 0;
+    OlapReaderStatistics* outer_stats = index_query_context ? index_query_context->stats : nullptr;
+    SCOPED_RAW_TIMER(outer_stats ? &outer_stats->inverted_index_query_timer : &query_timer_dummy);
+
    // DSL result cache: reuse InvertedIndexQueryCache with SEARCH_DSL_QUERY type
    auto* dsl_cache = enable_cache ? InvertedIndexQueryCache::instance() : nullptr;
    std::string seg_prefix;
@@ -410,9 +461,19 @@ Status FunctionSearch::evaluate_inverted_index_with_search_param(
                    dsl_sig};
            cache_usable = true;
            InvertedIndexQueryCacheHandle dsl_cache_handle;
-            if (dsl_cache->lookup(dsl_cache_key, &dsl_cache_handle)) {
+            bool dsl_hit = false;
+            {
+                int64_t lookup_dummy = 0;
+                SCOPED_RAW_TIMER(outer_stats ? &outer_stats->inverted_index_lookup_timer
+                                             : &lookup_dummy);
+                dsl_hit = dsl_cache->lookup(dsl_cache_key, &dsl_cache_handle);
+            }
+            if (dsl_hit) {
                auto cached_bitmap = dsl_cache_handle.get_bitmap();
                if (cached_bitmap) {
+                    if (outer_stats) {
+                        outer_stats->inverted_index_query_cache_hit++;
+                    }
                    // Also retrieve cached null bitmap for three-valued SQL logic
                    // (needed by compound operators NOT, OR, AND in VCompoundPred)
                    auto null_cache_key = InvertedIndexQueryCache::CacheKey {
@@ -431,6 +492,9 @@ Status FunctionSearch::evaluate_inverted_index_with_search_param(
                    return Status::OK();
                }
            }
+            if (outer_stats) {
+                outer_stats->inverted_index_query_cache_miss++;
+            }
        }
    }

@@ -542,11 +606,19 @@ Status FunctionSearch::evaluate_inverted_index_with_search_param(
        minimum_should_match = search_param.minimum_should_match;
    }

+    auto* stats = context->stats;
+    int64_t dummy_timer = 0;
+    SCOPED_RAW_TIMER(stats ? &stats->inverted_index_searcher_search_timer : &dummy_timer);
+
    query_v2::QueryPtr root_query;
    std::string root_binding_key;
-    RETURN_IF_ERROR(build_query_recursive(search_param.root, context, resolver, &root_query,
-                                          &root_binding_key, default_operator,
-                                          minimum_should_match));
+    {
+        int64_t init_dummy = 0;
+        SCOPED_RAW_TIMER(stats ? &stats->inverted_index_searcher_search_init_timer : &init_dummy);
+        RETURN_IF_ERROR(build_query_recursive(search_param.root, context, resolver, &root_query,
+                                              &root_binding_key, default_operator,
+                                              minimum_should_match));
+    }
    if (root_query == nullptr) {
        LOG(INFO) << "search: Query tree resolved to empty query, dsl:"
                  << search_param.original_dsl;
@@ -577,17 +649,22 @@ Status FunctionSearch::evaluate_inverted_index_with_search_param(
    }

    std::shared_ptr<roaring::Roaring> roaring = std::make_shared<roaring::Roaring>();
-    if (enable_scoring && !is_asc && top_k > 0) {
-        bool use_wand = index_query_context->runtime_state != nullptr &&
-                        index_query_context->runtime_state->query_options()
-                                .enable_inverted_index_wand_query;
-        query_v2::collect_multi_segment_top_k(weight, exec_ctx, root_binding_key, top_k, roaring,
-                                              index_query_context->collection_similarity, use_wand);
-    } else {
-        query_v2::collect_multi_segment_doc_set(
-                weight, exec_ctx, root_binding_key, roaring,
-                index_query_context ? index_query_context->collection_similarity : nullptr,
-                enable_scoring);
+    {
+        int64_t exec_dummy = 0;
+        SCOPED_RAW_TIMER(stats ? &stats->inverted_index_searcher_search_exec_timer : &exec_dummy);
+        if (enable_scoring && !is_asc && top_k > 0) {
+            bool use_wand = index_query_context->runtime_state != nullptr &&
+                            index_query_context->runtime_state->query_options()
+                                    .enable_inverted_index_wand_query;
+            query_v2::collect_multi_segment_top_k(
+                    weight, exec_ctx, root_binding_key, top_k, roaring,
+                    index_query_context->collection_similarity, use_wand);
+        } else {
+            query_v2::collect_multi_segment_doc_set(
+                    weight, exec_ctx, root_binding_key, roaring,
+                    index_query_context ? index_query_context->collection_similarity : nullptr,
+                    enable_scoring);
+        }
    }

    VLOG_DEBUG << "search: Query completed, matched " << roaring->cardinality() << " documents";
@@ -412,4 +412,4 @@ void DorisCompoundReader::initialize(const io::IOContext* io_ctx) {
 }

 } // namespace doris::segment_v2
-#include "common/compile_check_end.h"
+#include "common/compile_check_end.h"
@@ -35,6 +35,7 @@

 #include "gtest/gtest_pred_impl.h"
 #include "io/fs/local_file_system.h"
+#include "io/io_common.h"
 #include "runtime/exec_env.h"
 #include "storage/index/index_file_reader.h"
 #include "storage/index/index_file_writer.h"
@@ -999,4 +1000,60 @@ TEST_F(DorisCompoundReaderTest, OpenInputFromRAMDirectory) {
    reader.close();
 }

+// Verify that after initialize() + setIoContext(nullptr) (the cache-safe
+// transition), the main stream's io_ctx is cleared and sub-streams created
+// via openInput() do NOT carry stale io_ctx pointers.  This is the pattern
+// used by both MATCH and SEARCH paths before inserting an IndexSearcher
+// into the global InvertedIndexSearcherCache.
+TEST_F(DorisCompoundReaderTest, InitializeThenClearIoCtxForCacheSafety) {
+    std::string index_path = kTestDir + "/test_io_ctx_lifecycle.idx";
+    std::vector<std::string> file_names = {"segments.gen", "posting.dat"};
+    std::vector<int64_t> lengths = {30, 60};
+
+    CL_NS(store)::IndexInput* index_input =
+            create_mock_index_input(index_path, file_names, lengths);
+
+    DorisCompoundReader reader(index_input, 4096, nullptr);
+
+    // --- Phase 1: initialization (simulates index open with a query's io_ctx) ---
+    io::IOContext io_ctx;
+    io_ctx.reader_type = ReaderType::READER_QUERY;
+    reader.initialize(&io_ctx);
+
+    auto* stream = reader.getDorisIndexInput();
+    auto* ctx_after_init = (const io::IOContext*)stream->getIoContext();
+    // Main stream should carry the io_ctx during initialization reads
+    EXPECT_EQ(ctx_after_init->reader_type, ReaderType::READER_QUERY);
+
+    // --- Phase 2: cache-safe transition (mirrors create_index_searcher) ---
+    stream->setIoContext(nullptr);
+    stream->setIndexFile(false);
+
+    auto* ctx_after_clear = (const io::IOContext*)stream->getIoContext();
+    // Main stream io_ctx should be reset to defaults
+    EXPECT_EQ(ctx_after_clear->reader_type, ReaderType::UNKNOWN);
+    EXPECT_EQ(ctx_after_clear->file_cache_stats, nullptr);
+
+    // --- Phase 3: verify sub-streams don't inherit stale io_ctx ---
+    CLuceneError err;
+    lucene::store::IndexInput* sub_input = nullptr;
+    EXPECT_TRUE(reader.openInput("posting.dat", sub_input, err, 4096));
+    EXPECT_NE(sub_input, nullptr);
+
+    // CSIndexInput._io_ctx should be nullptr (not set by openInput on master)
+    // This means readInternal() will skip setIoContext on the base stream,
+    // allowing query-phase reads to use their own io_ctx through the
+    // CLucene API parameter chain (termDocs/termPositions/terms).
+    // We verify this indirectly: cloning should also have nullptr _io_ctx.
+    lucene::store::IndexInput* cloned = sub_input->clone();
+    EXPECT_NE(cloned, nullptr);
+
+    sub_input->close();
+    cloned->close();
+    _CLLDELETE(sub_input);
+    _CLLDELETE(cloned);
+
+    reader.close();
+}
+
 } // namespace doris::segment_v2
@@ -0,0 +1,22 @@
+-- This file is automatically generated. You may need to update it when you get
+--  temporary file 'regression-test/data/search/test_search_inverted_index_profile.out'.
+-- !io_ctx_miss --
+2
+5
+7
+
+-- !io_ctx_hit --
+2
+5
+7
+
+-- !io_ctx_multi --
+1
+2
+3
+4
+5
+6
+7
+8
+
@@ -0,0 +1,302 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements.  See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership.  The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License.  You may obtain a copy of the License at
+//
+//   http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied.  See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+import java.util.regex.Pattern
+
+suite("test_search_inverted_index_profile", "nonConcurrent") {
+    def tableName = "test_search_ii_profile"
+
+    sql "DROP TABLE IF EXISTS ${tableName}"
+    sql """
+        CREATE TABLE ${tableName} (
+            id INT,
+            title VARCHAR(200),
+            content TEXT,
+            INDEX idx_title(title) USING INVERTED PROPERTIES("parser" = "english"),
+            INDEX idx_content(content) USING INVERTED PROPERTIES("parser" = "english")
+        ) ENGINE=OLAP
+        DUPLICATE KEY(id)
+        DISTRIBUTED BY HASH(id) BUCKETS 1
+        PROPERTIES (
+            "replication_num" = "1",
+            "disable_auto_compaction" = "true"
+        )
+    """
+
+    sql """INSERT INTO ${tableName} VALUES
+        (1, 'apple banana cherry', 'red fruit sweet delicious'),
+        (2, 'banana grape mango', 'yellow fruit tropical summer'),
+        (3, 'cherry plum peach', 'stone fruit summer garden'),
+        (4, 'apple grape kiwi', 'green fruit fresh morning'),
+        (5, 'mango pineapple coconut', 'tropical fruit exotic island'),
+        (6, 'apple cherry plum', 'mixed fruit salad party'),
+        (7, 'banana coconut papaya', 'smoothie blend tropical drink'),
+        (8, 'grape cherry apple', 'wine fruit tart autumn')
+    """
+    sql "sync"
+
+    // Helper: extract a numeric counter value from profile string
+    def extractCounter = { String profileStr, String counterName ->
+        // Profile HTML uses &nbsp; for spacing
+        def pattern = Pattern.compile("${counterName}:(?:&nbsp;|\\s)*(\\d+)")
+        def matcher = pattern.matcher(profileStr)
+        if (matcher.find()) {
+            return Long.parseLong(matcher.group(1))
+        }
+        return -1L
+    }
+
+    // =========================================================================
+    // Test 1: SEARCH() profile metrics are populated on cache miss
+    //
+    // Disable both caches so every query triggers a full index open + search.
+    // Verify that InvertedIndexQueryTime, InvertedIndexSearcherOpenTime,
+    // InvertedIndexSearcherSearchTime, and cache miss counter are all > 0.
+    // =========================================================================
+    sql """ set enable_profile = true """
+    sql """ set profile_level = 2 """
+    sql """ set enable_sql_cache = false """
+    sql """ set enable_inverted_index_searcher_cache = false """
+    sql """ set enable_inverted_index_query_cache = false """
+    sql """ set enable_common_expr_pushdown = true """
+    sql """ set enable_common_expr_pushdown_for_inverted_index = true """
+
+    def queryId1 = "search_profile_miss_${System.currentTimeMillis()}"
+    try {
+        profile("${queryId1}") {
+            run {
+                sql """/* ${queryId1} */ SELECT id FROM ${tableName}
+                       WHERE search('title:apple') ORDER BY id"""
+            }
+            check { profileString, exception ->
+                if (exception != null) throw exception
+                log.info("=== Cache-miss profile ===")
+
+                def queryTime = extractCounter(profileString, "InvertedIndexQueryTime")
+                def openTime = extractCounter(profileString, "InvertedIndexSearcherOpenTime")
+                def searchTime = extractCounter(profileString, "InvertedIndexSearcherSearchTime")
+                def searchInitTime = extractCounter(profileString, "InvertedIndexSearcherSearchInitTime")
+                def searchExecTime = extractCounter(profileString, "InvertedIndexSearcherSearchExecTime")
+                def cacheMiss = extractCounter(profileString, "InvertedIndexSearcherCacheMiss")
+                def cacheHit = extractCounter(profileString, "InvertedIndexSearcherCacheHit")
+
+                log.info("InvertedIndexQueryTime: {}", queryTime)
+                log.info("InvertedIndexSearcherOpenTime: {}", openTime)
+                log.info("InvertedIndexSearcherSearchTime: {}", searchTime)
+                log.info("InvertedIndexSearcherSearchInitTime: {}", searchInitTime)
+                log.info("InvertedIndexSearcherSearchExecTime: {}", searchExecTime)
+                log.info("InvertedIndexSearcherCacheMiss: {}", cacheMiss)
+                log.info("InvertedIndexSearcherCacheHit: {}", cacheHit)
+
+                assertTrue(queryTime > 0,
+                    "InvertedIndexQueryTime should be > 0 for SEARCH(), got ${queryTime}")
+                assertTrue(searchTime > 0,
+                    "InvertedIndexSearcherSearchTime should be > 0, got ${searchTime}")
+                assertTrue(cacheMiss > 0,
+                    "InvertedIndexSearcherCacheMiss should be > 0 (cache disabled), got ${cacheMiss}")
+            }
+        }
+    } catch (IllegalStateException e) {
+        if (e.message?.contains("HttpCliAction failed")) {
+            log.warn("Profile HTTP request failed, skipping: {}", e.message)
+        } else {
+            throw e
+        }
+    }
+
+    // =========================================================================
+    // Test 2: SEARCH() cache hit — re-enable searcher cache, run twice.
+    // First run is a cache miss (populates cache), second run is a cache hit.
+    // Verify the second profile shows cache hit > 0 and open time == 0.
+    // =========================================================================
+    sql """ set enable_inverted_index_searcher_cache = true """
+    sql """ set enable_inverted_index_query_cache = false """
+
+    // First run: populate searcher cache
+    sql """SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+           id FROM ${tableName} WHERE search('title:cherry') ORDER BY id"""
+
+    // Second run: should hit searcher cache
+    def queryId2 = "search_profile_hit_${System.currentTimeMillis()}"
+    try {
+        profile("${queryId2}") {
+            run {
+                sql """/* ${queryId2} */ SELECT id FROM ${tableName}
+                       WHERE search('title:cherry') ORDER BY id"""
+            }
+            check { profileString, exception ->
+                if (exception != null) throw exception
+                log.info("=== Cache-hit profile ===")
+
+                def cacheHit = extractCounter(profileString, "InvertedIndexSearcherCacheHit")
+                def cacheMiss = extractCounter(profileString, "InvertedIndexSearcherCacheMiss")
+                def openTime = extractCounter(profileString, "InvertedIndexSearcherOpenTime")
+                def searchTime = extractCounter(profileString, "InvertedIndexSearcherSearchTime")
+
+                log.info("InvertedIndexSearcherCacheHit: {}", cacheHit)
+                log.info("InvertedIndexSearcherCacheMiss: {}", cacheMiss)
+                log.info("InvertedIndexSearcherOpenTime: {}", openTime)
+                log.info("InvertedIndexSearcherSearchTime: {}", searchTime)
+
+                assertTrue(cacheHit > 0,
+                    "InvertedIndexSearcherCacheHit should be > 0 on second run, got ${cacheHit}")
+                assertTrue(searchTime > 0,
+                    "InvertedIndexSearcherSearchTime should still be > 0 on cache hit, got ${searchTime}")
+            }
+        }
+    } catch (IllegalStateException e) {
+        if (e.message?.contains("HttpCliAction failed")) {
+            log.warn("Profile HTTP request failed, skipping: {}", e.message)
+        } else {
+            throw e
+        }
+    }
+
+    // =========================================================================
+    // Test 3: io_ctx safety — debug point verifies no stale io_ctx on the
+    // main stream after IndexSearcher creation (cache miss path).
+    // Then run a second query that hits the cache and confirm correct results.
+    // If the old dangling-pointer bug existed, ASAN would catch UAF here.
+    // =========================================================================
+    sql """ set enable_inverted_index_searcher_cache = true """
+    sql """ set enable_inverted_index_query_cache = false """
+
+    try {
+        GetDebugPoint().enableDebugPointForAllBEs("FieldReaderResolver.resolve.io_ctx")
+
+        // First query: cache miss, debug point validates io_ctx consistency
+        qt_io_ctx_miss """ SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+            id FROM ${tableName} WHERE search('content:tropical') ORDER BY id """
+
+        // Second query: cache hit, reuses the cached searcher
+        // If io_ctx was stale, this would crash under ASAN
+        qt_io_ctx_hit """ SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+            id FROM ${tableName} WHERE search('content:tropical') ORDER BY id """
+
+        // Third query: different DSL but same field — exercises resolver cache
+        qt_io_ctx_multi """ SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+            id FROM ${tableName} WHERE search('content:tropical OR content:fruit') ORDER BY id """
+    } finally {
+        GetDebugPoint().disableDebugPointForAllBEs("FieldReaderResolver.resolve.io_ctx")
+    }
+
+    // =========================================================================
+    // Test 4: DSL query-cache hit — enable query cache, run same DSL twice.
+    // First run populates the DSL cache (miss), second run hits it.
+    // Verify InvertedIndexQueryCacheHit > 0, InvertedIndexQueryTime > 0,
+    // and InvertedIndexLookupTime > 0 on the cache-hit path.
+    // =========================================================================
+    sql """ set enable_inverted_index_searcher_cache = true """
+    sql """ set enable_inverted_index_query_cache = true """
+
+    // First run: populate DSL cache
+    sql """SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+           id FROM ${tableName} WHERE search('title:banana') ORDER BY id"""
+
+    // Second run: should hit DSL cache
+    def queryId4 = "search_profile_dsl_hit_${System.currentTimeMillis()}"
+    try {
+        profile("${queryId4}") {
+            run {
+                sql """/* ${queryId4} */ SELECT id FROM ${tableName}
+                       WHERE search('title:banana') ORDER BY id"""
+            }
+            check { profileString, exception ->
+                if (exception != null) throw exception
+                log.info("=== DSL cache-hit profile ===")
+
+                def queryCacheHit = extractCounter(profileString, "InvertedIndexQueryCacheHit")
+                def queryTime = extractCounter(profileString, "InvertedIndexQueryTime")
+                def lookupTime = extractCounter(profileString, "InvertedIndexLookupTime")
+
+                log.info("InvertedIndexQueryCacheHit: {}", queryCacheHit)
+                log.info("InvertedIndexQueryTime: {}", queryTime)
+                log.info("InvertedIndexLookupTime: {}", lookupTime)
+
+                assertTrue(queryCacheHit > 0,
+                    "InvertedIndexQueryCacheHit should be > 0 on DSL cache hit, got ${queryCacheHit}")
+                assertTrue(queryTime > 0,
+                    "InvertedIndexQueryTime should be > 0 even on DSL cache hit, got ${queryTime}")
+            }
+        }
+    } catch (IllegalStateException e) {
+        if (e.message?.contains("HttpCliAction failed")) {
+            log.warn("Profile HTTP request failed, skipping: {}", e.message)
+        } else {
+            throw e
+        }
+    }
+
+    // =========================================================================
+    // Test 5: searcher cache disabled — run same DSL twice with searcher cache
+    // off (but query cache also off so DSL cache cannot mask the problem).
+    // Both runs must show cache miss and zero cache hits, proving the switch
+    // is actually respected and a second run does not silently hit the cache.
+    // =========================================================================
+    sql """ set enable_inverted_index_searcher_cache = false """
+    sql """ set enable_inverted_index_query_cache = false """
+
+    // First run: cache miss (searcher cache disabled, nothing to hit)
+    sql """SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+           id FROM ${tableName} WHERE search('title:grape') ORDER BY id"""
+
+    // Second run: should STILL be a cache miss because searcher cache is disabled
+    def queryId5 = "search_profile_no_cache_${System.currentTimeMillis()}"
+    try {
+        profile("${queryId5}") {
+            run {
+                sql """/* ${queryId5} */ SELECT id FROM ${tableName}
+                       WHERE search('title:grape') ORDER BY id"""
+            }
+            check { profileString, exception ->
+                if (exception != null) throw exception
+                log.info("=== Searcher cache disabled (2nd run) profile ===")
+
+                def cacheHit = extractCounter(profileString, "InvertedIndexSearcherCacheHit")
+                def cacheMiss = extractCounter(profileString, "InvertedIndexSearcherCacheMiss")
+
+                log.info("InvertedIndexSearcherCacheHit: {}", cacheHit)
+                log.info("InvertedIndexSearcherCacheMiss: {}", cacheMiss)
+
+                assertTrue(cacheHit == 0,
+                    "InvertedIndexSearcherCacheHit should be 0 when cache disabled, got ${cacheHit}")
+                assertTrue(cacheMiss > 0,
+                    "InvertedIndexSearcherCacheMiss should be > 0 when cache disabled, got ${cacheMiss}")
+            }
+        }
+    } catch (IllegalStateException e) {
+        if (e.message?.contains("HttpCliAction failed")) {
+            log.warn("Profile HTTP request failed, skipping: {}", e.message)
+        } else {
+            throw e
+        }
+    }
+
+    // =========================================================================
+    // Test 6: SEARCH vs MATCH consistency — same data, same predicate logic,
+    // both should return identical results.
+    // =========================================================================
+    def search_result = sql """
+        SELECT /*+SET_VAR(enable_common_expr_pushdown=true) */
+        id FROM ${tableName} WHERE search('title:apple') ORDER BY id
+    """
+    def match_result = sql """
+        SELECT id FROM ${tableName} WHERE title MATCH_ANY 'apple' ORDER BY id
+    """
+    assertEquals(search_result, match_result,
+        "SEARCH('title:apple') and MATCH_ANY 'apple' should return identical rows")
+}