#267 Improve search performance: reduce delay (#1717)

* #267 Improve search performance: reduce delay
Signed-off-by: Njinhai <haijin.chn@gmail.com>

* #267 Improve search performance: reduce delay - update CHANGELOG
Signed-off-by: Njinhai <haijin.chn@gmail.com>

* #267 Update
Signed-off-by: Njinhai <hai.jin@zilliz.com>

* #267 Update
Signed-off-by: Njinhai <hai.jin@zilliz.com>

* #267 Update
Signed-off-by: Njinhai <hai.jin@zilliz.com>

* #267 Update format
Signed-off-by: NJinHai-CN <hai.jin@zilliz.com>

CHANGELOG.md

@@ -18,6 +18,7 @@ Please mark all change in change log and use the issue from GitHub
 -   \#1660 IVF PQ CPU support deleted vectors searching
 
 ## Improvement
+-   \#267 Improve search performance: reduce delay
 -   \#342 Knowhere and Wrapper refactor
 -   \#1537 Optimize raw vector and uids read/write
 -   \#1546 Move Config.cpp to config directory
@@ -46,8 +47,8 @@ Please mark all change in change log and use the issue from GitHub
 -   \#995 Table count set to 0 if no tables found
 -   \#1010 Improve error message when offset or page_size is equal 0
 -   \#1022 Check if partition name is valid
--   \#1028 check if table exists when show partitions
--   \#1029 check if table exists when try to delete partition
+-   \#1028 Check if table exists when show partitions
+-   \#1029 Check if table exists when try to delete partition
 -   \#1066 Optimize http insert and search speed
 -   \#1022 Check if partition name is legal
 -   \#1028 Check if table exists when show partitions

core/src/cache/Cache.inl

@@ -177,9 +177,7 @@ Cache<ItemObj>::print() {
 #endif
     }
 
-    SERVER_LOG_DEBUG << "[Cache item count]: " << cache_count;
-    SERVER_LOG_DEBUG << "[Cache usage]: " << usage_ << " bytes";
-    SERVER_LOG_DEBUG << "[Cache capacity]: " << capacity_ << " bytes";
+    SERVER_LOG_DEBUG << "[Cache] [item count]: " << cache_count << " [capacity] " << capacity_ << "(bytes) [usage] " << usage_ << "(bytes)";
 }
 
 }  // namespace cache

core/src/index/knowhere/knowhere/index/vector_index/IndexIVF.cpp

@@ -289,6 +289,11 @@ IVF::QueryImpl(int64_t n, const float* data, int64_t k, float* distances, int64_
     auto ivf_index = dynamic_cast<faiss::IndexIVF*>(index_.get());
     ivf_index->nprobe = params->nprobe;
     stdclock::time_point before = stdclock::now();
+    if (params->nprobe > 1 && n <= 4) {
+        ivf_index->parallel_mode = 1;
+    } else {
+        ivf_index->parallel_mode = 0;
+    }
     ivf_index->search(n, (float*)data, k, distances, labels, bitset_);
     stdclock::time_point after = stdclock::now();
     double search_cost = (std::chrono::duration<double, std::micro>(after - before)).count();

core/src/scheduler/JobMgr.cpp

@@ -138,6 +138,7 @@ JobMgr::worker_function() {
 
         // disk resources NEVER be empty.
         if (auto disk = res_mgr_->GetDiskResources()[0].lock()) {
+            // if (auto disk = res_mgr_->GetCpuResources()[0].lock()) {
             for (auto& task : tasks) {
                 disk->task_table().Put(task, nullptr);
             }

core/src/scheduler/TaskTable.cpp

@@ -149,7 +149,7 @@ TaskTableItem::Dump() const {
 std::vector<uint64_t>
 TaskTable::PickToLoad(uint64_t limit) {
 #if 1
-    TimeRecorder rc("");
+    // TimeRecorder rc("");
     std::vector<uint64_t> indexes;
     bool cross = false;
 
@@ -182,7 +182,7 @@ TaskTable::PickToLoad(uint64_t limit) {
             ++pick_count;
         }
     }
-    rc.ElapseFromBegin("PickToLoad ");
+    // rc.ElapseFromBegin("PickToLoad ");
     return indexes;
 #else
     size_t count = 0;
@@ -233,7 +233,7 @@ TaskTable::PickToLoad(uint64_t limit) {
 
 std::vector<uint64_t>
 TaskTable::PickToExecute(uint64_t limit) {
-    TimeRecorder rc("");
+    // TimeRecorder rc("");
     std::vector<uint64_t> indexes;
     bool cross = false;
     uint64_t available_begin = table_.front() + 1;
@@ -254,7 +254,7 @@ TaskTable::PickToExecute(uint64_t limit) {
             ++pick_count;
         }
     }
-    rc.ElapseFromBegin("PickToExecute ");
+    // rc.ElapseFromBegin("PickToExecute ");
     return indexes;
 }
 

core/src/scheduler/task/SearchTask.cpp

@@ -226,7 +226,6 @@ XSearchTask::Execute() {
         uint64_t nq = search_job->nq();
         uint64_t topk = search_job->topk();
         const milvus::json& extra_params = search_job->extra_params();
-        ENGINE_LOG_DEBUG << "Search job extra params: " << extra_params.dump();
         const engine::VectorsData& vectors = search_job->vectors();
 
         output_ids.resize(topk * nq);

core/src/utils/TimeRecorder.h

@@ -13,8 +13,19 @@
 
 #include <chrono>
 #include <string>
+#include "utils/Log.h"
 
 namespace milvus {
+inline void
+print_timestamp(const std::string& message) {
+    std::chrono::time_point<std::chrono::system_clock> now = std::chrono::system_clock::now();
+    auto duration = now.time_since_epoch();
+    auto micros = std::chrono::duration_cast<std::chrono::microseconds>(duration).count();
+    micros %= 1000000;
+    double millisecond = (double)micros / 1000.0;
+
+    SERVER_LOG_DEBUG << std::fixed << " " << millisecond << "(ms) [timestamp]" << message;
+}
 
 class TimeRecorder {
     using stdclock = std::chrono::high_resolution_clock;