feat(sdk): add more timers to sync processing

crates/matrix-sdk-base/src/client.rs

@@ -24,6 +24,7 @@ use std::{
 use eyeball::{SharedObservable, Subscriber};
 use eyeball_im::{Vector, VectorDiff};
 use futures_util::Stream;
+use matrix_sdk_common::timer;
 #[cfg(feature = "e2e-encryption")]
 use matrix_sdk_crypto::{
     CollectStrategy, DecryptionSettings, EncryptionSettings, OlmError, OlmMachine,
@@ -1060,6 +1061,7 @@ impl BaseClient {
         &self,
         global_account_data_processor: &processors::account_data::Global,
     ) -> Result<Ruleset> {
+        let _timer = timer!(Level::TRACE, "get_push_rules");
         if let Some(event) = global_account_data_processor
             .push_rules()
             .and_then(|ev| ev.deserialize_as_unchecked::<PushRulesEvent>().ok())

crates/matrix-sdk-base/src/response_processors/account_data/global.rs

@@ -17,6 +17,7 @@ use std::{
     mem,
 };
 
+use matrix_sdk_common::timer;
 use ruma::{
     RoomId,
     events::{
@@ -43,6 +44,8 @@ pub struct Global {
 impl Global {
     /// Creates a new processor for global account data.
     fn process(events: &[Raw<AnyGlobalAccountDataEvent>]) -> Self {
+        let _timer = timer!(tracing::Level::TRACE, "Global::process (global account data)");
+
         let mut raw_by_type = BTreeMap::new();
         let mut parsed_events = Vec::new();
 
@@ -125,6 +128,8 @@ impl Global {
 
     /// Applies the processed data to the state changes and the state store.
     pub async fn apply(mut self, context: &mut Context, state_store: &BaseStateStore) {
+        let _timer = timer!(tracing::Level::TRACE, "Global::apply (global account data)");
+
         // Fill in the content of `changes.account_data`.
         mem::swap(&mut context.state_changes.account_data, &mut self.raw_by_type);
 

crates/matrix-sdk-base/src/response_processors/changes.rs

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 use eyeball::SharedObservable;
+use matrix_sdk_common::timer;
 use ruma::{
     events::{GlobalAccountDataEventType, ignored_user_list::IgnoredUserListEvent},
     serde::Raw,
@@ -29,6 +30,8 @@ use crate::{
 /// only! The changes aren't applied on the in-memory rooms.
 #[instrument(skip_all)]
 pub async fn save_only(context: Context, state_store: &BaseStateStore) -> Result<()> {
+    let _timer = timer!(tracing::Level::TRACE, "_method");
+
     save_changes(&context, state_store, None).await?;
     broadcast_room_info_notable_updates(&context, state_store);
 
@@ -44,6 +47,8 @@ pub async fn save_and_apply(
     ignore_user_list_changes: &SharedObservable<Vec<String>>,
     sync_token: Option<String>,
 ) -> Result<()> {
+    let _timer = timer!(tracing::Level::TRACE, "_method");
+
     trace!("ready to submit changes to store");
 
     let previous_ignored_user_list =

crates/matrix-sdk-base/src/response_processors/e2ee/tracked_users.rs

@@ -14,6 +14,7 @@
 
 use std::collections::BTreeSet;
 
+use matrix_sdk_common::timer;
 use matrix_sdk_crypto::OlmMachine;
 use ruma::{OwnedUserId, RoomId};
 
@@ -45,6 +46,8 @@ pub async fn update_or_set_if_room_is_newly_encrypted(
     room_id: &RoomId,
     state_store: &BaseStateStore,
 ) -> Result<()> {
+    let _timer = timer!(tracing::Level::TRACE, "update_or_set_if_room_is_newly_encrypted");
+
     if new_room_encryption_state.is_encrypted()
         && let Some(olm) = olm_machine
     {

crates/matrix-sdk-base/src/response_processors/room/display_name.rs

@@ -12,6 +12,8 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+use matrix_sdk_common::timer;
+
 use super::super::Context;
 use crate::{
     RoomInfoNotableUpdateReasons, room::UpdatedRoomDisplayName, store::BaseStateStore,
@@ -23,6 +25,8 @@ pub async fn update_for_rooms(
     room_updates: &RoomUpdates,
     state_store: &BaseStateStore,
 ) {
+    let _timer = timer!(tracing::Level::TRACE, "display_name::update_for_rooms");
+
     for room in room_updates.iter_all_room_ids().filter_map(|room_id| state_store.room(room_id)) {
         // Compute the display name. If it's different, let's register the `RoomInfo` in
         // the `StateChanges`.

crates/matrix-sdk-base/src/response_processors/room/msc4186/mod.rs

@@ -20,6 +20,7 @@ use std::collections::BTreeSet;
 
 #[cfg(feature = "e2e-encryption")]
 use matrix_sdk_common::deserialized_responses::TimelineEvent;
+use matrix_sdk_common::timer;
 use ruma::{
     JsOption, OwnedRoomId, RoomId, UserId,
     api::client::sync::sync_events::{
@@ -67,6 +68,8 @@ pub async fn update_any_room(
     #[cfg(feature = "e2e-encryption")] e2ee: e2ee::E2EE<'_>,
     notification: notification::Notification<'_>,
 ) -> Result<Option<(RoomInfo, RoomUpdateKind)>> {
+    let _timer = timer!(tracing::Level::TRACE, "update_any_room");
+
     let RoomCreationData {
         room_id,
         room_info_notable_update_sender,
@@ -438,6 +441,8 @@ pub(crate) async fn cache_latest_events(
         store::ambiguity_map::is_display_name_ambiguous,
     };
 
+    let _timer = timer!(tracing::Level::TRACE, "cache_latest_events");
+
     let mut encrypted_events =
         Vec::with_capacity(room.latest_encrypted_events.read().unwrap().capacity());
 

crates/matrix-sdk-base/src/response_processors/timeline.rs

@@ -12,7 +12,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
-use matrix_sdk_common::deserialized_responses::TimelineEvent;
+use matrix_sdk_common::{deserialized_responses::TimelineEvent, timer};
 #[cfg(feature = "e2e-encryption")]
 use ruma::events::SyncMessageLikeEvent;
 use ruma::{
@@ -44,6 +44,8 @@ pub async fn build<'notification, 'e2ee>(
     mut notification: notification::Notification<'notification>,
     #[cfg(feature = "e2e-encryption")] e2ee: e2ee::E2EE<'e2ee>,
 ) -> Result<Timeline> {
+    let _timer = timer!(tracing::Level::TRACE, "build a timeline from sync");
+
     let mut timeline = Timeline::new(timeline_inputs.limited, timeline_inputs.prev_batch);
     let mut push_condition_room_ctx = get_push_room_context(context, room, room_info).await?;
     let room_id = room.room_id();

crates/matrix-sdk-base/src/sliding_sync.rs

@@ -16,7 +16,7 @@
 
 #[cfg(feature = "e2e-encryption")]
 use matrix_sdk_common::deserialized_responses::ProcessedToDeviceEvent;
-use matrix_sdk_common::deserialized_responses::TimelineEvent;
+use matrix_sdk_common::{deserialized_responses::TimelineEvent, timer};
 use ruma::{OwnedRoomId, api::client::sync::sync_events::v5 as http};
 use tracing::{instrument, trace};
 
@@ -124,6 +124,8 @@ impl BaseClient {
             return Ok(SyncResponse::default());
         }
 
+        let _timer = timer!(tracing::Level::TRACE, "_method");
+
         let mut context = processors::Context::default();
 
         let state_store = self.state_store.clone();

crates/matrix-sdk-crypto/src/machine/mod.rs

@@ -31,7 +31,7 @@ use matrix_sdk_common::{
         UnsignedEventLocation, VerificationLevel, VerificationState,
     },
     locks::RwLock as StdRwLock,
-    BoxFuture,
+    timer, BoxFuture,
 };
 #[cfg(feature = "experimental-encrypted-state-events")]
 use ruma::events::{AnyStateEventContent, StateEventContent};
@@ -2203,6 +2203,8 @@ impl OlmMachine {
         decrypt_unsigned: bool,
         decryption_settings: &DecryptionSettings,
     ) -> MegolmResult<DecryptedRoomEvent> {
+        let _timer = timer!(tracing::Level::TRACE, "_method");
+
         let event = event.deserialize()?;
 
         Span::current()

crates/matrix-sdk/src/sliding_sync/client.rs

@@ -1,7 +1,7 @@
 use std::collections::BTreeSet;
 
 use matrix_sdk_base::{
-    sync::SyncResponse, RequestedRequiredStates, ThreadSubscriptionCatchupToken,
+    sync::SyncResponse, timer, RequestedRequiredStates, ThreadSubscriptionCatchupToken,
 };
 use matrix_sdk_common::deserialized_responses::ProcessedToDeviceEvent;
 use ruma::api::{
@@ -240,6 +240,8 @@ impl SlidingSyncResponseProcessor {
 ///
 /// This will only fill the in-memory caches, not save the info on disk.
 async fn update_in_memory_caches(client: &Client, response: &SyncResponse) -> Result<()> {
+    let _timer = timer!(tracing::Level::TRACE, "update_in_memory_caches");
+
     for room_id in response.rooms.joined.keys() {
         let Some(room) = client.get_room(room_id) else {
             error!(?room_id, "Cannot post process a room in sliding sync because it is missing");
@@ -258,6 +260,8 @@ async fn handle_receipts_extension(
     response: &http::Response,
     sync_response: &mut SyncResponse,
 ) -> Result<()> {
+    let _timer = timer!(tracing::Level::TRACE, "handle_receipts_extension");
+
     // We need to compute read receipts for each joined room that has received an
     // update, or from each room that has received a receipt ephemeral event.
     let room_ids = BTreeSet::from_iter(

crates/matrix-sdk/src/sync.rs

@@ -28,6 +28,7 @@ use matrix_sdk_base::{
     },
     sleep::sleep,
     sync::SyncResponse as BaseSyncResponse,
+    timer,
 };
 use matrix_sdk_common::deserialized_responses::ProcessedToDeviceEvent;
 use ruma::{
@@ -172,6 +173,8 @@ impl Client {
         &self,
         response: &BaseSyncResponse,
     ) -> Result<()> {
+        let _timer = timer!(tracing::Level::TRACE, "_method");
+
         let BaseSyncResponse { rooms, presence, account_data, to_device, notifications } = response;
 
         let now = Instant::now();