Tracing span adjustments for ret verbosity.

Signed-off-by: Jason Volk <jason@zemos.net>
This commit is contained in:
Jason Volk
2025-10-27 14:56:04 +00:00
parent f660e00bb5
commit e191730950
5 changed files with 32 additions and 18 deletions

View File

@@ -45,8 +45,6 @@ where
Fut: Future<Output = Result<Pdu>> + Send, Fut: Future<Output = Result<Pdu>> + Send,
Pdu: Event, Pdu: Event,
{ {
debug!("starting m.room.member check");
// Since v1, if there is no state_key property, or no membership property in // Since v1, if there is no state_key property, or no membership property in
// content, reject. // content, reject.
let Some(state_key) = room_member_event.state_key() else { let Some(state_key) = room_member_event.state_key() else {

View File

@@ -25,6 +25,7 @@ use super::test_utils;
use crate::{ use crate::{
Result, debug, Result, debug,
matrix::{Event, TypeStateKey}, matrix::{Event, TypeStateKey},
trace,
utils::stream::{BroadbandExt, IterStream}, utils::stream::{BroadbandExt, IterStream},
}; };
@@ -87,7 +88,7 @@ where
// Split the unconflicted state map and the conflicted state set. // Split the unconflicted state map and the conflicted state set.
let (unconflicted_state, conflicted_states) = split_conflicted_state(state_maps).await; let (unconflicted_state, conflicted_states) = split_conflicted_state(state_maps).await;
debug!(?unconflicted_state, unconflicted = unconflicted_state.len(), "unresolved state"); trace!(?unconflicted_state, unconflicted = unconflicted_state.len(), "unresolved state");
debug!(?conflicted_states, conflicted = conflicted_states.len(), "unresolved states"); debug!(?conflicted_states, conflicted = conflicted_states.len(), "unresolved states");
if conflicted_states.is_empty() { if conflicted_states.is_empty() {
@@ -120,7 +121,7 @@ where
.chain(conflicted_subgraph) .chain(conflicted_subgraph)
.collect::<AuthSet<_>>() .collect::<AuthSet<_>>()
.inspect(|set| debug!(count = set.len(), "full conflicted set")) .inspect(|set| debug!(count = set.len(), "full conflicted set"))
.inspect(|set| debug!(?set, "full conflicted set")) .inspect(|set| trace!(?set, "full conflicted set"))
.await; .await;
// 1. Select the set X of all power events that appear in the full conflicted // 1. Select the set X of all power events that appear in the full conflicted
@@ -129,7 +130,7 @@ where
// a list using the reverse topological power ordering. // a list using the reverse topological power ordering.
let sorted_power_events: Vec<_> = power_sort(rules, &full_conflicted_set, fetch) let sorted_power_events: Vec<_> = power_sort(rules, &full_conflicted_set, fetch)
.inspect_ok(|list| debug!(count = list.len(), "sorted power events")) .inspect_ok(|list| debug!(count = list.len(), "sorted power events"))
.inspect_ok(|list| debug!(?list, "sorted power events")) .inspect_ok(|list| trace!(?list, "sorted power events"))
.await?; .await?;
let sorted_power_events_set: AuthSet<_> = sorted_power_events.iter().collect(); let sorted_power_events_set: AuthSet<_> = sorted_power_events.iter().collect();
@@ -154,7 +155,7 @@ where
let partially_resolved_state = let partially_resolved_state =
iterative_auth_check(rules, sorted_power_events, initial_state, fetch) iterative_auth_check(rules, sorted_power_events, initial_state, fetch)
.inspect_ok(|map| debug!(count = map.len(), "partially resolved power state")) .inspect_ok(|map| debug!(count = map.len(), "partially resolved power state"))
.inspect_ok(|map| debug!(?map, "partially resolved power state")) .inspect_ok(|map| trace!(?map, "partially resolved power state"))
.await?; .await?;
// This "epochs" power level event // This "epochs" power level event
@@ -168,7 +169,7 @@ where
.collect(); .collect();
debug!(count = remaining_events.len(), "remaining events"); debug!(count = remaining_events.len(), "remaining events");
debug!(list = ?remaining_events, "remaining events"); trace!(list = ?remaining_events, "remaining events");
let have_remaining_events = !remaining_events.is_empty(); let have_remaining_events = !remaining_events.is_empty();
let remaining_events = remaining_events let remaining_events = remaining_events
@@ -188,7 +189,7 @@ where
.unwrap_or(Ok(Vec::new()))?; .unwrap_or(Ok(Vec::new()))?;
debug!(count = sorted_remaining_events.len(), "sorted remaining events"); debug!(count = sorted_remaining_events.len(), "sorted remaining events");
debug!(list = ?sorted_remaining_events, "sorted remaining events"); trace!(list = ?sorted_remaining_events, "sorted remaining events");
let sorted_remaining_events = sorted_remaining_events let sorted_remaining_events = sorted_remaining_events
.iter() .iter()
@@ -207,7 +208,7 @@ where
resolved_state.extend(unconflicted_state); resolved_state.extend(unconflicted_state);
debug!(resolved_state = resolved_state.len(), "resolved state"); debug!(resolved_state = resolved_state.len(), "resolved state");
debug!(?resolved_state, "resolved state"); trace!(?resolved_state, "resolved state");
Ok(resolved_state) Ok(resolved_state)
} }

View File

@@ -130,7 +130,12 @@ impl Service {
} }
/// Returns the private read marker PDU count. /// Returns the private read marker PDU count.
#[tracing::instrument(skip(self), level = "debug", name = "get_private_count", ret)] #[tracing::instrument(
name = "get_private_count",
level = "debug",
skip(self),
ret(level = "trace")
)]
pub async fn private_read_get_count( pub async fn private_read_get_count(
&self, &self,
room_id: &RoomId, room_id: &RoomId,
@@ -142,14 +147,24 @@ impl Service {
} }
/// Returns the PDU count of the last typing update in this room. /// Returns the PDU count of the last typing update in this room.
#[tracing::instrument(skip(self), level = "debug", name = "get_private_last", ret)] #[tracing::instrument(
name = "get_private_last",
level = "debug",
skip(self),
ret(level = "trace")
)]
pub async fn last_privateread_update(&self, user_id: &UserId, room_id: &RoomId) -> u64 { pub async fn last_privateread_update(&self, user_id: &UserId, room_id: &RoomId) -> u64 {
self.db self.db
.last_privateread_update(user_id, room_id) .last_privateread_update(user_id, room_id)
.await .await
} }
#[tracing::instrument(skip(self), level = "debug", name = "get_receipt_last", ret)] #[tracing::instrument(
name = "get_receipt_last",
level = "debug",
skip(self),
ret(level = "trace")
)]
pub async fn last_receipt_count( pub async fn last_receipt_count(
&self, &self,
room_id: &RoomId, room_id: &RoomId,

View File

@@ -471,7 +471,7 @@ pub async fn get_room_version_rules(&self, room_id: &RoomId) -> Result<RoomVersi
#[tracing::instrument( #[tracing::instrument(
level = "debug" level = "debug"
skip(self), skip(self),
ret, ret(level = "trace"),
)] )]
pub async fn get_room_version(&self, room_id: &RoomId) -> Result<RoomVersionId> { pub async fn get_room_version(&self, room_id: &RoomId) -> Result<RoomVersionId> {
self.services self.services
@@ -488,7 +488,7 @@ pub async fn get_room_version(&self, room_id: &RoomId) -> Result<RoomVersionId>
#[tracing::instrument( #[tracing::instrument(
level = "debug" level = "debug"
skip(self), skip(self),
ret, ret(level = "trace"),
)] )]
pub async fn get_room_shortstatehash(&self, room_id: &RoomId) -> Result<ShortStateHash> { pub async fn get_room_shortstatehash(&self, room_id: &RoomId) -> Result<ShortStateHash> {
self.db self.db
@@ -513,7 +513,7 @@ pub async fn pdu_shortstatehash(&self, event_id: &EventId) -> Result<ShortStateH
#[tracing::instrument( #[tracing::instrument(
level = "debug" level = "debug"
skip(self), skip(self),
ret, ret(level = "trace"),
)] )]
pub async fn get_shortstatehash(&self, shorteventid: ShortEventId) -> Result<ShortStateHash> { pub async fn get_shortstatehash(&self, shorteventid: ShortEventId) -> Result<ShortStateHash> {
const BUFSIZE: usize = size_of::<ShortEventId>(); const BUFSIZE: usize = size_of::<ShortEventId>();

View File

@@ -54,7 +54,7 @@ pub fn reset_notification_counts(&self, user_id: &UserId, room_id: &RoomId) {
} }
#[implement(Service)] #[implement(Service)]
#[tracing::instrument(level = "debug", skip(self), ret)] #[tracing::instrument(level = "debug", skip(self), ret(level = "trace"))]
pub async fn notification_count(&self, user_id: &UserId, room_id: &RoomId) -> u64 { pub async fn notification_count(&self, user_id: &UserId, room_id: &RoomId) -> u64 {
let key = (user_id, room_id); let key = (user_id, room_id);
self.db self.db
@@ -66,7 +66,7 @@ pub async fn notification_count(&self, user_id: &UserId, room_id: &RoomId) -> u6
} }
#[implement(Service)] #[implement(Service)]
#[tracing::instrument(level = "debug", skip(self), ret)] #[tracing::instrument(level = "debug", skip(self), ret(level = "trace"))]
pub async fn highlight_count(&self, user_id: &UserId, room_id: &RoomId) -> u64 { pub async fn highlight_count(&self, user_id: &UserId, room_id: &RoomId) -> u64 {
let key = (user_id, room_id); let key = (user_id, room_id);
self.db self.db
@@ -78,7 +78,7 @@ pub async fn highlight_count(&self, user_id: &UserId, room_id: &RoomId) -> u64 {
} }
#[implement(Service)] #[implement(Service)]
#[tracing::instrument(level = "debug", skip(self), ret)] #[tracing::instrument(level = "debug", skip(self), ret(level = "trace"))]
pub async fn last_notification_read(&self, user_id: &UserId, room_id: &RoomId) -> u64 { pub async fn last_notification_read(&self, user_id: &UserId, room_id: &RoomId) -> u64 {
let key = (room_id, user_id); let key = (room_id, user_id);
self.db self.db