Slow Build Times

[TroyKomodo]

Versions/Environment

1. Rustc / Os
   rustc 1.77.2 (25ef9e3d8 2024-04-09)
   Host: x86_64-unknown-linux-gnu
   Target: x86_64-unknown-linux-gnu

2. 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]

3. What version of MongoDB are you using? (Check with the MongoDB shell using db.version())

N/A

4. 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.

[isabelatkinson]

Hey @TroyKomodo, thanks for opening this issue! Slow build times are a known issue both for the driver (RUST-1558) and serde more generally (serde-rs/serde#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.

[github-actions]

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.

[github-actions]

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.