From d6b3aae8a6bba03f9e8f3b8f9b5de314a2f20754 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Cl=C3=A9ment=20Renault?= <clement@meilisearch.com>
Date: Thu, 26 Sep 2024 16:37:38 +0200
Subject: [PATCH] WIP add more logs

---
 milli/src/update/new/extract/mod.rs |  1 +
 milli/src/update/new/indexer/mod.rs |  8 +++++++-
 milli/src/update/new/merger.rs      | 14 ++++++++++++--
 3 files changed, 20 insertions(+), 3 deletions(-)

diff --git a/milli/src/update/new/extract/mod.rs b/milli/src/update/new/extract/mod.rs
index ef85abc43..2f88831e6 100644
--- a/milli/src/update/new/extract/mod.rs
+++ b/milli/src/update/new/extract/mod.rs
@@ -51,6 +51,7 @@ impl IntoIterator for HashMapMerger {
 
     fn into_iter(self) -> Self::IntoIter {
         let mut entries: Vec<_> = self.maps.into_iter().flat_map(|m| m.into_iter()).collect();
+        eprintln!("There are {} entries in the HashMapMerger", entries.len());
         entries.par_sort_unstable_by(|(ka, _), (kb, _)| ka.cmp(kb));
         IntoIter {
             sorted_entries: entries.into_iter(),
diff --git a/milli/src/update/new/indexer/mod.rs b/milli/src/update/new/indexer/mod.rs
index 6c002b74d..1dba5adb2 100644
--- a/milli/src/update/new/indexer/mod.rs
+++ b/milli/src/update/new/indexer/mod.rs
@@ -224,6 +224,7 @@ where
             )
         })?;
 
+        let mut entries_count = 0;
         for operation in writer_receiver {
             let database = operation.database(index);
             match operation.entry() {
@@ -232,10 +233,15 @@ where
                         unreachable!("We tried to delete an unknown key")
                     }
                 }
-                EntryOperation::Write(e) => database.put(wtxn, e.key(), e.value())?,
+                EntryOperation::Write(e) => {
+                    entries_count += 1;
+                    database.put(wtxn, e.key(), e.value())?
+                }
             }
         }
 
+        eprintln!("We saw {entries_count}");
+
         /// TODO handle the panicking threads
         handle.join().unwrap()?;
         handle2.join().unwrap()?;
diff --git a/milli/src/update/new/merger.rs b/milli/src/update/new/merger.rs
index eb2ecae0a..d0efbf122 100644
--- a/milli/src/update/new/merger.rs
+++ b/milli/src/update/new/merger.rs
@@ -248,6 +248,7 @@ impl GeoExtractor {
 }
 
 #[tracing::instrument(level = "trace", skip_all, target = "indexing::merge")]
+#[inline(never)]
 fn merge_and_send_docids<'t>(
     merger: HashMapMerger,
     database: Database<Bytes, Bytes>,
@@ -256,6 +257,7 @@ fn merge_and_send_docids<'t>(
     docids_sender: impl DocidsSender + Sync,
     // mut register_key: impl FnMut(DelAdd, &[u8]) -> Result<()> + Send + Sync,
 ) -> Result<()> {
+    let now = std::time::Instant::now();
     merger.into_iter().par_bridge().try_for_each(|(key, deladd)| {
         rtxn_pool.with(|rtxn| {
             let mut buffer = Vec::new();
@@ -274,10 +276,15 @@ fn merge_and_send_docids<'t>(
             }
             Ok(())
         })
-    })
+    })?;
+
+    eprintln!("I took to merger hashmaps {:.2?}", now.elapsed());
+
+    Ok(())
 }
 
 #[tracing::instrument(level = "trace", skip_all, target = "indexing::merge")]
+#[inline(never)]
 fn merge_and_send_facet_docids<'t>(
     merger: HashMapMerger,
     database: FacetDatabases,
@@ -285,6 +292,7 @@ fn merge_and_send_facet_docids<'t>(
     buffer: &mut Vec<u8>,
     docids_sender: impl DocidsSender + Sync,
 ) -> Result<()> {
+    let now = std::time::Instant::now();
     merger.into_iter().par_bridge().try_for_each(|(key, deladd)| {
         rtxn_pool.with(|rtxn| {
             let mut buffer = Vec::new();
@@ -301,7 +309,9 @@ fn merge_and_send_facet_docids<'t>(
             }
             Ok(())
         })
-    })
+    })?;
+    eprintln!("I took to merger hashmaps {:.2?}", now.elapsed());
+    Ok(())
 }
 
 struct FacetDatabases {