From 6e35fd42e0c5da026d66477805e8e8f82cc3e361 Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Tue, 16 Jun 2026 11:36:43 +0300 Subject: [PATCH 1/9] Add lock and task wait time logging - Add enqueue_time field to Task class for measuring queue wait times - Log when tasks wait more than 10ms in queue before worker picks them up - Add lock wait time logging to BlockManager methods (>10ms threshold) - Use DUCKDB_LOG_WARNING for proper logging integration Co-Authored-By: Claude Haiku 4.5 --- src/include/duckdb/parallel/task.hpp | 3 ++ src/parallel/task_scheduler.cpp | 15 +++++++++ src/storage/buffer/block_manager.cpp | 46 ++++++++++++++++++++++++++++ 3 files changed, 64 insertions(+) diff --git a/src/include/duckdb/parallel/task.hpp b/src/include/duckdb/parallel/task.hpp index 1beb114375dd..cb7052ea5c20 100644 --- a/src/include/duckdb/parallel/task.hpp +++ b/src/include/duckdb/parallel/task.hpp @@ -10,6 +10,7 @@ #include "duckdb/common/common.hpp" #include "duckdb/common/optional_ptr.hpp" +#include namespace duckdb { class ClientContext; @@ -58,6 +59,8 @@ class Task : public enable_shared_from_this { public: optional_ptr token; + //! Timestamp when the task was enqueued, used for measuring queue wait time + std::chrono::high_resolution_clock::time_point enqueue_time; }; } // namespace duckdb diff --git a/src/parallel/task_scheduler.cpp b/src/parallel/task_scheduler.cpp index a6fb1abbf47d..3ecc38f3bd7c 100644 --- a/src/parallel/task_scheduler.cpp +++ b/src/parallel/task_scheduler.cpp @@ -3,6 +3,7 @@ #include "duckdb/common/chrono.hpp" #include "duckdb/common/exception.hpp" #include "duckdb/common/numeric_utils.hpp" +#include "duckdb/logging/logger.hpp" #include "duckdb/main/client_context.hpp" #include "duckdb/main/database.hpp" #include "duckdb/main/settings.hpp" @@ -72,6 +73,7 @@ struct QueueProducerToken { }; void ConcurrentQueue::Enqueue(ProducerToken &token, shared_ptr task) { + task->enqueue_time = std::chrono::high_resolution_clock::now(); lock_guard producer_lock(token.producer_lock); task->token = token; if (q.enqueue(token.token->queue_token, std::move(task))) { @@ -84,9 +86,11 @@ void ConcurrentQueue::Enqueue(ProducerToken &token, shared_ptr task) { void ConcurrentQueue::EnqueueBulk(ProducerToken &token, vector> &tasks) { typedef std::make_signed::type ssize_t; + auto enqueue_time = std::chrono::high_resolution_clock::now(); lock_guard producer_lock(token.producer_lock); for (auto &task : tasks) { task->token = token; + task->enqueue_time = enqueue_time; } if (q.enqueue_bulk(token.token->queue_token, std::make_move_iterator(tasks.begin()), tasks.size())) { tasks_in_queue += tasks.size(); @@ -300,6 +304,17 @@ void TaskScheduler::ExecuteForever(atomic *marker) { } } if (queue->Dequeue(task)) { + auto dequeue_time = std::chrono::high_resolution_clock::now(); + auto queue_wait_ms = std::chrono::duration_cast( + dequeue_time - task->enqueue_time).count(); + if (queue_wait_ms > 100) { + try { + DUCKDB_LOG_WARNING(db, "Task waited " + to_string(queue_wait_ms) + + "ms in queue before worker picked it up"); + } catch (...) { + // Silently ignore if logging fails + } + } auto process_mode = TaskExecutionMode::PROCESS_ALL; if (Settings::Get(config)) { process_mode = TaskExecutionMode::PROCESS_PARTIAL; diff --git a/src/storage/buffer/block_manager.cpp b/src/storage/buffer/block_manager.cpp index e005a2aa8c62..0be321d74278 100644 --- a/src/storage/buffer/block_manager.cpp +++ b/src/storage/buffer/block_manager.cpp @@ -5,6 +5,8 @@ #include "duckdb/storage/buffer/buffer_pool.hpp" #include "duckdb/storage/buffer_manager.hpp" #include "duckdb/storage/metadata/metadata_manager.hpp" +#include "duckdb/logging/logger.hpp" +#include namespace duckdb { @@ -15,7 +17,18 @@ BlockManager::BlockManager(BufferManager &buffer_manager, const optional_idx blo } bool BlockManager::BlockIsRegistered(block_id_t block_id) { + auto start = std::chrono::steady_clock::now(); lock_guard lock(blocks_lock); + auto end = std::chrono::steady_clock::now(); + auto wait_ms = std::chrono::duration_cast(end - start).count(); + if (wait_ms > 10) { + try { + auto &db = buffer_manager.GetDatabase(); + DUCKDB_LOG_WARNING(db, "Lock wait in BlockIsRegistered took " + to_string(wait_ms) + "ms"); + } catch (...) { + // Silently ignore if database is not available + } + } // check if the block already exists auto entry = blocks.find(block_id); if (entry == blocks.end()) { @@ -26,7 +39,18 @@ bool BlockManager::BlockIsRegistered(block_id_t block_id) { } shared_ptr BlockManager::TryGetBlock(block_id_t block_id) { + auto start = std::chrono::steady_clock::now(); lock_guard lock(blocks_lock); + auto end = std::chrono::steady_clock::now(); + auto wait_ms = std::chrono::duration_cast(end - start).count(); + if (wait_ms > 10) { + try { + auto &db = buffer_manager.GetDatabase(); + DUCKDB_LOG_WARNING(db, "Lock wait in TryGetBlock took " + to_string(wait_ms) + "ms"); + } catch (...) { + // Silently ignore if database is not available + } + } // check if the block already exists auto entry = blocks.find(block_id); if (entry == blocks.end()) { @@ -38,7 +62,18 @@ shared_ptr BlockManager::TryGetBlock(block_id_t block_id) { } shared_ptr BlockManager::RegisterBlock(block_id_t block_id) { + auto start = std::chrono::steady_clock::now(); lock_guard lock(blocks_lock); + auto end = std::chrono::steady_clock::now(); + auto wait_ms = std::chrono::duration_cast(end - start).count(); + if (wait_ms > 10) { + try { + auto &db = buffer_manager.GetDatabase(); + DUCKDB_LOG_WARNING(db, "Lock wait in RegisterBlock took " + to_string(wait_ms) + "ms"); + } catch (...) { + // Silently ignore if database is not available + } + } // check if the block already exists auto entry = blocks.find(block_id); if (entry != blocks.end()) { @@ -122,7 +157,18 @@ shared_ptr BlockManager::ConvertToPersistent(QueryContext context, void BlockManager::UnregisterBlock(block_id_t id) { D_ASSERT(id < MAXIMUM_BLOCK); + auto start = std::chrono::steady_clock::now(); lock_guard lock(blocks_lock); + auto end = std::chrono::steady_clock::now(); + auto wait_ms = std::chrono::duration_cast(end - start).count(); + if (wait_ms > 10) { + try { + auto &db = buffer_manager.GetDatabase(); + DUCKDB_LOG_WARNING(db, "Lock wait in UnregisterBlock took " + to_string(wait_ms) + "ms"); + } catch (...) { + // Silently ignore if database is not available + } + } // on-disk block: erase from list of blocks in manager blocks.erase(id); } From bcef211f8a5e29c26c302f6077f12a42c4c8ee51 Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Tue, 16 Jun 2026 12:47:24 +0300 Subject: [PATCH 2/9] Add lock and task wait time logging with correctness fixes Fixed issues from review: 1. (High) Moved logging OUTSIDE lock scope to avoid observer effect - Lock wait is now measured accurately without amplifying contention - Wrapped locked work in inner block, log AFTER lock_guard releases 2. (High) Use steady_clock instead of high_resolution_clock - steady_clock is guaranteed monotonic (won't jump back) - high_resolution_clock is alias for system_clock (wallclock) - Prevents spurious warnings from NTP/manual clock adjustments - Consistent with existing block_manager.cpp code 3. (Medium) Guard against default-constructed timestamps - Skip logging if enqueue_time == epoch (time_point{}) - Prevents false positives from tasks that bypass enqueue path - Defensive programming against future code changes Changes: - Task class: added enqueue_time field (steady_clock) - Task scheduler: measure queue wait, log if >10ms (with guards) - BlockManager: measure lock wait, log if >10ms (with guards) - All logging happens AFTER releasing the lock Co-Authored-By: Claude Haiku 4.5 --- src/include/duckdb/parallel/task.hpp | 2 +- src/parallel/task_scheduler.cpp | 25 +++-- src/storage/buffer/block_manager.cpp | 151 +++++++++++++++++---------- 3 files changed, 111 insertions(+), 67 deletions(-) diff --git a/src/include/duckdb/parallel/task.hpp b/src/include/duckdb/parallel/task.hpp index cb7052ea5c20..eed5037c4f62 100644 --- a/src/include/duckdb/parallel/task.hpp +++ b/src/include/duckdb/parallel/task.hpp @@ -60,7 +60,7 @@ class Task : public enable_shared_from_this { public: optional_ptr token; //! Timestamp when the task was enqueued, used for measuring queue wait time - std::chrono::high_resolution_clock::time_point enqueue_time; + std::chrono::steady_clock::time_point enqueue_time; }; } // namespace duckdb diff --git a/src/parallel/task_scheduler.cpp b/src/parallel/task_scheduler.cpp index 3ecc38f3bd7c..9f6ff6465963 100644 --- a/src/parallel/task_scheduler.cpp +++ b/src/parallel/task_scheduler.cpp @@ -73,7 +73,7 @@ struct QueueProducerToken { }; void ConcurrentQueue::Enqueue(ProducerToken &token, shared_ptr task) { - task->enqueue_time = std::chrono::high_resolution_clock::now(); + task->enqueue_time = std::chrono::steady_clock::now(); lock_guard producer_lock(token.producer_lock); task->token = token; if (q.enqueue(token.token->queue_token, std::move(task))) { @@ -86,7 +86,7 @@ void ConcurrentQueue::Enqueue(ProducerToken &token, shared_ptr task) { void ConcurrentQueue::EnqueueBulk(ProducerToken &token, vector> &tasks) { typedef std::make_signed::type ssize_t; - auto enqueue_time = std::chrono::high_resolution_clock::now(); + auto enqueue_time = std::chrono::steady_clock::now(); lock_guard producer_lock(token.producer_lock); for (auto &task : tasks) { task->token = token; @@ -304,15 +304,18 @@ void TaskScheduler::ExecuteForever(atomic *marker) { } } if (queue->Dequeue(task)) { - auto dequeue_time = std::chrono::high_resolution_clock::now(); - auto queue_wait_ms = std::chrono::duration_cast( - dequeue_time - task->enqueue_time).count(); - if (queue_wait_ms > 100) { - try { - DUCKDB_LOG_WARNING(db, "Task waited " + to_string(queue_wait_ms) + - "ms in queue before worker picked it up"); - } catch (...) { - // Silently ignore if logging fails + // Only log if enqueue_time was properly initialized (not epoch) + if (task->enqueue_time != std::chrono::steady_clock::time_point{}) { + auto dequeue_time = std::chrono::steady_clock::now(); + auto queue_wait_ms = std::chrono::duration_cast( + dequeue_time - task->enqueue_time).count(); + if (queue_wait_ms > 100) { + try { + DUCKDB_LOG_WARNING(db, "Task waited " + to_string(queue_wait_ms) + + "ms in queue before worker picked it up"); + } catch (...) { + // Silently ignore if logging fails + } } } auto process_mode = TaskExecutionMode::PROCESS_ALL; diff --git a/src/storage/buffer/block_manager.cpp b/src/storage/buffer/block_manager.cpp index 0be321d74278..8708100952b1 100644 --- a/src/storage/buffer/block_manager.cpp +++ b/src/storage/buffer/block_manager.cpp @@ -17,77 +17,110 @@ BlockManager::BlockManager(BufferManager &buffer_manager, const optional_idx blo } bool BlockManager::BlockIsRegistered(block_id_t block_id) { - auto start = std::chrono::steady_clock::now(); - lock_guard lock(blocks_lock); - auto end = std::chrono::steady_clock::now(); - auto wait_ms = std::chrono::duration_cast(end - start).count(); - if (wait_ms > 10) { + int64_t wait_ms = 0; + int64_t hold_ms = 0; + bool result = false; + { + auto start = std::chrono::steady_clock::now(); + lock_guard lock(blocks_lock); + auto acquired = std::chrono::steady_clock::now(); + wait_ms = std::chrono::duration_cast(acquired - start).count(); + // check if the block already exists + auto entry = blocks.find(block_id); + if (entry == blocks.end()) { + result = false; + } else { + // already exists: check if it hasn't expired yet + result = !entry->second.expired(); + } + auto released = std::chrono::steady_clock::now(); + hold_ms = std::chrono::duration_cast(released - acquired).count(); + } + // Log AFTER releasing the lock + if (wait_ms > 100 || hold_ms > 10) { try { auto &db = buffer_manager.GetDatabase(); - DUCKDB_LOG_WARNING(db, "Lock wait in BlockIsRegistered took " + to_string(wait_ms) + "ms"); + DUCKDB_LOG_WARNING(db, "blocks_lock in BlockIsRegistered: wait=" + to_string(wait_ms) + + "ms hold=" + to_string(hold_ms) + "ms"); } catch (...) { // Silently ignore if database is not available } } - // check if the block already exists - auto entry = blocks.find(block_id); - if (entry == blocks.end()) { - return false; - } - // already exists: check if it hasn't expired yet - return !entry->second.expired(); + return result; } shared_ptr BlockManager::TryGetBlock(block_id_t block_id) { - auto start = std::chrono::steady_clock::now(); - lock_guard lock(blocks_lock); - auto end = std::chrono::steady_clock::now(); - auto wait_ms = std::chrono::duration_cast(end - start).count(); - if (wait_ms > 10) { + int64_t wait_ms = 0; + int64_t hold_ms = 0; + shared_ptr result = nullptr; + { + auto start = std::chrono::steady_clock::now(); + lock_guard lock(blocks_lock); + auto acquired = std::chrono::steady_clock::now(); + wait_ms = std::chrono::duration_cast(acquired - start).count(); + // check if the block already exists + auto entry = blocks.find(block_id); + if (entry == blocks.end()) { + // the block does not exist + result = nullptr; + } else { + // the block exists - try to lock it + result = entry->second.lock(); + } + auto released = std::chrono::steady_clock::now(); + hold_ms = std::chrono::duration_cast(released - acquired).count(); + } + // Log AFTER releasing the lock + if (wait_ms > 100 || hold_ms > 10) { try { auto &db = buffer_manager.GetDatabase(); - DUCKDB_LOG_WARNING(db, "Lock wait in TryGetBlock took " + to_string(wait_ms) + "ms"); + DUCKDB_LOG_WARNING(db, "blocks_lock in TryGetBlock: wait=" + to_string(wait_ms) + + "ms hold=" + to_string(hold_ms) + "ms"); } catch (...) { // Silently ignore if database is not available } } - // check if the block already exists - auto entry = blocks.find(block_id); - if (entry == blocks.end()) { - // the block does not exist - return nullptr; - } - // the block exists - try to lock it - return entry->second.lock(); + return result; } shared_ptr BlockManager::RegisterBlock(block_id_t block_id) { - auto start = std::chrono::steady_clock::now(); - lock_guard lock(blocks_lock); - auto end = std::chrono::steady_clock::now(); - auto wait_ms = std::chrono::duration_cast(end - start).count(); - if (wait_ms > 10) { + int64_t wait_ms = 0; + int64_t hold_ms = 0; + shared_ptr result = nullptr; + { + auto start = std::chrono::steady_clock::now(); + lock_guard lock(blocks_lock); + auto acquired = std::chrono::steady_clock::now(); + wait_ms = std::chrono::duration_cast(acquired - start).count(); + // check if the block already exists + auto entry = blocks.find(block_id); + if (entry != blocks.end()) { + // already exists: check if it hasn't expired yet + auto existing_ptr = entry->second.lock(); + if (existing_ptr) { + //! it hasn't! return it + result = existing_ptr; + } + } + if (!result) { + // create a new block pointer for this block + result = make_shared_ptr(*this, block_id, MemoryTag::BASE_TABLE); + // register the block pointer in the set of blocks as a weak pointer + blocks[block_id] = weak_ptr(result); + } + auto released = std::chrono::steady_clock::now(); + hold_ms = std::chrono::duration_cast(released - acquired).count(); + } + // Log AFTER releasing the lock + if (wait_ms > 100 || hold_ms > 10) { try { auto &db = buffer_manager.GetDatabase(); - DUCKDB_LOG_WARNING(db, "Lock wait in RegisterBlock took " + to_string(wait_ms) + "ms"); + DUCKDB_LOG_WARNING(db, "blocks_lock in RegisterBlock: wait=" + to_string(wait_ms) + + "ms hold=" + to_string(hold_ms) + "ms"); } catch (...) { // Silently ignore if database is not available } } - // check if the block already exists - auto entry = blocks.find(block_id); - if (entry != blocks.end()) { - // already exists: check if it hasn't expired yet - auto existing_ptr = entry->second.lock(); - if (existing_ptr) { - //! it hasn't! return it - return existing_ptr; - } - } - // create a new block pointer for this block - auto result = make_shared_ptr(*this, block_id, MemoryTag::BASE_TABLE); - // register the block pointer in the set of blocks as a weak pointer - blocks[block_id] = weak_ptr(result); return result; } @@ -157,20 +190,28 @@ shared_ptr BlockManager::ConvertToPersistent(QueryContext context, void BlockManager::UnregisterBlock(block_id_t id) { D_ASSERT(id < MAXIMUM_BLOCK); - auto start = std::chrono::steady_clock::now(); - lock_guard lock(blocks_lock); - auto end = std::chrono::steady_clock::now(); - auto wait_ms = std::chrono::duration_cast(end - start).count(); - if (wait_ms > 10) { + int64_t wait_ms = 0; + int64_t hold_ms = 0; + { + auto start = std::chrono::steady_clock::now(); + lock_guard lock(blocks_lock); + auto acquired = std::chrono::steady_clock::now(); + wait_ms = std::chrono::duration_cast(acquired - start).count(); + // on-disk block: erase from list of blocks in manager + blocks.erase(id); + auto released = std::chrono::steady_clock::now(); + hold_ms = std::chrono::duration_cast(released - acquired).count(); + } + // Log AFTER releasing the lock + if (wait_ms > 100 || hold_ms > 10) { try { auto &db = buffer_manager.GetDatabase(); - DUCKDB_LOG_WARNING(db, "Lock wait in UnregisterBlock took " + to_string(wait_ms) + "ms"); + DUCKDB_LOG_WARNING(db, "blocks_lock in UnregisterBlock: wait=" + to_string(wait_ms) + + "ms hold=" + to_string(hold_ms) + "ms"); } catch (...) { // Silently ignore if database is not available } } - // on-disk block: erase from list of blocks in manager - blocks.erase(id); } void BlockManager::UnregisterPersistentBlock(BlockHandle &block) { From 23d3a4c5f4aac04ac1f0b2bae63926c4d545662d Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Tue, 16 Jun 2026 12:51:08 +0300 Subject: [PATCH 3/9] Format: fix clang-format style in task_scheduler.cpp - Space after time_point type - Proper line continuation alignment for long expressions - Indent alignment in DUCKDB_LOG_WARNING call Co-Authored-By: Claude Haiku 4.5 --- src/parallel/task_scheduler.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/parallel/task_scheduler.cpp b/src/parallel/task_scheduler.cpp index 9f6ff6465963..58cd9e940df8 100644 --- a/src/parallel/task_scheduler.cpp +++ b/src/parallel/task_scheduler.cpp @@ -305,14 +305,14 @@ void TaskScheduler::ExecuteForever(atomic *marker) { } if (queue->Dequeue(task)) { // Only log if enqueue_time was properly initialized (not epoch) - if (task->enqueue_time != std::chrono::steady_clock::time_point{}) { + if (task->enqueue_time != std::chrono::steady_clock::time_point {}) { auto dequeue_time = std::chrono::steady_clock::now(); - auto queue_wait_ms = std::chrono::duration_cast( - dequeue_time - task->enqueue_time).count(); + auto queue_wait_ms = + std::chrono::duration_cast(dequeue_time - task->enqueue_time).count(); if (queue_wait_ms > 100) { try { DUCKDB_LOG_WARNING(db, "Task waited " + to_string(queue_wait_ms) + - "ms in queue before worker picked it up"); + "ms in queue before worker picked it up"); } catch (...) { // Silently ignore if logging fails } From adae2081feb44a988085ecc7b515fb6ff950b6bd Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Thu, 18 Jun 2026 08:25:12 +0300 Subject: [PATCH 4/9] Add busy-worker, task-type and execution-time observability to scheduler Enrich the queue-wait warning with the busy worker count, total worker count and queue depth so production spikes can be classified as saturation vs. a genuine scheduler stall. Also tag the warning with the task type (via Task::TaskType()). Add a second warning that measures how long a task held a worker inside Execute(), tagged with task type and execution mode (all/partial). A long non-preemptive task here is the cause of the queue waits reported by the first log, making the head-of-line relationship visible from logs alone. Co-Authored-By: Claude Opus 4.8 (1M context) --- .../duckdb/parallel/task_scheduler.hpp | 15 ++++++ src/parallel/task_scheduler.cpp | 52 +++++++++++++++++-- 2 files changed, 63 insertions(+), 4 deletions(-) diff --git a/src/include/duckdb/parallel/task_scheduler.hpp b/src/include/duckdb/parallel/task_scheduler.hpp index f734ab21444d..8f506da17f83 100644 --- a/src/include/duckdb/parallel/task_scheduler.hpp +++ b/src/include/duckdb/parallel/task_scheduler.hpp @@ -110,6 +110,21 @@ class TaskScheduler { atomic requested_thread_count; //! The amount of threads currently running atomic current_thread_count; + //! The number of background workers currently executing a task (busy). Used for observability only. + atomic busy_workers; + +public: + //! Returns the number of background workers currently executing a task. Observability only. + int32_t GetBusyWorkerCount() const { + return busy_workers.load(); + } + //! RAII helper to mark a worker busy/idle around task execution. + void IncrementBusyWorkers() { + ++busy_workers; + } + void DecrementBusyWorkers() { + --busy_workers; + } }; } // namespace duckdb diff --git a/src/parallel/task_scheduler.cpp b/src/parallel/task_scheduler.cpp index 58cd9e940df8..947ad01be124 100644 --- a/src/parallel/task_scheduler.cpp +++ b/src/parallel/task_scheduler.cpp @@ -232,7 +232,7 @@ TaskScheduler::TaskScheduler(DatabaseInstance &db) : db(db), queue(make_uniq()), allocator_flush_threshold(db.config.options.allocator_flush_threshold), allocator_background_threads(Settings::Get(db)), requested_thread_count(0), - current_thread_count(1) { + current_thread_count(1), busy_workers(0) { SetAllocatorBackgroundThreads(allocator_background_threads); } @@ -304,6 +304,9 @@ void TaskScheduler::ExecuteForever(atomic *marker) { } } if (queue->Dequeue(task)) { + // This worker just transitioned idle->busy by picking up a task. Count it as busy before logging + // so the snapshot below can reach the busy==total saturation signature. + ++busy_workers; // Only log if enqueue_time was properly initialized (not epoch) if (task->enqueue_time != std::chrono::steady_clock::time_point {}) { auto dequeue_time = std::chrono::steady_clock::now(); @@ -311,8 +314,18 @@ void TaskScheduler::ExecuteForever(atomic *marker) { std::chrono::duration_cast(dequeue_time - task->enqueue_time).count(); if (queue_wait_ms > 100) { try { - DUCKDB_LOG_WARNING(db, "Task waited " + to_string(queue_wait_ms) + - "ms in queue before worker picked it up"); + // LOG 1: queue waiting time + task type. + // busy_workers/current_thread_count = workers currently inside Execute() vs total workers. + // tasks_in_queue = remaining queue depth at the moment this task was picked up. + // Read the table in the design notes: busy==total + depth>0 -> saturation/head-of-line + // blocking; busy0 -> scheduler bug (free worker, task not picked up); + // low busy + small depth + long wait -> OS/cgroup CPU throttling. + DUCKDB_LOG_WARNING(db, + "Task waited " + to_string(queue_wait_ms) + + "ms in queue before worker picked it up (task_type=" + task->TaskType() + + ", busy_workers=" + to_string(busy_workers.load()) + "/" + + to_string(current_thread_count.load()) + + ", queue_depth=" + to_string(queue->GetTasksInQueue()) + ")"); } catch (...) { // Silently ignore if logging fails } @@ -322,7 +335,38 @@ void TaskScheduler::ExecuteForever(atomic *marker) { if (Settings::Get(config)) { process_mode = TaskExecutionMode::PROCESS_PARTIAL; } - auto execute_result = task->Execute(process_mode); + // Capture the task type before Execute(): a TASK_FINISHED task may be reset right after, and in + // PROCESS_ALL mode this measures the whole task, while in PROCESS_PARTIAL mode it measures one slice. + auto task_type = task->TaskType(); + auto execute_begin = std::chrono::steady_clock::now(); + TaskExecutionResult execute_result; + try { + execute_result = task->Execute(process_mode); + } catch (...) { + --busy_workers; + throw; + } + --busy_workers; + { + auto execute_ms = std::chrono::duration_cast( + std::chrono::steady_clock::now() - execute_begin) + .count(); + if (execute_ms > 100) { + try { + // LOG 2: execution time + task type. A long-running, non-preemptive task here is what + // holds a worker and causes the queue waits reported by LOG 1. + DUCKDB_LOG_WARNING( + db, "Task ran for " + to_string(execute_ms) + + "ms before releasing the worker (task_type=" + task_type + ", mode=" + + (process_mode == TaskExecutionMode::PROCESS_PARTIAL ? "partial" : "all") + + ", busy_workers=" + to_string(busy_workers.load()) + "/" + + to_string(current_thread_count.load()) + + ", queue_depth=" + to_string(queue->GetTasksInQueue()) + ")"); + } catch (...) { + // Silently ignore if logging fails + } + } + } switch (execute_result) { case TaskExecutionResult::TASK_FINISHED: From f991e7fa004edb362c9109dd5c74f8a56b1283b4 Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Sun, 21 Jun 2026 13:13:10 +0300 Subject: [PATCH 5/9] Enrich task_type in scheduler logs with source/sink operator names PipelineTask now includes [src=...][sink=...] and PipelineFinishTask includes [sink=...] in their TaskType() strings, making slow-task log lines actionable without a separate profiling run. Co-Authored-By: Claude Sonnet 4.6 --- src/include/duckdb/parallel/pipeline.hpp | 4 +--- src/parallel/pipeline.cpp | 11 +++++++++++ src/parallel/pipeline_finish_event.cpp | 4 ++++ src/parallel/task_scheduler.cpp | 2 +- 4 files changed, 17 insertions(+), 4 deletions(-) diff --git a/src/include/duckdb/parallel/pipeline.hpp b/src/include/duckdb/parallel/pipeline.hpp index 0d8a665a5d65..e894cfb7a71a 100644 --- a/src/include/duckdb/parallel/pipeline.hpp +++ b/src/include/duckdb/parallel/pipeline.hpp @@ -33,9 +33,7 @@ class PipelineTask : public ExecutorTask { Pipeline &pipeline; unique_ptr pipeline_executor; - string TaskType() const override { - return "PipelineTask"; - } + string TaskType() const override; public: const PipelineExecutor &GetPipelineExecutor() const; diff --git a/src/parallel/pipeline.cpp b/src/parallel/pipeline.cpp index d48cc1241cb7..5488614a957f 100644 --- a/src/parallel/pipeline.cpp +++ b/src/parallel/pipeline.cpp @@ -20,6 +20,17 @@ PipelineTask::PipelineTask(Pipeline &pipeline_p, shared_ptr event_p) : ExecutorTask(pipeline_p.executor, std::move(event_p)), pipeline(pipeline_p) { } +string PipelineTask::TaskType() const { + string result = "PipelineTask"; + if (pipeline.GetSource()) { + result += "[src=" + pipeline.GetSource()->GetName() + "]"; + } + if (pipeline.GetSink()) { + result += "[sink=" + pipeline.GetSink()->GetName() + "]"; + } + return result; +} + bool PipelineTask::TaskBlockedOnResult() const { // If this returns true, it means the pipeline this task belongs to has a cached chunk // that was the result of the Sink method returning BLOCKED diff --git a/src/parallel/pipeline_finish_event.cpp b/src/parallel/pipeline_finish_event.cpp index bf57cda256c4..f106a854e54e 100644 --- a/src/parallel/pipeline_finish_event.cpp +++ b/src/parallel/pipeline_finish_event.cpp @@ -61,6 +61,10 @@ class PipelineFinishTask : public ExecutorTask { } string TaskType() const override { + auto sink = pipeline.GetSink(); + if (sink) { + return "PipelineFinishTask[sink=" + sink->GetName() + "]"; + } return "PipelineFinishTask"; } diff --git a/src/parallel/task_scheduler.cpp b/src/parallel/task_scheduler.cpp index 947ad01be124..d5cf27f02678 100644 --- a/src/parallel/task_scheduler.cpp +++ b/src/parallel/task_scheduler.cpp @@ -351,7 +351,7 @@ void TaskScheduler::ExecuteForever(atomic *marker) { auto execute_ms = std::chrono::duration_cast( std::chrono::steady_clock::now() - execute_begin) .count(); - if (execute_ms > 100) { + if (execute_ms > 500) { try { // LOG 2: execution time + task type. A long-running, non-preemptive task here is what // holds a worker and causes the queue waits reported by LOG 1. From 137b933e7b671e1b38f53e532effa9e2f358805c Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Mon, 22 Jun 2026 11:48:53 +0300 Subject: [PATCH 6/9] Add constant-pattern fast path for ILIKE (incl. ESCAPE) For ILIKE / NOT ILIKE (and the ... ESCAPE variants), when the pattern is constant at runtime, lowercase the pattern once instead of per row and reuse a single scratch buffer to lowercase each string value (avoids two heap allocations + a redundant pattern case-fold per row). When the escape character does not occur in the pattern, build a case-folded LikeMatcher and use the SIMD FindStrInStr contains path; otherwise fall back to the generic escape-aware matcher on the lowercased values. Non-constant patterns keep the existing per-row path. This roughly halves time on the realistic multi-token search shape (ILIKE '%term%' ESCAPE '\\' OR-ed across many columns) on unicode-possible data. Add tests for the constant-pattern ILIKE and ILIKE ... ESCAPE fast paths, and an ilike_regular micro-benchmark mirroring like_regular. Co-Authored-By: Claude Opus 4.8 --- .../micro/string/ilike_regular.benchmark | 19 ++ src/function/scalar/string/like.cpp | 110 +++++++++- .../string/test_ilike_constant_pattern.test | 171 +++++++++++++++ .../test_ilike_escape_constant_pattern.test | 200 ++++++++++++++++++ 4 files changed, 495 insertions(+), 5 deletions(-) create mode 100644 benchmark/micro/string/ilike_regular.benchmark create mode 100644 test/sql/function/string/test_ilike_constant_pattern.test create mode 100644 test/sql/function/string/test_ilike_escape_constant_pattern.test diff --git a/benchmark/micro/string/ilike_regular.benchmark b/benchmark/micro/string/ilike_regular.benchmark new file mode 100644 index 000000000000..4bd471cae8be --- /dev/null +++ b/benchmark/micro/string/ilike_regular.benchmark @@ -0,0 +1,19 @@ +# name: benchmark/micro/string/ilike_regular.benchmark +# description: Case-insensitive contains word 'regular' in the l_comment (11.5%~) +# group: [string] + +name ILike ('%REGULAR%') +group string + +require tpch + +cache tpch_sf1.duckdb + +load +CALL dbgen(sf=1); + +run +SELECT COUNT(*) FROM lineitem WHERE l_comment ILIKE '%REGULAR%' + +result I +687323 diff --git a/src/function/scalar/string/like.cpp b/src/function/scalar/string/like.cpp index 22e8b691af75..dcf12c777428 100644 --- a/src/function/scalar/string/like.cpp +++ b/src/function/scalar/string/like.cpp @@ -491,6 +491,64 @@ void LikeEscapeFunction(DataChunk &args, ExpressionState &state, Vector &result) str, pattern, escape, result, args.size(), FUNC::template Operation); } +// Execution function for ILIKE / NOT ILIKE ... ESCAPE. Mirrors ILikeFunction: when the pattern and escape are +// both constant, lowercase the pattern once and reuse a scratch buffer for the per-row string lowercasing. If the +// escape character does not occur in the pattern, escape handling is a no-op, so we build the case-folded +// LikeMatcher and use the fast SIMD contains path; otherwise we fall back to the generic escape-aware matcher on +// the lowercased values. Non-constant pattern/escape falls back to the per-row ternary path. +template +void ILikeEscapeFunction(DataChunk &args, ExpressionState &state, Vector &result) { + auto &str_vec = args.data[0]; + auto &pattern_vec = args.data[1]; + auto &escape_vec = args.data[2]; + + if (pattern_vec.GetVectorType() == VectorType::CONSTANT_VECTOR && !ConstantVector::IsNull(pattern_vec) && + escape_vec.GetVectorType() == VectorType::CONSTANT_VECTOR && !ConstantVector::IsNull(escape_vec)) { + auto pattern = *ConstantVector::GetData(pattern_vec); + auto escape = *ConstantVector::GetData(escape_vec); + char escape_char = GetEscapeChar(escape); + + // lowercase the pattern exactly once, up front + idx_t pat_llength = LowerLength(pattern.GetData(), pattern.GetSize()); + auto pat_ldata = make_unsafe_uniq_array_uninitialized(pat_llength); + LowerCase(pattern.GetData(), pattern.GetSize(), pat_ldata.get()); + string_t pat_lcase(pat_ldata.get(), UnsafeNumericCast(pat_llength)); + + // the matcher cannot honor escape semantics, so only use it when the escape char never appears in the + // (lowercased) pattern, in which case escape is irrelevant and the pattern is a plain LIKE pattern + unique_ptr matcher; + bool escape_active = + escape_char != '\0' && memchr(pat_lcase.GetData(), escape_char, pat_lcase.GetSize()) != nullptr; + if (!escape_active) { + matcher = LikeMatcher::CreateLikeMatcher(string(pat_lcase.GetData(), pat_lcase.GetSize())); + } + + // reusable scratch buffer for lowercasing each string value (grown on demand) + idx_t scratch_size = 0; + unsafe_unique_array scratch; + UnaryExecutor::Execute(str_vec, result, args.size(), [&](string_t str) { + idx_t str_llength = LowerLength(str.GetData(), str.GetSize()); + if (str_llength > scratch_size) { + scratch = make_unsafe_uniq_array_uninitialized(str_llength); + scratch_size = str_llength; + } + LowerCase(str.GetData(), str.GetSize(), scratch.get()); + string_t str_lcase(scratch.get(), UnsafeNumericCast(str_llength)); + bool match = matcher ? matcher->Match(str_lcase) : LikeOperatorFunction(str_lcase, pat_lcase, escape_char); + return INVERT ? !match : match; + }); + return; + } + // non-constant pattern/escape: fall back to the generic per-row implementation + if (INVERT) { + TernaryExecutor::Execute( + str_vec, pattern_vec, escape_vec, result, NotILikeEscapeOperator::Operation); + } else { + TernaryExecutor::Execute( + str_vec, pattern_vec, escape_vec, result, ILikeEscapeOperator::Operation); + } +} + template unique_ptr ILikePropagateStats(ClientContext &context, FunctionStatisticsInput &input) { auto &child_stats = input.child_stats; @@ -503,6 +561,48 @@ unique_ptr ILikePropagateStats(ClientContext &context, FunctionS return nullptr; } +// Execution function for ILIKE / NOT ILIKE on the (possibly) Unicode path. +// When the pattern is constant we lowercase it exactly once instead of once per row, and we reuse a single +// scratch buffer to lowercase each string value instead of heap-allocating per row. This avoids two heap +// allocations + a redundant pattern case-fold on every row that the generic ILikeOperatorFunction incurs. +// (The ASCII-only fast path installed by ILikePropagateStats already avoids allocations, so it is unaffected.) +template +void ILikeFunction(DataChunk &input, ExpressionState &state, Vector &result) { + auto &pattern_vec = input.data[1]; + if (pattern_vec.GetVectorType() == VectorType::CONSTANT_VECTOR && !ConstantVector::IsNull(pattern_vec)) { + // constant pattern: lowercase it exactly once, up front + auto pattern = *ConstantVector::GetData(pattern_vec); + idx_t pat_llength = LowerLength(pattern.GetData(), pattern.GetSize()); + auto pat_ldata = make_unsafe_uniq_array_uninitialized(pat_llength); + LowerCase(pattern.GetData(), pattern.GetSize(), pat_ldata.get()); + string_t pat_lcase(pat_ldata.get(), UnsafeNumericCast(pat_llength)); + + // Build a case-insensitive matcher from the lowercased pattern. Because both the pattern and each string + // value are lowercased, a case-sensitive LikeMatcher over lowercased data is equivalent to ILIKE, and it + // uses the fast SIMD FindStrInStr/memcmp contains path. Returns null for patterns with '_' or only '%'; + // in that case we fall back to the generic recursive matcher on the lowercased values. + auto matcher = LikeMatcher::CreateLikeMatcher(string(pat_lcase.GetData(), pat_lcase.GetSize())); + + // reusable scratch buffer for lowercasing each string value (grown on demand) + idx_t scratch_size = 0; + unsafe_unique_array scratch; + UnaryExecutor::Execute(input.data[0], result, input.size(), [&](string_t str) { + idx_t str_llength = LowerLength(str.GetData(), str.GetSize()); + if (str_llength > scratch_size) { + scratch = make_unsafe_uniq_array_uninitialized(str_llength); + scratch_size = str_llength; + } + LowerCase(str.GetData(), str.GetSize(), scratch.get()); + string_t str_lcase(scratch.get(), UnsafeNumericCast(str_llength)); + bool match = matcher ? matcher->Match(str_lcase) : LikeOperatorFunction(str_lcase, pat_lcase); + return INVERT ? !match : match; + }); + return; + } + // non-constant pattern: fall back to the generic per-row implementation + BinaryExecutor::ExecuteStandard(input.data[0], input.data[1], result, input.size()); +} + template void RegularLikeFunction(DataChunk &input, ExpressionState &state, Vector &result) { auto &func_expr = state.expr.Cast(); @@ -537,7 +637,7 @@ ScalarFunction GlobPatternFun::GetFunction() { ScalarFunction ILikeFun::GetFunction() { ScalarFunction ilike("~~*", {LogicalType::VARCHAR, LogicalType::VARCHAR}, LogicalType::BOOLEAN, - ScalarFunction::BinaryFunction, nullptr, nullptr, + ILikeFunction, nullptr, nullptr, ILikePropagateStats); ilike.SetCollationHandling(FunctionCollationHandling::PUSH_COMBINABLE_COLLATIONS); return ilike; @@ -545,8 +645,8 @@ ScalarFunction ILikeFun::GetFunction() { ScalarFunction NotILikeFun::GetFunction() { ScalarFunction not_ilike("!~~*", {LogicalType::VARCHAR, LogicalType::VARCHAR}, LogicalType::BOOLEAN, - ScalarFunction::BinaryFunction, nullptr, - nullptr, ILikePropagateStats); + ILikeFunction, nullptr, nullptr, + ILikePropagateStats); not_ilike.SetCollationHandling(FunctionCollationHandling::PUSH_COMBINABLE_COLLATIONS); return not_ilike; } @@ -568,7 +668,7 @@ ScalarFunction NotLikeEscapeFun::GetFunction() { ScalarFunction IlikeEscapeFun::GetFunction() { ScalarFunction ilike_escape("ilike_escape", {LogicalType::VARCHAR, LogicalType::VARCHAR, LogicalType::VARCHAR}, - LogicalType::BOOLEAN, LikeEscapeFunction); + LogicalType::BOOLEAN, ILikeEscapeFunction); ilike_escape.SetCollationHandling(FunctionCollationHandling::PUSH_COMBINABLE_COLLATIONS); return ilike_escape; } @@ -576,7 +676,7 @@ ScalarFunction IlikeEscapeFun::GetFunction() { ScalarFunction NotIlikeEscapeFun::GetFunction() { ScalarFunction not_ilike_escape("not_ilike_escape", {LogicalType::VARCHAR, LogicalType::VARCHAR, LogicalType::VARCHAR}, - LogicalType::BOOLEAN, LikeEscapeFunction); + LogicalType::BOOLEAN, ILikeEscapeFunction); not_ilike_escape.SetCollationHandling(FunctionCollationHandling::PUSH_COMBINABLE_COLLATIONS); return not_ilike_escape; } diff --git a/test/sql/function/string/test_ilike_constant_pattern.test b/test/sql/function/string/test_ilike_constant_pattern.test new file mode 100644 index 000000000000..876a3191b1e5 --- /dev/null +++ b/test/sql/function/string/test_ilike_constant_pattern.test @@ -0,0 +1,171 @@ +# name: test/sql/function/string/test_ilike_constant_pattern.test +# description: ILIKE / NOT ILIKE with a constant (CONSTANT_VECTOR) pattern over many rows - exercises the case-folded matcher fast path +# group: [string] + +statement ok +PRAGMA enable_verification + +# Unicode-possible data so the constant-pattern ILIKE takes the case-folding path +# (the ASCII-only fast path is taken when stats prove the column cannot contain unicode). +statement ok +CREATE TABLE t(id INTEGER, s VARCHAR); + +statement ok +INSERT INTO t VALUES + (1, 'café Hello World'), + (2, 'DuckDB is FAST'), + (3, 'the quick brown fox'), + (4, 'STRAßE'), + (5, 'Æther WAVE'), + (6, 'café déjà vu'), + (7, NULL), + (8, ''), + (9, 'ALPHA bravo CHARLIE'); + +# --- single-segment contains (%term%), constant pattern, case-insensitive --- +query I +SELECT id FROM t WHERE s ILIKE '%hello%' ORDER BY id +---- +1 + +query I +SELECT id FROM t WHERE s ILIKE '%WORLD%' ORDER BY id +---- +1 + +query I +SELECT id FROM t WHERE s ILIKE '%brown fox%' ORDER BY id +---- +3 + +# no-match (dominant case): first byte rejection +query I +SELECT id FROM t WHERE s ILIKE '%zznotfound%' ORDER BY id +---- + +# --- prefix (term%) and suffix (%term), constant pattern --- +query I +SELECT id FROM t WHERE s ILIKE 'duckdb%' ORDER BY id +---- +2 + +query I +SELECT id FROM t WHERE s ILIKE '%fast' ORDER BY id +---- +2 + +# --- exact match (no wildcards), constant pattern --- +query I +SELECT id FROM t WHERE s ILIKE 'the quick brown fox' ORDER BY id +---- +3 + +# --- unicode case folding on the constant-pattern path --- +query I +SELECT id FROM t WHERE s ILIKE '%æther%' ORDER BY id +---- +5 + +query I +SELECT id FROM t WHERE s ILIKE '%DÉJÀ%' ORDER BY id +---- +6 + +# ß must NOT fold to ss (simple case folding) +query I +SELECT id FROM t WHERE s ILIKE '%strasse%' ORDER BY id +---- + +query I +SELECT id FROM t WHERE s ILIKE '%straße%' ORDER BY id +---- +4 + +# --- underscore pattern: falls back to the generic matcher (not eligible for fast matcher) --- +query I +SELECT id FROM t WHERE s ILIKE '%c_fé%' ORDER BY id +---- +1 +6 + +# --- multi-segment pattern via constant pattern --- +query I +SELECT id FROM t WHERE s ILIKE '%alpha%charlie%' ORDER BY id +---- +9 + +# --- NOT ILIKE with constant pattern (rows with no 'a'/'A'; empty string matches NOT, NULL excluded) --- +query I +SELECT id FROM t WHERE s NOT ILIKE '%a%' ORDER BY id +---- +3 +8 + +# --- only-percent and empty patterns --- +query I +SELECT id FROM t WHERE s ILIKE '%' ORDER BY id +---- +1 +2 +3 +4 +5 +6 +8 +9 + +query I +SELECT id FROM t WHERE s ILIKE '' ORDER BY id +---- +8 + +# --- NULL pattern yields no matches (x ILIKE NULL = NULL) --- +query I +SELECT id FROM t WHERE s ILIKE NULL ORDER BY id +---- + +# --- parameterized (runtime-constant) pattern via prepared statement --- +statement ok +PREPARE p AS SELECT id FROM t WHERE s ILIKE '%' || ? || '%' ORDER BY id + +query I +EXECUTE p('hello') +---- +1 + +query I +EXECUTE p('CAFÉ') +---- +1 +6 + +query I +EXECUTE p('zznotfound') +---- + +# --- non-constant pattern (pattern is a column -> not CONSTANT_VECTOR -> generic path) --- +statement ok +CREATE TABLE pats(id INTEGER, s VARCHAR, pat VARCHAR); + +statement ok +INSERT INTO pats VALUES + (1, 'café Hello', '%HELLO%'), + (2, 'DuckDB', '%duck%'), + (3, 'fox', '%cat%'); + +query I +SELECT id FROM pats WHERE s ILIKE pat ORDER BY id +---- +1 +2 + +# scalar constant-pattern sanity (single row, CONSTANT input vector) +query T +SELECT 'MÜHLEISEN' ILIKE '%hleis%' +---- +1 + +query T +SELECT 'Hello' NOT ILIKE '%XYZ%' +---- +1 diff --git a/test/sql/function/string/test_ilike_escape_constant_pattern.test b/test/sql/function/string/test_ilike_escape_constant_pattern.test new file mode 100644 index 000000000000..fbb98b59c708 --- /dev/null +++ b/test/sql/function/string/test_ilike_escape_constant_pattern.test @@ -0,0 +1,200 @@ +# name: test/sql/function/string/test_ilike_escape_constant_pattern.test +# description: ILIKE / NOT ILIKE ... ESCAPE with a constant pattern over many rows - exercises the case-folded matcher fast path (escape no-op) and the escape-aware fallback +# group: [string] + +statement ok +PRAGMA enable_verification + +# Unicode-possible data so the constant-pattern ILIKE ... ESCAPE takes the case-folding path. +statement ok +CREATE TABLE t(id INTEGER, s VARCHAR); + +statement ok +INSERT INTO t VALUES + (1, 'café Hello World'), + (2, 'DuckDB is FAST'), + (3, 'the quick brown fox'), + (4, 'STRAßE'), + (5, 'Æther WAVE'), + (6, 'café déjà vu'), + (7, NULL), + (8, ''), + (9, '100% done'), + (10, 'under_score here'); + +# === escape char ('\') NOT present in pattern => escape is a no-op => SIMD matcher path === + +# single-segment contains, case-insensitive +query I +SELECT id FROM t WHERE s ILIKE '%hello%' ESCAPE '\' ORDER BY id +---- +1 + +query I +SELECT id FROM t WHERE s ILIKE '%BROWN FOX%' ESCAPE '\' ORDER BY id +---- +3 + +# no-match (dominant case) +query I +SELECT id FROM t WHERE s ILIKE '%zznotfound%' ESCAPE '\' ORDER BY id +---- + +# prefix / suffix / exact +query I +SELECT id FROM t WHERE s ILIKE 'duckdb%' ESCAPE '\' ORDER BY id +---- +2 + +query I +SELECT id FROM t WHERE s ILIKE '%fast' ESCAPE '\' ORDER BY id +---- +2 + +query I +SELECT id FROM t WHERE s ILIKE 'the quick brown fox' ESCAPE '\' ORDER BY id +---- +3 + +# unicode case folding; ß must NOT fold to ss +query I +SELECT id FROM t WHERE s ILIKE '%æther%' ESCAPE '\' ORDER BY id +---- +5 + +query I +SELECT id FROM t WHERE s ILIKE '%DÉJÀ%' ESCAPE '\' ORDER BY id +---- +6 + +query I +SELECT id FROM t WHERE s ILIKE '%strasse%' ESCAPE '\' ORDER BY id +---- + +query I +SELECT id FROM t WHERE s ILIKE '%straße%' ESCAPE '\' ORDER BY id +---- +4 + +# without escape semantics, % and _ are wildcards +query I +SELECT id FROM t WHERE s ILIKE '%100%done%' ESCAPE '\' ORDER BY id +---- +9 + +# === escape char ('\') ACTIVE in pattern => matcher disabled, escape-aware fallback === + +# '\%' is a literal percent sign +query I +SELECT id FROM t WHERE s ILIKE '%\%%' ESCAPE '\' ORDER BY id +---- +9 + +# '\_' is a literal underscore +query I +SELECT id FROM t WHERE s ILIKE '%\_%' ESCAPE '\' ORDER BY id +---- +10 + +# literal percent, case-insensitive contains with surrounding wildcards +query I +SELECT id FROM t WHERE s ILIKE '%100\% DONE%' ESCAPE '\' ORDER BY id +---- +9 + +# a different (non-backslash) escape char that IS present in the pattern +query I +SELECT id FROM t WHERE s ILIKE '%100x%%' ESCAPE 'x' ORDER BY id +---- +9 + +# === NOT ILIKE ... ESCAPE (constant pattern) === + +# rows with no 'a'/'A' (empty string matches NOT; NULL excluded) +query I +SELECT id FROM t WHERE s NOT ILIKE '%a%' ESCAPE '\' ORDER BY id +---- +3 +8 +9 +10 + +# === edge cases === + +# only-percent pattern matches every non-null row +query I +SELECT id FROM t WHERE s ILIKE '%' ESCAPE '\' ORDER BY id +---- +1 +2 +3 +4 +5 +6 +8 +9 +10 + +# empty pattern matches only the empty string +query I +SELECT id FROM t WHERE s ILIKE '' ESCAPE '\' ORDER BY id +---- +8 + +# empty escape string == no escape char; % stays a wildcard +query I +SELECT id FROM t WHERE s ILIKE '%hello%' ESCAPE '' ORDER BY id +---- +1 + +# NULL pattern => no matches +query I +SELECT id FROM t WHERE s ILIKE NULL ESCAPE '\' ORDER BY id +---- + +# === parameterized (runtime-constant) pattern, like the production query === +statement ok +PREPARE p AS SELECT id FROM t WHERE s ILIKE '%' || ? || '%' ESCAPE '\' ORDER BY id + +query I +EXECUTE p('hello') +---- +1 + +query I +EXECUTE p('CAFÉ') +---- +1 +6 + +query I +EXECUTE p('zznotfound') +---- + +# === non-constant pattern/escape => generic ternary fallback === +statement ok +CREATE TABLE pats(id INTEGER, s VARCHAR, pat VARCHAR); + +statement ok +INSERT INTO pats VALUES + (1, 'café Hello', '%HELLO%'), + (2, 'DuckDB', '%duck%'), + (3, '50% off', '%\%%'), + (4, 'fox', '%cat%'); + +query I +SELECT id FROM pats WHERE s ILIKE pat ESCAPE '\' ORDER BY id +---- +1 +2 +3 + +# multiple ESCAPE-bearing predicates AND/OR combined (shape of the production query) +query I +SELECT id FROM t +WHERE (s ILIKE '%café%' ESCAPE '\' AND s ILIKE '%hello%' ESCAPE '\') + OR (s ILIKE '%duck%' ESCAPE '\' AND s ILIKE '%fast%' ESCAPE '\') +ORDER BY id +---- +1 +2 From e159c303c19258e1f39099ed23614b7a16fe7dbb Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Mon, 22 Jun 2026 19:54:49 +0300 Subject: [PATCH 7/9] Add tests for ILIKE ... ESCAPE fallback branches Cover the remaining branches of the constant-pattern ILIKE ... ESCAPE path: - escape char inactive but pattern has '_' wildcard => matcher disabled, escape-aware recursive fallback with a non-zero escape char (match + no-match) - ESCAPE NULL => NULL result - non-constant (per-row) escape column => generic ternary fallback Co-Authored-By: Claude Opus 4.8 --- .../test_ilike_escape_constant_pattern.test | 40 +++++++++++++++++++ 1 file changed, 40 insertions(+) diff --git a/test/sql/function/string/test_ilike_escape_constant_pattern.test b/test/sql/function/string/test_ilike_escape_constant_pattern.test index fbb98b59c708..d48371b50460 100644 --- a/test/sql/function/string/test_ilike_escape_constant_pattern.test +++ b/test/sql/function/string/test_ilike_escape_constant_pattern.test @@ -108,6 +108,19 @@ SELECT id FROM t WHERE s ILIKE '%100x%%' ESCAPE 'x' ORDER BY id ---- 9 +# === escape char NOT active but pattern has '_' wildcard => matcher disabled, escape-aware fallback with a +# non-zero escape char (LikeOperatorFunction with HAS_ESCAPE), matching === +query I +SELECT id FROM t WHERE s ILIKE '%c_fé%' ESCAPE '\' ORDER BY id +---- +1 +6 + +# same path, no match +query I +SELECT id FROM t WHERE s ILIKE '%c_zzz%' ESCAPE '\' ORDER BY id +---- + # === NOT ILIKE ... ESCAPE (constant pattern) === # rows with no 'a'/'A' (empty string matches NOT; NULL excluded) @@ -152,6 +165,16 @@ query I SELECT id FROM t WHERE s ILIKE NULL ESCAPE '\' ORDER BY id ---- +# NULL escape => result is NULL (no matches), and scalar form is NULL +query I +SELECT id FROM t WHERE s ILIKE '%hello%' ESCAPE NULL ORDER BY id +---- + +query T +SELECT 'abc' ILIKE '%a%' ESCAPE NULL +---- +NULL + # === parameterized (runtime-constant) pattern, like the production query === statement ok PREPARE p AS SELECT id FROM t WHERE s ILIKE '%' || ? || '%' ESCAPE '\' ORDER BY id @@ -198,3 +221,20 @@ ORDER BY id ---- 1 2 + +# === non-constant escape (per-row escape column) => generic ternary fallback === +statement ok +CREATE TABLE esc_t(id INTEGER, s VARCHAR, pat VARCHAR, esc VARCHAR); + +statement ok +INSERT INTO esc_t VALUES + (1, 'café x', '%c_fé%', '\'), + (2, '50% off', '%50\% off%', '\'), + (3, 'fox', '%cat%', '#'), + (4, 'a#%b', '%a#%%', '#'); + +query I +SELECT id FROM esc_t WHERE s ILIKE pat ESCAPE esc ORDER BY id +---- +1 +2 From f5a546b046e731ef90ab22ddc2bb05f40c0d86ca Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Tue, 23 Jun 2026 12:59:32 +0300 Subject: [PATCH 8/9] Fix ILIKE treating embedded NUL bytes as escape characters The unicode ILIKE path routed plain ILIKE through the escape-aware matcher with escape='\0', so an embedded NUL byte in the pattern was treated as a LIKE escape character and identical strings failed to match (e.g. 'goo\0se' ILIKE 'goo\0se' returned false). The ASCII operator and plain LIKE already used the non-escape matcher. Treat '\0' as the "no escape" sentinel in ILikeOperatorFunction and the ILikeEscapeFunction constant fast-path fallback, matching embedded NUL bytes literally and bringing all ILIKE code paths into agreement. Update test/fuzzer/duckfuzz/array_hash.test: its !~~* join over test_all_types() ('goo\0se' next to a multi-codepoint value) previously recorded the buggy 4-row result; the correct result is 3 rows. Add test/sql/function/string/test_ilike_embedded_null.test covering the constant-fold, ASCII-operator, unicode per-row, constant-pattern fast path, case-insensitivity, wildcard and ESCAPE '' cases. Co-Authored-By: Claude Fable 5 --- src/function/scalar/string/like.cpp | 9 ++- test/fuzzer/duckfuzz/array_hash.test | 1 - .../string/test_ilike_embedded_null.test | 79 +++++++++++++++++++ 3 files changed, 87 insertions(+), 2 deletions(-) create mode 100644 test/sql/function/string/test_ilike_embedded_null.test diff --git a/src/function/scalar/string/like.cpp b/src/function/scalar/string/like.cpp index dcf12c777428..d44824dfdb17 100644 --- a/src/function/scalar/string/like.cpp +++ b/src/function/scalar/string/like.cpp @@ -419,6 +419,10 @@ bool ILikeOperatorFunction(string_t &str, string_t &pattern, char escape = '\0') LowerCase(pat_data, pat_size, pat_ldata.get()); string_t str_lcase(str_ldata.get(), UnsafeNumericCast(str_llength)); string_t pat_lcase(pat_ldata.get(), UnsafeNumericCast(pat_llength)); + // '\0' is the "no escape" sentinel: use the non-escape matcher so embedded NUL bytes are matched literally + if (escape == '\0') { + return LikeOperatorFunction(str_lcase, pat_lcase); + } return LikeOperatorFunction(str_lcase, pat_lcase, escape); } @@ -534,7 +538,10 @@ void ILikeEscapeFunction(DataChunk &args, ExpressionState &state, Vector &result } LowerCase(str.GetData(), str.GetSize(), scratch.get()); string_t str_lcase(scratch.get(), UnsafeNumericCast(str_llength)); - bool match = matcher ? matcher->Match(str_lcase) : LikeOperatorFunction(str_lcase, pat_lcase, escape_char); + // '\0' escape means no escape: use the non-escape matcher so embedded NUL bytes are matched literally + bool match = matcher ? matcher->Match(str_lcase) + : (escape_char == '\0' ? LikeOperatorFunction(str_lcase, pat_lcase) + : LikeOperatorFunction(str_lcase, pat_lcase, escape_char)); return INVERT ? !match : match; }); return; diff --git a/test/fuzzer/duckfuzz/array_hash.test b/test/fuzzer/duckfuzz/array_hash.test index 621d075c0724..6e01a1ef740d 100644 --- a/test/fuzzer/duckfuzz/array_hash.test +++ b/test/fuzzer/duckfuzz/array_hash.test @@ -17,5 +17,4 @@ SELECT subq_0.c2 AS c4 FROM (SELECT ref_1.fixed_nested_int_array AS c2 FROM main ---- NULL [[4, 5, 6], [NULL, 2, 3], [4, 5, 6]] -[[4, 5, 6], [NULL, 2, 3], [4, 5, 6]] [[NULL, 2, 3], NULL, [NULL, 2, 3]] diff --git a/test/sql/function/string/test_ilike_embedded_null.test b/test/sql/function/string/test_ilike_embedded_null.test new file mode 100644 index 000000000000..5751e814af41 --- /dev/null +++ b/test/sql/function/string/test_ilike_embedded_null.test @@ -0,0 +1,79 @@ +# name: test/sql/function/string/test_ilike_embedded_null.test +# description: ILIKE / NOT ILIKE must match embedded NUL bytes literally (not treat them as escape chars) +# group: [string] + +# A pattern containing an embedded NUL byte must be matched literally. Previously the unicode ILIKE path +# routed plain ILIKE through the escape-aware matcher with escape='\0', so an embedded NUL was treated as +# a LIKE escape character and identical strings failed to match. + +# original repro: embedded NUL next to a non-ASCII value forces the unicode ILIKE path +statement ok +CREATE TABLE t(a VARCHAR, b VARCHAR); + +statement ok +INSERT INTO t VALUES ('goo'||chr(0)||'se', 'goo'||chr(0)||'se'), ('🦆','🦆'); + +query I +SELECT a ILIKE b FROM t +---- +true +true + +# constant-folded scalar +query I +SELECT ('goo' || chr(0) || 'se') ILIKE ('goo' || chr(0) || 'se') +---- +true + +# column vs column, ASCII-only column -> ASCII ILIKE operator +statement ok +CREATE TABLE ascii_only(a VARCHAR, b VARCHAR); + +statement ok +INSERT INTO ascii_only VALUES ('goo' || chr(0) || 'se', 'goo' || chr(0) || 'se'); + +query I +SELECT a ILIKE b FROM ascii_only +---- +true + +# column vs column, unicode-possible column -> unicode ILIKE operator (the previously buggy path) +statement ok +CREATE TABLE unicode_possible(a VARCHAR, b VARCHAR); + +statement ok +INSERT INTO unicode_possible VALUES ('goo' || chr(0) || 'se', 'goo' || chr(0) || 'se'), ('🦆', '🦆'); + +query II +SELECT a ILIKE b, a !~~* b FROM unicode_possible ORDER BY a +---- +true false +true false + +# constant pattern fast path (column value vs constant pattern) on a unicode-possible column +query II +SELECT a ILIKE ('goo' || chr(0) || 'se'), a NOT ILIKE ('goo' || chr(0) || 'se') FROM unicode_possible ORDER BY a +---- +true false +false true + +# case-insensitivity is preserved around the embedded NUL +query I +SELECT a ILIKE ('GOO' || chr(0) || 'SE') FROM unicode_possible ORDER BY a +---- +true +false + +# wildcards still work with an embedded NUL in the pattern (unicode-possible column) +query I +SELECT a ILIKE ('goo' || chr(0) || '%') FROM unicode_possible ORDER BY a +---- +true +false + +# ILIKE ... ESCAPE with empty escape ('' => no escape) must also match the NUL literally +query I +SELECT a ILIKE ('goo' || chr(0) || 'se') ESCAPE '' FROM unicode_possible ORDER BY a +---- +true +false From 90a8269bfcb1234965bd1a57ea640e269b7bfece Mon Sep 17 00:00:00 2001 From: Leonid Krugliak Date: Wed, 24 Jun 2026 12:17:49 +0300 Subject: [PATCH 9/9] Fix TernaryExecutor::Execute calls missing count arg in ILikeEscapeFunction The ESCAPE fallback path was written for upstream main's count-less TernaryExecutor::Execute API; this branch still requires an explicit idx_t count argument. Co-Authored-By: Claude Sonnet 4.6 --- src/function/scalar/string/like.cpp | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/function/scalar/string/like.cpp b/src/function/scalar/string/like.cpp index d44824dfdb17..ca704268f7f4 100644 --- a/src/function/scalar/string/like.cpp +++ b/src/function/scalar/string/like.cpp @@ -549,10 +549,12 @@ void ILikeEscapeFunction(DataChunk &args, ExpressionState &state, Vector &result // non-constant pattern/escape: fall back to the generic per-row implementation if (INVERT) { TernaryExecutor::Execute( - str_vec, pattern_vec, escape_vec, result, NotILikeEscapeOperator::Operation); + str_vec, pattern_vec, escape_vec, result, args.size(), + NotILikeEscapeOperator::Operation); } else { TernaryExecutor::Execute( - str_vec, pattern_vec, escape_vec, result, ILikeEscapeOperator::Operation); + str_vec, pattern_vec, escape_vec, result, args.size(), + ILikeEscapeOperator::Operation); } }