Slow Build Times
Versions/Environment
-
Rustc / Os rustc 1.77.2 (25ef9e3d8 2024-04-09) Host: x86_64-unknown-linux-gnu Target: x86_64-unknown-linux-gnu
-
What versions of the driver and its dependencies are you using?
registry+https://github.com/rust-lang/crates.io-index#[email protected] registry+https://github.com/rust-lang/crates.io-index#[email protected]
- What version of MongoDB are you using? (Check with the MongoDB shell using
db.version())
N/A
- What is your MongoDB topology (standalone, replica set, sharded cluster, serverless)?
N/A
Describe the bug
Large codegen slowing down builds causing long linking times.
Running cargo build --timings shows mongodb takes roughly 20s of a 70s build and is not executed in parallel.
Running cargo llvm-lines
Shows that bson serde implementation is generating a wildly large amount of LLVM IR.
Lines Copies Function name
----- ------ -------------
3466340 76515 (TOTAL)
125174 (3.6%, 3.6%) 84 (0.1%, 0.1%) bson::de::raw::Deserializer::deserialize_next
54462 (1.6%, 5.2%) 124 (0.2%, 0.3%) bson::de::serde::Deserializer::deserialize_next
48905 (1.4%, 6.6%) 320 (0.4%, 0.7%) bson::de::raw::DocumentAccess::read
46484 (1.3%, 7.9%) 914 (1.2%, 1.9%) std::panicking::try
44157 (1.3%, 9.2%) 123 (0.2%, 2.0%) alloc::raw_vec::RawVec<T,A>::grow_amortized
41480 (1.2%, 10.4%) 34 (0.0%, 2.1%) <&mut bson::ser::raw::value_serializer::ValueSerializer as serde::ser::SerializeStruct>::serialize_field
38171 (1.1%, 11.5%) 447 (0.6%, 2.7%) <alloc::boxed::Box<T,A> as core::ops::drop::Drop>::drop
35217 (1.0%, 12.5%) 235 (0.3%, 3.0%) bson::de::raw::Deserializer::access_document
33818 (1.0%, 13.5%) 914 (1.2%, 4.2%) std::panicking::try::do_catch
26409 (0.8%, 14.3%) 182 (0.2%, 4.4%) tokio::runtime::task::core::Cell<T,S>::new
25431 (0.7%, 15.0%) 650 (0.8%, 5.3%) tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
23734 (0.7%, 15.7%) 110 (0.1%, 5.4%) bson::de::raw::Deserializer::deserialize_document
23569 (0.7%, 16.4%) 867 (1.1%, 6.5%) <core::result::Result<T,E> as core::ops::try_trait::Try>::branch
22956 (0.7%, 17.0%) 182 (0.2%, 6.8%) tokio::runtime::task::harness::poll_future
22484 (0.6%, 17.7%) 914 (1.2%, 8.0%) std::panicking::try::do_call
21999 (0.6%, 18.3%) 1295 (1.7%, 9.7%) core::ops::function::FnOnce::call_once
21816 (0.6%, 18.9%) 96 (0.1%, 9.8%) <shared::database::types::role::permissions::_::<impl serde::de::Deserialize for shared::database::types::role::permissions::AllowDeny<T>>::deserialize::__Visitor<T> as serde::de::Visitor>::visit_map
21776 (0.6%, 19.6%) 636 (0.8%, 10.6%) serde::de::Visitor::visit_map
20968 (0.6%, 20.2%) 220 (0.3%, 10.9%) <shared::database::id::Id<S> as serde::de::Deserialize>::deserialize
19675 (0.6%, 20.7%) 12 (0.0%, 10.9%) <shared::database::types::product::_::<impl serde::de::Deserialize for shared::database::types::product::Product>::deserialize::__Visitor as serde::de::Visitor>::visit_map
18661 (0.5%, 21.3%) 152 (0.2%, 11.1%) bson::de::raw::CodeWithScopeDeserializer::read
18395 (0.5%, 21.8%) 490 (0.6%, 11.8%) core::result::Result<T,E>::map_err
18056 (0.5%, 22.3%) 7 (0.0%, 11.8%) mongodb::client::executor::<impl mongodb::client::Client>::execute_operation_on_connection::{{closure}}
17649 (0.5%, 22.8%) 146 (0.2%, 12.0%) std::thread::local::LocalKey<T>::try_with
17035 (0.5%, 23.3%) 12 (0.0%, 12.0%) <shared::database::types::role::_::<impl serde::de::Deserialize for shared::database::types::role::Role>::deserialize::__Visitor as serde::de::Visitor>::visit_map
16591 (0.5%, 23.8%) 12 (0.0%, 12.0%) <shared::database::types::user::_::<impl serde::de::Deserialize for shared::database::types::user::User>::deserialize::__Visitor as serde::de::Visitor>::visit_map
16586 (0.5%, 24.3%) 424 (0.6%, 12.5%) core::result::Result<T,E>::map
16518 (0.5%, 24.8%) 7 (0.0%, 12.6%) mongodb::client::executor::<impl mongodb::client::Client>::execute_operation_with_retry::{{closure}}
14913 (0.4%, 25.2%) 385 (0.5%, 13.1%) core::option::Option<T>::map
14815 (0.4%, 25.6%) 12 (0.0%, 13.1%) <shared::database::types::role::permissions::_::<impl serde::de::Deserialize for shared::database::types::role::permissions::Permissions>::deserialize::__Visitor as serde::de::Visitor>::visit_map
14566 (0.4%, 26.0%) 114 (0.1%, 13.2%) <bson::de::raw::DocumentAccess as serde::de::SeqAccess>::next_element_seed
Perhaps an investigation into why this is the case is in order.
I am unsure if this is normal behavior or not I just noticed on my 128core build machine that im spending roughly 20s building mongodb alone and 40s linking a binary in a debug build. (the total build time is 70s). I know that not all of that build time / linking time is cause by this repo and is likely caused by other dependencies in the tree. I am opening this issue here because of the strange build timings output where mongodb is not being compiled in parallel and because of llvm-lines showing bson producing exorbitant amounts of LLVM-IR which I think is the leading contributor to the slow build times I am facing.
Hey @TroyKomodo, thanks for opening this issue! Slow build times are a known issue both for the driver (RUST-1558) and serde more generally (https://github.com/serde-rs/serde/issues/1146). We don't have the bandwidth to dig into this more right now, but we do have a project slated for later this year for making some improvements to the BSON library, so I will make sure we consider this as part of that work. Feel free to follow the Jira ticket I linked for more updates.
There has not been any recent activity on this ticket, so we are marking it as stale. If we do not hear anything further from you, this issue will be automatically closed in one week.
There has not been any recent activity on this ticket, so we are closing it. Thanks for reaching out and please feel free to file a new issue if you have further questions.