diff --git a/.github/workflows/test-suite.yml b/.github/workflows/test-suite.yml index e363d36c8..ed264592c 100644 --- a/.github/workflows/test-suite.yml +++ b/.github/workflows/test-suite.yml @@ -30,20 +30,20 @@ jobs: run: | apt-get update && apt-get install -y curl apt-get install build-essential -y - - name: Run test with Rust stable + - name: Setup test with Rust stable if: github.event_name != 'schedule' uses: actions-rs/toolchain@v1 with: toolchain: stable override: true - - name: Run test with Rust nightly + - name: Setup test with Rust nightly if: github.event_name == 'schedule' uses: actions-rs/toolchain@v1 with: toolchain: nightly override: true - name: Cache dependencies - uses: Swatinem/rust-cache@v2.4.0 + uses: Swatinem/rust-cache@v2.5.0 - name: Run cargo check without any default features uses: actions-rs/cargo@v1 with: @@ -65,7 +65,7 @@ jobs: steps: - uses: actions/checkout@v3 - name: Cache dependencies - uses: Swatinem/rust-cache@v2.4.0 + uses: Swatinem/rust-cache@v2.5.0 - name: Run cargo check without any default features uses: actions-rs/cargo@v1 with: @@ -117,17 +117,17 @@ jobs: run: | apt-get update apt-get install --assume-yes build-essential curl - - uses: actions-rs/toolchain@v1 - with: - toolchain: stable - override: true + - uses: actions-rs/toolchain@v1 + with: + toolchain: stable + override: true - name: Run cargo tree without default features and check lindera is not present run: | cargo tree -f '{p} {f}' -e normal --no-default-features | grep lindera -vqz - name: Run cargo tree with default features and check lindera is pressent run: | cargo tree -f '{p} {f}' -e normal | grep lindera -qz - + # We run tests in debug also, to make sure that the debug_assertions are hit test-debug: name: Run tests in debug @@ -146,7 +146,7 @@ jobs: toolchain: stable override: true - name: Cache dependencies - uses: Swatinem/rust-cache@v2.4.0 + uses: Swatinem/rust-cache@v2.5.0 - name: Run tests in debug uses: actions-rs/cargo@v1 with: @@ -165,7 +165,7 @@ jobs: override: true components: clippy - name: Cache dependencies - uses: Swatinem/rust-cache@v2.4.0 + uses: Swatinem/rust-cache@v2.5.0 - name: Run cargo clippy uses: actions-rs/cargo@v1 with: @@ -184,7 +184,7 @@ jobs: override: true components: rustfmt - name: Cache dependencies - uses: Swatinem/rust-cache@v2.4.0 + uses: Swatinem/rust-cache@v2.5.0 - name: Run cargo fmt # Since we never ran the `build.rs` script in the benchmark directory we are missing one auto-generated import file. # Since we want to trigger (and fail) this action as fast as possible, instead of building the benchmark crate diff --git a/Cargo.lock b/Cargo.lock index 4aa7c7b67..dd51e7b07 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -405,7 +405,7 @@ checksum = "16e62a023e7c117e27523144c5d2459f4397fcc3cab0085af8e2224f643a0193" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -416,7 +416,7 @@ checksum = "b9ccdd8f2a161be9bd5c023df56f1b2a0bd1d83872ae53b71a84a12c9bf6e842" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -603,7 +603,7 @@ checksum = "fdde5c9cd29ebd706ce1b35600920a33550e402fc998a2e53ad3b42c3c47a192" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -794,7 +794,7 @@ dependencies = [ "heck", "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -1336,7 +1336,7 @@ checksum = "eecf8589574ce9b895052fa12d69af7a233f99e6107f5cb8dd1044f2a17bfdcb" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -1537,7 +1537,7 @@ checksum = "89ca545a94061b6365f2c7355b4b32bd20df3ff95f02da9329b34ccc3bd6ee72" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -1912,6 +1912,7 @@ dependencies = [ "meilisearch-types", "nelson", "page_size 0.5.0", + "puffin", "roaring", "serde", "serde_json", @@ -2022,12 +2023,12 @@ dependencies = [ [[package]] name = "is-terminal" -version = "0.4.8" +version = "0.4.9" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "24fddda5af7e54bf7da53067d6e802dbcc381d0a8eef629df528e3ebf68755cb" +checksum = "cb0889898416213fab133e1d33a0e5858a48177452750691bde3666d0fdbaf8b" dependencies = [ "hermit-abi 0.3.1", - "rustix 0.38.2", + "rustix 0.38.4", "windows-sys 0.48.0", ] @@ -2397,9 +2398,9 @@ checksum = "ef53942eb7bf7ff43a617b3e2c1c4a5ecf5944a7c1bc12d7ee39bbb15e5c1519" [[package]] name = "linux-raw-sys" -version = "0.4.3" +version = "0.4.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "09fc20d2ca12cb9f044c93e3bd6d32d523e6e2ec3db4f7b2939cd99026ecd3f0" +checksum = "57bcfdad1b858c2db7c38303a6d2ad4dfaf5eb53dfeb0910128b2c26d6158503" [[package]] name = "lmdb-rkv-sys" @@ -2467,6 +2468,12 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "lz4_flex" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b8c72594ac26bfd34f2d99dfced2edfaddfe8a476e3ff2ca0eb293d925c4f83" + [[package]] name = "manifest-dir-macros" version = "0.1.17" @@ -2476,7 +2483,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -2556,6 +2563,8 @@ dependencies = [ "pin-project-lite", "platform-dirs", "prometheus", + "puffin", + "puffin_http", "rand", "rayon", "regex", @@ -2700,6 +2709,7 @@ dependencies = [ "obkv", "once_cell", "ordered-float", + "puffin", "rand", "rand_pcg", "rayon", @@ -3030,7 +3040,7 @@ dependencies = [ "pest_meta", "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -3175,9 +3185,9 @@ dependencies = [ [[package]] name = "proc-macro2" -version = "1.0.66" +version = "1.0.64" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "18fb31db3f9bddb2ea821cde30a9f70117e3f119938b5ee630b7403aa6e2ead9" +checksum = "78803b62cbf1f46fde80d7c0e803111524b9877184cfe7c3033659490ac7a7da" dependencies = [ "unicode-ident", ] @@ -3219,10 +3229,39 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "106dd99e98437432fed6519dedecfade6a06a73bb7b2a1e019fdd2bee5778d94" [[package]] -name = "quote" -version = "1.0.31" +name = "puffin" +version = "0.16.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5fe8a65d69dd0808184ebb5f836ab526bb259db23c657efa38711b1072ee47f0" +checksum = "76425abd4e1a0ad4bd6995dd974b52f414fca9974171df8e3708b3e660d05a21" +dependencies = [ + "anyhow", + "bincode", + "byteorder", + "cfg-if", + "instant", + "lz4_flex", + "once_cell", + "parking_lot", + "serde", +] + +[[package]] +name = "puffin_http" +version = "0.13.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "13bffc600c35913d282ae1e96a6ffcdf36dc7a7cdb9310e0ba15914d258c8193" +dependencies = [ + "anyhow", + "crossbeam-channel", + "log", + "puffin", +] + +[[package]] +name = "quote" +version = "1.0.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5907a1b7c277254a8b15170f6e7c97cfa60ee7872a3217663bb81151e48184bb" dependencies = [ "proc-macro2", ] @@ -3470,14 +3509,14 @@ dependencies = [ [[package]] name = "rustix" -version = "0.38.2" +version = "0.38.4" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "aabcb0461ebd01d6b79945797c27f8529082226cb630a9865a71870ff63532a4" +checksum = "0a962918ea88d644592894bc6dc55acc6c0956488adcebbfb6e273506b7fd6e5" dependencies = [ "bitflags 2.3.3", "errno", "libc", - "linux-raw-sys 0.4.3", + "linux-raw-sys 0.4.5", "windows-sys 0.48.0", ] @@ -3583,9 +3622,9 @@ checksum = "bebd363326d05ec3e2f532ab7660680f3b02130d780c299bca73469d521bc0ed" [[package]] name = "serde" -version = "1.0.171" +version = "1.0.180" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "30e27d1e4fd7659406c492fd6cfaf2066ba8773de45ca75e855590f856dc34a9" +checksum = "0ea67f183f058fe88a4e3ec6e2788e003840893b91bac4559cabedd00863b3ed" dependencies = [ "serde_derive", ] @@ -3610,20 +3649,20 @@ dependencies = [ [[package]] name = "serde_derive" -version = "1.0.171" +version = "1.0.180" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "389894603bd18c46fa56231694f8d827779c0951a667087194cf9de94ed24682" +checksum = "24e744d7782b686ab3b73267ef05697159cc0e5abbed3f47f9933165e5219036" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] name = "serde_json" -version = "1.0.103" +version = "1.0.104" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d03b412469450d4404fe8499a268edd7f8b79fecb074b0d812ad64ca21f4031b" +checksum = "076066c5f1078eac5b722a31827a8832fe108bed65dfa75e233c89f8206e976c" dependencies = [ "indexmap 2.0.0", "itoa", @@ -3833,9 +3872,9 @@ dependencies = [ [[package]] name = "syn" -version = "2.0.26" +version = "2.0.28" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "45c3457aacde3c65315de5031ec191ce46604304d2446e803d71ade03308d970" +checksum = "04361975b3f5e348b2189d8dc55bc942f278b2d482a6a0365de5bdd62d351567" dependencies = [ "proc-macro2", "quote", @@ -3922,22 +3961,22 @@ dependencies = [ [[package]] name = "thiserror" -version = "1.0.43" +version = "1.0.44" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a35fc5b8971143ca348fa6df4f024d4d55264f3468c71ad1c2f365b0a4d58c42" +checksum = "611040a08a0439f8248d1990b111c95baa9c704c805fa1f62104b39655fd7f90" dependencies = [ "thiserror-impl", ] [[package]] name = "thiserror-impl" -version = "1.0.43" +version = "1.0.44" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "463fe12d7993d3b327787537ce8dd4dfa058de32fc2b195ef3cde03dc4771e8f" +checksum = "090198534930841fab3a5d1bb637cde49e339654e606195f8d9c76eeb081dc96" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -4019,7 +4058,7 @@ checksum = "630bdcf245f78637c13ec01ffae6187cca34625e8c63150d424b59e55af2675e" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", ] [[package]] @@ -4344,7 +4383,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", "wasm-bindgen-shared", ] @@ -4378,7 +4417,7 @@ checksum = "e128beba882dd1eb6200e1dc92ae6c5dbaa4311aa7bb211ca035779e5efc39f8" dependencies = [ "proc-macro2", "quote", - "syn 2.0.26", + "syn 2.0.28", "wasm-bindgen-backend", "wasm-bindgen-shared", ] diff --git a/PROFILING.md b/PROFILING.md new file mode 100644 index 000000000..4ae21f2f5 --- /dev/null +++ b/PROFILING.md @@ -0,0 +1,19 @@ +# Profiling Meilisearch + +Search engine technologies are complex pieces of software that require thorough profiling tools. We chose to use [Puffin](https://github.com/EmbarkStudios/puffin), which the Rust gaming industry uses extensively. You can export and import the profiling reports using the top bar's _File_ menu options. + +![An example profiling with Puffin viewer](assets/profiling-example.png) + +## Profiling the Indexing Process + +When you enable the `profile-with-puffin` feature of Meilisearch, a Puffin HTTP server will run on Meilisearch and listen on the default _0.0.0.0:8585_ address. This server will record a "frame" whenever it executes the `IndexScheduler::tick` method. + +Once your Meilisearch is running and awaits new indexation operations, you must [install and run the `puffin_viewer` tool](https://github.com/EmbarkStudios/puffin/tree/main/puffin_viewer) to see the profiling results. I advise you to run the viewer with the `RUST_LOG=puffin_http::client=debug` environment variable to see the client trying to connect to your server. + +Another piece of advice on the Puffin viewer UI interface is to consider the _Merge children with same ID_ option. It can hide the exact actual timings at which events were sent. Please turn it off when you see strange gaps on the Flamegraph. It can help. + +## Profiling the Search Process + +We still need to take the time to profile the search side of the engine with Puffin. It would require time to profile the filtering phase, query parsing, creation, and execution. We could even profile the Actix HTTP server. + +The only issue we see is the framing system. Puffin requires a global frame-based profiling phase, which collides with Meilisearch's ability to accept and answer multiple requests on different threads simultaneously. diff --git a/assets/profiling-example.png b/assets/profiling-example.png new file mode 100644 index 000000000..44314581b Binary files /dev/null and b/assets/profiling-example.png differ diff --git a/benchmarks/Cargo.toml b/benchmarks/Cargo.toml index 330947b34..f30478a9e 100644 --- a/benchmarks/Cargo.toml +++ b/benchmarks/Cargo.toml @@ -14,7 +14,7 @@ license.workspace = true anyhow = "1.0.70" csv = "1.2.1" milli = { path = "../milli" } -mimalloc = { version = "0.1.36", default-features = false } +mimalloc = { version = "0.1.37", default-features = false } serde_json = { version = "1.0.95", features = ["preserve_order"] } [dev-dependencies] diff --git a/index-scheduler/Cargo.toml b/index-scheduler/Cargo.toml index 36c28cd67..9e7c2ae4b 100644 --- a/index-scheduler/Cargo.toml +++ b/index-scheduler/Cargo.toml @@ -22,6 +22,7 @@ log = "0.4.17" meilisearch-auth = { path = "../meilisearch-auth" } meilisearch-types = { path = "../meilisearch-types" } page_size = "0.5.0" +puffin = "0.16.0" roaring = { version = "0.10.1", features = ["serde"] } serde = { version = "1.0.160", features = ["derive"] } serde_json = { version = "1.0.95", features = ["preserve_order"] } diff --git a/index-scheduler/src/batch.rs b/index-scheduler/src/batch.rs index 2948e7506..fb865a98b 100644 --- a/index-scheduler/src/batch.rs +++ b/index-scheduler/src/batch.rs @@ -471,6 +471,8 @@ impl IndexScheduler { #[cfg(test)] self.maybe_fail(crate::tests::FailureLocation::InsideCreateBatch)?; + puffin::profile_function!(); + let enqueued = &self.get_status(rtxn, Status::Enqueued)?; let to_cancel = self.get_kind(rtxn, Kind::TaskCancelation)? & enqueued; @@ -575,6 +577,9 @@ impl IndexScheduler { self.maybe_fail(crate::tests::FailureLocation::PanicInsideProcessBatch)?; self.breakpoint(crate::Breakpoint::InsideProcessBatch); } + + puffin::profile_function!(format!("{:?}", batch)); + match batch { Batch::TaskCancelation { mut task, previous_started_at, previous_processing_tasks } => { // 1. Retrieve the tasks that matched the query at enqueue-time. @@ -1111,6 +1116,8 @@ impl IndexScheduler { index: &'i Index, operation: IndexOperation, ) -> Result> { + puffin::profile_function!(); + match operation { IndexOperation::DocumentClear { mut tasks, .. } => { let count = milli::update::ClearDocuments::new(index_wtxn, index).execute()?; diff --git a/index-scheduler/src/lib.rs b/index-scheduler/src/lib.rs index 9b921a756..b7b8685aa 100644 --- a/index-scheduler/src/lib.rs +++ b/index-scheduler/src/lib.rs @@ -1053,6 +1053,8 @@ impl IndexScheduler { self.breakpoint(Breakpoint::Start); } + puffin::GlobalProfiler::lock().new_frame(); + self.cleanup_task_queue()?; let rtxn = self.env.read_txn().map_err(Error::HeedTransaction)?; diff --git a/meilisearch/Cargo.toml b/meilisearch/Cargo.toml index 24a6fbd0f..d33f53906 100644 --- a/meilisearch/Cargo.toml +++ b/meilisearch/Cargo.toml @@ -58,7 +58,7 @@ lazy_static = "1.4.0" log = "0.4.17" meilisearch-auth = { path = "../meilisearch-auth" } meilisearch-types = { path = "../meilisearch-types" } -mimalloc = { version = "0.1.36", default-features = false } +mimalloc = { version = "0.1.37", default-features = false } mime = "0.3.17" num_cpus = "1.15.0" obkv = "0.2.0" @@ -69,6 +69,8 @@ permissive-json-pointer = { path = "../permissive-json-pointer" } pin-project-lite = "0.2.9" platform-dirs = "0.3.0" prometheus = { version = "0.13.3", features = ["process"] } +puffin = "0.16.0" +puffin_http = { version = "0.13.0", optional = true } rand = "0.8.5" rayon = "1.7.0" regex = "1.7.3" @@ -133,7 +135,18 @@ zip = { version = "0.6.4", optional = true } [features] default = ["analytics", "meilisearch-types/all-tokenizations", "mini-dashboard"] analytics = ["segment"] -mini-dashboard = ["actix-web-static-files", "static-files", "anyhow", "cargo_toml", "hex", "reqwest", "sha-1", "tempfile", "zip"] +profile-with-puffin = ["dep:puffin_http"] +mini-dashboard = [ + "actix-web-static-files", + "static-files", + "anyhow", + "cargo_toml", + "hex", + "reqwest", + "sha-1", + "tempfile", + "zip", +] chinese = ["meilisearch-types/chinese"] hebrew = ["meilisearch-types/hebrew"] japanese = ["meilisearch-types/japanese"] diff --git a/meilisearch/src/main.rs b/meilisearch/src/main.rs index 246d62c3b..a3905d451 100644 --- a/meilisearch/src/main.rs +++ b/meilisearch/src/main.rs @@ -30,6 +30,10 @@ fn setup(opt: &Opt) -> anyhow::Result<()> { async fn main() -> anyhow::Result<()> { let (opt, config_read_from) = Opt::try_build()?; + #[cfg(feature = "profile-with-puffin")] + let _server = puffin_http::Server::new(&format!("0.0.0.0:{}", puffin_http::DEFAULT_PORT))?; + puffin::set_scopes_on(cfg!(feature = "profile-with-puffin")); + anyhow::ensure!( !(cfg!(windows) && opt.experimental_reduce_indexing_memory_usage), "The `experimental-reduce-indexing-memory-usage` flag is not supported on Windows" diff --git a/milli/Cargo.toml b/milli/Cargo.toml index 4831ea990..7ad15aa64 100644 --- a/milli/Cargo.toml +++ b/milli/Cargo.toml @@ -65,13 +65,16 @@ filter-parser = { path = "../filter-parser" } # documents words self-join itertools = "0.10.5" +# profiling +puffin = "0.16.0" + # logging log = "0.4.17" logging_timer = "1.1.0" csv = "1.2.1" [dev-dependencies] -mimalloc = { version = "0.1.29", default-features = false } +mimalloc = { version = "0.1.37", default-features = false } big_s = "1.0.2" insta = "1.29.0" maplit = "1.0.2" diff --git a/milli/src/update/clear_documents.rs b/milli/src/update/clear_documents.rs index 2d2f78d5e..ab42fd854 100644 --- a/milli/src/update/clear_documents.rs +++ b/milli/src/update/clear_documents.rs @@ -15,6 +15,8 @@ impl<'t, 'u, 'i> ClearDocuments<'t, 'u, 'i> { } pub fn execute(self) -> Result { + puffin::profile_function!(); + self.index.set_updated_at(self.wtxn, &OffsetDateTime::now_utc())?; let Index { env: _env, diff --git a/milli/src/update/delete_documents.rs b/milli/src/update/delete_documents.rs index 01fc50a13..e23714530 100644 --- a/milli/src/update/delete_documents.rs +++ b/milli/src/update/delete_documents.rs @@ -109,6 +109,8 @@ impl<'t, 'u, 'i> DeleteDocuments<'t, 'u, 'i> { Some(docid) } pub fn execute(self) -> Result { + puffin::profile_function!(); + let DetailedDocumentDeletionResult { deleted_documents, remaining_documents } = self.execute_inner()?; diff --git a/milli/src/update/index_documents/enrich.rs b/milli/src/update/index_documents/enrich.rs index 09599ac82..35a7c33f3 100644 --- a/milli/src/update/index_documents/enrich.rs +++ b/milli/src/update/index_documents/enrich.rs @@ -31,6 +31,8 @@ pub fn enrich_documents_batch( autogenerate_docids: bool, reader: DocumentsBatchReader, ) -> Result, UserError>> { + puffin::profile_function!(); + let (mut cursor, mut documents_batch_index) = reader.into_cursor_and_fields_index(); let mut external_ids = tempfile::tempfile().map(grenad::Writer::new)?; diff --git a/milli/src/update/index_documents/extract/extract_docid_word_positions.rs b/milli/src/update/index_documents/extract/extract_docid_word_positions.rs index 8985534db..f726bf866 100644 --- a/milli/src/update/index_documents/extract/extract_docid_word_positions.rs +++ b/milli/src/update/index_documents/extract/extract_docid_word_positions.rs @@ -30,6 +30,8 @@ pub fn extract_docid_word_positions( stop_words: Option<&fst::Set<&[u8]>>, max_positions_per_attributes: Option, ) -> Result<(RoaringBitmap, grenad::Reader, ScriptLanguageDocidsMap)> { + puffin::profile_function!(); + let max_positions_per_attributes = max_positions_per_attributes .map_or(MAX_POSITION_PER_ATTRIBUTE, |max| max.min(MAX_POSITION_PER_ATTRIBUTE)); let max_memory = indexer.max_memory_by_thread(); diff --git a/milli/src/update/index_documents/extract/extract_facet_number_docids.rs b/milli/src/update/index_documents/extract/extract_facet_number_docids.rs index 33dd5ce5b..dec02b120 100644 --- a/milli/src/update/index_documents/extract/extract_facet_number_docids.rs +++ b/milli/src/update/index_documents/extract/extract_facet_number_docids.rs @@ -20,6 +20,8 @@ pub fn extract_facet_number_docids( docid_fid_facet_number: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut facet_number_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_facet_string_docids.rs b/milli/src/update/index_documents/extract/extract_facet_string_docids.rs index 0d9c0981e..e5e864b66 100644 --- a/milli/src/update/index_documents/extract/extract_facet_string_docids.rs +++ b/milli/src/update/index_documents/extract/extract_facet_string_docids.rs @@ -18,6 +18,8 @@ pub fn extract_facet_string_docids( docid_fid_facet_string: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut facet_string_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_fid_docid_facet_values.rs b/milli/src/update/index_documents/extract/extract_fid_docid_facet_values.rs index 77a5561fe..882d7779f 100644 --- a/milli/src/update/index_documents/extract/extract_fid_docid_facet_values.rs +++ b/milli/src/update/index_documents/extract/extract_fid_docid_facet_values.rs @@ -34,6 +34,8 @@ pub fn extract_fid_docid_facet_values( indexer: GrenadParameters, faceted_fields: &HashSet, ) -> Result { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut fid_docid_facet_numbers_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_fid_word_count_docids.rs b/milli/src/update/index_documents/extract/extract_fid_word_count_docids.rs index fe8eb93ed..79cf4c7fe 100644 --- a/milli/src/update/index_documents/extract/extract_fid_word_count_docids.rs +++ b/milli/src/update/index_documents/extract/extract_fid_word_count_docids.rs @@ -22,6 +22,8 @@ pub fn extract_fid_word_count_docids( docid_word_positions: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut fid_word_count_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_geo_points.rs b/milli/src/update/index_documents/extract/extract_geo_points.rs index ddb38abe5..139e8230a 100644 --- a/milli/src/update/index_documents/extract/extract_geo_points.rs +++ b/milli/src/update/index_documents/extract/extract_geo_points.rs @@ -19,6 +19,8 @@ pub fn extract_geo_points( primary_key_id: FieldId, (lat_fid, lng_fid): (FieldId, FieldId), ) -> Result> { + puffin::profile_function!(); + let mut writer = create_writer( indexer.chunk_compression_type, indexer.chunk_compression_level, diff --git a/milli/src/update/index_documents/extract/extract_vector_points.rs b/milli/src/update/index_documents/extract/extract_vector_points.rs index 0fad3be07..69fbff9b5 100644 --- a/milli/src/update/index_documents/extract/extract_vector_points.rs +++ b/milli/src/update/index_documents/extract/extract_vector_points.rs @@ -19,6 +19,8 @@ pub fn extract_vector_points( primary_key_id: FieldId, vectors_fid: FieldId, ) -> Result> { + puffin::profile_function!(); + let mut writer = create_writer( indexer.chunk_compression_type, indexer.chunk_compression_level, diff --git a/milli/src/update/index_documents/extract/extract_word_docids.rs b/milli/src/update/index_documents/extract/extract_word_docids.rs index da59f9dde..f1656d024 100644 --- a/milli/src/update/index_documents/extract/extract_word_docids.rs +++ b/milli/src/update/index_documents/extract/extract_word_docids.rs @@ -27,6 +27,8 @@ pub fn extract_word_docids( indexer: GrenadParameters, exact_attributes: &HashSet, ) -> Result<(grenad::Reader, grenad::Reader)> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut word_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_word_fid_docids.rs b/milli/src/update/index_documents/extract/extract_word_fid_docids.rs index 9ee33ea0d..aaf8fad79 100644 --- a/milli/src/update/index_documents/extract/extract_word_fid_docids.rs +++ b/milli/src/update/index_documents/extract/extract_word_fid_docids.rs @@ -15,6 +15,8 @@ pub fn extract_word_fid_docids( docid_word_positions: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut word_fid_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_word_pair_proximity_docids.rs b/milli/src/update/index_documents/extract/extract_word_pair_proximity_docids.rs index 6707fc268..4c910f32e 100644 --- a/milli/src/update/index_documents/extract/extract_word_pair_proximity_docids.rs +++ b/milli/src/update/index_documents/extract/extract_word_pair_proximity_docids.rs @@ -21,6 +21,8 @@ pub fn extract_word_pair_proximity_docids( docid_word_positions: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut word_pair_proximity_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/extract_word_position_docids.rs b/milli/src/update/index_documents/extract/extract_word_position_docids.rs index 9bb43b004..e945833e6 100644 --- a/milli/src/update/index_documents/extract/extract_word_position_docids.rs +++ b/milli/src/update/index_documents/extract/extract_word_position_docids.rs @@ -18,6 +18,8 @@ pub fn extract_word_position_docids( docid_word_positions: grenad::Reader, indexer: GrenadParameters, ) -> Result> { + puffin::profile_function!(); + let max_memory = indexer.max_memory_by_thread(); let mut word_position_docids_sorter = create_sorter( diff --git a/milli/src/update/index_documents/extract/mod.rs b/milli/src/update/index_documents/extract/mod.rs index 6259c7272..1b1dc1420 100644 --- a/milli/src/update/index_documents/extract/mod.rs +++ b/milli/src/update/index_documents/extract/mod.rs @@ -52,6 +52,8 @@ pub(crate) fn data_from_obkv_documents( max_positions_per_attributes: Option, exact_attributes: HashSet, ) -> Result<()> { + puffin::profile_function!(); + original_obkv_chunks .par_bridge() .map(|original_documents_chunk| { @@ -238,11 +240,13 @@ fn spawn_extraction_task( M::Output: Send, { rayon::spawn(move || { + puffin::profile_scope!("extract_multiple_chunks", name); let chunks: Result = chunks.into_par_iter().map(|chunk| extract_fn(chunk, indexer)).collect(); rayon::spawn(move || match chunks { Ok(chunks) => { debug!("merge {} database", name); + puffin::profile_scope!("merge_multiple_chunks", name); let reader = chunks.merge(merge_fn, &indexer); let _ = lmdb_writer_sx.send(reader.map(serialize_fn)); } diff --git a/milli/src/update/index_documents/helpers/grenad_helpers.rs b/milli/src/update/index_documents/helpers/grenad_helpers.rs index eb66a28fe..d5f5ac0bd 100644 --- a/milli/src/update/index_documents/helpers/grenad_helpers.rs +++ b/milli/src/update/index_documents/helpers/grenad_helpers.rs @@ -214,6 +214,7 @@ pub fn sorter_into_lmdb_database( sorter: Sorter, merge: MergeFn, ) -> Result<()> { + puffin::profile_function!(); debug!("Writing MTBL sorter..."); let before = Instant::now(); diff --git a/milli/src/update/index_documents/mod.rs b/milli/src/update/index_documents/mod.rs index 849e84035..cdb105788 100644 --- a/milli/src/update/index_documents/mod.rs +++ b/milli/src/update/index_documents/mod.rs @@ -137,6 +137,8 @@ where mut self, reader: DocumentsBatchReader, ) -> Result<(Self, StdResult)> { + puffin::profile_function!(); + // Early return when there is no document to add if reader.is_empty() { return Ok((self, Ok(0))); @@ -175,6 +177,8 @@ where mut self, to_delete: Vec, ) -> Result<(Self, StdResult)> { + puffin::profile_function!(); + // Early return when there is no document to add if to_delete.is_empty() { return Ok((self, Ok(0))); @@ -194,6 +198,8 @@ where #[logging_timer::time("IndexDocuments::{}")] pub fn execute(mut self) -> Result { + puffin::profile_function!(); + if self.added_documents == 0 { let number_of_documents = self.index.number_of_documents(self.wtxn)?; return Ok(DocumentAdditionResult { indexed_documents: 0, number_of_documents }); @@ -232,6 +238,8 @@ where FP: Fn(UpdateIndexingStep) + Sync, FA: Fn() -> bool + Sync, { + puffin::profile_function!(); + let TransformOutput { primary_key, fields_ids_map, @@ -322,6 +330,7 @@ where // Run extraction pipeline in parallel. pool.install(|| { + puffin::profile_scope!("extract_and_send_grenad_chunks"); // split obkv file into several chunks let original_chunk_iter = grenad_obkv_into_chunks(original_documents, pool_params, documents_chunk_size); @@ -477,6 +486,8 @@ where FP: Fn(UpdateIndexingStep) + Sync, FA: Fn() -> bool + Sync, { + puffin::profile_function!(); + // Merged databases are already been indexed, we start from this count; let mut databases_seen = MERGED_DATABASE_COUNT; @@ -511,26 +522,36 @@ where return Err(Error::InternalError(InternalError::AbortedIndexation)); } - let current_prefix_fst = self.index.words_prefixes_fst(self.wtxn)?; + let current_prefix_fst; + let common_prefix_fst_words_tmp; + let common_prefix_fst_words: Vec<_>; + let new_prefix_fst_words; + let del_prefix_fst_words; - // We retrieve the common words between the previous and new prefix word fst. - let common_prefix_fst_words = fst_stream_into_vec( - previous_words_prefixes_fst.op().add(¤t_prefix_fst).intersection(), - ); - let common_prefix_fst_words: Vec<_> = common_prefix_fst_words - .as_slice() - .linear_group_by_key(|x| x.chars().next().unwrap()) - .collect(); + { + puffin::profile_scope!("compute_prefix_diffs"); - // We retrieve the newly added words between the previous and new prefix word fst. - let new_prefix_fst_words = fst_stream_into_vec( - current_prefix_fst.op().add(&previous_words_prefixes_fst).difference(), - ); + current_prefix_fst = self.index.words_prefixes_fst(self.wtxn)?; - // We compute the set of prefixes that are no more part of the prefix fst. - let del_prefix_fst_words = fst_stream_into_hashset( - previous_words_prefixes_fst.op().add(¤t_prefix_fst).difference(), - ); + // We retrieve the common words between the previous and new prefix word fst. + common_prefix_fst_words_tmp = fst_stream_into_vec( + previous_words_prefixes_fst.op().add(¤t_prefix_fst).intersection(), + ); + common_prefix_fst_words = common_prefix_fst_words_tmp + .as_slice() + .linear_group_by_key(|x| x.chars().next().unwrap()) + .collect(); + + // We retrieve the newly added words between the previous and new prefix word fst. + new_prefix_fst_words = fst_stream_into_vec( + current_prefix_fst.op().add(&previous_words_prefixes_fst).difference(), + ); + + // We compute the set of prefixes that are no more part of the prefix fst. + del_prefix_fst_words = fst_stream_into_hashset( + previous_words_prefixes_fst.op().add(¤t_prefix_fst).difference(), + ); + } databases_seen += 1; (self.progress)(UpdateIndexingStep::MergeDataIntoFinalDatabase { @@ -668,6 +689,8 @@ fn execute_word_prefix_docids( common_prefix_fst_words: &[&[String]], del_prefix_fst_words: &HashSet>, ) -> Result<()> { + puffin::profile_function!(); + let cursor = reader.into_cursor()?; let mut builder = WordPrefixDocids::new(txn, word_docids_db, word_prefix_docids_db); builder.chunk_compression_type = indexer_config.chunk_compression_type; diff --git a/milli/src/update/index_documents/transform.rs b/milli/src/update/index_documents/transform.rs index ee6831be5..7a0c811a8 100644 --- a/milli/src/update/index_documents/transform.rs +++ b/milli/src/update/index_documents/transform.rs @@ -558,6 +558,8 @@ impl<'a, 'i> Transform<'a, 'i> { where F: Fn(UpdateIndexingStep) + Sync, { + puffin::profile_function!(); + let primary_key = self .index .primary_key(wtxn)? diff --git a/milli/src/update/index_documents/typed_chunk.rs b/milli/src/update/index_documents/typed_chunk.rs index 921ce4ecd..788aaf93d 100644 --- a/milli/src/update/index_documents/typed_chunk.rs +++ b/milli/src/update/index_documents/typed_chunk.rs @@ -46,6 +46,66 @@ pub(crate) enum TypedChunk { ScriptLanguageDocids(HashMap<(Script, Language), RoaringBitmap>), } +impl TypedChunk { + pub fn to_debug_string(&self) -> String { + match self { + TypedChunk::FieldIdDocidFacetStrings(grenad) => { + format!("FieldIdDocidFacetStrings {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdDocidFacetNumbers(grenad) => { + format!("FieldIdDocidFacetNumbers {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::Documents(grenad) => { + format!("Documents {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdWordcountDocids(grenad) => { + format!("FieldIdWordcountDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::NewDocumentsIds(grenad) => { + format!("NewDocumentsIds {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::WordDocids { word_docids_reader, exact_word_docids_reader } => format!( + "WordDocids {{ word_docids_reader: {}, exact_word_docids_reader: {} }}", + word_docids_reader.len(), + exact_word_docids_reader.len() + ), + TypedChunk::WordPositionDocids(grenad) => { + format!("WordPositionDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::WordFidDocids(grenad) => { + format!("WordFidDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::WordPairProximityDocids(grenad) => { + format!("WordPairProximityDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdFacetStringDocids(grenad) => { + format!("FieldIdFacetStringDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdFacetNumberDocids(grenad) => { + format!("FieldIdFacetNumberDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdFacetExistsDocids(grenad) => { + format!("FieldIdFacetExistsDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdFacetIsNullDocids(grenad) => { + format!("FieldIdFacetIsNullDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::FieldIdFacetIsEmptyDocids(grenad) => { + format!("FieldIdFacetIsEmptyDocids {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::GeoPoints(grenad) => { + format!("GeoPoints {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::VectorPoints(grenad) => { + format!("VectorPoints {{ number_of_entries: {} }}", grenad.len()) + } + TypedChunk::ScriptLanguageDocids(grenad) => { + format!("ScriptLanguageDocids {{ number_of_entries: {} }}", grenad.len()) + } + } + } +} + /// Write typed chunk in the corresponding LMDB database of the provided index. /// Return new documents seen. pub(crate) fn write_typed_chunk_into_index( @@ -54,6 +114,8 @@ pub(crate) fn write_typed_chunk_into_index( wtxn: &mut RwTxn, index_is_empty: bool, ) -> Result<(RoaringBitmap, bool)> { + puffin::profile_function!(typed_chunk.to_debug_string()); + let mut is_merged_database = false; match typed_chunk { TypedChunk::Documents(obkv_documents_iter) => { @@ -350,6 +412,8 @@ where FS: for<'a> Fn(&'a [u8], &'a mut Vec) -> Result<&'a [u8]>, FM: Fn(&[u8], &[u8], &mut Vec) -> Result<()>, { + puffin::profile_function!(format!("number of entries: {}", data.len())); + let mut buffer = Vec::new(); let database = database.remap_types::(); @@ -392,6 +456,8 @@ where FS: for<'a> Fn(&'a [u8], &'a mut Vec) -> Result<&'a [u8]>, FM: Fn(&[u8], &[u8], &mut Vec) -> Result<()>, { + puffin::profile_function!(format!("number of entries: {}", data.len())); + if !index_is_empty { return write_entries_into_database( data, diff --git a/milli/src/update/prefix_word_pairs/mod.rs b/milli/src/update/prefix_word_pairs/mod.rs index bed542bdb..3105b16e4 100644 --- a/milli/src/update/prefix_word_pairs/mod.rs +++ b/milli/src/update/prefix_word_pairs/mod.rs @@ -50,6 +50,8 @@ impl<'t, 'u, 'i> PrefixWordPairsProximityDocids<'t, 'u, 'i> { common_prefix_fst_words: &[&'a [String]], del_prefix_fst_words: &HashSet>, ) -> Result<()> { + puffin::profile_function!(); + index_word_prefix_database( self.wtxn, self.index.word_pair_proximity_docids, diff --git a/milli/src/update/prefix_word_pairs/prefix_word.rs b/milli/src/update/prefix_word_pairs/prefix_word.rs index 60e2e554e..1ec66d010 100644 --- a/milli/src/update/prefix_word_pairs/prefix_word.rs +++ b/milli/src/update/prefix_word_pairs/prefix_word.rs @@ -27,6 +27,8 @@ pub fn index_prefix_word_database( chunk_compression_type: CompressionType, chunk_compression_level: Option, ) -> Result<()> { + puffin::profile_function!(); + let max_proximity = max_proximity - 1; debug!("Computing and writing the word prefix pair proximity docids into LMDB on disk..."); diff --git a/milli/src/update/prefix_word_pairs/word_prefix.rs b/milli/src/update/prefix_word_pairs/word_prefix.rs index db607e56c..570adece9 100644 --- a/milli/src/update/prefix_word_pairs/word_prefix.rs +++ b/milli/src/update/prefix_word_pairs/word_prefix.rs @@ -191,6 +191,7 @@ pub fn index_word_prefix_database( chunk_compression_type: CompressionType, chunk_compression_level: Option, ) -> Result<()> { + puffin::profile_function!(); debug!("Computing and writing the word prefix pair proximity docids into LMDB on disk..."); // Make a prefix trie from the common prefixes that are shorter than self.max_prefix_length diff --git a/milli/src/update/settings.rs b/milli/src/update/settings.rs index 33f86a4bb..86e6e0500 100644 --- a/milli/src/update/settings.rs +++ b/milli/src/update/settings.rs @@ -303,6 +303,8 @@ impl<'a, 't, 'u, 'i> Settings<'a, 't, 'u, 'i> { FP: Fn(UpdateIndexingStep) + Sync, FA: Fn() -> bool + Sync, { + puffin::profile_function!(); + let fields_ids_map = self.index.fields_ids_map(self.wtxn)?; // if the settings are set before any document update, we don't need to do anything, and // will set the primary key during the first document addition. diff --git a/milli/src/update/word_prefix_docids.rs b/milli/src/update/word_prefix_docids.rs index b235c44a6..a30254994 100644 --- a/milli/src/update/word_prefix_docids.rs +++ b/milli/src/update/word_prefix_docids.rs @@ -45,6 +45,8 @@ impl<'t, 'u, 'i> WordPrefixDocids<'t, 'u, 'i> { common_prefix_fst_words: &[&[String]], del_prefix_fst_words: &HashSet>, ) -> Result<()> { + puffin::profile_function!(); + // It is forbidden to keep a mutable reference into the database // and write into it at the same time, therefore we write into another file. let mut prefix_docids_sorter = create_sorter( diff --git a/milli/src/update/words_prefix_integer_docids.rs b/milli/src/update/words_prefix_integer_docids.rs index 63ca178ef..c65438928 100644 --- a/milli/src/update/words_prefix_integer_docids.rs +++ b/milli/src/update/words_prefix_integer_docids.rs @@ -50,6 +50,7 @@ impl<'t, 'u, 'i> WordPrefixIntegerDocids<'t, 'u, 'i> { common_prefix_fst_words: &[&[String]], del_prefix_fst_words: &HashSet>, ) -> Result<()> { + puffin::profile_function!(); debug!("Computing and writing the word levels integers docids into LMDB on disk..."); let mut prefix_integer_docids_sorter = create_sorter( diff --git a/milli/src/update/words_prefixes_fst.rs b/milli/src/update/words_prefixes_fst.rs index 57fed0922..121b45c4a 100644 --- a/milli/src/update/words_prefixes_fst.rs +++ b/milli/src/update/words_prefixes_fst.rs @@ -42,6 +42,8 @@ impl<'t, 'u, 'i> WordsPrefixesFst<'t, 'u, 'i> { #[logging_timer::time("WordsPrefixesFst::{}")] pub fn execute(self) -> Result<()> { + puffin::profile_function!(); + let words_fst = self.index.words_fst(self.wtxn)?; let mut current_prefix = vec![SmallString32::new(); self.max_prefix_length];