diff --git a/src/service/admin.rs b/src/service/admin.rs index 5d191fae..bd14e045 100644 --- a/src/service/admin.rs +++ b/src/service/admin.rs @@ -38,11 +38,12 @@ use tracing::warn; use super::pdu::PduBuilder; use crate::{ api::client_server::{leave_all_rooms, AUTO_GEN_PASSWORD_LENGTH}, - services, utils, Error, PduEvent, Result, + services, + utils::{self, truncate_str_for_debug}, + Error, PduEvent, Result, }; -#[cfg_attr(test, derive(Debug))] -#[derive(Parser)] +#[derive(Debug, Parser)] #[command(name = "@grapevine:server.name:", version = env!("CARGO_PKG_VERSION"))] enum AdminCommand { #[command(verbatim_doc_comment)] @@ -298,10 +299,17 @@ impl Service { .unwrap(); } + #[tracing::instrument( + skip(self, room_message), + fields( + room_message = truncate_str_for_debug(&room_message, 50).as_ref(), + ), + )] pub(crate) fn process_message(&self, room_message: String) { self.sender.send(AdminRoomEvent::ProcessMessage(room_message)).unwrap(); } + #[tracing::instrument(skip(self, message_content))] pub(crate) fn send_message( &self, message_content: RoomMessageEventContent, @@ -310,6 +318,12 @@ impl Service { } // Parse and process a message from the admin room + #[tracing::instrument( + skip(self, room_message), + fields( + room_message = truncate_str_for_debug(&room_message, 50).as_ref(), + ), + )] async fn process_admin_message( &self, room_message: String, @@ -355,6 +369,12 @@ impl Service { } // Parse chat messages from the admin room into an AdminCommand object + #[tracing::instrument( + skip(command_line), + fields( + command_line = truncate_str_for_debug(command_line, 50).as_ref(), + ), + )] fn parse_admin_command( command_line: &str, ) -> std::result::Result { @@ -380,6 +400,7 @@ impl Service { } #[allow(clippy::too_many_lines)] + #[tracing::instrument(skip(self, body))] async fn process_admin_command( &self, command: AdminCommand, @@ -1067,6 +1088,7 @@ impl Service { } // Utility to turn clap's `--help` text to HTML. + #[tracing::instrument(skip_all)] fn usage_to_html(text: &str, server_name: &ServerName) -> String { // Replace `@grapevine:servername:-subcmdname` with // `@grapevine:servername: subcmdname` @@ -1151,6 +1173,7 @@ impl Service { /// be used to issue admin commands by talking to the server user inside /// it. #[allow(clippy::too_many_lines)] + #[tracing::instrument(skip(self))] pub(crate) async fn create_admin_room(&self) -> Result<()> { let room_id = RoomId::new(services().globals.server_name()); @@ -1435,6 +1458,7 @@ impl Service { /// Invite the user to the grapevine admin room. /// /// In grapevine, this is equivalent to granting admin privileges. + #[tracing::instrument(skip(self))] pub(crate) async fn make_user_admin( &self, user_id: &UserId, diff --git a/src/service/appservice.rs b/src/service/appservice.rs index 8abc7735..ff0b9785 100644 --- a/src/service/appservice.rs +++ b/src/service/appservice.rs @@ -136,6 +136,7 @@ impl Service { } /// Registers an appservice and returns the ID to the caller. + #[tracing::instrument(skip(self, yaml), fields(appservice_id = yaml.id))] pub(crate) async fn register_appservice( &self, yaml: Registration, @@ -154,6 +155,7 @@ impl Service { /// # Arguments /// /// * `service_name` - the name you send to register the service previously + #[tracing::instrument(skip(self))] pub(crate) async fn unregister_appservice( &self, service_name: &str, @@ -171,6 +173,7 @@ impl Service { self.db.unregister_appservice(service_name) } + #[tracing::instrument(skip(self))] pub(crate) async fn get_registration( &self, id: &str, @@ -187,6 +190,7 @@ impl Service { self.registration_info.read().await.keys().cloned().collect() } + #[tracing::instrument(skip(self))] pub(crate) async fn find_from_token( &self, token: &str, @@ -199,6 +203,7 @@ impl Service { } // Checks if a given user id matches any exclusive appservice regex + #[tracing::instrument(skip(self), ret(level = "trace"))] pub(crate) async fn is_exclusive_user_id(&self, user_id: &UserId) -> bool { self.read() .await @@ -207,6 +212,7 @@ impl Service { } // Checks if a given room alias matches any exclusive appservice regex + #[tracing::instrument(skip(self), ret(level = "trace"))] pub(crate) async fn is_exclusive_alias(&self, alias: &RoomAliasId) -> bool { self.read() .await diff --git a/src/service/globals.rs b/src/service/globals.rs index a97f08a9..131610b4 100644 --- a/src/service/globals.rs +++ b/src/service/globals.rs @@ -29,7 +29,7 @@ use ruma::{ OwnedServerSigningKeyId, RoomVersionId, ServerName, UserId, }; use tokio::sync::{broadcast, Mutex, RwLock, Semaphore}; -use tracing::{error, info}; +use tracing::{error, info, Instrument}; use trust_dns_resolver::TokioAsyncResolver; use crate::{api::server_server::FedDest, services, Config, Error, Result}; @@ -126,6 +126,7 @@ impl Resolver { } impl Resolve for Resolver { + #[tracing::instrument(skip(self))] fn resolve(&self, name: Name) -> Resolving { self.overrides .read() @@ -144,18 +145,25 @@ impl Resolve for Resolver { }) .unwrap_or_else(|| { let this = &mut self.inner.clone(); - Box::pin(HyperService::::call(this, name).map(|result| { - result.map(|addrs| -> Addrs { Box::new(addrs) }).map_err( - |err| -> Box { - Box::new(err) - }, - ) - })) + Box::pin( + HyperService::::call(this, name) + .map(|result| { + result + .map(|addrs| -> Addrs { Box::new(addrs) }) + .map_err( + |err| -> Box { + Box::new(err) + }, + ) + }) + .in_current_span(), + ) }) } } impl Service { + #[tracing::instrument(skip_all)] pub(crate) fn load(db: &'static dyn Data, config: Config) -> Result { let keypair = db.load_keypair(); diff --git a/src/service/media.rs b/src/service/media.rs index f5127842..c326575f 100644 --- a/src/service/media.rs +++ b/src/service/media.rs @@ -30,6 +30,7 @@ pub(crate) struct Service { impl Service { /// Uploads a file. + #[tracing::instrument(skip(self, file))] pub(crate) async fn create( &self, mxc: String, @@ -54,6 +55,7 @@ impl Service { /// Uploads or replaces a file thumbnail. #[allow(clippy::too_many_arguments)] + #[tracing::instrument(skip(self, file))] pub(crate) async fn upload_thumbnail( &self, mxc: String, @@ -79,6 +81,7 @@ impl Service { } /// Downloads a file. + #[tracing::instrument(skip(self))] pub(crate) async fn get(&self, mxc: String) -> Result> { if let Ok((content_disposition, content_type, key)) = self.db.search_file_metadata(mxc, 0, 0) @@ -129,6 +132,7 @@ impl Service { /// For width,height <= 96 the server uses another thumbnailing algorithm /// which crops the image afterwards. #[allow(clippy::too_many_lines)] + #[tracing::instrument(skip(self))] pub(crate) async fn get_thumbnail( &self, mxc: String, diff --git a/src/service/pdu.rs b/src/service/pdu.rs index a5296ceb..46dafa2e 100644 --- a/src/service/pdu.rs +++ b/src/service/pdu.rs @@ -351,7 +351,7 @@ impl PduEvent { } /// This does not return a full `Pdu` it is only to satisfy ruma's types. - #[tracing::instrument] + #[tracing::instrument(skip(pdu_json))] pub(crate) fn convert_to_outgoing_federation_event( mut pdu_json: CanonicalJsonObject, ) -> Box { diff --git a/src/service/rooms/auth_chain.rs b/src/service/rooms/auth_chain.rs index 2a601830..e7383e1f 100644 --- a/src/service/rooms/auth_chain.rs +++ b/src/service/rooms/auth_chain.rs @@ -8,7 +8,7 @@ pub(crate) use data::Data; use ruma::{api::client::error::ErrorKind, EventId, RoomId}; use tracing::{debug, error, warn}; -use crate::{services, Error, Result}; +use crate::{services, utils::debug_slice_truncated, Error, Result}; pub(crate) struct Service { pub(crate) db: &'static dyn Data, @@ -31,7 +31,10 @@ impl Service { self.db.cache_auth_chain(key, auth_chain) } - #[tracing::instrument(skip(self, starting_events))] + #[tracing::instrument( + skip(self, starting_events), + fields(starting_events = debug_slice_truncated(&starting_events, 5)), + )] pub(crate) async fn get_auth_chain<'a>( &self, room_id: &RoomId, @@ -138,7 +141,7 @@ impl Service { })) } - #[tracing::instrument(skip(self, event_id))] + #[tracing::instrument(skip(self))] fn get_auth_chain_inner( &self, room_id: &RoomId, diff --git a/src/service/rooms/edus/typing.rs b/src/service/rooms/edus/typing.rs index 52761d69..49b5de95 100644 --- a/src/service/rooms/edus/typing.rs +++ b/src/service/rooms/edus/typing.rs @@ -21,6 +21,7 @@ pub(crate) struct Service { impl Service { /// Sets a user as typing until the timeout timestamp is reached or /// `roomtyping_remove` is called. + #[tracing::instrument(skip(self))] pub(crate) async fn typing_add( &self, user_id: &UserId, @@ -47,6 +48,7 @@ impl Service { } /// Removes a user from typing before the timeout is reached. + #[tracing::instrument(skip(self))] pub(crate) async fn typing_remove( &self, user_id: &UserId, @@ -71,6 +73,7 @@ impl Service { Ok(()) } + #[tracing::instrument(skip(self))] pub(crate) async fn wait_for_update(&self, room_id: &RoomId) -> Result<()> { let mut receiver = self.typing_update_sender.subscribe(); while let Ok(next) = receiver.recv().await { @@ -83,6 +86,7 @@ impl Service { } /// Makes sure that typing events with old timestamps get removed. + #[tracing::instrument(skip(self, room_id))] async fn typings_maintain(&self, room_id: &RoomId) -> Result<()> { let current_timestamp = utils::millis_since_unix_epoch(); let mut removable = Vec::new(); @@ -119,6 +123,7 @@ impl Service { } /// Returns the count of the last typing update in this room. + #[tracing::instrument(skip(self))] pub(crate) async fn last_typing_update( &self, room_id: &RoomId, @@ -134,6 +139,7 @@ impl Service { } /// Returns a new typing EDU. + #[tracing::instrument(skip(self))] pub(crate) async fn typings_all( &self, room_id: &RoomId, diff --git a/src/service/rooms/event_handler.rs b/src/service/rooms/event_handler.rs index 48c40be1..3faf8f93 100644 --- a/src/service/rooms/event_handler.rs +++ b/src/service/rooms/event_handler.rs @@ -1085,6 +1085,7 @@ impl Service { Ok(pdu_id) } + #[tracing::instrument(skip(self, room_version_id, incoming_state))] async fn resolve_state( &self, room_id: &RoomId, @@ -1397,6 +1398,8 @@ impl Service { }) } + #[tracing::instrument(skip_all)] + #[allow(clippy::type_complexity)] async fn fetch_unknown_prev_events( &self, origin: &ServerName, @@ -1558,6 +1561,7 @@ impl Service { // Gets a list of servers for which we don't have the signing key yet. We go // over the PDUs and either cache the key or add it to the list that // needs to be retrieved. + #[tracing::instrument(skip_all)] async fn get_server_keys_from_cache( &self, pdu: &RawJsonValue, @@ -1797,6 +1801,7 @@ impl Service { /// Returns Ok if the acl allows the server // Allowed because this function uses `services()` #[allow(clippy::unused_self)] + #[tracing::instrument(skip_all)] pub(crate) fn acl_check( &self, server_name: &ServerName, @@ -2010,6 +2015,7 @@ impl Service { Err(Error::BadServerResponse("Failed to find public key for server")) } + #[tracing::instrument(skip_all)] fn check_room_id(room_id: &RoomId, pdu: &PduEvent) -> Result<()> { if pdu.room_id != room_id { warn!("Found event from room {} in room {}", pdu.room_id, room_id); diff --git a/src/service/rooms/pdu_metadata.rs b/src/service/rooms/pdu_metadata.rs index d8acc698..7dcbbe84 100644 --- a/src/service/rooms/pdu_metadata.rs +++ b/src/service/rooms/pdu_metadata.rs @@ -51,6 +51,7 @@ impl Service { // Allowed because this function uses `services()` clippy::unused_self, )] + #[tracing::instrument(skip(self))] pub(crate) fn paginate_relations_with_filter( &self, sender_user: &UserId, @@ -178,6 +179,7 @@ impl Service { } } + #[tracing::instrument(skip_all)] pub(crate) fn relations_until<'a>( &'a self, user_id: &'a UserId, diff --git a/src/service/rooms/spaces.rs b/src/service/rooms/spaces.rs index 854d6d44..6dccafed 100644 --- a/src/service/rooms/spaces.rs +++ b/src/service/rooms/spaces.rs @@ -51,6 +51,7 @@ pub(crate) struct Service { impl Service { #[allow(clippy::too_many_lines)] + #[tracing::instrument(skip(self))] pub(crate) async fn get_hierarchy( &self, sender_user: &UserId, @@ -326,6 +327,7 @@ impl Service { } #[allow(clippy::too_many_lines)] + #[tracing::instrument(skip(self, sender_user, children))] fn get_room_chunk( &self, sender_user: &UserId, @@ -525,6 +527,7 @@ impl Service { Ok(allowed) } + #[tracing::instrument(skip(self, sender_user))] fn handle_join_rule( &self, join_rule: &JoinRule, diff --git a/src/service/rooms/state.rs b/src/service/rooms/state.rs index 07e5fc5e..a62f2394 100644 --- a/src/service/rooms/state.rs +++ b/src/service/rooms/state.rs @@ -20,7 +20,11 @@ use tokio::sync::MutexGuard; use tracing::warn; use super::state_compressor::CompressedStateEvent; -use crate::{services, utils::calculate_hash, Error, PduEvent, Result}; +use crate::{ + services, + utils::{calculate_hash, debug_slice_truncated}, + Error, PduEvent, Result, +}; pub(crate) struct Service { pub(crate) db: &'static dyn Data, @@ -28,6 +32,12 @@ pub(crate) struct Service { impl Service { /// Set the room to the given statehash and update caches. + #[tracing::instrument(skip( + self, + statediffnew, + _statediffremoved, + state_lock + ))] pub(crate) async fn force_state( &self, room_id: &RoomId, @@ -354,6 +364,7 @@ impl Service { Ok(create_event_content.room_version) } + #[tracing::instrument(skip(self))] pub(crate) fn get_room_shortstatehash( &self, room_id: &RoomId, @@ -361,6 +372,7 @@ impl Service { self.db.get_room_shortstatehash(room_id) } + #[tracing::instrument(skip(self))] pub(crate) fn get_forward_extremities( &self, room_id: &RoomId, @@ -368,6 +380,10 @@ impl Service { self.db.get_forward_extremities(room_id) } + #[tracing::instrument( + skip(self, event_ids, state_lock), + fields(event_ids = debug_slice_truncated(&event_ids, 5)), + )] pub(crate) fn set_forward_extremities( &self, room_id: &RoomId, diff --git a/src/service/rooms/state_accessor.rs b/src/service/rooms/state_accessor.rs index d980b3bf..18d8e61e 100644 --- a/src/service/rooms/state_accessor.rs +++ b/src/service/rooms/state_accessor.rs @@ -47,6 +47,7 @@ impl Service { self.db.state_full_ids(shortstatehash).await } + #[tracing::instrument(skip(self))] pub(crate) async fn state_full( &self, shortstatehash: u64, @@ -68,6 +69,7 @@ impl Service { /// Returns a single PDU from `room_id` with key (`event_type`, /// `state_key`). + #[tracing::instrument(skip(self))] pub(crate) fn state_get( &self, shortstatehash: u64, @@ -78,6 +80,7 @@ impl Service { } /// Get membership for given user in state + #[tracing::instrument(skip(self))] fn user_membership( &self, shortstatehash: u64, @@ -100,6 +103,7 @@ impl Service { } /// The user was a joined member at this state (potentially in the past) + #[tracing::instrument(skip(self), ret(level = "trace"))] fn user_was_joined(&self, shortstatehash: u64, user_id: &UserId) -> bool { self.user_membership(shortstatehash, user_id) .map(|s| s == MembershipState::Join) @@ -108,6 +112,7 @@ impl Service { /// The user was an invited or joined room member at this state (potentially /// in the past) + #[tracing::instrument(skip(self), ret(level = "trace"))] fn user_was_invited(&self, shortstatehash: u64, user_id: &UserId) -> bool { self.user_membership(shortstatehash, user_id) .map(|s| s == MembershipState::Join || s == MembershipState::Invite) @@ -294,6 +299,7 @@ impl Service { } /// Returns the state hash for this pdu. + #[tracing::instrument(skip(self))] pub(crate) fn pdu_shortstatehash( &self, event_id: &EventId, @@ -334,6 +340,7 @@ impl Service { self.db.room_state_get(room_id, event_type, state_key) } + #[tracing::instrument(skip(self))] pub(crate) fn get_name(&self, room_id: &RoomId) -> Result> { self.room_state_get(room_id, &StateEventType::RoomName, "")?.map_or( Ok(None), @@ -354,6 +361,7 @@ impl Service { ) } + #[tracing::instrument(skip(self))] pub(crate) fn get_avatar( &self, room_id: &RoomId, @@ -372,6 +380,7 @@ impl Service { // Allowed because this function uses `services()` #[allow(clippy::unused_self)] + #[tracing::instrument(skip(self), ret(level = "trace"))] pub(crate) fn user_can_invite( &self, room_id: &RoomId, @@ -398,6 +407,7 @@ impl Service { .is_ok() } + #[tracing::instrument(skip(self))] pub(crate) fn get_member( &self, room_id: &RoomId, @@ -420,6 +430,7 @@ impl Service { /// If `federation` is `true`, it allows redaction events from any user of /// the same server as the original event sender, [as required by room /// versions >= v3](https://spec.matrix.org/v1.10/rooms/v11/#handling-redactions) + #[tracing::instrument(skip(self))] pub(crate) fn user_can_redact( &self, redacts: &EventId, diff --git a/src/service/rooms/state_compressor.rs b/src/service/rooms/state_compressor.rs index 6e5fedf0..538c75f1 100644 --- a/src/service/rooms/state_compressor.rs +++ b/src/service/rooms/state_compressor.rs @@ -286,6 +286,7 @@ impl Service { /// Returns the new shortstatehash, and the state diff from the previous /// room state #[allow(clippy::type_complexity)] + #[tracing::instrument(skip(self, new_state_ids_compressed))] pub(crate) fn save_state( &self, room_id: &RoomId, diff --git a/src/service/sending.rs b/src/service/sending.rs index fd4eb2c9..bb392948 100644 --- a/src/service/sending.rs +++ b/src/service/sending.rs @@ -40,7 +40,7 @@ use tracing::{debug, error, warn}; use crate::{ api::{appservice_server, server_server}, services, - utils::calculate_hash, + utils::{calculate_hash, debug_slice_truncated}, Config, Error, PduEvent, Result, }; @@ -301,12 +301,13 @@ impl Service { } } - #[tracing::instrument(skip( - self, - outgoing_kind, - new_events, - current_transaction_status - ))] + #[tracing::instrument( + skip(self, new_events, current_transaction_status), + fields( + new_events = debug_slice_truncated(&new_events, 3), + current_status = ?current_transaction_status.get(outgoing_kind), + ), + )] fn select_events( &self, outgoing_kind: &OutgoingKind, @@ -386,7 +387,7 @@ impl Service { Ok(Some(events)) } - #[tracing::instrument(skip(self, server_name))] + #[tracing::instrument(skip(self))] pub(crate) fn select_edus( &self, server_name: &ServerName, @@ -598,7 +599,7 @@ impl Service { Ok(()) } - #[tracing::instrument(skip(events, kind))] + #[tracing::instrument(skip(events))] async fn handle_events( kind: OutgoingKind, events: Vec, @@ -876,7 +877,7 @@ impl Service { } } - #[tracing::instrument(skip(self, destination, request))] + #[tracing::instrument(skip(self, request))] pub(crate) async fn send_federation_request( &self, destination: &ServerName, @@ -906,7 +907,10 @@ impl Service { /// /// Only returns None if there is no url specified in the appservice /// registration file - #[tracing::instrument(skip(self, registration, request))] + #[tracing::instrument( + skip(self, registration, request), + fields(appservice_id = registration.id), + )] pub(crate) async fn send_appservice_request( &self, registration: Registration,