fix: add logger everywhere we need to print (intel#122)

Co-authored-by: GitHub Actions <41898282+github-actions[bot]@users.noreply.github.com>

Author: yuejiaointel

include/svs/core/kmeans.h

@@ -158,7 +158,8 @@ data::SimpleData<float> train_impl(
     const KMeansParameters& parameters,
     const Data& data,
     Pool& threadpool,
-    Callback&& post_epoch_callback = lib::donothing()
+    Callback&& post_epoch_callback = lib::donothing(),
+    svs::logging::logger_ptr logger = svs::logging::get()
 ) {
     size_t ndims = data.dimensions();
     auto num_clusters = parameters.clusters;
@@ -211,7 +212,7 @@ data::SimpleData<float> train_impl(
             old_counts[i] = 0;
         }
     }
-    svs::logging::debug("{}", timer);
+    svs::logging::debug(logger, "{}", timer);
     return centroids;
 }
 
@@ -223,11 +224,12 @@ data::SimpleData<float> train(
     const KMeansParameters& parameters,
     const Data& data,
     ThreadPoolProto threadpool_proto,
-    Callback&& post_epoch_callback = lib::donothing()
+    Callback&& post_epoch_callback = lib::donothing(),
+    svs::logging::logger_ptr logger = svs::logging::get()
 ) {
     auto threadpool = threads::as_threadpool(std::move(threadpool_proto));
     return train_impl(
-        parameters, data, threadpool, std::forward<Callback>(post_epoch_callback)
+        parameters, data, threadpool, std::forward<Callback>(post_epoch_callback), logger
     );
 }
 
@@ -239,10 +241,11 @@ data::SimpleData<float> train(
     const KMeansParameters& parameters,
     const Data& data,
     Pool& threadpool,
-    Callback&& post_epoch_callback = lib::donothing()
+    Callback&& post_epoch_callback = lib::donothing(),
+    svs::logging::logger_ptr logger = svs::logging::get()
 ) {
     return train_impl(
-        parameters, data, threadpool, std::forward<Callback>(post_epoch_callback)
+        parameters, data, threadpool, std::forward<Callback>(post_epoch_callback), logger
     );
 }
 } // namespace svs

include/svs/index/inverted/clustering.h

@@ -778,7 +778,8 @@ auto build_primary_index(
     std::span<const I> ids,
     const vamana::VamanaBuildParameters& vamana_parameters,
     const Distance& distance,
-    Pool threadpool
+    Pool threadpool,
+    svs::logging::logger_ptr logger = svs::logging::get()
 ) {
     return vamana::auto_build(
         vamana_parameters,
@@ -792,7 +793,8 @@ auto build_primary_index(
         }),
         distance,
         std::move(threadpool),
-        HugepageAllocator<I>()
+        HugepageAllocator<I>(),
+        logger
     );
 }
 

include/svs/index/inverted/memory_based.h

@@ -577,7 +577,8 @@ auto auto_build(
         lib::as_const_span(centroids),
         parameters.primary_parameters_,
         distance,
-        std::move(threadpool)
+        std::move(threadpool),
+        logger
     );
 
     // Cluster the dataset with the help of the primary index.

include/svs/index/vamana/calibrate.h

@@ -177,7 +177,7 @@ VamanaSearchParameters optimize_split_buffer(
     VamanaSearchParameters current,
     const F& compute_recall,
     const DoSearch& do_search,
-    svs::logging::logger_ptr logger = svs::logging::get()
+    svs::logging::logger_ptr logger
 ) {
     svs::logging::trace(logger, "Entering split buffer optimization routine");
     assert(
@@ -334,7 +334,8 @@ std::pair<VamanaSearchParameters, bool> optimize_search_buffer(
             target_recall,
             current,
             compute_recall,
-            do_search
+            do_search,
+            logger
         );
     }
     return std::make_pair(current, converged);
@@ -346,7 +347,7 @@ VamanaSearchParameters tune_prefetch(
     Index& index,
     VamanaSearchParameters search_parameters,
     const DoSearch& do_search,
-    svs::logging::logger_ptr logger = svs::logging::get()
+    svs::logging::logger_ptr logger
 ) {
     svs::logging::trace(logger, "Tuning prefetch parameters");
     const auto& prefetch_steps = calibration_parameters.prefetch_steps_;
@@ -480,7 +481,8 @@ VamanaSearchParameters calibrate(
     size_t num_neighbors,
     double target_recall,
     F&& compute_recall,
-    DoSearch&& do_search
+    DoSearch&& do_search,
+    svs::logging::logger_ptr logger = svs::logging::get()
 ) {
     // Get the existing parameters and the default values decide which to use as the seed.
     auto default_parameters = VamanaSearchParameters();
@@ -492,30 +494,32 @@ VamanaSearchParameters calibrate(
 
     // Step 1: Optimize aspects of the search buffer if desired.
     if (calibration_parameters.should_optimize_search_buffer()) {
-        svs::logging::trace("Optimizing search buffer.");
+        svs::logging::trace(logger, "Optimizing search buffer.");
         auto [best, converged] = calibration::optimize_search_buffer<Index>(
             calibration_parameters,
             current,
             num_neighbors,
             target_recall,
             compute_recall,
-            do_search
+            do_search,
+            logger
         );
         current = best;
 
         if (!converged) {
             svs::logging::warn(
-                "Target recall could not be achieved. Exiting optimization early."
+                logger, "Target recall could not be achieved. Exiting optimization early."
             );
             return current;
         }
     }
 
     // Step 2: Optimize prefetch parameters.
     if (calibration_parameters.train_prefetchers_) {
-        svs::logging::trace("Training Prefetchers.");
-        current =
-            calibration::tune_prefetch(calibration_parameters, index, current, do_search);
+        svs::logging::trace(logger, "Training Prefetchers.");
+        current = calibration::tune_prefetch(
+            calibration_parameters, index, current, do_search, logger
+        );
     }
 
     // Finish up.

include/svs/index/vamana/dynamic_index.h

@@ -688,7 +688,7 @@ class MutableVamanaIndex {
             GreedySearchPrefetchParameters{sp.prefetch_lookahead_, sp.prefetch_step_};
         VamanaBuilder builder{
             graph_, data_, distance_, parameters, threadpool_, prefetch_parameters};
-        builder.construct(alpha_, entry_point(), slots, logging::Level::Trace);
+        builder.construct(alpha_, entry_point(), slots, logging::Level::Trace, logger_);
         // Mark all added entries as valid.
         for (const auto& i : slots) {
             status_[i] = SlotMetadata::Valid;
@@ -935,11 +935,10 @@ class MutableVamanaIndex {
         assert(entry_point_.size() == 1);
         auto entry_point = entry_point_[0];
         if (status_.at(entry_point) == SlotMetadata::Deleted) {
-            auto logger = svs::logging::get();
-            svs::logging::debug(logger, "Replacing entry point.");
+            svs::logging::debug(logger_, "Replacing entry point.");
             auto new_entry_point =
                 extensions::compute_entry_point(data_, threadpool_, valid);
-            svs::logging::debug(logger, "New point: {}", new_entry_point);
+            svs::logging::debug(logger_, "New point: {}", new_entry_point);
             assert(!is_deleted(new_entry_point));
             entry_point_[0] = new_entry_point;
         }
@@ -1051,7 +1050,8 @@ class MutableVamanaIndex {
             num_neighbors,
             target_recall,
             compute_recall,
-            do_search
+            do_search,
+            logger_
         );
 
         set_search_parameters(p);
@@ -1267,6 +1267,15 @@ MutableVamanaIndex(
     svs::logging::logger_ptr
 ) -> MutableVamanaIndex<graphs::SimpleBlockedGraph<uint32_t>, Data, Dist>;
 
+template <typename Data, typename Dist, typename ExternalIds>
+MutableVamanaIndex(
+    const VamanaBuildParameters&,
+    Data,
+    const ExternalIds&,
+    Dist,
+    size_t,
+    svs::logging::logger_ptr
+) -> MutableVamanaIndex<graphs::SimpleBlockedGraph<uint32_t>, Data, Dist>;
 namespace detail {
 
 struct VamanaStateLoader {

include/svs/index/vamana/index.h

@@ -99,8 +99,12 @@ struct VamanaIndexParameters {
         return schema == serialization_schema && version <= save_version;
     }
 
-    static VamanaIndexParameters load_legacy(const lib::ContextFreeLoadTable& table) {
+    static VamanaIndexParameters load_legacy(
+        const lib::ContextFreeLoadTable& table,
+        svs::logging::logger_ptr logger = svs::logging::get()
+    ) {
         svs::logging::warn(
+            logger,
             "Loading a legacy IndexParameters class. Please consider resaving this "
             "index to update the save version and prevent future breaking!\n"
         );

include/svs/misc/dynamic_helper.h

@@ -155,7 +155,8 @@ template <typename Idx, typename Eltype, size_t N, typename Dist> class Referenc
         size_t bucket_size,
         size_t num_neighbors,
         const Queries& queries,
-        uint64_t rng_seed
+        uint64_t rng_seed,
+        svs::logging::logger_ptr logger = svs::logging::get()
     )
         : data_{std::move(data)}
         , num_queries_{queries.size()}
@@ -214,7 +215,7 @@ template <typename Idx, typename Eltype, size_t N, typename Dist> class Referenc
             reserve_buckets_.emplace_back(ids, std::move(bucket_groundtruth));
             start = stop;
         }
-        svs::logging::debug("{}", timer);
+        svs::logging::debug(logger, "{}", timer);
     }
 
     /// @brief Return the total number of elements in the dataset.

tests/svs/index/flat/flat.cpp

@@ -26,6 +26,7 @@
 CATCH_TEST_CASE("FlatIndex Logging Test", "[logging]") {
     // Vector to store captured log messages
     std::vector<std::string> captured_logs;
+    std::vector<std::string> global_captured_logs;
 
     // Create a callback sink to capture log messages
     auto callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
@@ -39,6 +40,15 @@ CATCH_TEST_CASE("FlatIndex Logging Test", "[logging]") {
     auto test_logger = std::make_shared<spdlog::logger>("test_logger", callback_sink);
     test_logger->set_level(spdlog::level::trace);
 
+    auto global_callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
+        [&global_captured_logs](const spdlog::details::log_msg& msg) {
+            global_captured_logs.emplace_back(msg.payload.data(), msg.payload.size());
+        }
+    );
+    global_callback_sink->set_level(spdlog::level::trace);
+    auto original_logger = svs::logging::get();
+    original_logger->sinks().push_back(global_callback_sink);
+
     std::vector<float> data{1.0f, 2.0f};
     auto dataView = svs::data::SimpleDataView<float>(data.data(), 2, 1);
     svs::distance::DistanceL2 dist;
@@ -52,6 +62,7 @@ CATCH_TEST_CASE("FlatIndex Logging Test", "[logging]") {
     test_logger->info("Test FlatIndex Logging");
 
     // Verify the log output
+    CATCH_REQUIRE(global_captured_logs.empty());
     CATCH_REQUIRE(captured_logs.size() == 1);
     CATCH_REQUIRE(captured_logs[0] == "Test FlatIndex Logging");
 }

tests/svs/index/inverted/clustering.cpp

@@ -396,6 +396,8 @@ CATCH_TEST_CASE("Random Clustering - End to End", "[inverted][random_clustering]
 CATCH_TEST_CASE("Clustering with Logger", "[logging]") {
     // Setup logger
     std::vector<std::string> captured_logs;
+    std::vector<std::string> global_captured_logs;
+
     auto callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
         [&captured_logs](const spdlog::details::log_msg& msg) {
             captured_logs.emplace_back(msg.payload.data(), msg.payload.size());
@@ -405,6 +407,15 @@ CATCH_TEST_CASE("Clustering with Logger", "[logging]") {
     auto test_logger = std::make_shared<spdlog::logger>("test_logger", callback_sink);
     test_logger->set_level(spdlog::level::trace);
 
+    auto global_callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
+        [&global_captured_logs](const spdlog::details::log_msg& msg) {
+            global_captured_logs.emplace_back(msg.payload.data(), msg.payload.size());
+        }
+    );
+    global_callback_sink->set_level(spdlog::level::trace);
+    auto original_logger = svs::logging::get();
+    original_logger->sinks().push_back(global_callback_sink);
+
     // Setup cluster
     auto data = svs::data::SimpleData<float>::load(test_dataset::data_svs_file());
     auto vamana_parameters =
@@ -427,12 +438,14 @@ CATCH_TEST_CASE("Clustering with Logger", "[logging]") {
         svs::lib::as_const_span(centroids),
         vamana_parameters,
         svs::DistanceL2(),
-        std::move(threadpool)
+        std::move(threadpool),
+        test_logger
     );
     auto clustering = svs::index::inverted::cluster_with(
         data, svs::lib::as_const_span(centroids), clustering_parameters, index, test_logger
     );
 
     // Verify the internal log messages
-    CATCH_REQUIRE(captured_logs[0].find("Processing batch") != std::string::npos);
+    CATCH_REQUIRE(global_captured_logs.empty());
+    CATCH_REQUIRE(captured_logs[0].find("Number of syncs") != std::string::npos);
 }

tests/svs/index/inverted/memory_based.cpp

@@ -26,6 +26,7 @@
 CATCH_TEST_CASE("InvertedIndex Logging Test", "[logging]") {
     // Vector to store captured log messages
     std::vector<std::string> captured_logs;
+    std::vector<std::string> global_captured_logs;
 
     // Create a callback sink to capture log messages
     auto callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
@@ -39,6 +40,15 @@ CATCH_TEST_CASE("InvertedIndex Logging Test", "[logging]") {
     auto test_logger = std::make_shared<spdlog::logger>("test_logger", callback_sink);
     test_logger->set_level(spdlog::level::trace);
 
+    auto global_callback_sink = std::make_shared<spdlog::sinks::callback_sink_mt>(
+        [&global_captured_logs](const spdlog::details::log_msg& msg) {
+            global_captured_logs.emplace_back(msg.payload.data(), msg.payload.size());
+        }
+    );
+    global_callback_sink->set_level(spdlog::level::trace);
+    auto original_logger = svs::logging::get();
+    original_logger->sinks().push_back(global_callback_sink);
+
     // Setup index
     auto distance = svs::DistanceL2();
     constexpr auto distance_type = svs::distance_type_v<svs::DistanceL2>;
@@ -59,5 +69,6 @@ CATCH_TEST_CASE("InvertedIndex Logging Test", "[logging]") {
     );
 
     // Verify the internal log messages
-    CATCH_REQUIRE(captured_logs[0].find("Processing batch") != std::string::npos);
+    CATCH_REQUIRE(global_captured_logs.empty());
+    CATCH_REQUIRE(captured_logs[0].find("Number of syncs") != std::string::npos);
 }