Merge branch 'olivia/better-sending-logs' into 'main'

giant error reporting refactor

See merge request matrix/grapevine!155

Cargo.lock

@@ -947,6 +947,7 @@ dependencies = [
  "tracing-opentelemetry",
  "tracing-subscriber",
  "trust-dns-resolver",
+ "wee-woo",
  "xdg",
 ]
 
@@ -3871,6 +3872,12 @@ dependencies = [
  "wasm-bindgen",
 ]
 
+[[package]]
+name = "wee-woo"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "005e18f8367a2e0e375c29dd4d266c97e7590ec9d64bb05dc5af054a555eda05"
+
 [[package]]
 name = "weezl"
 version = "0.1.8"

Cargo.toml

@@ -144,6 +144,7 @@ tracing-flame = "0.2.0"
 tracing-opentelemetry = "0.25.0"
 tracing-subscriber = { version = "0.3.19", features = ["env-filter", "json"] }
 trust-dns-resolver = "0.23.2"
+wee-woo = "0.1.0"
 xdg = "2.5.2"
 
 [target.'cfg(unix)'.dependencies]

book/changelog.md

@@ -116,7 +116,8 @@ This will be the first release of Grapevine since it was forked from Conduit
    [!69](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/69),
    [!102](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/102),
    [!127](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/127),
-   [!141](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/141))
+   [!141](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/141),
+   [!155](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/155))
 4. Stop returning unnecessary member counts from `/_matrix/client/{r0,v3}/sync`.
    ([!12](https://gitlab.computer.surgery/matrix/grapevine/-/merge_requests/12))
 5. **BREAKING:** Allow federation by default.

book/contributing/style-guide.md

@@ -89,6 +89,13 @@ in mind. Especially, keeping Cargo unit tests in a dedicated tests file
 
 ## Tracing
 
+Modules that emit tracing events should import
+`crate::observability::prelude::*`, which re-exports `tracing` as `t`, instead
+of importing tracing macros directly and using them without a path.
+
+**Why?** Avoiding name collisions and diff churn, since the set of tracing
+macros used by a module tends to change frequently.
+
 `tracing` events should:
 
 1. Start with a capital letter (when applicable).
@@ -102,26 +109,33 @@ in mind. Especially, keeping Cargo unit tests in a dedicated tests file
 **Why?** Consistency is good. Also, interpolating values into the event message
 essentially defeats the point of structured logging.
 
+When emitting tracing events containing errors, use the `<level>_err!` macros
+from `observability::prelude` instead of `t::<level>!`.
+
+**Why?** This will log the full source chain instead of just the `Display` impl
+of the first error in the chain, making it easier to identify the cause of
+errors in thelogs.
+
 ### Examples
 
 #### 1
 
 ```rust,ignore
 // This does not conform because it does not start with a capital letter.
-info!("started pentametric fan");
+t::info!("started pentametric fan");
 
 // Do this instead:
-info!("Started pentametric fan");
+t::info!("Started pentametric fan");
 ```
 
 #### 2
 
 ```rust,ignore
 // This does not conform because it ends with punctuation.
-info!("Started pentametric fan.");
+t::info!("Started pentametric fan.");
 
 // Do this instead:
-info!("Started pentametric fan");
+t::info!("Started pentametric fan");
 ```
 
 #### 3
@@ -129,10 +143,20 @@ info!("Started pentametric fan");
 ```rust,ignore
 // This does not conform because it interpolates values into the event's
 // message.
-warn!("Noticed {} discombobulated waneshafts", count);
+t::warn!("Noticed {} discombobulated waneshafts", count);
 
 // Do this instead:
-warn!(count, "Noticed discombobulated waneshafts");
+t::warn!(count, "Noticed discombobulated waneshafts");
+```
+
+#### 4
+
+```rust,ignore
+// This does not conform because it logs only the first error in the chain
+t::error!(%error, "Failed to automatically synchronize cardinal grammeters");
+
+// Do this instead:
+error_err!(error, "Failed to automatically synchronize cardinal grammeters");
 ```
 
 ## Services

src/api/appservice_server.rs

@@ -5,15 +5,14 @@ use ruma::api::{
     appservice::Registration, IncomingResponse, MatrixVersion, OutgoingRequest,
     SendAccessToken,
 };
-use tracing::warn;
 
-use crate::{services, utils, Error, Result};
+use crate::{observability::prelude::*, services, utils, Error, Result};
 
 /// Sends a request to an appservice
 ///
 /// Only returns None if there is no url specified in the appservice
 /// registration file
-#[tracing::instrument(skip(request))]
+#[t::instrument(skip(request))]
 pub(crate) async fn send_request<T>(
     registration: Registration,
     request: T,
@@ -63,8 +62,8 @@ where
         .execute(reqwest_request)
         .await
         .inspect_err(|error| {
-            warn!(
+            warn_err!(
-                %error,
+                error,
                 appservice = registration.id,
                 %destination,
                 "Could not send request to appservice",
@@ -84,12 +83,12 @@ where
 
     // TODO: handle timeout
     let body = response.bytes().await.unwrap_or_else(|error| {
-        warn!(%error, "Server error");
+        warn_err!(error, "Server error");
         Vec::new().into()
     });
 
     if status != 200 {
-        warn!(
+        t::warn!(
             appservice = %destination,
             %status,
             %url,
@@ -108,8 +107,8 @@ where
     );
 
     response.map(Some).map_err(|error| {
-        warn!(
+        warn_err!(
-            %error,
+            error,
             appservice = %destination,
             %url,
             "Appservice returned invalid response bytes",

src/api/client_server/account.rs

@@ -16,10 +16,12 @@ use ruma::{
     },
     push, UserId,
 };
-use tracing::{info, warn};
 
 use super::{DEVICE_ID_LENGTH, SESSION_ID_LENGTH, TOKEN_LENGTH};
-use crate::{api::client_server, services, utils, Ar, Error, Ra, Result};
+use crate::{
+    api::client_server, observability::prelude::*, services, utils, Ar, Error,
+    Ra, Result,
+};
 
 const RANDOM_USER_ID_LENGTH: usize = 10;
 
@@ -276,7 +278,7 @@ pub(crate) async fn register_route(
         body.initial_device_display_name.clone(),
     )?;
 
-    info!(%user_id, "New user registered on this server");
+    t::info!(%user_id, "New user registered on this server");
     if body.appservice_info.is_none() && !is_guest {
         services().admin.send_message(RoomMessageEventContent::notice_plain(
             format!("New user {user_id} registered on this server."),
@@ -292,7 +294,7 @@ pub(crate) async fn register_route(
             {
                 services().admin.make_user_admin(&user_id, displayname).await?;
 
-                warn!(
+                t::warn!(
                     %user_id,
                     "Granting admin privileges to the first user",
                 );
@@ -375,7 +377,7 @@ pub(crate) async fn change_password_route(
         }
     }
 
-    info!(user_id = %sender_user, "User changed their password");
+    t::info!(user_id = %sender_user, "User changed their password");
     services().admin.send_message(RoomMessageEventContent::notice_plain(
         format!("User {sender_user} changed their password."),
     ));
@@ -455,7 +457,7 @@ pub(crate) async fn deactivate_route(
     // Remove devices and mark account as deactivated
     services().users.deactivate_account(sender_user)?;
 
-    info!(user_id = %sender_user, "User deactivated their account");
+    t::info!(user_id = %sender_user, "User deactivated their account");
     services().admin.send_message(RoomMessageEventContent::notice_plain(
         format!("User {sender_user} deactivated their account."),
     ));

src/api/client_server/alias.rs

@@ -44,7 +44,7 @@ pub(crate) async fn create_alias_route(
     }
 
     if services().rooms.alias.resolve_local_alias(&body.room_alias)?.is_some() {
-        return Err(Error::Conflict("Alias already exists."));
+        return Err(Error::AliasConflict);
     }
 
     services().rooms.alias.set_alias(

src/api/client_server/context.rs

@@ -7,9 +7,8 @@ use ruma::{
     events::StateEventType,
     uint,
 };
-use tracing::error;
 
-use crate::{services, Ar, Error, Ra, Result};
+use crate::{observability::prelude::*, services, Ar, Error, Ra, Result};
 
 /// # `GET /_matrix/client/r0/rooms/{roomId}/context`
 ///
@@ -165,14 +164,14 @@ pub(crate) async fn get_context_route(
         if event_type != StateEventType::RoomMember {
             let Some(pdu) = services().rooms.timeline.get_pdu(&event_id)?
             else {
-                error!(%event_id, "Event in state not found");
+                t::error!(%event_id, "Event in state not found");
                 continue;
             };
             state.push(pdu.to_state_event());
         } else if !lazy_load_enabled || lazy_loaded.contains(&state_key) {
             let Some(pdu) = services().rooms.timeline.get_pdu(&event_id)?
             else {
-                error!(%event_id, "Event in state not found");
+                t::error!(%event_id, "Event in state not found");
                 continue;
             };
             state.push(pdu.to_state_event());

src/api/client_server/directory.rs

@@ -26,10 +26,10 @@ use ruma::{
     },
     uint, ServerName, UInt,
 };
-use tracing::{error, info, warn};
 
 use crate::{
-    service::rooms::state::ExtractType, services, Ar, Error, Ra, Result,
+    observability::prelude::*, service::rooms::state::ExtractType, services,
+    Ar, Error, Ra, Result,
 };
 
 /// # `POST /_matrix/client/r0/publicRooms`
@@ -94,7 +94,7 @@ pub(crate) async fn set_room_visibility_route(
     match &body.visibility {
         room::Visibility::Public => {
             services().rooms.directory.set_public(&body.room_id)?;
-            info!(
+            t::info!(
                 user_id = %sender_user,
                 room_id = %body.room_id,
                 "User made room public",
@@ -269,7 +269,7 @@ pub(crate) async fn get_public_rooms_filtered_helper(
 }
 
 #[allow(clippy::too_many_lines)]
-#[tracing::instrument]
+#[t::instrument]
 fn room_id_to_chunk(room_id: ruma::OwnedRoomId) -> Result<PublicRoomsChunk> {
     let canonical_alias = services()
         .rooms
@@ -292,7 +292,7 @@ fn room_id_to_chunk(room_id: ruma::OwnedRoomId) -> Result<PublicRoomsChunk> {
         .state_cache
         .room_joined_count(&room_id)?
         .unwrap_or_else(|| {
-            warn!("Room has no member count");
+            t::warn!("Room has no member count");
             0
         })
         .try_into()
@@ -306,7 +306,7 @@ fn room_id_to_chunk(room_id: ruma::OwnedRoomId) -> Result<PublicRoomsChunk> {
             serde_json::from_str(s.content.get())
                 .map(|c: RoomTopicEventContent| Some(c.topic))
                 .map_err(|_| {
-                    error!("Invalid room topic event in database for room",);
+                    t::error!("Invalid room topic event in database for room",);
                     Error::bad_database("Invalid room topic event in database.")
                 })
         })?;
@@ -371,7 +371,10 @@ fn room_id_to_chunk(room_id: ruma::OwnedRoomId) -> Result<PublicRoomsChunk> {
                     _ => None,
                 })
                 .map_err(|error| {
-                    error!(%error, "Invalid room join rule event in database");
+                    error_err!(
+                        error,
+                        "Invalid room join rule event in database"
+                    );
                     Error::BadDatabase(
                         "Invalid room join rule event in database.",
                     )

src/api/client_server/keys.rs

@@ -21,10 +21,11 @@ use ruma::{
     ServerName, UserId,
 };
 use serde_json::json;
-use tracing::debug;
 
 use super::SESSION_ID_LENGTH;
-use crate::{services, utils, Ar, Error, Ra, Result};
+use crate::{
+    observability::prelude::*, services, utils, Ar, Error, Ra, Result,
+};
 
 /// # `POST /_matrix/client/r0/keys/upload`
 ///
@@ -465,7 +466,7 @@ async fn check_key_requests_back_off(server: &ServerName) -> Result<()> {
         if let Some(remaining) =
             min_elapsed_duration.checked_sub(time.elapsed())
         {
-            debug!(%server, %tries, ?remaining, "Backing off from server");
+            t::debug!(%server, %tries, ?remaining, "Backing off from server");
             return Err(Error::BadServerResponse(
                 "bad query, still backing off",
             ));
@@ -504,7 +505,7 @@ async fn request_keys_from(
     match &result {
         Ok(_) => reset_key_request_back_off(server).await,
         Err(error) => {
-            debug!(%server, %error, "remote device key query failed");
+            debug_err!(error, %server, "remote device key query failed");
             back_off_key_requests(server.to_owned()).await;
         }
     }

src/api/client_server/media.rs

@@ -17,9 +17,9 @@ use ruma::{
     },
     http_headers::{ContentDisposition, ContentDispositionType},
 };
-use tracing::{debug, error, info, warn};
 
 use crate::{
+    observability::prelude::*,
     service::media::FileMeta,
     services,
     utils::{self, MxcData},
@@ -111,7 +111,11 @@ fn set_header_or_panic(
     header_value: HeaderValue,
 ) {
     if let Some(header_value) = response.headers().get(&header_name) {
-        error!(?header_name, ?header_value, "unexpected pre-existing header");
+        t::error!(
+            ?header_name,
+            ?header_value,
+            "unexpected pre-existing header"
+        );
         panic!(
             "expected {header_name:?} to be unset but it was set to \
              {header_value:?}"
@@ -203,12 +207,12 @@ struct RemoteResponse {
 
 /// Fetches remote media content from a URL specified in a
 /// `/_matrix/federation/v1/media/*/{mediaId}` `Location` header
-#[tracing::instrument]
+#[t::instrument]
 async fn get_redirected_content(
     location: String,
 ) -> Result<authenticated_media_fed::Content> {
     let location = location.parse().map_err(|error| {
-        warn!(location, %error, "Invalid redirect location");
+        warn_err!(error, location, "Invalid redirect location");
         Error::BadServerResponse("Invalid redirect location")
     })?;
     let response = services()
@@ -222,11 +226,7 @@ async fn get_redirected_content(
         .get(CONTENT_TYPE)
         .map(|value| {
             value.to_str().map_err(|error| {
-                error!(
+                error_err!(error, ?value, "Invalid Content-Type header");
-                    ?value,
-                    %error,
-                    "Invalid Content-Type header"
-                );
                 Error::BadServerResponse("Invalid Content-Type header")
             })
         })
@@ -238,11 +238,7 @@ async fn get_redirected_content(
         .get(CONTENT_DISPOSITION)
         .map(|value| {
             ContentDisposition::try_from(value.as_bytes()).map_err(|error| {
-                error!(
+                error_err!(error, ?value, "Invalid Content-Disposition header");
-                    ?value,
-                    %error,
-                    "Invalid Content-Disposition header"
-                );
                 Error::BadServerResponse("Invalid Content-Disposition header")
             })
         })
@@ -255,7 +251,7 @@ async fn get_redirected_content(
     })
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn get_remote_content_via_federation_api(
     mxc: &MxcData<'_>,
 ) -> Result<RemoteResponse, Error> {
@@ -275,11 +271,11 @@ async fn get_remote_content_via_federation_api(
 
     let content = match content {
         authenticated_media_fed::FileOrLocation::File(content) => {
-            debug!("Got media from remote server");
+            t::debug!("Got media from remote server");
             content
         }
         authenticated_media_fed::FileOrLocation::Location(location) => {
-            debug!(location, "Following redirect");
+            t::debug!(location, "Following redirect");
             get_redirected_content(location).await?
         }
     };
@@ -291,7 +287,7 @@ async fn get_remote_content_via_federation_api(
 }
 
 #[allow(deprecated)] // unauthenticated media
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn get_remote_content_via_legacy_api(
     mxc: &MxcData<'_>,
 ) -> Result<RemoteResponse, Error> {
@@ -319,7 +315,7 @@ async fn get_remote_content_via_legacy_api(
     })
 }
 
-#[tracing::instrument]
+#[t::instrument]
 pub(crate) async fn get_remote_content(
     mxc: &MxcData<'_>,
 ) -> Result<RemoteResponse, Error> {
@@ -327,7 +323,7 @@ pub(crate) async fn get_remote_content(
 
     let response = match fed_result {
         Ok(response) => {
-            debug!("Got remote content via authenticated media API");
+            t::debug!("Got remote content via authenticated media API");
             response
         }
         Err(Error::Federation(_, error))
@@ -335,7 +331,7 @@ pub(crate) async fn get_remote_content(
                 // https://github.com/t2bot/matrix-media-repo/issues/609
                 || error.error_kind() == Some(&ErrorKind::Unauthorized) =>
         {
-            info!(
+            t::info!(
                 "Remote server does not support authenticated media, falling \
                  back to deprecated API"
             );
@@ -713,7 +709,7 @@ pub(crate) async fn get_content_thumbnail_route(
     })
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn get_remote_thumbnail_via_federation_api(
     server_name: &ruma::ServerName,
     request: authenticated_media_fed::get_content_thumbnail::v1::Request,
@@ -728,11 +724,11 @@ async fn get_remote_thumbnail_via_federation_api(
 
     let content = match content {
         authenticated_media_fed::FileOrLocation::File(content) => {
-            debug!("Got thumbnail from remote server");
+            t::debug!("Got thumbnail from remote server");
             content
         }
         authenticated_media_fed::FileOrLocation::Location(location) => {
-            debug!(location, "Following redirect");
+            t::debug!(location, "Following redirect");
             get_redirected_content(location).await?
         }
     };
@@ -744,7 +740,7 @@ async fn get_remote_thumbnail_via_federation_api(
 }
 
 #[allow(deprecated)] // unauthenticated media
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn get_remote_thumbnail_via_legacy_api(
     server_name: &ruma::ServerName,
     authenticated_media_fed::get_content_thumbnail::v1::Request {
@@ -784,7 +780,7 @@ async fn get_remote_thumbnail_via_legacy_api(
     })
 }
 
-#[tracing::instrument]
+#[t::instrument]
 pub(crate) async fn get_remote_thumbnail(
     server_name: &ruma::ServerName,
     request: authenticated_media_fed::get_content_thumbnail::v1::Request,
@@ -795,7 +791,7 @@ pub(crate) async fn get_remote_thumbnail(
 
     let response = match fed_result {
         Ok(response) => {
-            debug!("Got remote content via authenticated media API");
+            t::debug!("Got remote content via authenticated media API");
             response
         }
         Err(Error::Federation(_, error))
@@ -803,7 +799,7 @@ pub(crate) async fn get_remote_thumbnail(
                 // https://github.com/t2bot/matrix-media-repo/issues/609
                 || error.error_kind() == Some(&ErrorKind::Unauthorized) =>
         {
-            info!(
+            t::info!(
                 "Remote server does not support authenticated media, falling \
                  back to deprecated API"
             );
@@ -891,8 +887,8 @@ async fn get_content_thumbnail_route_ruma(
                     resp.content.content_type,
                 ));
             }
-            Err(error) => warn!(
+            Err(error) => warn_err!(
-                %error,
+                error,
                 "Failed to fetch thumbnail via federation, trying to fetch \
                  original media and create thumbnail ourselves"
             ),
@@ -912,7 +908,9 @@ async fn get_content_thumbnail_route_ruma(
             return Ok(make_response(file, content_type));
         }
 
-        error!("Source media doesn't exist even after fetching it from remote");
+        t::error!(
+            "Source media doesn't exist even after fetching it from remote"
+        );
     }
 
     Err(Error::BadRequest(ErrorKind::NotYetUploaded, "Media not found."))

src/api/client_server/membership.rs

@@ -31,10 +31,10 @@ use ruma::{
 };
 use serde_json::value::{to_raw_value, RawValue as RawJsonValue};
 use tokio::sync::RwLock;
-use tracing::{debug, error, info, warn};
 
 use super::get_alias_helper;
 use crate::{
+    observability::prelude::*,
     service::{
         globals::SigningKeys,
         pdu::{gen_event_id_canonical_json, PduBuilder},
@@ -501,7 +501,7 @@ pub(crate) async fn joined_members_route(
 }
 
 #[allow(clippy::too_many_lines)]
-#[tracing::instrument(skip(reason, _third_party_signed))]
+#[t::instrument(skip(reason, _third_party_signed))]
 async fn join_room_by_id_helper(
     sender_user: Option<&UserId>,
     room_id: &RoomId,
@@ -523,7 +523,7 @@ async fn join_room_by_id_helper(
         .state_cache
         .server_in_room(services().globals.server_name(), room_id)?
     {
-        info!("We can join locally");
+        t::info!("We can join locally");
 
         let join_rules_event = services().rooms.state_accessor.room_state_get(
             room_id,
@@ -537,7 +537,7 @@ async fn join_room_by_id_helper(
                 .map(|join_rules_event| {
                     serde_json::from_str(join_rules_event.content.get())
                         .map_err(|error| {
-                            warn!(%error, "Invalid join rules event");
+                            warn_err!(error, "Invalid join rules event");
                             Error::bad_database(
                                 "Invalid join rules event in db.",
                             )
@@ -636,7 +636,7 @@ async fn join_room_by_id_helper(
             return Err(error);
         }
 
-        info!(
+        t::info!(
             "We couldn't do the join locally, maybe federation can help to \
              satisfy the restricted join requirements"
         );
@@ -791,12 +791,12 @@ async fn join_room_by_id_helper(
             )
             .await?;
     } else {
-        info!("Joining over federation.");
+        t::info!("Joining over federation.");
 
         let (make_join_response, remote_server) =
             make_join_request(sender_user, room_id, servers).await?;
 
-        info!("make_join finished");
+        t::info!("make_join finished");
 
         let room_version_id = match make_join_response.room_version {
             Some(room_version)
@@ -895,7 +895,7 @@ async fn join_room_by_id_helper(
         // It has enough fields to be called a proper event now
         let mut join_event = join_event_stub;
 
-        info!(server = %remote_server, "Asking other server for send_join");
+        t::info!(server = %remote_server, "Asking other server for send_join");
         let send_join_response = services()
             .sending
             .send_federation_request(
@@ -911,10 +911,10 @@ async fn join_room_by_id_helper(
             )
             .await?;
 
-        info!("send_join finished");
+        t::info!("send_join finished");
 
         if let Some(signed_raw) = &send_join_response.room_state.event {
-            info!(
+            t::info!(
                 "There is a signed event. This room is probably using \
                  restricted joins. Adding signature to our event"
             );
@@ -956,8 +956,8 @@ async fn join_room_by_id_helper(
                         .insert(remote_server.to_string(), signature.clone());
                 }
                 Err(error) => {
-                    warn!(
+                    warn_err!(
-                        %error,
+                        error,
                         server = %remote_server,
                         event = ?signed_value,
                         "Other server sent invalid signature in sendjoin \
@@ -969,7 +969,7 @@ async fn join_room_by_id_helper(
 
         services().rooms.short.get_or_create_shortroomid(room_id)?;
 
-        info!("Parsing join event");
+        t::info!("Parsing join event");
         let parsed_join_pdu =
             PduEvent::from_id_val(event_id, join_event.clone()).map_err(
                 |_| Error::BadServerResponse("Invalid join event PDU."),
@@ -978,7 +978,7 @@ async fn join_room_by_id_helper(
         let mut state = HashMap::new();
         let pub_key_map = RwLock::new(BTreeMap::new());
 
-        info!("Fetching join signing keys");
+        t::info!("Fetching join signing keys");
         services()
             .rooms
             .event_handler
@@ -989,7 +989,7 @@ async fn join_room_by_id_helper(
             )
             .await?;
 
-        info!("Going through send_join response room_state");
+        t::info!("Going through send_join response room_state");
         for result in send_join_response.room_state.state.iter().map(|pdu| {
             validate_and_add_event_id(pdu, &room_version_id, &pub_key_map)
         }) {
@@ -999,8 +999,8 @@ async fn join_room_by_id_helper(
 
             let pdu = PduEvent::from_id_val(&event_id, value.clone()).map_err(
                 |error| {
-                    warn!(
+                    warn_err!(
-                        %error,
+                        error,
                         object = ?value,
                         "Invalid PDU in send_join response",
                     );
@@ -1021,7 +1021,7 @@ async fn join_room_by_id_helper(
             }
         }
 
-        info!("Going through send_join response auth_chain");
+        t::info!("Going through send_join response auth_chain");
         for result in
             send_join_response.room_state.auth_chain.iter().map(|pdu| {
                 validate_and_add_event_id(pdu, &room_version_id, &pub_key_map)
@@ -1034,7 +1034,7 @@ async fn join_room_by_id_helper(
             services().rooms.outlier.add_pdu_outlier(&event_id, &value)?;
         }
 
-        info!("Running send_join auth check");
+        t::info!("Running send_join auth check");
         let authenticated = state_res::event_auth::auth_check(
             &state_res::RoomVersion::new(&room_version_id).map_err(|_| {
                 Error::UnsupportedRoomVersion(room_version_id.clone())
@@ -1062,7 +1062,7 @@ async fn join_room_by_id_helper(
             },
         )
         .map_err(|error| {
-            warn!(%error, "Auth check failed");
+            warn_err!(error, "Auth check failed");
             Error::BadRequest(ErrorKind::InvalidParam, "Auth check failed")
         })?;
 
@@ -1073,7 +1073,7 @@ async fn join_room_by_id_helper(
             ));
         }
 
-        info!("Saving state from send_join");
+        t::info!("Saving state from send_join");
         let (statehash_before_join, new, removed) =
             services().rooms.state_compressor.save_state(
                 room_id,
@@ -1096,7 +1096,7 @@ async fn join_room_by_id_helper(
             .force_state(&room_token, statehash_before_join, new, removed)
             .await?;
 
-        info!("Updating joined counts for new room");
+        t::info!("Updating joined counts for new room");
         services().rooms.state_cache.update_joined_count(room_id)?;
 
         // We append to state before appending the pdu, so we don't have a
@@ -1105,7 +1105,7 @@ async fn join_room_by_id_helper(
         let statehash_after_join =
             services().rooms.state.append_to_state(&parsed_join_pdu)?;
 
-        info!("Appending new room join event");
+        t::info!("Appending new room join event");
         services()
             .rooms
             .timeline
@@ -1117,7 +1117,7 @@ async fn join_room_by_id_helper(
             )
             .await?;
 
-        info!("Setting final room state for new room");
+        t::info!("Setting final room state for new room");
         // We set the room state after inserting the pdu, so that we never have
         // a moment in time where events in the current room state do
         // not exist
@@ -1146,7 +1146,7 @@ async fn make_join_request(
         if remote_server == services().globals.server_name() {
             continue;
         }
-        info!(server = %remote_server, "Asking other server for make_join");
+        t::info!(server = %remote_server, "Asking other server for make_join");
         let make_join_response = services()
             .sending
             .send_federation_request(
@@ -1164,8 +1164,8 @@ async fn make_join_request(
                 return Ok((r, remote_server.clone()));
             }
             Err(error) => {
-                warn!(
+                warn_err!(
-                    %error,
+                    error,
                     server = %remote_server,
                     "Remote join request failed",
                 );
@@ -1184,7 +1184,7 @@ async fn validate_and_add_event_id(
 ) -> Result<(OwnedEventId, CanonicalJsonObject)> {
     let mut value: CanonicalJsonObject = serde_json::from_str(pdu.get())
         .map_err(|error| {
-            error!(%error, object = ?pdu, "Invalid PDU in server response");
+            error_err!(error, object = ?pdu, "Invalid PDU in server response");
             Error::BadServerResponse("Invalid PDU in server response")
         })?;
     let event_id = EventId::parse(format!(
@@ -1216,7 +1216,7 @@ async fn validate_and_add_event_id(
         }
 
         if time.elapsed() < min_elapsed_duration {
-            debug!(%event_id, "Backing off from event");
+            t::debug!(%event_id, "Backing off from event");
             return Err(Error::BadServerResponse(
                 "bad event, still backing off",
             ));
@@ -1224,7 +1224,7 @@ async fn validate_and_add_event_id(
     }
 
     let origin_server_ts = value.get("origin_server_ts").ok_or_else(|| {
-        error!("Invalid PDU, no origin_server_ts field");
+        t::error!("Invalid PDU, no origin_server_ts field");
         Error::BadRequest(
             ErrorKind::MissingParam,
             "Invalid PDU, no origin_server_ts field",
@@ -1258,9 +1258,9 @@ async fn validate_and_add_event_id(
     if let Err(error) =
         ruma::signatures::verify_event(&keys, &value, room_version)
     {
-        warn!(
+        warn_err!(
+            error,
             %event_id,
-            %error,
             ?pdu,
             "Event failed verification",
         );
@@ -1361,7 +1361,7 @@ pub(crate) async fn invite_helper(
         };
 
         if *pdu.event_id != *event_id {
-            warn!(
+            t::warn!(
                 server = %user_id.server_name(),
                 our_object = ?pdu_json,
                 their_object = ?value,
@@ -1481,14 +1481,14 @@ pub(crate) async fn leave_all_rooms(user_id: &UserId) -> Result<()> {
         };
 
         if let Err(error) = leave_room(user_id, &room_id, None).await {
-            warn!(%user_id, %room_id, %error, "Failed to leave room");
+            warn_err!(error, %user_id, %room_id, "Failed to leave room");
         }
     }
 
     Ok(())
 }
 
-#[tracing::instrument(skip(reason))]
+#[t::instrument(skip(reason))]
 pub(crate) async fn leave_room(
     user_id: &UserId,
     room_id: &RoomId,
@@ -1515,7 +1515,7 @@ pub(crate) async fn leave_room(
         // Fix for broken rooms
         let member_event = match member_event {
             None => {
-                error!("Trying to leave a room you are not a member of.");
+                t::error!("Trying to leave a room you are not a member of.");
 
                 services().rooms.state_cache.update_membership(
                     room_id,
@@ -1557,7 +1557,7 @@ pub(crate) async fn leave_room(
             .await?;
     } else {
         if let Err(error) = remote_leave_room(user_id, room_id).await {
-            warn!(%error, "Failed to leave room remotely");
+            warn_err!(error, "Failed to leave room remotely");
             // Don't tell the client about this error
         }
 

src/api/client_server/profile.rs

@@ -14,9 +14,11 @@ use ruma::{
     },
 };
 use serde_json::value::to_raw_value;
-use tracing::warn;
 
-use crate::{service::pdu::PduBuilder, services, Ar, Error, Ra, Result};
+use crate::{
+    observability::prelude::*, service::pdu::PduBuilder, services, Ar, Error,
+    Ra, Result,
+};
 
 /// # `PUT /_matrix/client/r0/profile/{userId}/displayname`
 ///
@@ -91,7 +93,7 @@ pub(crate) async fn set_displayname_route(
             .build_and_append_pdu(pdu_builder, sender_user, &room_token)
             .await
         {
-            warn!(%error, "failed to add PDU");
+            warn_err!(error, "failed to add PDU");
         }
     }
 
@@ -203,7 +205,7 @@ pub(crate) async fn set_avatar_url_route(
             .build_and_append_pdu(pdu_builder, sender_user, &room_token)
             .await
         {
-            warn!(%error, "failed to add PDU");
+            warn_err!(error, "failed to add PDU");
         };
     }
 

src/api/client_server/room.rs

@@ -27,11 +27,11 @@ use ruma::{
     CanonicalJsonObject, OwnedRoomAliasId, RoomAliasId, RoomId,
 };
 use serde_json::{json, value::to_raw_value};
-use tracing::{info, warn};
 
 use crate::{
-    api::client_server::invite_helper, service::pdu::PduBuilder, services,
+    api::client_server::invite_helper, observability::prelude::*,
-    utils::room_version::RoomVersion, Ar, Error, Ra, Result,
+    service::pdu::PduBuilder, services, utils::room_version::RoomVersion, Ar,
+    Error, Ra, Result,
 };
 
 /// # `POST /_matrix/client/r0/createRoom`
@@ -400,7 +400,7 @@ pub(crate) async fn create_room_route(
     for event in &body.initial_state {
         let mut pdu_builder =
             event.deserialize_as::<PduBuilder>().map_err(|error| {
-                warn!(%error, "Invalid initial state event");
+                warn_err!(error, "Invalid initial state event");
                 Error::BadRequest(
                     ErrorKind::InvalidParam,
                     "Invalid initial state event.",
@@ -474,7 +474,7 @@ pub(crate) async fn create_room_route(
             invite_helper(sender_user, user_id, &room_id, None, body.is_direct)
                 .await
         {
-            warn!(%error, "Invite helper failed");
+            warn_err!(error, "Invite helper failed");
         };
     }
 
@@ -487,7 +487,7 @@ pub(crate) async fn create_room_route(
         services().rooms.directory.set_public(&room_id)?;
     }
 
-    info!(user_id = %sender_user, room_id = %room_id, "User created a room");
+    t::info!(user_id = %sender_user, room_id = %room_id, "User created a room");
 
     Ok(Ra(create_room::v3::Response::new(room_id)))
 }
@@ -505,7 +505,7 @@ pub(crate) async fn get_room_event_route(
 
     let event = services().rooms.timeline.get_pdu(&body.event_id)?.ok_or_else(
         || {
-            warn!(event_id = %body.event_id, "Event not found");
+            t::warn!(event_id = %body.event_id, "Event not found");
             Error::BadRequest(ErrorKind::NotFound, "Event not found.")
         },
     )?;

src/api/client_server/session.rs

@@ -13,10 +13,11 @@ use ruma::{
     UserId,
 };
 use serde::Deserialize;
-use tracing::{info, warn};
 
 use super::{DEVICE_ID_LENGTH, TOKEN_LENGTH};
-use crate::{services, utils, Ar, Error, Ra, Result};
+use crate::{
+    observability::prelude::*, services, utils, Ar, Error, Ra, Result,
+};
 
 #[derive(Debug, Deserialize)]
 struct Claims {
@@ -79,7 +80,7 @@ pub(crate) async fn login_route(
                 } else if let Some(user) = user {
                     UserId::parse(user)
                 } else {
-                    warn!(kind = ?body.login_info, "Bad login kind");
+                    t::warn!(kind = ?body.login_info, "Bad login kind");
                     return Err(Error::BadRequest(
                         ErrorKind::forbidden(),
                         "Bad login type.",
@@ -184,7 +185,7 @@ pub(crate) async fn login_route(
                 } else if let Some(user) = user {
                     UserId::parse(user)
                 } else {
-                    warn!(kind = ?body.login_info, "Bad login kind");
+                    t::warn!(kind = ?body.login_info, "Bad login kind");
                     return Err(Error::BadRequest(
                         ErrorKind::forbidden(),
                         "Bad login type.",
@@ -214,7 +215,10 @@ pub(crate) async fn login_route(
             user_id
         }
         _ => {
-            warn!(kind = ?body.login_info, "Unsupported or unknown login kind");
+            t::warn!(
+                kind = ?body.login_info,
+                "Unsupported or unknown login kind"
+            );
             return Err(Error::BadRequest(
                 ErrorKind::Unknown,
                 "Unsupported login type.",
@@ -250,7 +254,7 @@ pub(crate) async fn login_route(
         )?;
     }
 
-    info!(%user_id, %device_id, "User logged in");
+    t::info!(%user_id, %device_id, "User logged in");
 
     // Homeservers are still required to send the `home_server` field
     #[allow(deprecated)]
@@ -292,7 +296,11 @@ pub(crate) async fn logout_route(
 
     services().users.remove_device(sender_user, sender_device)?;
 
-    info!(user_id = %sender_user, device_id = %sender_device, "User logged out");
+    t::info!(
+        user_id = %sender_user,
+        device_id = %sender_device,
+        "User logged out"
+    );
 
     Ok(Ra(logout::v3::Response::new()))
 }

src/api/client_server/state.rs

@@ -13,9 +13,11 @@ use ruma::{
     EventId, RoomAliasId, RoomId, UserId,
 };
 use serde::Deserialize;
-use tracing::warn;
 
-use crate::{service::pdu::PduBuilder, services, Ar, Error, Ra, Result};
+use crate::{
+    observability::prelude::*, service::pdu::PduBuilder, services, Ar, Error,
+    Ra, Result,
+};
 
 /// # `PUT /_matrix/client/r0/rooms/{roomId}/state/{eventType}/{stateKey}`
 ///
@@ -146,9 +148,10 @@ pub(crate) async fn get_state_events_for_key_route(
         .state_accessor
         .room_state_get(&body.room_id, &body.event_type, &body.state_key)?
         .ok_or_else(|| {
-            warn!(
+            t::warn!(
                 "State event {:?} not found in room {:?}",
-                &body.event_type, &body.room_id
+                &body.event_type,
+                &body.room_id
             );
             Error::BadRequest(ErrorKind::NotFound, "State event not found.")
         })?;
@@ -187,9 +190,10 @@ pub(crate) async fn get_state_events_for_empty_key_route(
         .state_accessor
         .room_state_get(&body.room_id, &body.event_type, "")?
         .ok_or_else(|| {
-            warn!(
+            t::warn!(
                 "State event {:?} not found in room {:?}",
-                &body.event_type, &body.room_id
+                &body.event_type,
+                &body.room_id
             );
             Error::BadRequest(ErrorKind::NotFound, "State event not found.")
         })?;
@@ -278,7 +282,7 @@ async fn validate_canonical_alias_event(
         .and_then(|old_event| {
             serde_json::from_str::<Extract>(old_event.content.get())
                 .inspect_err(|error| {
-                    warn!(
+                    t::warn!(
                         %error,
                         event_id=%old_event.event_id,
                        "Invalid canonical alias event in database"

src/api/client_server/sync.rs

@@ -1,8 +1,8 @@
 use ruma::{events::StateEventType, RoomId, UserId};
-use tracing::error;
 
 use crate::{
-    service::rooms::timeline::PduCount, services, Error, PduEvent, Result,
+    observability::prelude::*, service::rooms::timeline::PduCount, services,
+    Error, PduEvent, Result,
 };
 
 pub(crate) mod msc3575;
@@ -26,7 +26,7 @@ fn load_timeline(
             .filter_map(|x| match x {
                 Ok(x) => Some(x),
                 Err(error) => {
-                    error!(%error, "Bad PDU in pdus_since");
+                    error_err!(error, "Bad PDU in pdus_since");
                     None
                 }
             })

src/api/client_server/sync/msc3575.rs

@@ -21,11 +21,11 @@ use ruma::{
     },
     uint, JsOption, UInt, UserId,
 };
-use tracing::{debug, error};
 
 use super::{load_timeline, share_encrypted_room};
 use crate::{
-    service::rooms::timeline::PduCount, services, Ar, Error, Ra, Result,
+    observability::prelude::*, service::rooms::timeline::PduCount, services,
+    Ar, Error, Ra, Result,
 };
 
 #[allow(clippy::too_many_lines)]
@@ -93,7 +93,7 @@ pub(crate) async fn sync_events_v4_route(
             let Some(current_shortstatehash) =
                 services().rooms.state.get_room_shortstatehash(room_id)?
             else {
-                error!(%room_id, "Room has no state");
+                t::error!(%room_id, "Room has no state");
                 continue;
             };
 
@@ -171,7 +171,10 @@ pub(crate) async fn sync_events_v4_route(
                             let Some(pdu) =
                                 services().rooms.timeline.get_pdu(&event_id)?
                             else {
-                                error!(%event_id, "Event in state not found");
+                                t::error!(
+                                    %event_id,
+                                    "Event in state not found"
+                                );
                                 continue;
                             };
                             if pdu.kind == TimelineEventType::RoomMember {
@@ -450,7 +453,7 @@ pub(crate) async fn sync_events_v4_route(
             .map_or(Ok::<_, Error>(None), |(pdu_count, _)| {
                 Ok(Some(match pdu_count {
                     PduCount::Backfilled(_) => {
-                        error!("Timeline in backfill state?!");
+                        t::error!("Timeline in backfill state?!");
                         "0".to_owned()
                     }
                     PduCount::Normal(c) => c.to_string(),
@@ -602,7 +605,7 @@ pub(crate) async fn sync_events_v4_route(
         }
         match tokio::time::timeout(duration, watcher).await {
             Ok(x) => x.expect("watcher should succeed"),
-            Err(error) => debug!(%error, "Timed out"),
+            Err(error) => debug_err!(error, "Timed out"),
         };
     }
 

src/api/client_server/sync/v3.rs

@@ -23,10 +23,10 @@ use ruma::{
     },
     uint, DeviceId, EventId, OwnedRoomId, OwnedUserId, RoomId, UInt, UserId,
 };
-use tracing::{debug, error, field};
 
 use super::{load_timeline, share_encrypted_room};
 use crate::{
+    observability::prelude::*,
     service::{pdu::EventHash, rooms::timeline::PduCount},
     services, utils, Ar, Error, PduEvent, Ra, Result,
 };
@@ -85,7 +85,7 @@ struct SyncContext<'a> {
 /// - If the user left after `since`: `prev_batch` token, empty state (TODO:
 ///   subset of the state at the point of the leave)
 #[allow(clippy::too_many_lines)]
-#[tracing::instrument(
+#[t::instrument(
     skip_all,
     fields(
         sender_user,
@@ -99,12 +99,12 @@ struct SyncContext<'a> {
 pub(crate) async fn sync_events_route(
     body: Ar<sync_events::v3::Request>,
 ) -> Result<Ra<sync_events::v3::Response>, Ra<UiaaResponse>> {
-    let current_span = tracing::Span::current();
+    let current_span = t::Span::current();
 
     let sender_user = body.sender_user.expect("user is authenticated");
-    current_span.record("sender_user", field::display(&sender_user));
+    current_span.record("sender_user", t::field::display(&sender_user));
     let sender_device = body.sender_device.expect("user is authenticated");
-    current_span.record("sender_device", field::display(&sender_device));
+    current_span.record("sender_device", t::field::display(&sender_device));
     let body = body.body;
 
     // Setup watchers, so if there's no response, we can wait for them
@@ -279,13 +279,13 @@ pub(crate) async fn sync_events_route(
         }
         match tokio::time::timeout(duration, watcher).await {
             Ok(x) => x.expect("watcher should succeed"),
-            Err(error) => debug!(%error, "Timed out"),
+            Err(error) => debug_err!(error, "Timed out"),
         };
     }
     Ok(Ra(response))
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn collect_joined_rooms(
     ctx: &SyncContext<'_>,
     device_list_updates: &mut HashSet<OwnedUserId>,
@@ -316,7 +316,7 @@ async fn collect_joined_rooms(
     Ok(joined_rooms)
 }
 
-#[tracing::instrument(skip_all, fields(room_id = %room_id))]
+#[t::instrument(skip_all, fields(room_id = %room_id))]
 #[allow(clippy::too_many_arguments, clippy::too_many_lines)]
 async fn load_joined_room(
     ctx: &SyncContext<'_>,
@@ -366,7 +366,7 @@ async fn load_joined_room(
     let Some(current_shortstatehash) =
         services().rooms.state.get_room_shortstatehash(room_id)?
     else {
-        error!("Room has no state");
+        t::error!("Room has no state");
         return Err(Error::BadDatabase("Room has no state"));
     };
 
@@ -526,7 +526,7 @@ async fn load_joined_room(
                     let Some(pdu) =
                         services().rooms.timeline.get_pdu(&event_id)?
                     else {
-                        error!(%event_id, "Event in state not found");
+                        t::error!(%event_id, "Event in state not found");
                         continue;
                     };
                     state_events.push(pdu);
@@ -544,7 +544,7 @@ async fn load_joined_room(
                     let Some(pdu) =
                         services().rooms.timeline.get_pdu(&event_id)?
                     else {
-                        error!(%event_id, "Event in state not found");
+                        t::error!(%event_id, "Event in state not found");
                         continue;
                     };
 
@@ -615,7 +615,7 @@ async fn load_joined_room(
                         let Some(pdu) =
                             services().rooms.timeline.get_pdu(&event_id)?
                         else {
-                            error!(%event_id, "Event in state not found");
+                            t::error!(%event_id, "Event in state not found");
                             continue;
                         };
 
@@ -748,9 +748,9 @@ async fn load_joined_room(
                             lazy_loaded.insert(state_key_userid);
                         }
                         Err(error) => {
-                            error!(
+                            error_err!(
+                                error,
                                 event_id = %pdu.event_id,
-                                %error,
                                 "Invalid state key for member event",
                             );
                         }
@@ -834,7 +834,7 @@ async fn load_joined_room(
         |(pdu_count, _)| {
             Ok(Some(match pdu_count {
                 PduCount::Backfilled(_) => {
-                    error!("Timeline in backfill state?!");
+                    t::error!("Timeline in backfill state?!");
                     "0".to_owned()
                 }
                 PduCount::Normal(c) => c.to_string(),
@@ -921,7 +921,7 @@ async fn load_joined_room(
     })
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn collect_left_rooms(
     ctx: &SyncContext<'_>,
 ) -> Result<BTreeMap<OwnedRoomId, LeftRoom>> {
@@ -1017,7 +1017,7 @@ async fn collect_left_rooms(
                 ctx.sender_user.as_str(),
             )?
         else {
-            error!("Left room but no left state event");
+            t::error!("Left room but no left state event");
             continue;
         };
 
@@ -1026,7 +1026,7 @@ async fn collect_left_rooms(
             .state_accessor
             .pdu_shortstatehash(&left_event_id)?
         else {
-            error!("Leave event has no state");
+            t::error!("Leave event has no state");
             continue;
         };
 
@@ -1059,7 +1059,7 @@ async fn collect_left_rooms(
                     let Some(pdu) =
                         services().rooms.timeline.get_pdu(&event_id)?
                     else {
-                        error!(%event_id, "Event in state not found");
+                        t::error!(%event_id, "Event in state not found");
                         continue;
                     };
 
@@ -1094,7 +1094,7 @@ async fn collect_left_rooms(
     Ok(left_rooms)
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn collect_invited_rooms(
     ctx: &SyncContext<'_>,
 ) -> Result<BTreeMap<OwnedRoomId, InvitedRoom>> {

src/api/ruma_wrapper/axum.rs

@@ -25,10 +25,12 @@ use ruma::{
     OwnedServerName, OwnedUserId, UserId,
 };
 use serde::Deserialize;
-use tracing::{error, warn};
 
 use super::{Ar, Ra};
-use crate::{service::appservice::RegistrationInfo, services, Error, Result};
+use crate::{
+    observability::prelude::*, service::appservice::RegistrationInfo, services,
+    Error, Result,
+};
 
 enum Token {
     Appservice(Box<RegistrationInfo>),
@@ -82,7 +84,7 @@ async fn ar_from_request_inner(
     let query_params: QueryParams = match serde_html_form::from_str(query) {
         Ok(params) => params,
         Err(error) => {
-            error!(%error, %query, "Failed to deserialize query parameters");
+            error_err!(error, %query, "Failed to deserialize query parameters");
             return Err(Error::BadRequest(
                 ErrorKind::Unknown,
                 "Failed to read query parameters",
@@ -182,7 +184,10 @@ async fn ar_from_request_inner(
                     .extract::<TypedHeader<Authorization<XMatrix>>>()
                     .await
                     .map_err(|error| {
-                        warn!(%error, "Missing or invalid Authorization header");
+                        warn_err!(
+                            error,
+                            "Missing or invalid Authorization header"
+                        );
 
                         let msg = match error.reason() {
                             TypedHeaderRejectionReason::Missing => {
@@ -199,7 +204,7 @@ async fn ar_from_request_inner(
 
                 if let Some(destination) = x_matrix.destination {
                     if destination != services().globals.server_name() {
-                        warn!(
+                        t::warn!(
                             %destination,
                             "Incorrect destination in X-Matrix header"
                         );
@@ -278,7 +283,7 @@ async fn ar_from_request_inner(
                 let keys = match keys_result {
                     Ok(b) => b,
                     Err(error) => {
-                        warn!(%error, "Failed to fetch signing keys");
+                        warn_err!(error, "Failed to fetch signing keys");
                         return Err(Error::BadRequest(
                             ErrorKind::forbidden(),
                             "Failed to fetch signing keys.",
@@ -304,15 +309,15 @@ async fn ar_from_request_inner(
                 {
                     Ok(()) => (None, None, Some(x_matrix.origin), None),
                     Err(error) => {
-                        warn!(
+                        warn_err!(
-                            %error,
+                            error,
                             origin = %x_matrix.origin,
                             object = ?request_map,
                             "Failed to verify JSON request"
                         );
 
                         if parts.uri.to_string().contains('@') {
-                            warn!(
+                            t::warn!(
                                 "Request uri contained '@' character. Make \
                                  sure your reverse proxy gives Grapevine the \
                                  raw uri (apache: use nocanon)"
@@ -405,7 +410,7 @@ where
 {
     type Rejection = Error;
 
-    #[tracing::instrument("ar_from_request", skip_all)]
+    #[t::instrument("ar_from_request", skip_all)]
     async fn from_request(
         req: axum::extract::Request,
         _state: &S,
@@ -415,8 +420,8 @@ where
         let body =
             T::try_from_http_request(pieces.http_request, &pieces.path_params)
                 .map_err(|error| {
-                    warn!(
+                    warn_err!(
-                        %error,
+                        error,
                         body = ?pieces.json_body,
                         "Request body JSON structure is incorrect"
                     );

src/api/server_server.rs

@@ -63,12 +63,11 @@ use ruma::{
 };
 use serde_json::value::{to_raw_value, RawValue as RawJsonValue};
 use tokio::sync::RwLock;
-use tracing::{debug, error, field, trace, trace_span, warn};
 
 use super::appservice_server;
 use crate::{
     api::client_server::{self, claim_keys_helper, get_keys_helper},
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     service::{
         globals::SigningKeys,
         pdu::{gen_event_id_canonical_json, PduBuilder},
@@ -147,7 +146,7 @@ pub(crate) enum AllowLoopbackRequests {
     No,
 }
 
-#[tracing::instrument(skip(request, log_error, allow_loopback), fields(url))]
+#[t::instrument(skip(request, log_error, allow_loopback), fields(url))]
 pub(crate) async fn send_request<T>(
     destination: &ServerName,
     request: T,
@@ -169,7 +168,7 @@ where
         ));
     }
 
-    debug!("Preparing to send request");
+    t::debug!("Preparing to send request");
 
     let mut write_destination_to_cache = false;
 
@@ -201,8 +200,8 @@ where
             &[MatrixVersion::V1_11],
         )
         .map_err(|error| {
-            warn!(
+            warn_err!(
-                %error,
+                error,
                 actual_destination = actual_destination_str,
                 "Failed to find destination",
             );
@@ -273,8 +272,8 @@ where
 
     // can be enabled selectively using `filter =
     // grapevine[outgoing_request_curl]=trace` in config
-    trace_span!("outgoing_request_curl").in_scope(|| {
+    t::trace_span!("outgoing_request_curl").in_scope(|| {
-        trace!(
+        t::trace!(
             cmd = utils::curlify(&http_request),
             "curl command line for outgoing request"
         );
@@ -282,21 +281,21 @@ where
     let reqwest_request = reqwest::Request::try_from(http_request)?;
 
     let url = reqwest_request.url().clone();
-    tracing::Span::current().record("url", field::display(url));
+    t::Span::current().record("url", t::field::display(url));
 
-    debug!("Sending request");
+    t::debug!("Sending request");
     let response =
         services().globals.federation_client().execute(reqwest_request).await;
 
     let mut response = response.inspect_err(|error| {
         if log_error == LogRequestError::Yes {
-            warn!(%error, "Could not send request");
+            warn_err!(error, "Could not send request");
         }
     })?;
 
     // reqwest::Response -> http::Response conversion
     let status = response.status();
-    debug!(status = u16::from(status), "Received response");
+    t::debug!(status = u16::from(status), "Received response");
     let mut http_response_builder =
         http::Response::builder().status(status).version(response.version());
     mem::swap(
@@ -306,16 +305,16 @@ where
             .expect("http::response::Builder is usable"),
     );
 
-    debug!("Getting response bytes");
+    t::debug!("Getting response bytes");
     // TODO: handle timeout
     let body = response.bytes().await.unwrap_or_else(|error| {
-        warn!(%error, "Server error");
+        warn_err!(error, "Server error");
         Vec::new().into()
     });
-    debug!("Got response bytes");
+    t::debug!("Got response bytes");
 
     if status != 200 {
-        warn!(
+        t::warn!(
             status = u16::from(status),
             response =
                 dbg_truncate_str(String::from_utf8_lossy(&body).as_ref(), 100)
@@ -335,7 +334,7 @@ where
         ));
     }
 
-    debug!("Parsing response bytes");
+    t::debug!("Parsing response bytes");
     let response = T::IncomingResponse::try_from_http_response(http_response);
     if response.is_ok() && write_destination_to_cache {
         METRICS.record_lookup(Lookup::FederationDestination, FoundIn::Remote);
@@ -346,7 +345,7 @@ where
     }
 
     response.map_err(|e| {
-        warn!(error = %e, "Invalid 200 response");
+        warn_err!(e, "Invalid 200 response");
         Error::BadServerResponse("Server returned bad 200 response.")
     })
 }
@@ -374,29 +373,29 @@ fn add_port_to_hostname(destination_str: &str) -> FedDest {
 /// Numbers in comments below refer to bullet points in linked section of
 /// specification
 #[allow(clippy::too_many_lines)]
-#[tracing::instrument(ret(level = "debug"))]
+#[t::instrument(ret(level = "debug"))]
 async fn find_actual_destination(
     destination: &'_ ServerName,
 ) -> (FedDest, FedDest) {
-    debug!("Finding actual destination");
+    t::debug!("Finding actual destination");
     let destination_str = destination.as_str().to_owned();
     let mut hostname = destination_str.clone();
     let actual_destination = match get_ip_with_port(&destination_str) {
         Some(host_port) => {
-            debug!("1: IP literal with provided or default port");
+            t::debug!("1: IP literal with provided or default port");
             host_port
         }
         None => {
             if let Some(pos) = destination_str.find(':') {
-                debug!("2: Hostname with included port");
+                t::debug!("2: Hostname with included port");
                 let (host, port) = destination_str.split_at(pos);
                 FedDest::Named(host.to_owned(), port.to_owned())
             } else {
-                debug!(%destination, "Requesting well known");
+                t::debug!(%destination, "Requesting well known");
                 if let Some(delegated_hostname) =
                     request_well_known(destination.as_str()).await
                 {
-                    debug!("3: A .well-known file is available");
+                    t::debug!("3: A .well-known file is available");
                     hostname = add_port_to_hostname(&delegated_hostname)
                         .to_uri_string();
                     if let Some(host_and_port) =
@@ -404,15 +403,19 @@ async fn find_actual_destination(
                     {
                         host_and_port
                     } else if let Some(pos) = delegated_hostname.find(':') {
-                        debug!("3.2: Hostname with port in .well-known file");
+                        t::debug!(
+                            "3.2: Hostname with port in .well-known file"
+                        );
                         let (host, port) = delegated_hostname.split_at(pos);
                         FedDest::Named(host.to_owned(), port.to_owned())
                     } else {
-                        debug!("Delegated hostname has no port in this branch");
+                        t::debug!(
+                            "Delegated hostname has no port in this branch"
+                        );
                         if let Some(hostname_override) =
                             query_srv_record(&delegated_hostname).await
                         {
-                            debug!("3.3: SRV lookup successful");
+                            t::debug!("3.3: SRV lookup successful");
                             let force_port = hostname_override.port();
 
                             if let Ok(override_ip) = services()
@@ -434,7 +437,7 @@ async fn find_actual_destination(
                                         ),
                                     );
                             } else {
-                                warn!(
+                                t::warn!(
                                     "Using SRV record, but could not resolve \
                                      to IP"
                                 );
@@ -449,7 +452,7 @@ async fn find_actual_destination(
                                 add_port_to_hostname(&delegated_hostname)
                             }
                         } else {
-                            debug!(
+                            t::debug!(
                                 "3.4: No SRV records, just use the hostname \
                                  from .well-known"
                             );
@@ -457,11 +460,11 @@ async fn find_actual_destination(
                         }
                     }
                 } else {
-                    debug!("4: No .well-known or an error occured");
+                    t::debug!("4: No .well-known or an error occured");
                     if let Some(hostname_override) =
                         query_srv_record(&destination_str).await
                     {
-                        debug!("4: SRV record found");
+                        t::debug!("4: SRV record found");
                         let force_port = hostname_override.port();
 
                         if let Ok(override_ip) = services()
@@ -483,7 +486,7 @@ async fn find_actual_destination(
                                     ),
                                 );
                         } else {
-                            warn!(
+                            t::warn!(
                                 "Using SRV record, but could not resolve to IP"
                             );
                         }
@@ -494,14 +497,14 @@ async fn find_actual_destination(
                             add_port_to_hostname(&hostname)
                         }
                     } else {
-                        debug!("5: No SRV record found");
+                        t::debug!("5: No SRV record found");
                         add_port_to_hostname(&destination_str)
                     }
                 }
             }
         }
     };
-    debug!(?actual_destination, "Resolved actual destination");
+    t::debug!(?actual_destination, "Resolved actual destination");
 
     // Can't use get_ip_with_port here because we don't want to add a port
     // to an IP address if it wasn't specified
@@ -518,7 +521,7 @@ async fn find_actual_destination(
     (actual_destination, hostname)
 }
 
-#[tracing::instrument(ret(level = "debug"))]
+#[t::instrument(ret(level = "debug"))]
 async fn query_given_srv_record(record: &str) -> Option<FedDest> {
     services()
         .globals
@@ -540,7 +543,7 @@ async fn query_given_srv_record(record: &str) -> Option<FedDest> {
         .unwrap_or(None)
 }
 
-#[tracing::instrument(ret(level = "debug"))]
+#[t::instrument(ret(level = "debug"))]
 async fn query_srv_record(hostname: &'_ str) -> Option<FedDest> {
     let hostname = hostname.trim_end_matches('.');
 
@@ -553,7 +556,7 @@ async fn query_srv_record(hostname: &'_ str) -> Option<FedDest> {
     }
 }
 
-#[tracing::instrument(ret(level = "debug"))]
+#[t::instrument(ret(level = "debug"))]
 async fn request_well_known(destination: &str) -> Option<String> {
     let response = services()
         .globals
@@ -561,13 +564,13 @@ async fn request_well_known(destination: &str) -> Option<String> {
         .get(format!("https://{destination}/.well-known/matrix/server"))
         .send()
         .await;
-    debug!("Got well known response");
+    t::debug!("Got well known response");
     if let Err(error) = &response {
-        debug!(%error, "Failed to request .well-known");
+        debug_err!(error, "Failed to request .well-known");
         return None;
     }
     let text = response.ok()?.text().await;
-    debug!("Got well known response text");
+    t::debug!("Got well known response text");
     let body: serde_json::Value = serde_json::from_str(&text.ok()?).ok()?;
     Some(body.get("m.server")?.as_str()?.to_owned())
 }
@@ -695,13 +698,13 @@ pub(crate) async fn get_public_rooms_route(
     }))
 }
 
-#[tracing::instrument(skip(pdu))]
+#[t::instrument(skip(pdu))]
 pub(crate) fn parse_incoming_pdu(
     pdu: &RawJsonValue,
 ) -> Result<(OwnedEventId, CanonicalJsonObject, OwnedRoomId)> {
     let value: CanonicalJsonObject =
         serde_json::from_str(pdu.get()).map_err(|error| {
-            warn!(%error, object = ?pdu, "Error parsing incoming event");
+            warn_err!(error, object = ?pdu, "Error parsing incoming event");
             Error::BadServerResponse("Invalid PDU in server response")
         })?;
 
@@ -747,7 +750,7 @@ pub(crate) async fn send_transaction_message_route(
     for pdu in &body.pdus {
         let value: CanonicalJsonObject = serde_json::from_str(pdu.get())
             .map_err(|error| {
-                warn!(%error, object = ?pdu, "Error parsing incoming event");
+                warn_err!(error, object = ?pdu, "Error parsing incoming event");
                 Error::BadServerResponse("Invalid PDU in server response")
             })?;
         let room_id: OwnedRoomId = value
@@ -764,7 +767,7 @@ pub(crate) async fn send_transaction_message_route(
             .get_create_content::<ExtractVersion>(&room_id)
             .is_err()
         {
-            debug!(%room_id, "This server is not in the room");
+            t::debug!(%room_id, "This server is not in the room");
             continue;
         }
 
@@ -772,7 +775,7 @@ pub(crate) async fn send_transaction_message_route(
         let (event_id, value, room_id) = match r {
             Ok(t) => t,
             Err(error) => {
-                warn!(%error, object = ?pdu, "Error parsing incoming event");
+                warn_err!(error, object = ?pdu, "Error parsing incoming event");
                 continue;
             }
         };
@@ -803,7 +806,7 @@ pub(crate) async fn send_transaction_message_route(
         );
         drop(federation_token);
 
-        debug!(
+        t::debug!(
             %event_id,
             elapsed = ?start_time.elapsed(),
             "Finished handling event",
@@ -813,7 +816,7 @@ pub(crate) async fn send_transaction_message_route(
     for pdu in &resolved_map {
         if let (event_id, Err(error)) = pdu {
             if matches!(error, Error::BadRequest(ErrorKind::NotFound, _)) {
-                warn!(%error, %event_id, "Incoming PDU failed");
+                warn_err!(error, %event_id, "Incoming PDU failed");
             }
         }
     }
@@ -828,7 +831,7 @@ pub(crate) async fn send_transaction_message_route(
                 for (room_id, room_updates) in receipt.receipts {
                     for (user_id, user_updates) in room_updates.read {
                         if user_id.server_name() != sender_servername {
-                            warn!(
+                            t::warn!(
                                 %user_id,
                                 %sender_servername,
                                 "Got receipt EDU from incorrect homeserver, \
@@ -874,7 +877,7 @@ pub(crate) async fn send_transaction_message_route(
                                 )?;
                         } else {
                             // TODO fetch missing events
-                            debug!(
+                            t::debug!(
                                 ?user_updates,
                                 "No known event ids in read receipt",
                             );
@@ -884,7 +887,7 @@ pub(crate) async fn send_transaction_message_route(
             }
             Edu::Typing(typing) => {
                 if typing.user_id.server_name() != sender_servername {
-                    warn!(
+                    t::warn!(
                         user_id = %typing.user_id,
                         %sender_servername,
                         "Got typing EDU from incorrect homeserver, ignoring",
@@ -922,7 +925,7 @@ pub(crate) async fn send_transaction_message_route(
                 ..
             }) => {
                 if user_id.server_name() != sender_servername {
-                    warn!(
+                    t::warn!(
                         %user_id,
                         %sender_servername,
                         "Got device list update EDU from incorrect homeserver, \
@@ -939,7 +942,7 @@ pub(crate) async fn send_transaction_message_route(
                 messages,
             }) => {
                 if sender.server_name() != sender_servername {
-                    warn!(
+                    t::warn!(
                         user_id = %sender,
                         %sender_servername,
                         "Got direct-to-device EDU from incorrect homeserver, \
@@ -965,8 +968,8 @@ pub(crate) async fn send_transaction_message_route(
                                     &ev_type.to_string(),
                                     event.deserialize_as().map_err(
                                         |error| {
-                                            warn!(
+                                            warn_err!(
-                                                %error,
+                                                error,
                                                 object = ?event.json(),
                                                 "To-Device event is invalid",
                                             );
@@ -1018,7 +1021,7 @@ pub(crate) async fn send_transaction_message_route(
                 self_signing_key,
             }) => {
                 if user_id.server_name() != sender_servername {
-                    warn!(
+                    t::warn!(
                         %user_id,
                         %sender_servername,
                         "Got signing key update from incorrect homeserver, \
@@ -1063,7 +1066,7 @@ pub(crate) async fn get_event_route(
     let event =
         services().rooms.timeline.get_pdu_json(&body.event_id)?.ok_or_else(
             || {
-                warn!(event_id = %body.event_id, "Event not found");
+                t::warn!(event_id = %body.event_id, "Event not found");
                 Error::BadRequest(ErrorKind::NotFound, "Event not found.")
             },
         )?;
@@ -1116,7 +1119,7 @@ pub(crate) async fn get_backfill_route(
     let sender_servername =
         body.sender_servername.as_ref().expect("server is authenticated");
 
-    debug!(server = %sender_servername, "Got backfill request");
+    t::debug!(server = %sender_servername, "Got backfill request");
 
     if !services()
         .rooms
@@ -1225,7 +1228,7 @@ pub(crate) async fn get_missing_events_route(
                 })?;
 
             if event_room_id != body.room_id {
-                warn!(
+                t::warn!(
                     event_id = %queued_events[i],
                     expected_room_id = %body.room_id,
                     actual_room_id = %event_room_id,
@@ -1308,7 +1311,7 @@ pub(crate) async fn get_event_authorization_route(
     let event =
         services().rooms.timeline.get_pdu_json(&body.event_id)?.ok_or_else(
             || {
-                warn!(event_id = %body.event_id, "Event not found");
+                t::warn!(event_id = %body.event_id, "Event not found");
                 Error::BadRequest(ErrorKind::NotFound, "Event not found.")
             },
         )?;
@@ -1399,7 +1402,7 @@ pub(crate) async fn get_room_state_route(
                 {
                     Some(PduEvent::convert_to_outgoing_federation_event(json))
                 } else {
-                    error!(%event_id, "Could not find event JSON for event");
+                    t::error!(%event_id, "Could not find event JSON for event");
                     None
                 }
             })
@@ -1504,7 +1507,7 @@ pub(crate) async fn create_join_event_template_route(
             .map(|join_rules_event| {
                 serde_json::from_str(join_rules_event.content.get()).map_err(
                     |error| {
-                        warn!(%error, "Invalid join rules event");
+                        warn_err!(error, "Invalid join rules event");
                         Error::bad_database("Invalid join rules event in db.")
                     },
                 )
@@ -1601,7 +1604,7 @@ async fn create_join_event(
             .map(|join_rules_event| {
                 serde_json::from_str(join_rules_event.content.get()).map_err(
                     |error| {
-                        warn!(%error, "Invalid join rules event");
+                        warn_err!(error, "Invalid join rules event");
                         Error::bad_database("Invalid join rules event in db.")
                     },
                 )
@@ -1864,7 +1867,7 @@ pub(crate) async fn create_invite_route(
 
     let pdu: PduEvent =
         serde_json::from_value(event.into()).map_err(|error| {
-            warn!(%error, "Invalid invite event");
+            warn_err!(error, "Invalid invite event");
             Error::BadRequest(ErrorKind::InvalidParam, "Invalid invite event.")
         })?;
 
@@ -2098,10 +2101,11 @@ pub(crate) async fn media_download_route(
     };
 
     let content_disposition = content_disposition.and_then(|s| {
-        s.parse().inspect_err(
+        s.parse()
-            |error| warn!(%error, "Invalid Content-Disposition in database"),
+            .inspect_err(|error| {
-        )
+                warn_err!(error, "Invalid Content-Disposition in database");
-        .ok()
+            })
+            .ok()
     });
 
     Ok(Ra(authenticated_media::get_content::v1::Response {

src/cli/check_config.rs

@@ -1,12 +1,10 @@
-use tracing::info;
+use crate::{cli::CheckConfigArgs, config, error, observability::prelude::*};
-
-use crate::{cli::CheckConfigArgs, config, error};
 
 pub(crate) async fn run(
     args: CheckConfigArgs,
 ) -> Result<(), error::CheckConfigCommand> {
     let _config =
         config::load(args.config.config.as_ref(), args.sandboxed).await?;
-    info!("Configuration looks good");
+    t::info!("Configuration looks good");
     Ok(())
 }

src/cli/serve.rs

@@ -46,7 +46,6 @@ use tower_http::{
     trace::TraceLayer,
     ServiceBuilderExt as _,
 };
-use tracing::{debug, info, info_span, warn, Instrument};
 
 use super::ServeArgs;
 use crate::{
@@ -58,7 +57,9 @@ use crate::{
     },
     config::{self, Config, ListenComponent, ListenConfig, ListenTransport},
     database::KeyValueDatabase,
-    error, observability, services, set_application_state,
+    error, observability,
+    observability::prelude::*,
+    services, set_application_state,
     utils::{
         self,
         error::{Error, Result},
@@ -78,7 +79,7 @@ pub(crate) async fn run(args: ServeArgs) -> Result<(), error::ServeCommand> {
 
     let (_guard, reload_handles) = observability::init(&config)?;
 
-    info!("Loading database");
+    t::info!("Loading database");
     let db = Box::leak(Box::new(
         KeyValueDatabase::load_or_create(&config)
             .map_err(Error::DatabaseError)?,
@@ -92,19 +93,19 @@ pub(crate) async fn run(args: ServeArgs) -> Result<(), error::ServeCommand> {
 
     db.apply_migrations().await.map_err(Error::DatabaseError)?;
 
-    info!("Starting background tasks");
+    t::info!("Starting background tasks");
     services().admin.start_handler();
     services().sending.start_handler();
     KeyValueDatabase::start_cleanup_task();
     services().globals.set_emergency_access();
 
-    info!("Starting server");
+    t::info!("Starting server");
     run_server().await?;
 
     Ok(())
 }
 
-#[tracing::instrument]
+#[t::instrument]
 async fn federation_self_test() -> Result<()> {
     let response = server_server::send_request(
         &services().globals.config.server_name,
@@ -119,7 +120,7 @@ async fn federation_self_test() -> Result<()> {
         .as_ref()
         .is_none_or(|s| s.name.as_deref() != Some(env!("CARGO_PKG_NAME")))
     {
-        error!(?response, "unexpected server version");
+        t::error!(?response, "unexpected server version");
         return Err(Error::BadConfig(
             "Got unexpected version from our own version endpoint",
         ));
@@ -309,7 +310,7 @@ async fn run_server() -> Result<(), error::Serve> {
                             |h| h.proxied_address().map(|addr| addr.source),
                         );
 
-                    tracing::info_span!(
+                    t::info_span!(
                         "http_request",
                         otel.name = format!("{method} {endpoint}"),
                         %method,
@@ -320,21 +321,17 @@ async fn run_server() -> Result<(), error::Serve> {
                         ),
                     )
                 })
-                .on_request(
+                .on_request(|request: &http::Request<_>, _span: &t::Span| {
-                    |request: &http::Request<_>, _span: &tracing::Span| {
+                    // can be enabled selectively using `filter =
-                        // can be enabled selectively using `filter =
+                    // grapevine[incoming_request_curl]=trace` in config
-                        // grapevine[incoming_request_curl]=trace` in config
+                    t::trace_span!("incoming_request_curl").in_scope(|| {
-                        tracing::trace_span!("incoming_request_curl").in_scope(
+                        t::trace!(
-                            || {
+                            cmd = utils::curlify(request),
-                                tracing::trace!(
+                            "curl command line for incoming request (guessed \
-                                    cmd = utils::curlify(request),
+                             hostname)"
-                                    "curl command line for incoming request \
-                                     (guessed hostname)"
-                                );
-                            },
                         );
-                    },
+                    });
-                ),
+                }),
         )
         .layer(axum::middleware::from_fn(unrecognized_method))
         .layer(
@@ -372,7 +369,7 @@ async fn run_server() -> Result<(), error::Serve> {
     }
 
     for listen in &config.listen {
-        info!(listener = %listen, "Listening for incoming traffic");
+        t::info!(listener = %listen, "Listening for incoming traffic");
         spawner.spawn_server(listen.clone())?;
     }
 
@@ -382,7 +379,7 @@ async fn run_server() -> Result<(), error::Serve> {
         federation_self_test()
             .await
             .map_err(error::Serve::FederationSelfTestFailed)?;
-        debug!("Federation self-test completed successfully");
+        t::debug!("Federation self-test completed successfully");
     }
 
     set_application_state(ApplicationState::Ready);
@@ -420,7 +417,7 @@ async fn unrecognized_method(
     let uri = req.uri().clone();
     let inner = next.run(req).await;
     if inner.status() == StatusCode::METHOD_NOT_ALLOWED {
-        warn!(%method, %uri, "Method not allowed");
+        t::warn!(%method, %uri, "Method not allowed");
         return Ok(Ra(UiaaResponse::MatrixError(RumaError {
             body: ErrorBody::Standard {
                 kind: ErrorKind::Unrecognized,
@@ -747,13 +744,13 @@ async fn handle_signals(
     let sig = loop {
         tokio::select! {
             () = sighup() => {
-                info!("Received reload request");
+                t::info!("Received reload request");
 
                 set_application_state(ApplicationState::Reloading);
 
                 if let Some(tls_config) = tls_config.as_ref() {
                     if let Err(error) = reload_tls_config(tls_config).await {
-                        error!(?error, "Failed to reload TLS config");
+                        t::error!(?error, "Failed to reload TLS config");
                     }
                 }
 
@@ -764,7 +761,7 @@ async fn handle_signals(
         }
     };
 
-    warn!(signal = %sig, "Shutting down due to signal");
+    t::warn!(signal = %sig, "Shutting down due to signal");
 
     services().globals.shutdown();
 
@@ -787,7 +784,7 @@ async fn unauthenticated_media_disabled(_: Uri) -> impl IntoResponse {
 }
 
 async fn not_found(method: Method, uri: Uri) -> impl IntoResponse {
-    debug!(%method, %uri, "Unknown route");
+    t::debug!(%method, %uri, "Unknown route");
     Error::BadRequest(ErrorKind::Unrecognized, "Unrecognized request")
 }
 
@@ -853,7 +850,7 @@ macro_rules! impl_ruma_handler {
                         on(
                             method_filter,
                             |$( $ty: $ty, )* req: Ar<Req>| async move {
-                                let span = info_span!(
+                                let span = t::info_span!(
                                     "run_ruma_handler",
                                     auth.user = ?req.sender_user,
                                     auth.device = ?req.sender_device,

src/database.rs

@@ -11,10 +11,10 @@ use ruma::{
     push::Ruleset,
     EventId, OwnedRoomId, RoomId, UserId,
 };
-use tracing::{debug, error, info, info_span, warn, Instrument};
 
 use crate::{
     config::DatabaseBackend,
+    observability::prelude::*,
     service::{
         media::MediaFileKey,
         rooms::{
@@ -258,7 +258,7 @@ impl KeyValueDatabase {
         }
 
         if count > 1 {
-            warn!("Multiple databases at database_path detected");
+            t::warn!("Multiple databases at database_path detected");
             return Ok(());
         }
 
@@ -469,7 +469,7 @@ impl KeyValueDatabase {
                     let room_id =
                         parts.next().expect("split always returns one element");
                     let Some(servername) = parts.next() else {
-                        error!("Migration: Invalid roomserverid in db.");
+                        t::error!("Migration: Invalid roomserverid in db.");
                         continue;
                     };
                     let mut serverroomid = servername.to_vec();
@@ -532,7 +532,7 @@ impl KeyValueDatabase {
                             if user.server_name()
                                 != services().globals.server_name()
                             {
-                                info!(?user, "Migration: creating user");
+                                t::info!(?user, "Migration: creating user");
                                 services().users.create(&user, None)?;
                             }
                         }
@@ -718,7 +718,7 @@ impl KeyValueDatabase {
                     let shortroomid =
                         services().globals.next_count()?.to_be_bytes();
                     self.roomid_shortroomid.insert(&room_id, &shortroomid)?;
-                    info!("Migration: 8");
+                    t::info!("Migration: 8");
                 }
                 // Update pduids db layout
                 let mut batch = self.pduid_pdu.iter().filter_map(|(key, v)| {
@@ -799,10 +799,10 @@ impl KeyValueDatabase {
                 while iter.peek().is_some() {
                     self.tokenids
                         .insert_batch(&mut iter.by_ref().take(1000))?;
-                    debug!("Inserted smaller batch");
+                    t::debug!("Inserted smaller batch");
                 }
 
-                info!("Deleting starts");
+                t::info!("Deleting starts");
 
                 let batch2: Vec<_> = self
                     .tokenids
@@ -848,8 +848,8 @@ impl KeyValueDatabase {
                     ) {
                         Ok(u) => u,
                         Err(error) => {
-                            warn!(
+                            warn_err!(
-                                %error,
+                                error,
                                 user_localpart = %username,
                                 "Invalid username",
                             );
@@ -950,8 +950,8 @@ impl KeyValueDatabase {
                     ) {
                         Ok(u) => u,
                         Err(error) => {
-                            warn!(
+                            warn_err!(
-                                %error,
+                                error,
                                 user_localpart = %username,
                                 "Invalid username",
                             );
@@ -1002,7 +1002,7 @@ impl KeyValueDatabase {
                 "database should be migrated to the current version",
             );
 
-            info!(
+            t::info!(
                 backend = %services().globals.config.database.backend,
                 version = latest_database_version,
                 "Loaded database",
@@ -1015,7 +1015,7 @@ impl KeyValueDatabase {
             // Create the admin room and server user on first run
             services().admin.create_admin_room().await?;
 
-            info!(
+            t::info!(
                 backend = %services().globals.config.database.backend,
                 version = latest_database_version,
                 "Created new database",
@@ -1025,7 +1025,7 @@ impl KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument]
+    #[t::instrument]
     pub(crate) fn start_cleanup_task() {
         use std::time::{Duration, Instant};
 
@@ -1046,28 +1046,31 @@ impl KeyValueDatabase {
                 #[cfg(unix)]
                 let msg = tokio::select! {
                     _ = i.tick() => || {
-                        debug!("cleanup: Timer ticked");
+                        t::debug!("cleanup: Timer ticked");
                     },
                     _ = s.recv() => || {
-                        debug!("cleanup: Received SIGHUP");
+                        t::debug!("cleanup: Received SIGHUP");
                     },
                 };
                 #[cfg(not(unix))]
                 let msg = {
                     i.tick().await;
-                    || debug!("cleanup: Timer ticked")
+                    || t::debug!("cleanup: Timer ticked")
                 };
 
                 async {
                     msg();
                     let start = Instant::now();
                     if let Err(error) = services().globals.cleanup() {
-                        error!(%error, "cleanup: Error");
+                        error_err!(error, "cleanup: Error");
                     } else {
-                        debug!(elapsed = ?start.elapsed(), "cleanup: Finished");
+                        t::debug!(
+                            elapsed = ?start.elapsed(),
+                            "cleanup: Finished"
+                        );
                     }
                 }
-                .instrument(info_span!("database_cleanup"))
+                .instrument(t::info_span!("database_cleanup"))
                 .await;
             }
         });
@@ -1084,7 +1087,7 @@ where
     if current_version < new_version {
         migration()?;
         services().globals.bump_database_version(new_version)?;
-        warn!("Migration: {current_version} -> {new_version} finished");
+        t::warn!("Migration: {current_version} -> {new_version} finished");
     }
     Ok(())
 }

src/database/abstraction/rocksdb.rs

@@ -10,12 +10,11 @@ use rocksdb::{
     DBCompactionStyle, DBCompressionType, DBRecoveryMode, DBWithThreadMode,
     Direction, IteratorMode, MultiThreaded, Options, ReadOptions, WriteOptions,
 };
-use tracing::Level;
 
 use super::{
     super::Config, watchers::Watchers, KeyValueDatabaseEngine, KvTree,
 };
-use crate::{utils, Result};
+use crate::{observability::prelude::*, utils, Result};
 
 pub(crate) struct Engine {
     rocks: DBWithThreadMode<MultiThreaded>,
@@ -151,14 +150,14 @@ impl RocksDbEngineTree<'_> {
 }
 
 impl KvTree for RocksDbEngineTree<'_> {
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn get(&self, key: &[u8]) -> Result<Option<Vec<u8>>> {
         let readoptions = ReadOptions::default();
 
         Ok(self.db.rocks.get_cf_opt(&self.cf(), key, &readoptions)?)
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn insert(&self, key: &[u8], value: &[u8]) -> Result<()> {
         let writeoptions = WriteOptions::default();
         let lock = self.write_lock.read().unwrap();
@@ -170,7 +169,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         Ok(())
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn insert_batch(
         &self,
         iter: &mut dyn Iterator<Item = (Vec<u8>, Vec<u8>)>,
@@ -183,13 +182,13 @@ impl KvTree for RocksDbEngineTree<'_> {
         Ok(())
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn remove(&self, key: &[u8]) -> Result<()> {
         let writeoptions = WriteOptions::default();
         Ok(self.db.rocks.delete_cf_opt(&self.cf(), key, &writeoptions)?)
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn iter<'a>(&'a self) -> Box<dyn Iterator<Item = (Vec<u8>, Vec<u8>)> + 'a> {
         let readoptions = ReadOptions::default();
 
@@ -202,7 +201,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         )
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn iter_from<'a>(
         &'a self,
         from: &[u8],
@@ -230,7 +229,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         )
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn increment(&self, key: &[u8]) -> Result<Vec<u8>> {
         let readoptions = ReadOptions::default();
         let writeoptions = WriteOptions::default();
@@ -245,7 +244,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         Ok(new)
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn increment_batch(
         &self,
         iter: &mut dyn Iterator<Item = Vec<u8>>,
@@ -267,7 +266,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         Ok(())
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn scan_prefix<'a>(
         &'a self,
         prefix: Vec<u8>,
@@ -288,7 +287,7 @@ impl KvTree for RocksDbEngineTree<'_> {
         )
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip_all)]
+    #[t::instrument(level = t::Level::TRACE, skip_all)]
     fn watch_prefix<'a>(
         &'a self,
         prefix: &[u8],

src/database/abstraction/sqlite.rs

@@ -9,10 +9,9 @@ use std::{
 use parking_lot::{Mutex, MutexGuard};
 use rusqlite::{Connection, DatabaseName::Main, OptionalExtension};
 use thread_local::ThreadLocal;
-use tracing::debug;
 
 use super::{watchers::Watchers, KeyValueDatabaseEngine, KvTree};
-use crate::{database::Config, Result};
+use crate::{database::Config, observability::prelude::*, Result};
 
 thread_local! {
     static READ_CONNECTION: RefCell<Option<&'static Connection>> =
@@ -397,11 +396,11 @@ impl KvTree for SqliteTable {
     }
 
     fn clear(&self) -> Result<()> {
-        debug!("clear: running");
+        t::debug!("clear: running");
         self.engine
             .write_lock()
             .execute(format!("DELETE FROM {}", self.name).as_str(), [])?;
-        debug!("clear: ran");
+        t::debug!("clear: ran");
         Ok(())
     }
 }

src/database/key_value/account_data.rs

@@ -8,13 +8,14 @@ use ruma::{
 };
 
 use crate::{
-    database::KeyValueDatabase, service, services, utils, Error, Result,
+    database::KeyValueDatabase, observability::prelude::*, service, services,
+    utils, Error, Result,
 };
 
 impl service::account_data::Data for KeyValueDatabase {
     /// Places one event in the account data of the user and removes the
     /// previous entry.
-    #[tracing::instrument(skip(self, room_id, user_id, event_type, data))]
+    #[t::instrument(skip(self, room_id, user_id, event_type, data))]
     fn update(
         &self,
         room_id: Option<&RoomId>,
@@ -66,7 +67,7 @@ impl service::account_data::Data for KeyValueDatabase {
     }
 
     /// Searches the account data for a specific kind.
-    #[tracing::instrument(skip(self, room_id, user_id, kind))]
+    #[t::instrument(skip(self, room_id, user_id, kind))]
     fn get(
         &self,
         room_id: Option<&RoomId>,
@@ -97,7 +98,7 @@ impl service::account_data::Data for KeyValueDatabase {
     }
 
     /// Returns all changes to the account data that happened after `since`.
-    #[tracing::instrument(skip(self, room_id, user_id, since))]
+    #[t::instrument(skip(self, room_id, user_id, since))]
     fn changes_since(
         &self,
         room_id: Option<&RoomId>,

src/database/key_value/globals.rs

@@ -8,6 +8,7 @@ use ruma::{
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{self, globals::SigningKeys},
     services, utils, Error, Result,
 };
@@ -28,7 +29,7 @@ impl service::globals::Data for KeyValueDatabase {
         })
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     async fn watch(
         &self,
         user_id: &UserId,

src/database/key_value/media.rs

@@ -2,6 +2,7 @@ use ruma::OwnedMxcUri;
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{
         self,
         media::{FileMeta, MediaFileKey},
@@ -20,7 +21,7 @@ struct MediaFileKeyParts {
 impl TryFrom<&MediaFileKey> for MediaFileKeyParts {
     type Error = Error;
 
-    #[tracing::instrument(
+    #[t::instrument(
         err,
         fields(key = utils::u8_slice_to_hex(key.as_bytes())),
     )]

src/database/key_value/rooms/alias.rs

@@ -4,11 +4,12 @@ use ruma::{
 };
 
 use crate::{
-    database::KeyValueDatabase, service, services, utils, Error, Result,
+    database::KeyValueDatabase, observability::prelude::*, service, services,
+    utils, Error, Result,
 };
 
 impl service::rooms::alias::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn set_alias(&self, alias: &RoomAliasId, room_id: &RoomId) -> Result<()> {
         self.alias_roomid
             .insert(alias.alias().as_bytes(), room_id.as_bytes())?;
@@ -20,7 +21,7 @@ impl service::rooms::alias::Data for KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn remove_alias(&self, alias: &RoomAliasId) -> Result<()> {
         if let Some(room_id) =
             self.alias_roomid.get(alias.alias().as_bytes())?
@@ -41,7 +42,7 @@ impl service::rooms::alias::Data for KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn resolve_local_alias(
         &self,
         alias: &RoomAliasId,
@@ -63,7 +64,7 @@ impl service::rooms::alias::Data for KeyValueDatabase {
             .transpose()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn local_aliases_for_room<'a>(
         &'a self,
         room_id: &RoomId,

src/database/key_value/rooms/auth_chain.rs

@@ -2,12 +2,13 @@ use std::{collections::HashSet, mem::size_of};
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{self, rooms::short::ShortEventId},
     utils, Result,
 };
 
 impl service::rooms::auth_chain::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self, key))]
+    #[t::instrument(skip(self, key))]
     fn get_cached_eventid_authchain(
         &self,
         key: &[ShortEventId],

src/database/key_value/rooms/directory.rs

@@ -1,24 +1,27 @@
 use ruma::{OwnedRoomId, RoomId};
 
-use crate::{database::KeyValueDatabase, service, utils, Error, Result};
+use crate::{
+    database::KeyValueDatabase, observability::prelude::*, service, utils,
+    Error, Result,
+};
 
 impl service::rooms::directory::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn set_public(&self, room_id: &RoomId) -> Result<()> {
         self.publicroomids.insert(room_id.as_bytes(), &[])
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn set_not_public(&self, room_id: &RoomId) -> Result<()> {
         self.publicroomids.remove(room_id.as_bytes())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn is_public_room(&self, room_id: &RoomId) -> Result<bool> {
         Ok(self.publicroomids.get(room_id.as_bytes())?.is_some())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn public_rooms<'a>(
         &'a self,
     ) -> Box<dyn Iterator<Item = Result<OwnedRoomId>> + 'a> {

src/database/key_value/rooms/edus/read_receipt.rs

@@ -4,11 +4,12 @@ use ruma::{
 };
 
 use crate::{
-    database::KeyValueDatabase, service, services, utils, Error, Result,
+    database::KeyValueDatabase, observability::prelude::*, service, services,
+    utils, Error, Result,
 };
 
 impl service::rooms::edus::read_receipt::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self, event))]
+    #[t::instrument(skip(self, event))]
     fn readreceipt_update(
         &self,
         user_id: &UserId,
@@ -52,7 +53,7 @@ impl service::rooms::edus::read_receipt::Data for KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     #[allow(clippy::type_complexity)]
     fn readreceipts_since<'a>(
         &'a self,
@@ -126,7 +127,7 @@ impl service::rooms::edus::read_receipt::Data for KeyValueDatabase {
         )
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn private_read_set(
         &self,
         room_id: &RoomId,
@@ -143,7 +144,7 @@ impl service::rooms::edus::read_receipt::Data for KeyValueDatabase {
             .insert(&key, &services().globals.next_count()?.to_be_bytes())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn private_read_get(
         &self,
         room_id: &RoomId,

src/database/key_value/rooms/metadata.rs

@@ -1,11 +1,12 @@
 use ruma::{OwnedRoomId, RoomId};
 
 use crate::{
-    database::KeyValueDatabase, service, services, utils, Error, Result,
+    database::KeyValueDatabase, observability::prelude::*, service, services,
+    utils, Error, Result,
 };
 
 impl service::rooms::metadata::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn exists(&self, room_id: &RoomId) -> Result<bool> {
         let prefix = match services().rooms.short.get_shortroomid(room_id)? {
             Some(b) => b.get().to_be_bytes().to_vec(),

src/database/key_value/rooms/outlier.rs

@@ -1,6 +1,9 @@
 use ruma::{CanonicalJsonObject, EventId};
 
-use crate::{database::KeyValueDatabase, service, Error, Result};
+use crate::{
+    database::KeyValueDatabase, observability::prelude::*, service, Error,
+    Result,
+};
 
 impl service::rooms::outlier::Data for KeyValueDatabase {
     fn get_outlier_pdu_json(
@@ -16,7 +19,7 @@ impl service::rooms::outlier::Data for KeyValueDatabase {
         )
     }
 
-    #[tracing::instrument(skip(self, pdu))]
+    #[t::instrument(skip(self, pdu))]
     fn add_pdu_outlier(
         &self,
         event_id: &EventId,

src/database/key_value/rooms/search.rs

@@ -2,6 +2,7 @@ use ruma::RoomId;
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{
         self,
         rooms::{short::ShortRoomId, timeline::PduId},
@@ -21,7 +22,7 @@ fn tokenize(body: &str) -> impl Iterator<Item = String> + '_ {
 }
 
 impl service::rooms::search::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn index_pdu(
         &self,
         shortroomid: ShortRoomId,
@@ -40,7 +41,7 @@ impl service::rooms::search::Data for KeyValueDatabase {
         self.tokenids.insert_batch(&mut batch)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn deindex_pdu(
         &self,
         shortroomid: ShortRoomId,
@@ -63,7 +64,7 @@ impl service::rooms::search::Data for KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     #[allow(clippy::type_complexity)]
     fn search_pdus<'a>(
         &'a self,

src/database/key_value/rooms/short.rs

@@ -4,6 +4,7 @@ use ruma::{events::StateEventType, EventId, RoomId};
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{
         self,
         rooms::short::{
@@ -14,7 +15,7 @@ use crate::{
 };
 
 impl service::rooms::short::Data for KeyValueDatabase {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_or_create_shorteventid(
         &self,
         event_id: &EventId,
@@ -40,7 +41,7 @@ impl service::rooms::short::Data for KeyValueDatabase {
         Ok((ShortEventId::new(short), created))
     }
 
-    #[tracing::instrument(skip(self), fields(cache_result))]
+    #[t::instrument(skip(self), fields(cache_result))]
     fn get_shortstatekey(
         &self,
         event_type: &StateEventType,
@@ -65,7 +66,7 @@ impl service::rooms::short::Data for KeyValueDatabase {
         Ok(short)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_or_create_shortstatekey(
         &self,
         event_type: &StateEventType,
@@ -98,7 +99,7 @@ impl service::rooms::short::Data for KeyValueDatabase {
         Ok((short, created))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_eventid_from_short(
         &self,
         shorteventid: ShortEventId,
@@ -124,7 +125,7 @@ impl service::rooms::short::Data for KeyValueDatabase {
         Ok(event_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_statekey_from_short(
         &self,
         shortstatekey: ShortStateKey,
@@ -162,7 +163,7 @@ impl service::rooms::short::Data for KeyValueDatabase {
     }
 
     /// Returns `(shortstatehash, already_existed)`
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_or_create_shortstatehash(
         &self,
         state_hash: &[u8],

src/database/key_value/rooms/state_cache.rs

@@ -8,6 +8,7 @@ use ruma::{
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{self, appservice::RegistrationInfo},
     services, utils, Error, Result,
 };
@@ -166,7 +167,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         Ok(real_users)
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, appservice),
         fields(appservice_id = appservice.registration.id),
     )]
@@ -193,7 +194,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
     }
 
     /// Makes a user forget a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn forget(&self, room_id: &RoomId, user_id: &UserId) -> Result<()> {
         let mut userroom_id = user_id.as_bytes().to_vec();
         userroom_id.push(0xFF);
@@ -210,7 +211,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
     }
 
     /// Returns an iterator of all servers participating in this room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn room_servers<'a>(
         &'a self,
         room_id: &RoomId,
@@ -237,7 +238,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         }))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn server_in_room(
         &self,
         server: &ServerName,
@@ -252,7 +253,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
 
     /// Returns an iterator of all rooms a server participates in (as far as we
     /// know).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn server_rooms<'a>(
         &'a self,
         server: &ServerName,
@@ -280,7 +281,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
     }
 
     /// Returns an iterator over all joined members of a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn room_members<'a>(
         &'a self,
         room_id: &RoomId,
@@ -307,7 +308,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         }))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn room_joined_count(&self, room_id: &RoomId) -> Result<Option<u64>> {
         self.roomid_joinedcount
             .get(room_id.as_bytes())?
@@ -319,7 +320,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
             .transpose()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn room_invited_count(&self, room_id: &RoomId) -> Result<Option<u64>> {
         self.roomid_invitedcount
             .get(room_id.as_bytes())?
@@ -332,7 +333,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
     }
 
     /// Returns an iterator over all invited members of a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn room_members_invited<'a>(
         &'a self,
         room_id: &RoomId,
@@ -363,7 +364,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         ))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_invite_count(
         &self,
         room_id: &RoomId,
@@ -380,7 +381,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         })
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_left_count(
         &self,
         room_id: &RoomId,
@@ -401,7 +402,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
     }
 
     /// Returns an iterator over all rooms this user joined.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn rooms_joined<'a>(
         &'a self,
         user_id: &UserId,
@@ -434,7 +435,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
 
     /// Returns an iterator over all rooms a user was invited to.
     #[allow(clippy::type_complexity)]
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn rooms_invited<'a>(
         &'a self,
         user_id: &UserId,
@@ -477,7 +478,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         ))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn invite_state(
         &self,
         user_id: &UserId,
@@ -501,7 +502,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
             .transpose()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn left_state(
         &self,
         user_id: &UserId,
@@ -527,7 +528,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
 
     /// Returns an iterator over all rooms a user left.
     #[allow(clippy::type_complexity)]
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn rooms_left<'a>(
         &'a self,
         user_id: &UserId,
@@ -569,7 +570,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         ))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn once_joined(&self, user_id: &UserId, room_id: &RoomId) -> Result<bool> {
         let mut userroom_id = user_id.as_bytes().to_vec();
         userroom_id.push(0xFF);
@@ -578,7 +579,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         Ok(self.roomuseroncejoinedids.get(&userroom_id)?.is_some())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn is_joined(&self, user_id: &UserId, room_id: &RoomId) -> Result<bool> {
         let mut userroom_id = user_id.as_bytes().to_vec();
         userroom_id.push(0xFF);
@@ -587,7 +588,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         Ok(self.userroomid_joined.get(&userroom_id)?.is_some())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn is_invited(&self, user_id: &UserId, room_id: &RoomId) -> Result<bool> {
         let mut userroom_id = user_id.as_bytes().to_vec();
         userroom_id.push(0xFF);
@@ -596,7 +597,7 @@ impl service::rooms::state_cache::Data for KeyValueDatabase {
         Ok(self.userroomid_invitestate.get(&userroom_id)?.is_some())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn is_left(&self, user_id: &UserId, room_id: &RoomId) -> Result<bool> {
         let mut userroom_id = user_id.as_bytes().to_vec();
         userroom_id.push(0xFF);

src/database/key_value/rooms/timeline.rs

@@ -8,6 +8,7 @@ use service::rooms::timeline::PduCount;
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{self, rooms::timeline::PduId},
     services, utils, Error, PduEvent, Result,
 };
@@ -89,7 +90,7 @@ impl service::rooms::timeline::Data for KeyValueDatabase {
     /// Returns the pdu.
     ///
     /// Checks the `eventid_outlierpdu` Tree if not found in the timeline.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_pdu(&self, event_id: &EventId) -> Result<Option<Arc<PduEvent>>> {
         Ok(self
             .get_non_outlier_pdu(event_id)?

src/database/key_value/sending.rs

@@ -2,6 +2,7 @@ use ruma::{serde::Raw, ServerName, UserId};
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{
         self,
         rooms::timeline::PduId,
@@ -130,7 +131,7 @@ impl service::sending::Data for KeyValueDatabase {
     }
 }
 
-#[tracing::instrument(skip(key, value))]
+#[t::instrument(skip(key, value))]
 fn parse_servercurrentevent(
     key: &RequestKey,
     value: Vec<u8>,

src/database/key_value/users.rs

@@ -9,10 +9,10 @@ use ruma::{
     OwnedDeviceId, OwnedKeyId, OwnedMxcUri, OwnedOneTimeKeyId, OwnedUserId,
     UInt, UserId,
 };
-use tracing::warn;
 
 use crate::{
     database::KeyValueDatabase,
+    observability::prelude::*,
     service::{self, users::clean_signatures},
     services, utils, Error, Result,
 };
@@ -490,7 +490,7 @@ impl service::users::Data for KeyValueDatabase {
         Ok(counts)
     }
 
-    #[tracing::instrument(skip(self, device_keys))]
+    #[t::instrument(skip(self, device_keys))]
     fn add_device_keys(
         &self,
         user_id: &UserId,
@@ -512,7 +512,7 @@ impl service::users::Data for KeyValueDatabase {
         Ok(())
     }
 
-    #[tracing::instrument(skip(
+    #[t::instrument(skip(
         self,
         master_key,
         self_signing_key,
@@ -700,14 +700,14 @@ impl service::users::Data for KeyValueDatabase {
                             if let Ok(c) = utils::u64_from_bytes(current) {
                                 c <= to
                             } else {
-                                warn!(
+                                t::warn!(
                                     "BadDatabase: Could not parse \
                                      keychangeid_userid bytes"
                                 );
                                 false
                             }
                         } else {
-                            warn!(
+                            t::warn!(
                                 "BadDatabase: Could not parse \
                                  keychangeid_userid"
                             );
@@ -732,7 +732,7 @@ impl service::users::Data for KeyValueDatabase {
         )
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn mark_device_key_update(&self, user_id: &UserId) -> Result<()> {
         let count = services().globals.next_count()?.to_be_bytes();
         for room_id in services()
@@ -1102,7 +1102,7 @@ fn get_username_with_valid_password(
         match utils::string_from_bytes(username) {
             Ok(u) => Some(u),
             Err(e) => {
-                warn!(
+                t::warn!(
                     "Failed to parse username while calling \
                      get_local_users(): {}",
                     e.to_string()

src/error.rs

@@ -1,38 +1,10 @@
 //! Error handling facilities
 
-use std::{fmt, iter, path::PathBuf};
+use std::path::PathBuf;
 
 use thiserror::Error;
 
-use crate::config::ListenConfig;
+use crate::{config::ListenConfig, observability::prelude::*};
-
-/// Formats an [`Error`][0] and its [`source`][1]s with a separator
-///
-/// [0]: std::error::Error
-/// [1]: std::error::Error::source
-pub(crate) struct DisplayWithSources<'a> {
-    /// The error (and its sources) to write
-    pub(crate) error: &'a dyn std::error::Error,
-
-    /// Separator to write between the original error and subsequent sources
-    pub(crate) infix: &'static str,
-}
-
-impl fmt::Display for DisplayWithSources<'_> {
-    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        write!(f, "{}", self.error)?;
-
-        let mut source = self.error.source();
-
-        source
-            .into_iter()
-            .chain(iter::from_fn(|| {
-                source = source.and_then(std::error::Error::source);
-                source
-            }))
-            .try_for_each(|source| write!(f, "{}{source}", self.infix))
-    }
-}
 
 /// Top-level errors
 // Missing docs are allowed here since that kind of information should be
@@ -44,7 +16,7 @@ pub(crate) enum Main {
     ServeCommand(#[from] ServeCommand),
 
     #[error("failed to install global default tracing subscriber")]
-    SetSubscriber(#[from] tracing::subscriber::SetGlobalDefaultError),
+    SetSubscriber(#[from] t::subscriber::SetGlobalDefaultError),
 
     #[error(transparent)]
     CheckConfigCommand(#[from] CheckConfigCommand),
@@ -112,7 +84,7 @@ pub(crate) enum Observability {
     Otel(#[from] opentelemetry::trace::TraceError),
 
     #[error("failed to install global default tracing subscriber")]
-    SetSubscriber(#[from] tracing::subscriber::SetGlobalDefaultError),
+    SetSubscriber(#[from] t::subscriber::SetGlobalDefaultError),
 
     // Upstream's documentation on what this error means is very sparse
     #[error("tracing_flame error")]

src/main.rs

@@ -7,7 +7,9 @@ use std::process::ExitCode;
 use clap::Parser;
 #[cfg(all(not(target_env = "msvc"), feature = "jemalloc"))]
 use tikv_jemallocator::Jemalloc;
-use tracing::{error, info};
+use wee_woo::ErrorExt;
+
+use crate::observability::prelude::*;
 
 mod api;
 mod cli;
@@ -49,7 +51,7 @@ enum ApplicationState {
 }
 
 fn set_application_state(state: ApplicationState) {
-    info!(?state, "Application state changed");
+    t::info!(?state, "Application state changed");
 
     #[cfg(feature = "systemd")]
     {
@@ -100,32 +102,25 @@ async fn main() -> ExitCode {
         return ExitCode::SUCCESS;
     };
 
-    eprintln!(
+    eprintln!("Error: {}", e.display_with_sources("\n    Caused by: "));
-        "Error: {}",
-        error::DisplayWithSources {
-            error: &e,
-            infix: "\n    Caused by: "
-        }
-    );
 
     ExitCode::FAILURE
 }
 
 #[cfg(unix)]
-#[tracing::instrument(err)]
+#[t::instrument(err)]
 fn maximize_fd_limit() -> Result<(), nix::errno::Errno> {
     use nix::sys::resource::{getrlimit, setrlimit, Resource};
-    use tracing::debug;
 
     let res = Resource::RLIMIT_NOFILE;
 
     let (soft_limit, hard_limit) = getrlimit(res)?;
 
-    debug!(soft_limit, "Current nofile soft limit");
+    t::debug!(soft_limit, "Current nofile soft limit");
 
     setrlimit(res, hard_limit, hard_limit)?;
 
-    debug!(hard_limit, "Increased nofile soft limit to the hard limit");
+    t::debug!(hard_limit, "Increased nofile soft limit to the hard limit");
 
     Ok(())
 }

src/observability.rs

@@ -23,7 +23,7 @@ use opentelemetry_sdk::{
 use strum::{AsRefStr, IntoStaticStr};
 use thiserror::Error;
 use tokio::time::Instant;
-use tracing::{subscriber::SetGlobalDefaultError, Span};
+use tracing::subscriber::SetGlobalDefaultError;
 use tracing_flame::{FlameLayer, FlushGuard};
 use tracing_opentelemetry::OtelData;
 use tracing_subscriber::{
@@ -35,9 +35,12 @@ use tracing_subscriber::{
 use crate::{
     config::{Config, EnvFilterClone, LogFormat},
     error,
+    observability::prelude::*,
     utils::error::Result,
 };
 
+pub(crate) mod prelude;
+
 /// Globally accessible metrics state
 pub(crate) static METRICS: LazyLock<Metrics> = LazyLock::new(Metrics::new);
 
@@ -312,7 +315,7 @@ pub(crate) fn init(
         .with(traces_layer)
         .with(flame_layer)
         .with(log_layer);
-    tracing::subscriber::set_global_default(subscriber)?;
+    t::subscriber::set_global_default(subscriber)?;
 
     Ok((
         Guard {
@@ -497,8 +500,8 @@ pub(crate) async fn http_metrics_layer(req: Request, next: Next) -> Response {
 pub(crate) async fn traceresponse_layer(req: Request, next: Next) -> Response {
     let mut resp = next.run(req).await;
 
-    let ids = tracing::dispatcher::get_default(|dispatch| {
+    let ids = t::dispatcher::get_default(|dispatch| {
-        Span::current()
+        t::Span::current()
             .id()
             .and_then(|id| {
                 dispatch
@@ -555,5 +558,5 @@ pub(crate) fn init_for_cli(
 
     let subscriber = Registry::default().with(log_layer);
 
-    tracing::subscriber::set_global_default(subscriber).map_err(Into::into)
+    t::subscriber::set_global_default(subscriber).map_err(Into::into)
 }

src/observability/prelude.rs

@@ -0,0 +1,125 @@
+//! Common tracing-related items intended to be wildcard imported in most
+//! modules:
+//!
+//! ```
+//! use crate::observability::prelude::*;
+//! ```
+//!
+//! This avoids diff churn in the imports when adding/removing log statements.
+//!
+//! [`tracing`] is re-exported as `t`, to avoid name collisions.
+
+pub(crate) use tracing as t;
+pub(crate) use tracing::Instrument;
+
+/// [`tracing::event!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+macro_rules! event_err {
+    ($level:expr, $error:expr, $($rest:tt)+) => {
+        ::tracing::event!(
+            $level,
+            error=%::wee_woo::ErrorExt::display_with_sources(&$error, " -> "),
+            $($rest)+
+        )
+    }
+}
+
+/// [`tracing::trace!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+macro_rules! trace_err {
+    ($error:expr, $($rest:tt)+) => {
+        $crate::observability::prelude::event_err!(
+            ::tracing::Level::TRACE,
+            $error,
+            $($rest)+
+        )
+    }
+}
+
+/// [`tracing::debug!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+macro_rules! debug_err {
+    ($error:expr, $($rest:tt)+) => {
+        $crate::observability::prelude::event_err!(
+            ::tracing::Level::DEBUG,
+            $error,
+            $($rest)+
+        )
+    }
+}
+
+/// [`tracing::info!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+macro_rules! info_err {
+    ($error:expr, $($rest:tt)+) => {
+        $crate::observability::prelude::event_err!(
+            ::tracing::Level::INFO,
+            $error,
+            $($rest)+
+        )
+    }
+}
+
+/// [`tracing::warn!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+macro_rules! warn_err {
+    ($error:expr, $($rest:tt)+) => {
+        $crate::observability::prelude::event_err!(
+            ::tracing::Level::WARN,
+            $error,
+            $($rest)+
+        )
+    }
+}
+
+/// [`tracing::error!`] but takes an error and formats its source chain as an
+/// `error` field.
+///
+/// The `parent:` and `target:` arguments from the original macro are not
+/// supported.
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+macro_rules! error_err {
+    ($error:expr, $($rest:tt)+) => {
+        $crate::observability::prelude::event_err!(
+            ::tracing::Level::ERROR,
+            $error,
+            $($rest)+
+        )
+    }
+}
+
+// Allowed because all of these variants exist for completeness, even if they
+// aren't currently used.
+#[allow(unused)]
+pub(crate) use {
+    debug_err, error_err, event_err, info_err, trace_err, warn_err,
+};

src/service/admin.rs

@@ -28,11 +28,11 @@ use ruma::{
 };
 use serde_json::value::to_raw_value;
 use tokio::sync::{mpsc, Mutex, RwLock};
-use tracing::warn;
 
 use super::pdu::PduBuilder;
 use crate::{
     api::client_server::{leave_all_rooms, AUTO_GEN_PASSWORD_LENGTH},
+    observability::prelude::*,
     services,
     utils::{self, dbg_truncate_str, room_version::RoomVersion},
     Error, PduEvent, Result,
@@ -289,7 +289,7 @@ impl Service {
         });
     }
 
-    #[tracing::instrument(skip(self, grapevine_room))]
+    #[t::instrument(skip(self, grapevine_room))]
     async fn handle_event(
         &self,
         event: AdminRoomEvent,
@@ -327,7 +327,7 @@ impl Service {
             .unwrap();
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, room_message),
         fields(
             room_message = dbg_truncate_str(&room_message, 50).as_ref(),
@@ -337,7 +337,7 @@ impl Service {
         self.sender.send(AdminRoomEvent::ProcessMessage(room_message)).unwrap();
     }
 
-    #[tracing::instrument(skip(self, message_content))]
+    #[t::instrument(skip(self, message_content))]
     pub(crate) fn send_message(
         &self,
         message_content: RoomMessageEventContent,
@@ -346,7 +346,7 @@ impl Service {
     }
 
     // Parse and process a message from the admin room
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, room_message),
         fields(
             room_message = dbg_truncate_str(&room_message, 50).as_ref(),
@@ -397,7 +397,7 @@ impl Service {
     }
 
     // Parse chat messages from the admin room into an AdminCommand object
-    #[tracing::instrument(
+    #[t::instrument(
         skip(command_line),
         fields(
             command_line = dbg_truncate_str(command_line, 50).as_ref(),
@@ -428,7 +428,7 @@ impl Service {
     }
 
     #[allow(clippy::too_many_lines)]
-    #[tracing::instrument(skip(self, body))]
+    #[t::instrument(skip(self, body))]
     async fn process_admin_command(
         &self,
         command: AdminCommand,
@@ -1068,7 +1068,11 @@ impl Service {
                     if leave_rooms {
                         for &user_id in &user_ids {
                             if let Err(error) = leave_all_rooms(user_id).await {
-                                warn!(%user_id, %error, "failed to leave one or more rooms");
+                                warn_err!(
+                                    error,
+                                    %user_id,
+                                    "failed to leave one or more rooms"
+                                );
                             }
                         }
                     }
@@ -1253,7 +1257,7 @@ impl Service {
     }
 
     // Utility to turn clap's `--help` text to HTML.
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     fn usage_to_html(text: &str, server_name: &ServerName) -> String {
         // Replace `@grapevine:servername:-subcmdname` with
         // `@grapevine:servername: subcmdname`
@@ -1334,7 +1338,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))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn create_admin_room(&self) -> Result<()> {
         let room_id = RoomId::new(services().globals.server_name());
 
@@ -1586,7 +1590,7 @@ impl Service {
     /// Invite the user to the grapevine admin room.
     ///
     /// In grapevine, this is equivalent to granting admin privileges.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn make_user_admin(
         &self,
         user_id: &UserId,

src/service/appservice.rs

@@ -8,7 +8,7 @@ use ruma::{
 };
 use tokio::sync::RwLock;
 
-use crate::Result;
+use crate::{observability::prelude::*, Result};
 
 mod data;
 
@@ -137,7 +137,7 @@ impl Service {
     }
 
     /// Registers an appservice and returns the ID to the caller.
-    #[tracing::instrument(skip(self, yaml), fields(appservice_id = yaml.id))]
+    #[t::instrument(skip(self, yaml), fields(appservice_id = yaml.id))]
     pub(crate) async fn register_appservice(
         &self,
         yaml: Registration,
@@ -156,7 +156,7 @@ impl Service {
     /// # Arguments
     ///
     /// * `service_name` - the name you send to register the service previously
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn unregister_appservice(
         &self,
         service_name: &str,
@@ -168,7 +168,7 @@ impl Service {
         self.db.unregister_appservice(service_name)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn get_registration(
         &self,
         id: &str,
@@ -185,7 +185,7 @@ impl Service {
         self.registration_info.read().await.keys().cloned().collect()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn find_from_token(
         &self,
         token: &str,
@@ -198,7 +198,7 @@ impl Service {
     }
 
     // Checks if a given user id matches any exclusive appservice regex
-    #[tracing::instrument(skip(self), ret(level = "trace"))]
+    #[t::instrument(skip(self), ret(level = "trace"))]
     pub(crate) async fn is_exclusive_user_id(&self, user_id: &UserId) -> bool {
         self.read()
             .await
@@ -207,7 +207,7 @@ impl Service {
     }
 
     // Checks if a given room alias matches any exclusive appservice regex
-    #[tracing::instrument(skip(self), ret(level = "trace"))]
+    #[t::instrument(skip(self), ret(level = "trace"))]
     pub(crate) async fn is_exclusive_alias(&self, alias: &RoomAliasId) -> bool {
         self.read()
             .await

src/service/globals.rs

@@ -34,13 +34,12 @@ use ruma::{
     ServerName, UInt, UserId,
 };
 use tokio::sync::{broadcast, Mutex, RwLock, Semaphore};
-use tracing::{error, warn, Instrument};
 use trust_dns_resolver::TokioAsyncResolver;
 
 use crate::{
     api::server_server::FedDest,
     config::{MediaBackendConfig, MediaFilesystemConfig},
-    observability::FilterReloadHandles,
+    observability::{prelude::*, FilterReloadHandles},
     service::media::MediaFileKey,
     services,
     utils::on_demand_hashmap::{OnDemandHashMap, TokenSet},
@@ -156,7 +155,7 @@ impl Resolver {
 }
 
 impl Resolve for Resolver {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn resolve(&self, name: Name) -> Resolving {
         self.overrides
             .read()
@@ -197,7 +196,7 @@ impl Resolve for Resolver {
 }
 
 impl Service {
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     pub(crate) fn new(
         db: &'static dyn Data,
         config: Config,
@@ -208,7 +207,7 @@ impl Service {
         let keypair = match keypair {
             Ok(k) => k,
             Err(e) => {
-                error!("Keypair invalid. Deleting...");
+                t::error!("Keypair invalid. Deleting...");
                 db.remove_keypair()?;
                 return Err(e);
             }
@@ -257,7 +256,7 @@ impl Service {
             keypair: Arc::new(keypair),
             dns_resolver: TokioAsyncResolver::tokio_from_system_conf()
                 .map_err(|e| {
-                    error!(
+                    t::error!(
                         "Failed to set up trust dns resolver with system \
                          config: {}",
                         e
@@ -300,7 +299,12 @@ impl Service {
 
         if !s.supported_room_versions().contains(&s.config.default_room_version)
         {
-            error!(config=?s.config.default_room_version, fallback=?crate::config::default_default_room_version(), "Room version in config isn't supported, falling back to default version");
+            t::error!(
+                config=?s.config.default_room_version,
+                fallback=?crate::config::default_default_room_version(),
+                "Room version in config isn't supported, falling back to \
+                 default version"
+            );
             s.config.default_room_version =
                 crate::config::default_default_room_version();
         };
@@ -356,12 +360,12 @@ impl Service {
         self.federation_client.clone()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn next_count(&self) -> Result<u64> {
         self.db.next_count()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn current_count(&self) -> Result<u64> {
         self.db.current_count()
     }
@@ -483,7 +487,7 @@ impl Service {
         match inner() {
             Ok(pwd_set) => {
                 if pwd_set {
-                    warn!(
+                    t::warn!(
                         "The Grapevine account emergency password is set! \
                          Please unset it as soon as you finish admin account \
                          recovery!"
@@ -498,8 +502,8 @@ impl Service {
                 }
             }
             Err(error) => {
-                error!(
+                error_err!(
-                    %error,
+                    error,
                     "Could not set the configured emergency password for the \
                      Grapevine user",
                 );

src/service/media.rs

@@ -9,9 +9,8 @@ use tokio::{
     fs::{self, File},
     io::{AsyncReadExt, AsyncWriteExt},
 };
-use tracing::{debug, warn};
 
-use crate::{services, utils, Error, Result};
+use crate::{observability::prelude::*, services, utils, Error, Result};
 
 mod data;
 
@@ -47,7 +46,7 @@ pub(crate) struct Service {
 
 impl Service {
     /// Uploads a file.
-    #[tracing::instrument(skip(self, file))]
+    #[t::instrument(skip(self, file))]
     pub(crate) async fn create(
         &self,
         mxc: OwnedMxcUri,
@@ -68,7 +67,7 @@ impl Service {
     }
 
     /// Uploads or replaces a file thumbnail.
-    #[tracing::instrument(skip(self, file))]
+    #[t::instrument(skip(self, file))]
     pub(crate) async fn upload_thumbnail(
         &self,
         mxc: OwnedMxcUri,
@@ -89,7 +88,7 @@ impl Service {
     }
 
     /// Downloads a file.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn get(
         &self,
         mxc: OwnedMxcUri,
@@ -102,7 +101,7 @@ impl Service {
     }
 
     /// Deletes a media object and all associated thumbnails.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn delete(&self, mxc: OwnedMxcUri) -> Result<()> {
         let mut any_files = false;
 
@@ -111,11 +110,10 @@ impl Service {
             any_files = true;
             self.delete_by_key(thumbnail_key.clone()).await.inspect_err(
                 |error| {
-                    warn!(
+                    warn_err!(
-                        thumbnail_key = utils::u8_slice_to_hex(
+                        error,
-                            thumbnail_key.as_bytes()
+                        thumbnail_key =
-                        ),
+                            utils::u8_slice_to_hex(thumbnail_key.as_bytes()),
-                        %error,
                         "Failed to delete thumbnail media"
                     );
                 },
@@ -123,14 +121,14 @@ impl Service {
         }
 
         if let Some((_, key)) =
-            self.db.search_file_metadata(mxc, 0, 0).inspect_err(
+            self.db.search_file_metadata(mxc, 0, 0).inspect_err(|error| {
-                |error| warn!(%error, "Failed to find original media key"),
+                warn_err!(error, "Failed to find original media key");
-            )?
+            })?
         {
             any_files = true;
-            self.delete_by_key(key).await.inspect_err(
+            self.delete_by_key(key).await.inspect_err(|error| {
-                |error| warn!(%error, "Failed to delete original media"),
+                warn_err!(error, "Failed to delete original media");
-            )?;
+            })?;
         }
 
         if any_files {
@@ -138,7 +136,7 @@ impl Service {
         } else {
             let error =
                 Error::BadRequest(ErrorKind::NotFound, "Media not found");
-            warn!(%error, "Failed to delete media");
+            warn_err!(error, "Failed to delete media");
             Err(error)
         }
     }
@@ -167,7 +165,7 @@ impl Service {
     ///
     /// Each MXC is listed once. Thumbnails are not included separately from the
     /// original media.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn iter_all(&self) -> impl Iterator<Item = Result<OwnedMxcUri>> {
         let mut prev_mxc = None;
         self.db
@@ -206,7 +204,7 @@ impl Service {
 
     /// Generates a thumbnail from the given image file contents. Returns
     /// `Ok(None)` if the input image should be used as-is.
-    #[tracing::instrument(
+    #[t::instrument(
         skip(file),
         fields(input_size = file.len(), original_width, original_height),
     )]
@@ -219,18 +217,18 @@ impl Service {
         let image = match image::load_from_memory(file) {
             Ok(image) => image,
             Err(error) => {
-                warn!(%error, "Failed to parse source image");
+                warn_err!(error, "Failed to parse source image");
                 return Ok(None);
             }
         };
 
         let original_width = image.width();
         let original_height = image.height();
-        tracing::Span::current().record("original_width", original_width);
+        t::Span::current().record("original_width", original_width);
-        tracing::Span::current().record("original_height", original_height);
+        t::Span::current().record("original_height", original_height);
 
         if width > original_width || height > original_height {
-            debug!("Requested thumbnail is larger than source image");
+            t::debug!("Requested thumbnail is larger than source image");
             return Ok(None);
         }
 
@@ -276,12 +274,14 @@ impl Service {
             image.thumbnail_exact(exact_width, exact_height)
         };
 
-        debug!("Serializing thumbnail as PNG");
+        t::debug!("Serializing thumbnail as PNG");
         let mut thumbnail_bytes = Vec::new();
-        thumbnail.write_to(
+        thumbnail
-            &mut Cursor::new(&mut thumbnail_bytes),
+            .write_to(
-            image::ImageFormat::Png,
+                &mut Cursor::new(&mut thumbnail_bytes),
-        )?;
+                image::ImageFormat::Png,
+            )
+            .map_err(Error::GenerateThumbnail)?;
 
         Ok(Some(thumbnail_bytes))
     }
@@ -299,7 +299,7 @@ impl Service {
     ///
     /// For width,height <= 96 the server uses another thumbnailing algorithm
     /// which crops the image afterwards.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn get_thumbnail(
         &self,
         mxc: OwnedMxcUri,
@@ -313,26 +313,26 @@ impl Service {
         if let Some((meta, key)) =
             self.db.search_file_metadata(mxc.clone(), width, height)?
         {
-            debug!("Using saved thumbnail");
+            t::debug!("Using saved thumbnail");
             return Ok(self.read_content(&key).await?.map(|file| (meta, file)));
         }
 
         let Some((meta, key)) =
             self.db.search_file_metadata(mxc.clone(), 0, 0)?
         else {
-            debug!("Original image not found, can't generate thumbnail");
+            t::debug!("Original image not found, can't generate thumbnail");
             return Ok(None);
         };
 
         let Some(file) = self.read_content(&key).await? else {
-            debug!("Original image not found, can't generate thumbnail");
+            t::debug!("Original image not found, can't generate thumbnail");
             return Ok(None);
         };
 
-        debug!("Generating thumbnail");
+        t::debug!("Generating thumbnail");
         let thumbnail_result = {
             let file = file.clone();
-            let outer_span = tracing::span::Span::current();
+            let outer_span = t::span::Span::current();
 
             tokio::task::spawn_blocking(move || {
                 outer_span.in_scope(|| {
@@ -344,11 +344,11 @@ impl Service {
         };
 
         let Some(thumbnail_bytes) = thumbnail_result? else {
-            debug!("Returning source image as-is");
+            t::debug!("Returning source image as-is");
             return Ok(Some((meta, file)));
         };
 
-        debug!("Saving created thumbnail");
+        t::debug!("Saving created thumbnail");
 
         // Save thumbnail in database so we don't have to generate it
         // again next time

src/service/pdu.rs

@@ -22,9 +22,8 @@ use serde_json::{
     json,
     value::{to_raw_value, RawValue as RawJsonValue},
 };
-use tracing::warn;
 
-use crate::Error;
+use crate::{observability::prelude::*, Error};
 
 /// Content hashes of a PDU.
 #[derive(Clone, Debug, Deserialize, Serialize)]
@@ -60,7 +59,7 @@ pub(crate) struct PduEvent {
 }
 
 impl PduEvent {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn redact(
         &mut self,
         room_version_id: RoomVersionId,
@@ -183,7 +182,7 @@ impl PduEvent {
         (self.redacts.clone(), self.content.clone())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_sync_room_event(&self) -> Raw<AnySyncTimelineEvent> {
         let (redacts, content) = self.copy_redacts();
         let mut json = json!({
@@ -208,7 +207,7 @@ impl PduEvent {
     }
 
     /// This only works for events that are also AnyRoomEvents.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_any_event(&self) -> Raw<AnyEphemeralRoomEvent> {
         let mut json = json!({
             "content": self.content,
@@ -232,7 +231,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_room_event(&self) -> Raw<AnyTimelineEvent> {
         let (redacts, content) = self.copy_redacts();
         let mut json = json!({
@@ -257,7 +256,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_message_like_event(&self) -> Raw<AnyMessageLikeEvent> {
         let (redacts, content) = self.copy_redacts();
         let mut json = json!({
@@ -282,7 +281,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_state_event(&self) -> Raw<AnyStateEvent> {
         let mut json = json!({
             "content": self.content,
@@ -301,7 +300,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_sync_state_event(&self) -> Raw<AnySyncStateEvent> {
         let mut json = json!({
             "content": self.content,
@@ -319,7 +318,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_stripped_state_event(&self) -> Raw<AnyStrippedStateEvent> {
         let json = json!({
             "content": self.content,
@@ -331,7 +330,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_stripped_spacechild_state_event(
         &self,
     ) -> Raw<HierarchySpaceChildEvent> {
@@ -346,7 +345,7 @@ impl PduEvent {
         serde_json::from_value(json).expect("Raw::from_value always works")
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn to_member_event(
         &self,
     ) -> Raw<StateEvent<RoomMemberEventContent>> {
@@ -369,7 +368,7 @@ impl PduEvent {
     }
 
     /// This does not return a full `Pdu` it is only to satisfy ruma's types.
-    #[tracing::instrument(skip(pdu_json))]
+    #[t::instrument(skip(pdu_json))]
     pub(crate) fn convert_to_outgoing_federation_event(
         mut pdu_json: CanonicalJsonObject,
     ) -> Box<RawJsonValue> {
@@ -475,7 +474,7 @@ pub(crate) fn gen_event_id_canonical_json(
 ) -> crate::Result<(OwnedEventId, CanonicalJsonObject)> {
     let value: CanonicalJsonObject =
         serde_json::from_str(pdu.get()).map_err(|error| {
-            warn!(%error, object = ?pdu, "Error parsing incoming event");
+            warn_err!(error, object = ?pdu, "Error parsing incoming event");
             Error::BadServerResponse("Invalid PDU in server response")
         })?;
 

src/service/pusher.rs

@@ -23,9 +23,10 @@ use ruma::{
     serde::Raw,
     uint, RoomId, UInt, UserId,
 };
-use tracing::warn;
 
-use crate::{services, utils, Error, PduEvent, Result};
+use crate::{
+    observability::prelude::*, services, utils, Error, PduEvent, Result,
+};
 
 mod data;
 
@@ -63,7 +64,7 @@ impl Service {
         self.db.get_pushkeys(sender)
     }
 
-    #[tracing::instrument(skip(self, destination, request))]
+    #[t::instrument(skip(self, destination, request))]
     pub(crate) async fn send_request<T>(
         &self,
         destination: &str,
@@ -81,7 +82,7 @@ impl Service {
                 &[MatrixVersion::V1_0],
             )
             .map_err(|error| {
-                warn!(%error, %destination, "Failed to find destination");
+                warn_err!(error, %destination, "Failed to find destination");
                 Error::BadServerResponse("Invalid destination")
             })?
             .map(BytesMut::freeze);
@@ -108,12 +109,12 @@ impl Service {
 
                 // TODO: handle timeout
                 let body = response.bytes().await.unwrap_or_else(|error| {
-                    warn!(%error, "Server error");
+                    warn_err!(error, "Server error");
                     Vec::new().into()
                 });
 
                 if status != 200 {
-                    warn!(
+                    t::warn!(
                         push_gateway = %destination,
                         %status,
                         %url,
@@ -131,8 +132,8 @@ impl Service {
                         .expect("reqwest body is valid http body"),
                 );
                 response.map_err(|error| {
-                    warn!(
+                    warn_err!(
-                        %error,
+                        error,
                         appservice = %destination,
                         %url,
                         "Push gateway returned invalid response bytes",
@@ -143,8 +144,8 @@ impl Service {
                 })
             }
             Err(error) => {
-                warn!(
+                warn_err!(
-                    %error,
+                    error,
                     %destination,
                     "Could not send request to push gateway",
                 );
@@ -153,7 +154,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip(self, user, unread, pusher, ruleset, pdu))]
+    #[t::instrument(skip(self, user, unread, pusher, ruleset, pdu))]
     pub(crate) async fn send_push_notice(
         &self,
         user: &UserId,
@@ -210,7 +211,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, user, ruleset, pdu))]
+    #[t::instrument(skip(self, user, ruleset, pdu))]
     pub(crate) fn get_actions<'a>(
         &self,
         user: &UserId,
@@ -240,7 +241,7 @@ impl Service {
         Ok(ruleset.get_actions(pdu, &ctx))
     }
 
-    #[tracing::instrument(skip(self, unread, pusher, tweaks, event))]
+    #[t::instrument(skip(self, unread, pusher, tweaks, event))]
     async fn send_notice(
         &self,
         unread: UInt,

src/service/rooms/auth_chain.rs

@@ -5,11 +5,10 @@ use std::{
 
 use lru_cache::LruCache;
 use ruma::{api::client::error::ErrorKind, EventId, RoomId};
-use tracing::{debug, error, warn};
 
 use super::short::ShortEventId;
 use crate::{
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     services,
     utils::debug_slice_truncated,
     Error, Result,
@@ -66,7 +65,7 @@ impl Service {
         Ok(Some(chain))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn cache_auth_chain(
         &self,
         key: Vec<ShortEventId>,
@@ -79,7 +78,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, starting_events),
         fields(starting_events = debug_slice_truncated(&starting_events, 5)),
     )]
@@ -146,7 +145,7 @@ impl Service {
                         vec![sevent_id],
                         Arc::clone(&auth_chain),
                     )?;
-                    debug!(
+                    t::debug!(
                         event_id = ?event_id,
                         chain_length = ?auth_chain.len(),
                         "Cache missed event"
@@ -159,7 +158,7 @@ impl Service {
                     }
                 };
             }
-            debug!(
+            t::debug!(
                 chunk_cache_length = ?chunk_cache.len(),
                 hits = ?hits2,
                 misses = ?misses2,
@@ -170,7 +169,7 @@ impl Service {
             full_auth_chain.extend(chunk_cache.iter());
         }
 
-        debug!(
+        t::debug!(
             chain_length = ?full_auth_chain.len(),
             hits = ?hits,
             misses = ?misses,
@@ -182,7 +181,7 @@ impl Service {
         }))
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn get_auth_chain_inner(
         &self,
         room_id: &RoomId,
@@ -195,7 +194,11 @@ impl Service {
             match services().rooms.timeline.get_pdu(&event_id) {
                 Ok(Some(pdu)) => {
                     if pdu.room_id != room_id {
-                        warn!(bad_room_id = %pdu.room_id, "Event referenced in auth chain has incorrect room id");
+                        t::warn!(
+                            bad_room_id = %pdu.room_id,
+                            "Event referenced in auth chain has incorrect room \
+                             id"
+                        );
                         return Err(Error::BadRequest(
                             ErrorKind::forbidden(),
                             "Event has incorrect room id",
@@ -214,15 +217,15 @@ impl Service {
                     }
                 }
                 Ok(None) => {
-                    warn!(
+                    t::warn!(
                         ?event_id,
                         "Could not find pdu mentioned in auth events"
                     );
                 }
                 Err(error) => {
-                    error!(
+                    error_err!(
+                        error,
                         ?event_id,
-                        ?error,
                         "Could not load event in auth chain"
                     );
                 }

src/service/rooms/edus/typing.rs

@@ -5,9 +5,8 @@ use ruma::{
     OwnedRoomId, OwnedUserId, RoomId, UserId,
 };
 use tokio::sync::{broadcast, RwLock};
-use tracing::trace;
 
-use crate::{services, utils, Result};
+use crate::{observability::prelude::*, services, utils, Result};
 
 pub(crate) struct Service {
     // u64 is unix timestamp of timeout
@@ -28,7 +27,7 @@ impl Service {
 
     /// Sets a user as typing until the timeout timestamp is reached or
     /// `roomtyping_remove` is called.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn typing_add(
         &self,
         user_id: &UserId,
@@ -46,7 +45,7 @@ impl Service {
             .await
             .insert(room_id.to_owned(), services().globals.next_count()?);
         if self.typing_update_sender.send(room_id.to_owned()).is_err() {
-            trace!(
+            t::trace!(
                 "receiver found what it was looking for and is no longer \
                  interested"
             );
@@ -55,7 +54,7 @@ impl Service {
     }
 
     /// Removes a user from typing before the timeout is reached.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn typing_remove(
         &self,
         user_id: &UserId,
@@ -72,7 +71,7 @@ impl Service {
             .await
             .insert(room_id.to_owned(), services().globals.next_count()?);
         if self.typing_update_sender.send(room_id.to_owned()).is_err() {
-            trace!(
+            t::trace!(
                 "receiver found what it was looking for and is no longer \
                  interested"
             );
@@ -80,7 +79,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::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 {
@@ -93,7 +92,7 @@ impl Service {
     }
 
     /// Makes sure that typing events with old timestamps get removed.
-    #[tracing::instrument(skip(self, room_id))]
+    #[t::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();
@@ -120,7 +119,7 @@ impl Service {
                 .await
                 .insert(room_id.to_owned(), services().globals.next_count()?);
             if self.typing_update_sender.send(room_id.to_owned()).is_err() {
-                trace!(
+                t::trace!(
                     "receiver found what it was looking for and is no longer \
                      interested"
                 );
@@ -130,7 +129,7 @@ impl Service {
     }
 
     /// Returns the count of the last typing update in this room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn last_typing_update(
         &self,
         room_id: &RoomId,
@@ -146,7 +145,7 @@ impl Service {
     }
 
     /// Returns a new typing EDU.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn typings_all(
         &self,
         room_id: &RoomId,

src/service/rooms/event_handler.rs

@@ -34,13 +34,13 @@ use ruma::{
 use serde::Deserialize;
 use serde_json::value::RawValue as RawJsonValue;
 use tokio::sync::{RwLock, RwLockWriteGuard, Semaphore};
-use tracing::{debug, error, info, trace, warn};
 
 use super::{
     short::ShortStateKey, state_compressor::CompressedStateEvent,
     timeline::PduId,
 };
 use crate::{
+    observability::prelude::*,
     service::{globals::SigningKeys, pdu, rooms::state::ExtractVersion},
     services,
     utils::{debug_slice_truncated, room_version::RoomVersion},
@@ -82,7 +82,7 @@ impl Service {
     /// 13. Use state resolution to find new room state
     /// 14. Check if the event passes auth based on the "current state" of the
     ///     room, if not soft fail it
-    #[tracing::instrument(skip(self, value, is_timeline_event, pub_key_map))]
+    #[t::instrument(skip(self, value, is_timeline_event, pub_key_map))]
     pub(crate) async fn handle_incoming_pdu<'a>(
         &self,
         origin: &'a ServerName,
@@ -160,7 +160,7 @@ impl Service {
             .await?;
 
         let mut errors = 0;
-        debug!(events = ?sorted_prev_events, "Got previous events");
+        t::debug!(events = ?sorted_prev_events, "Got previous events");
         for prev_id in sorted_prev_events {
             // Check for disabled again because it might have changed
             if services().rooms.metadata.is_disabled(room_id)? {
@@ -186,7 +186,10 @@ impl Service {
                 }
 
                 if time.elapsed() < min_elapsed_duration {
-                    info!(event_id = %prev_id, "Backing off from prev event");
+                    t::info!(
+                        event_id = %prev_id,
+                        "Backing off from prev event"
+                    );
                     continue;
                 }
             }
@@ -239,7 +242,7 @@ impl Service {
                     .await
                 {
                     errors += 1;
-                    warn!(%error, event_id = %prev_id, "Prev event failed");
+                    warn_err!(error, event_id = %prev_id, "Prev event failed");
                     match services()
                         .globals
                         .bad_event_ratelimiter
@@ -261,7 +264,7 @@ impl Service {
                     .write()
                     .await
                     .remove(&room_id.to_owned());
-                debug!(
+                t::debug!(
                     elapsed = ?start_time.elapsed(),
                     event_id = %prev_id,
                     "Finished handling prev event",
@@ -299,7 +302,7 @@ impl Service {
     }
 
     #[allow(clippy::too_many_arguments)]
-    #[tracing::instrument(skip(self, origin, room_id, value, pub_key_map))]
+    #[t::instrument(skip(self, origin, room_id, value, pub_key_map))]
     fn handle_outlier_pdu<'a>(
         &'a self,
         origin: &'a ServerName,
@@ -333,7 +336,7 @@ impl Service {
 
             let origin_server_ts =
                 value.get("origin_server_ts").ok_or_else(|| {
-                    error!("Invalid PDU, no origin_server_ts field");
+                    t::error!("Invalid PDU, no origin_server_ts field");
                     Error::BadRequest(
                         ErrorKind::MissingParam,
                         "Invalid PDU, no origin_server_ts field",
@@ -377,7 +380,7 @@ impl Service {
             ) {
                 Err(error) => {
                     // Drop
-                    warn!(%event_id, %error, "Dropping bad event");
+                    warn_err!(error, %event_id, "Dropping bad event");
                     return Err(Error::BadRequest(
                         ErrorKind::InvalidParam,
                         "Signature verification failed",
@@ -385,7 +388,7 @@ impl Service {
                 }
                 Ok(ruma::signatures::Verified::Signatures) => {
                     // Redact
-                    warn!(%event_id, "Calculated hash does not match");
+                    t::warn!(%event_id, "Calculated hash does not match");
                     let Ok(obj) = ruma::canonical_json::redact(
                         value,
                         room_version_id,
@@ -440,7 +443,10 @@ impl Service {
                 //    to auth events"
                 // NOTE: Step 5 is not applied anymore because it failed too
                 // often
-                debug!(event_id = ?incoming_pdu.event_id, "Fetching auth events");
+                t::debug!(
+                    event_id = ?incoming_pdu.event_id,
+                    "Fetching auth events"
+                );
                 self.fetch_and_handle_outliers(
                     origin,
                     &incoming_pdu
@@ -457,7 +463,7 @@ impl Service {
 
             // 6. Reject "due to auth events" if the event doesn't pass auth
             //    based on the auth events
-            debug!(
+            t::debug!(
                 event_id = %incoming_pdu.event_id,
                 "Starting auth check for event based on auth events",
             );
@@ -468,7 +474,7 @@ impl Service {
                 let Some(auth_event) =
                     services().rooms.timeline.get_pdu(event_id)?
                 else {
-                    warn!(%event_id, "Could not find auth event");
+                    t::warn!(%event_id, "Could not find auth event");
                     continue;
                 };
 
@@ -521,7 +527,7 @@ impl Service {
                 ));
             }
 
-            debug!("Validation successful");
+            t::debug!("Validation successful");
 
             // 7. Persist the event as an outlier.
             services()
@@ -529,13 +535,13 @@ impl Service {
                 .outlier
                 .add_pdu_outlier(&incoming_pdu.event_id, &val)?;
 
-            debug!("Added pdu as outlier");
+            t::debug!("Added pdu as outlier");
 
             Ok((Arc::new(incoming_pdu), val))
         })
     }
 
-    #[tracing::instrument(skip_all, fields(
+    #[t::instrument(skip_all, fields(
         incoming_pdu = %incoming_pdu.event_id,
     ))]
     pub(crate) async fn upgrade_outlier_to_timeline_pdu(
@@ -565,7 +571,7 @@ impl Service {
             ));
         }
 
-        debug!(
+        t::debug!(
             event_id = %incoming_pdu.event_id,
             "Upgrading event to timeline pdu",
         );
@@ -584,7 +590,7 @@ impl Service {
         // the request and build the state from a known point and
         // resolve if > 1 prev_event
 
-        debug!("Requesting state at event");
+        t::debug!("Requesting state at event");
         let mut state_at_incoming_event = None;
 
         if incoming_pdu.prev_events.len() == 1 {
@@ -607,7 +613,7 @@ impl Service {
             };
 
             if let Some(Ok(mut state)) = state {
-                debug!("Using cached state");
+                t::debug!("Using cached state");
                 let prev_pdu = services()
                     .rooms
                     .timeline
@@ -634,7 +640,7 @@ impl Service {
                 state_at_incoming_event = Some(state);
             }
         } else {
-            debug!("Calculating state at event using state res");
+            t::debug!("Calculating state at event using state res");
             let mut extremity_sstatehashes = HashMap::new();
 
             let mut okay = true;
@@ -701,7 +707,7 @@ impl Service {
                                 id.clone(),
                             );
                         } else {
-                            warn!("Failed to get_statekey_from_short");
+                            t::warn!("Failed to get_statekey_from_short");
                         }
                         starting_events.push(id);
                     }
@@ -727,7 +733,11 @@ impl Service {
                     |event_id| {
                         let res = services().rooms.timeline.get_pdu(event_id);
                         if let Err(error) = &res {
-                            error!(%error, %event_id, "Failed to fetch event");
+                            error_err!(
+                                error,
+                                %event_id,
+                                "Failed to fetch event"
+                            );
                         }
                         res.ok().flatten()
                     },
@@ -751,10 +761,10 @@ impl Service {
                             .collect::<Result<_>>()?,
                     ),
                     Err(error) => {
-                        warn!(
+                        warn_err!(
-                            %error,
+                            error,
                             "State resolution on prev events failed, either \
-                            an event could not be found or deserialization"
+                             an event could not be found or deserialization"
                         );
                         None
                     }
@@ -763,7 +773,7 @@ impl Service {
         }
 
         if state_at_incoming_event.is_none() {
-            debug!("Calling /state_ids");
+            t::debug!("Calling /state_ids");
             // Call /state_ids to find out what the state at this pdu is. We
             // trust the server's response to some extend, but we
             // still do a lot of checks on the events
@@ -779,7 +789,7 @@ impl Service {
                 .await
             {
                 Ok(res) => {
-                    debug!("Fetching state events at event");
+                    t::debug!("Fetching state events at event");
                     let collect = res
                         .pdu_ids
                         .iter()
@@ -863,7 +873,7 @@ impl Service {
                     state_at_incoming_event = Some(state);
                 }
                 Err(error) => {
-                    warn!(%error, "Fetching state for event failed");
+                    warn_err!(error, "Fetching state for event failed");
                     return Err(error);
                 }
             };
@@ -872,7 +882,7 @@ impl Service {
         let state_at_incoming_event =
             state_at_incoming_event.expect("we always set this to some above");
 
-        debug!("Starting auth check");
+        t::debug!("Starting auth check");
         // 11. Check the auth of the event passes based on the state of the
         //     event
         let check_result = state_res::event_auth::auth_check(
@@ -909,7 +919,7 @@ impl Service {
                 "Event has failed auth check with state at the event.",
             ));
         }
-        debug!("Auth check succeeded");
+        t::debug!("Auth check succeeded");
 
         // Soft fail check before doing state res
         let auth_events = services().rooms.state.get_auth_events(
@@ -972,7 +982,7 @@ impl Service {
         // Now we calculate the set of extremities this room has after the
         // incoming event has been applied. We start with the previous
         // extremities (aka leaves)
-        debug!("Calculating extremities");
+        t::debug!("Calculating extremities");
         let mut extremities =
             services().rooms.state.get_forward_extremities(room_id)?;
 
@@ -992,7 +1002,7 @@ impl Service {
             )
         });
 
-        debug!("Compressing state at event");
+        t::debug!("Compressing state at event");
         let state_ids_compressed = Arc::new(
             state_at_incoming_event
                 .iter()
@@ -1006,7 +1016,7 @@ impl Service {
         );
 
         if incoming_pdu.state_key.is_some() {
-            debug!("Preparing for stateres to derive new room state");
+            t::debug!("Preparing for stateres to derive new room state");
 
             // We also add state after incoming event to the fork states
             let mut state_after = state_at_incoming_event.clone();
@@ -1026,7 +1036,7 @@ impl Service {
                 .await?;
 
             // Set the new room state to the resolved state
-            debug!("Forcing new room state");
+            t::debug!("Forcing new room state");
 
             let (sstatehash, new, removed) = services()
                 .rooms
@@ -1042,7 +1052,7 @@ impl Service {
 
         // 14. Check if the event passes auth based on the "current state" of
         //     the room, if not soft fail it
-        debug!("Starting soft fail auth check");
+        t::debug!("Starting soft fail auth check");
 
         if soft_fail {
             services()
@@ -1060,7 +1070,7 @@ impl Service {
 
             // Soft fail, we keep the event as an outlier but don't add it to
             // the timeline
-            warn!("Event was soft failed");
+            t::warn!("Event was soft failed");
             services()
                 .rooms
                 .pdu_metadata
@@ -1071,7 +1081,7 @@ impl Service {
             ));
         }
 
-        debug!("Appending pdu to timeline");
+        t::debug!("Appending pdu to timeline");
         extremities.insert(incoming_pdu.event_id.clone());
 
         // Now that the event has passed all auth it is added into the timeline.
@@ -1091,21 +1101,21 @@ impl Service {
             )
             .await?;
 
-        debug!("Appended incoming pdu");
+        t::debug!("Appended incoming pdu");
 
         // Event has passed all auth/stateres checks
         drop(room_token);
         Ok(pdu_id)
     }
 
-    #[tracing::instrument(skip(self, room_version_id, incoming_state))]
+    #[t::instrument(skip(self, room_version_id, incoming_state))]
     async fn resolve_state(
         &self,
         room_id: &RoomId,
         room_version_id: &RoomVersionId,
         incoming_state: HashMap<ShortStateKey, Arc<EventId>>,
     ) -> Result<Arc<HashSet<CompressedStateEvent>>> {
-        debug!("Loading current room state ids");
+        t::debug!("Loading current room state ids");
         let current_sstatehash = services()
             .rooms
             .state
@@ -1135,7 +1145,7 @@ impl Service {
             );
         }
 
-        debug!("Loading fork states");
+        t::debug!("Loading fork states");
 
         let fork_states: Vec<_> = fork_states
             .into_iter()
@@ -1155,12 +1165,12 @@ impl Service {
             })
             .collect();
 
-        debug!("Resolving state");
+        t::debug!("Resolving state");
 
         let fetch_event = |id: &_| {
             let res = services().rooms.timeline.get_pdu(id);
             if let Err(error) = &res {
-                error!(%error, "Failed to fetch event");
+                error_err!(error, "Failed to fetch event");
             }
             res.ok().flatten()
         };
@@ -1180,7 +1190,7 @@ impl Service {
 
         drop(lock);
 
-        debug!("State resolution done; compressing state");
+        t::debug!("State resolution done; compressing state");
 
         let new_room_state = state
             .into_iter()
@@ -1209,7 +1219,7 @@ impl Service {
     /// b. Look at outlier pdu tree
     /// c. Ask origin server over federation
     /// d. TODO: Ask other servers over federation?
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     pub(crate) fn fetch_and_handle_outliers<'a>(
         &'a self,
         origin: &'a ServerName,
@@ -1244,7 +1254,7 @@ impl Service {
                 if let Ok(Some(local_pdu)) =
                     services().rooms.timeline.get_pdu(event_id)
                 {
-                    trace!(%event_id, "Found event locally");
+                    t::trace!(%event_id, "Found event locally");
                     pdus.push((local_pdu, None));
                     continue;
                 }
@@ -1275,7 +1285,7 @@ impl Service {
                         }
 
                         if time.elapsed() < min_elapsed_duration {
-                            info!(
+                            t::info!(
                                 event_id = %next_id,
                                 "Backing off from event",
                             );
@@ -1295,11 +1305,11 @@ impl Service {
                     if let Ok(Some(_)) =
                         services().rooms.timeline.get_pdu(&next_id)
                     {
-                        trace!(event_id = %next_id, "Found event locally");
+                        t::trace!(event_id = %next_id, "Found event locally");
                         continue;
                     }
 
-                    info!(
+                    t::info!(
                         event_id = %next_id,
                         "Fetching event over federation",
                     );
@@ -1313,7 +1323,10 @@ impl Service {
                         )
                         .await
                     {
-                        info!(event_id = %next_id, "Got event over federation");
+                        t::info!(
+                            event_id = %next_id,
+                            "Got event over federation"
+                        );
                         let Ok((calculated_event_id, value)) =
                             pdu::gen_event_id_canonical_json(
                                 &res.pdu,
@@ -1325,7 +1338,7 @@ impl Service {
                         };
 
                         if calculated_event_id != *next_id {
-                            warn!(
+                            t::warn!(
                                 expected_event_id = %next_id,
                                 actual_event_id = %calculated_event_id,
                                 "Server returned an event with a different ID \
@@ -1343,17 +1356,17 @@ impl Service {
                                     let a: Arc<EventId> = auth_event;
                                     todo_auth_events.push(a);
                                 } else {
-                                    warn!("Auth event id is not valid");
+                                    t::warn!("Auth event id is not valid");
                                 }
                             }
                         } else {
-                            warn!("Auth event list invalid");
+                            t::warn!("Auth event list invalid");
                         }
 
                         events_in_reverse_order.push((next_id.clone(), value));
                         events_all.insert(next_id);
                     } else {
-                        warn!(event_id = %next_id, "Failed to fetch event");
+                        t::warn!(event_id = %next_id, "Failed to fetch event");
                         back_off((*next_id).to_owned()).await;
                     }
                 }
@@ -1377,7 +1390,7 @@ impl Service {
                         }
 
                         if time.elapsed() < min_elapsed_duration {
-                            info!(
+                            t::info!(
                                 event_id = %next_id,
                                 "Backing off from event",
                             );
@@ -1403,9 +1416,9 @@ impl Service {
                             }
                         }
                         Err(error) => {
-                            warn!(
+                            warn_err!(
+                                error,
                                 event_id = %next_id,
-                                %error,
                                 "Event failed auth checks",
                             );
                             back_off((**next_id).to_owned()).await;
@@ -1417,7 +1430,7 @@ impl Service {
         })
     }
 
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     #[allow(clippy::type_complexity)]
     async fn fetch_unknown_prev_events(
         &self,
@@ -1457,7 +1470,7 @@ impl Service {
 
                 if amount > services().globals.max_fetch_prev_events() {
                     // Max limit reached
-                    warn!("Max prev event limit reached!");
+                    t::warn!("Max prev event limit reached!");
                     graph.insert(prev_event_id.clone(), HashSet::new());
                     continue;
                 }
@@ -1519,7 +1532,7 @@ impl Service {
         Ok((sorted, eventid_info))
     }
 
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     pub(crate) async fn fetch_required_signing_keys(
         &self,
         event: &CanonicalJsonObject,
@@ -1560,7 +1573,7 @@ impl Service {
                 .await;
 
             let Ok(keys) = fetch_res else {
-                warn!("Failed to fetch signing key");
+                t::warn!("Failed to fetch signing key");
                 continue;
             };
 
@@ -1573,7 +1586,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)]
+    #[t::instrument(skip_all)]
     async fn get_server_keys_from_cache(
         &self,
         pdu: &RawJsonValue,
@@ -1586,7 +1599,7 @@ impl Service {
     ) -> Result<()> {
         let value: CanonicalJsonObject = serde_json::from_str(pdu.get())
             .map_err(|error| {
-                error!(%error, ?pdu, "Invalid PDU in server response");
+                error_err!(error, ?pdu, "Invalid PDU in server response");
                 Error::BadServerResponse("Invalid PDU in server response")
             })?;
 
@@ -1618,7 +1631,7 @@ impl Service {
             }
 
             if time.elapsed() < min_elapsed_duration {
-                debug!(%event_id, "Backing off from event");
+                t::debug!(%event_id, "Backing off from event");
                 return Err(Error::BadServerResponse(
                     "Bad event, still backing off",
                 ));
@@ -1674,11 +1687,14 @@ impl Service {
                 continue;
             }
 
-            trace!(server = %origin, "Loading signing keys for other server");
+            t::trace!(
+                server = %origin,
+                "Loading signing keys for other server"
+            );
 
             let result = services().globals.signing_keys_for(origin)?;
             if !result.as_ref().is_some_and(contains_all_ids) {
-                trace!(
+                t::trace!(
                     server = %origin,
                     "Signing key not loaded for server",
                 );
@@ -1724,7 +1740,7 @@ impl Service {
                     )
                     .await
                 {
-                    debug!(%error, "Failed to get server keys from cache");
+                    debug_err!(error, "Failed to get server keys from cache");
                 };
             }
 
@@ -1732,12 +1748,12 @@ impl Service {
         };
 
         if servers.is_empty() {
-            info!("We had all keys locally");
+            t::info!("We had all keys locally");
             return Ok(());
         }
 
         for server in services().globals.trusted_servers() {
-            info!(%server, "Asking batch signing keys from trusted server");
+            t::info!(%server, "Asking batch signing keys from trusted server");
             if let Ok(keys) = services()
                 .sending
                 .send_federation_request(
@@ -1748,14 +1764,14 @@ impl Service {
                 )
                 .await
             {
-                trace!(signing_keys = ?keys, "Got signing keys");
+                t::trace!(signing_keys = ?keys, "Got signing keys");
                 let mut pkm = pub_key_map.write().await;
                 for k in keys.server_keys {
                     let k = match k.deserialize() {
                         Ok(key) => key,
                         Err(error) => {
-                            warn!(
+                            warn_err!(
-                                %error,
+                                error,
                                 %server,
                                 object = ?k.json(),
                                 "Failed to fetch keys from trusted server",
@@ -1779,12 +1795,12 @@ impl Service {
             }
 
             if servers.is_empty() {
-                info!("Trusted server supplied all signing keys");
+                t::info!("Trusted server supplied all signing keys");
                 return Ok(());
             }
         }
 
-        info!(?servers, "Asking individual servers for signing keys");
+        t::info!(?servers, "Asking individual servers for signing keys");
         let mut futures: FuturesUnordered<_> = servers
             .into_keys()
             .map(|server| async move {
@@ -1803,7 +1819,7 @@ impl Service {
 
         while let Some(result) = futures.next().await {
             if let (Ok(get_keys_response), origin) = result {
-                info!(server = %origin, "Received new result from server");
+                t::info!(server = %origin, "Received new result from server");
                 if let Ok(key) = get_keys_response.server_key.deserialize() {
                     let result = services()
                         .globals
@@ -1814,10 +1830,10 @@ impl Service {
                         .insert(origin.to_string(), result);
                 }
             }
-            info!("Done handling result");
+            t::info!("Done handling result");
         }
 
-        info!("Search for signing keys done");
+        t::info!("Search for signing keys done");
 
         Ok(())
     }
@@ -1825,7 +1841,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)]
+    #[t::instrument(skip_all)]
     pub(crate) fn acl_check(
         &self,
         server_name: &ServerName,
@@ -1846,7 +1862,7 @@ impl Service {
         {
             Ok(x) => x,
             Err(error) => {
-                warn!(%error, "Invalid ACL event");
+                warn_err!(error, "Invalid ACL event");
                 return Ok(());
             }
         };
@@ -1859,7 +1875,7 @@ impl Service {
         if acl_event_content.is_allowed(server_name) {
             Ok(())
         } else {
-            info!(
+            t::info!(
                 server = %server_name,
                 %room_id,
                 "Other server was denied by room ACL",
@@ -1873,7 +1889,7 @@ impl Service {
 
     /// Search the DB for the signing keys of the given server, if we don't have
     /// them fetch them from the server and save to our DB.
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, signature_ids),
         fields(signature_ids = debug_slice_truncated(&signature_ids, 3))
     )]
@@ -1899,7 +1915,7 @@ impl Service {
                     .any(|key_id| id == &key_id);
 
                 if !in_verify_keys && !in_old_verify_keys {
-                    trace!(id, "signature key not yet in known set");
+                    t::trace!(id, "signature key not yet in known set");
                     return false;
                 }
             }
@@ -1945,14 +1961,14 @@ impl Service {
             }
 
             if time.elapsed() < min_elapsed_duration {
-                debug!(?signature_ids, "Backing off from signatures");
+                t::debug!(?signature_ids, "Backing off from signatures");
                 return Err(Error::BadServerResponse(
                     "bad signature, still backing off",
                 ));
             }
         }
 
-        trace!("Loading signing keys from database");
+        t::trace!("Loading signing keys from database");
 
         let result = services().globals.signing_keys_for(origin)?;
 
@@ -1964,7 +1980,7 @@ impl Service {
             )
             .expect("Should be valid until year 500,000,000");
 
-            debug!(
+            t::debug!(
                 server = %origin,
                 key_ids = ?result.verify_keys.keys().collect::<Vec<_>>(),
                 old_key_ids =
@@ -1978,7 +1994,7 @@ impl Service {
                 // We want to ensure that the keys remain valid by the time the
                 // other functions that handle signatures reach them
                 if result.valid_until_ts > ts_threshold {
-                    debug!(
+                    t::debug!(
                         origin = %origin,
                         valid_until_ts = %result.valid_until_ts.get(),
                         "Keys are valid because they expire after threshold",
@@ -1987,7 +2003,7 @@ impl Service {
                 }
 
                 expires_soon_or_has_expired = true;
-                trace!("Found all keys, but they will expire too soon");
+                t::trace!("Found all keys, but they will expire too soon");
             }
         }
 
@@ -2004,7 +2020,7 @@ impl Service {
         )
         .expect("Should be valid until year 500,000,000");
 
-        debug!("Fetching signing keys over federation");
+        t::debug!("Fetching signing keys over federation");
 
         if let Some(mut server_key) = services()
             .sending
@@ -2052,7 +2068,7 @@ impl Service {
 
         if query_via_trusted_servers {
             for server in services().globals.trusted_servers() {
-                debug!(
+                t::debug!(
                     trusted_server = %server,
                     origin = %origin,
                     "Asking trusted server for signing keys",
@@ -2080,7 +2096,7 @@ impl Service {
                             .collect::<Vec<_>>()
                     })
                 {
-                    trace!(
+                    t::trace!(
                         ?server_keys,
                         "Got signing keys from trusted server"
                     );
@@ -2129,7 +2145,7 @@ impl Service {
                                     .map(|(id, key)| (id.to_string(), key)),
                             );
                         } else {
-                            warn!(
+                            t::warn!(
                                 origin = %origin,
                                 valid_until = %k.valid_until_ts.get(),
                                 "Server gave us keys older than we \
@@ -2147,7 +2163,7 @@ impl Service {
 
         // We should return these keys if fresher keys were not found
         if expires_soon_or_has_expired {
-            info!(origin = %origin, "Returning stale keys");
+            t::info!(origin = %origin, "Returning stale keys");
             return Ok(keys);
         }
 
@@ -2155,14 +2171,14 @@ impl Service {
 
         back_off(signature_ids).await;
 
-        warn!("Failed to find all public keys");
+        t::warn!("Failed to find all public keys");
         Err(Error::BadServerResponse("Failed to find public key for server"))
     }
 
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     fn check_room_id(room_id: &RoomId, pdu: &PduEvent) -> Result<()> {
         if pdu.room_id != room_id {
-            warn!(
+            t::warn!(
                 event_id = %pdu.event_id,
                 expected_room_id = %pdu.room_id,
                 actual_room_id = %room_id,

src/service/rooms/lazy_loading.rs

@@ -4,7 +4,7 @@ use ruma::{DeviceId, OwnedDeviceId, OwnedRoomId, OwnedUserId, RoomId, UserId};
 use tokio::sync::Mutex;
 
 use super::timeline::PduCount;
-use crate::Result;
+use crate::{observability::prelude::*, Result};
 
 mod data;
 
@@ -30,7 +30,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn lazy_load_was_sent_before(
         &self,
         user_id: &UserId,
@@ -41,7 +41,7 @@ impl Service {
         self.db.lazy_load_was_sent_before(user_id, device_id, room_id, ll_user)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn lazy_load_mark_sent(
         &self,
         user_id: &UserId,
@@ -61,7 +61,7 @@ impl Service {
         );
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn lazy_load_confirm_delivery(
         &self,
         user_id: &UserId,
@@ -86,7 +86,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn lazy_load_reset(
         &self,
         user_id: &UserId,

src/service/rooms/pdu_metadata.rs

@@ -8,7 +8,7 @@ use ruma::{
 use serde::Deserialize;
 
 use super::timeline::PduCount;
-use crate::{services, PduEvent, Result};
+use crate::{observability::prelude::*, services, PduEvent, Result};
 
 mod data;
 
@@ -29,7 +29,7 @@ struct ExtractRelatesToEventId {
 }
 
 impl Service {
-    #[tracing::instrument(skip(self, from, to))]
+    #[t::instrument(skip(self, from, to))]
     pub(crate) fn add_relation(
         &self,
         from: PduCount,
@@ -48,7 +48,7 @@ impl Service {
     }
 
     #[allow(clippy::too_many_arguments, clippy::too_many_lines)]
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn paginate_relations_with_filter(
         &self,
         sender_user: &UserId,
@@ -176,7 +176,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     pub(crate) fn relations_until<'a>(
         &'a self,
         user_id: &'a UserId,
@@ -195,7 +195,7 @@ impl Service {
         self.db.relations_until(user_id, room_id, target, until)
     }
 
-    #[tracing::instrument(skip(self, room_id, event_ids))]
+    #[t::instrument(skip(self, room_id, event_ids))]
     pub(crate) fn mark_as_referenced(
         &self,
         room_id: &RoomId,
@@ -204,7 +204,7 @@ impl Service {
         self.db.mark_as_referenced(room_id, event_ids)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn is_event_referenced(
         &self,
         room_id: &RoomId,
@@ -213,7 +213,7 @@ impl Service {
         self.db.is_event_referenced(room_id, event_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn mark_event_soft_failed(
         &self,
         event_id: &EventId,
@@ -221,7 +221,7 @@ impl Service {
         self.db.mark_event_soft_failed(event_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn is_event_soft_failed(
         &self,
         event_id: &EventId,

src/service/rooms/spaces.rs

@@ -29,10 +29,9 @@ use ruma::{
     OwnedRoomId, RoomId, UserId,
 };
 use tokio::sync::Mutex;
-use tracing::{debug, error, warn};
 
 use super::state::ExtractType;
-use crate::{services, Error, PduEvent, Result};
+use crate::{observability::prelude::*, services, Error, PduEvent, Result};
 
 pub(crate) enum CachedJoinRule {
     Full(JoinRule),
@@ -59,7 +58,7 @@ impl Service {
     }
 
     #[allow(clippy::too_many_lines)]
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn get_hierarchy(
         &self,
         sender_user: &UserId,
@@ -185,8 +184,8 @@ impl Service {
                             serde_json::from_str(s.content.get())
                                 .map(|c: RoomJoinRulesEventContent| c.join_rule)
                                 .map_err(|error| {
-                                    error!(
+                                    error_err!(
-                                        %error,
+                                        error,
                                         "Invalid room join rule event"
                                     );
                                     Error::BadDatabase(
@@ -224,7 +223,7 @@ impl Service {
                     // Early return so the client can see some data already
                     break;
                 }
-                debug!(%server, "Asking other server for /hierarchy");
+                t::debug!(%server, "Asking other server for /hierarchy");
                 if let Ok(response) = services()
                     .sending
                     .send_federation_request(
@@ -236,7 +235,7 @@ impl Service {
                     )
                     .await
                 {
-                    warn!(
+                    t::warn!(
                         %server,
                         ?response,
                         "Got response from other server for /hierarchy",
@@ -333,7 +332,7 @@ impl Service {
     }
 
     #[allow(clippy::too_many_lines)]
-    #[tracing::instrument(skip(self, children))]
+    #[t::instrument(skip(self, children))]
     fn get_room_chunk(
         &self,
         sender_user: &UserId,
@@ -353,8 +352,8 @@ impl Service {
                     serde_json::from_str(s.content.get())
                         .map(|c: RoomCanonicalAliasEventContent| c.alias)
                         .map_err(|error| {
-                            error!(
+                            error_err!(
-                                %error,
+                                error,
                                 event_id = %s.event_id,
                                 "Invalid room canonical alias event"
                             );
@@ -369,7 +368,7 @@ impl Service {
                 .state_cache
                 .room_joined_count(room_id)?
                 .unwrap_or_else(|| {
-                    warn!("Room has no member count");
+                    t::warn!("Room has no member count");
                     0
                 })
                 .try_into()
@@ -383,8 +382,8 @@ impl Service {
                     serde_json::from_str(s.content.get())
                         .map(|c: RoomTopicEventContent| Some(c.topic))
                         .map_err(|error| {
-                            error!(
+                            error_err!(
-                                %error,
+                                error,
                                 event_id = %s.event_id,
                                 "Invalid room topic event"
                             );
@@ -408,8 +407,8 @@ impl Service {
                                 == HistoryVisibility::WorldReadable
                         })
                         .map_err(|error| {
-                            error!(
+                            error_err!(
-                                %error,
+                                error,
                                 event_id = %s.event_id,
                                 "Invalid room history visibility event"
                             );
@@ -429,8 +428,8 @@ impl Service {
                             c.guest_access == GuestAccess::CanJoin
                         })
                         .map_err(|error| {
-                            error!(
+                            error_err!(
-                                %error,
+                                error,
                                 event_id = %s.event_id,
                                 "Invalid room guest access event"
                             );
@@ -447,8 +446,8 @@ impl Service {
                     serde_json::from_str(s.content.get())
                         .map(|c: RoomAvatarEventContent| c.url)
                         .map_err(|error| {
-                            error!(
+                            error_err!(
-                                %error,
+                                error,
                                 event_id = %s.event_id,
                                 "Invalid room avatar event"
                             );
@@ -472,8 +471,8 @@ impl Service {
                         serde_json::from_str(s.content.get())
                             .map(|c: RoomJoinRulesEventContent| c.join_rule)
                             .map_err(|error| {
-                                error!(
+                                error_err!(
-                                    %error,
+                                    error,
                                     event_id = %s.event_id,
                                     "Invalid room join rule event",
                                 );
@@ -486,7 +485,7 @@ impl Service {
                     .unwrap_or(JoinRule::Invite);
 
                 if !self.handle_join_rule(&join_rule, sender_user, room_id)? {
-                    debug!("User is not allowed to see room");
+                    t::debug!("User is not allowed to see room");
                     // This error will be caught later
                     return Err(Error::BadRequest(
                         ErrorKind::forbidden(),
@@ -547,7 +546,7 @@ impl Service {
         Ok(allowed)
     }
 
-    #[tracing::instrument(skip(self, sender_user))]
+    #[t::instrument(skip(self, sender_user))]
     fn handle_join_rule(
         &self,
         join_rule: &JoinRule,

src/service/rooms/state.rs

@@ -16,10 +16,10 @@ use ruma::{
     EventId, OwnedEventId, OwnedRoomId, RoomId, RoomVersionId, UserId,
 };
 use serde::{de::DeserializeOwned, Deserialize};
-use tracing::warn;
 
 use super::{short::ShortStateHash, state_compressor::CompressedStateEvent};
 use crate::{
+    observability::prelude::*,
     service::globals::marker,
     services,
     utils::{
@@ -86,7 +86,7 @@ pub(crate) struct Service {
 
 impl Service {
     /// Set the room to the given statehash and update caches.
-    #[tracing::instrument(skip(self, statediffnew, _statediffremoved))]
+    #[t::instrument(skip(self, statediffnew, _statediffremoved))]
     pub(crate) async fn force_state(
         &self,
         room_id: &KeyToken<OwnedRoomId, marker::State>,
@@ -170,7 +170,7 @@ impl Service {
     ///
     /// This adds all current state events (not including the incoming event)
     /// to `stateid_pduid` and adds the incoming event to `eventid_statehash`.
-    #[tracing::instrument(skip(self, state_ids_compressed))]
+    #[t::instrument(skip(self, state_ids_compressed))]
     pub(crate) fn set_event_state(
         &self,
         event_id: &EventId,
@@ -237,7 +237,7 @@ impl Service {
     ///
     /// This adds all current state events (not including the incoming event)
     /// to `stateid_pduid` and adds the incoming event to `eventid_statehash`.
-    #[tracing::instrument(skip(self, new_pdu))]
+    #[t::instrument(skip(self, new_pdu))]
     pub(crate) fn append_to_state(
         &self,
         new_pdu: &PduEvent,
@@ -319,7 +319,7 @@ impl Service {
     /// Gather events to help the invited user identify the room
     ///
     /// Also includes the invite event itself.
-    #[tracing::instrument(skip(self, invite_event))]
+    #[t::instrument(skip(self, invite_event))]
     pub(crate) fn get_helpful_invite_events(
         &self,
         invite_event: &PduEvent,
@@ -355,7 +355,7 @@ impl Service {
     }
 
     /// Set the state hash to a new version, but does not update state_cache.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn set_room_state(
         &self,
         room_id: &KeyToken<OwnedRoomId, marker::State>,
@@ -365,7 +365,7 @@ impl Service {
     }
 
     /// Returns the value of a field of an `m.room.create` event's `content`.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_create_content<T: ExtractCreateContent>(
         &self,
         room_id: &RoomId,
@@ -381,7 +381,7 @@ impl Service {
             .map(|create_event| {
                 serde_json::from_str::<T>(create_event.content.get()).map_err(
                     |error| {
-                        warn!(%error, "Invalid create event");
+                        warn_err!(error, "Invalid create event");
                         Error::BadDatabase("Invalid create event in db.")
                     },
                 )
@@ -397,7 +397,7 @@ impl Service {
         Ok(content_field.extract())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_room_shortstatehash(
         &self,
         room_id: &RoomId,
@@ -405,7 +405,7 @@ impl Service {
         self.db.get_room_shortstatehash(room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_forward_extremities(
         &self,
         room_id: &RoomId,
@@ -413,7 +413,7 @@ impl Service {
         self.db.get_forward_extremities(room_id)
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, event_ids),
         fields(event_ids = debug_slice_truncated(&event_ids, 5)),
     )]
@@ -426,7 +426,7 @@ impl Service {
     }
 
     /// This fetches auth events from the current state.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_auth_events(
         &self,
         room_id: &RoomId,

src/service/rooms/state_accessor.rs

@@ -22,11 +22,10 @@ use ruma::{
     ServerName, UserId,
 };
 use serde_json::value::to_raw_value;
-use tracing::{error, warn};
 
 use super::short::{ShortStateHash, ShortStateKey};
 use crate::{
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     service::{globals::marker, pdu::PduBuilder},
     services,
     utils::on_demand_hashmap::KeyToken,
@@ -63,7 +62,7 @@ impl Service {
 
     /// Builds a StateMap by iterating over all keys that start
     /// with state_hash, this gives the full state for the given state_hash.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn state_full_ids(
         &self,
         shortstatehash: ShortStateHash,
@@ -92,7 +91,7 @@ impl Service {
         Ok(result)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn state_full(
         &self,
         shortstatehash: ShortStateHash,
@@ -140,7 +139,7 @@ impl Service {
 
     /// Returns a single PDU from `room_id` with key (`event_type`,
     /// `state_key`).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn state_get_id(
         &self,
         shortstatehash: ShortStateHash,
@@ -174,7 +173,7 @@ impl Service {
 
     /// Returns a single PDU from `room_id` with key (`event_type`,
     /// `state_key`).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn state_get(
         &self,
         shortstatehash: ShortStateHash,
@@ -188,7 +187,7 @@ impl Service {
     }
 
     /// Get membership for given user in state
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn user_membership(
         &self,
         shortstatehash: ShortStateHash,
@@ -211,7 +210,7 @@ impl Service {
     }
 
     /// The user was a joined member at this state (potentially in the past)
-    #[tracing::instrument(skip(self), ret(level = "trace"))]
+    #[t::instrument(skip(self), ret(level = "trace"))]
     fn user_was_joined(
         &self,
         shortstatehash: ShortStateHash,
@@ -223,7 +222,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"))]
+    #[t::instrument(skip(self), ret(level = "trace"))]
     fn user_was_invited(
         &self,
         shortstatehash: ShortStateHash,
@@ -236,7 +235,7 @@ impl Service {
 
     /// Whether a server is allowed to see an event through federation, based on
     /// the room's history_visibility at that event's state.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn server_can_see_event(
         &self,
         origin: &ServerName,
@@ -302,7 +301,7 @@ impl Service {
                     .any(|member| self.user_was_joined(shortstatehash, &member))
             }
             other => {
-                error!(kind = %other, "Unknown history visibility");
+                t::error!(kind = %other, "Unknown history visibility");
                 false
             }
         };
@@ -321,7 +320,7 @@ impl Service {
 
     /// Whether a user is allowed to see an event, based on
     /// the room's history_visibility at that event's state.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn user_can_see_event(
         &self,
         user_id: &UserId,
@@ -379,7 +378,7 @@ impl Service {
                 self.user_was_joined(shortstatehash, user_id)
             }
             other => {
-                error!(kind = %other, "Unknown history visibility");
+                t::error!(kind = %other, "Unknown history visibility");
                 false
             }
         };
@@ -398,7 +397,7 @@ impl Service {
 
     /// Whether a user is allowed to see an event, based on
     /// the room's history_visibility at that event's state.
-    #[tracing::instrument(skip(self, user_id, room_id))]
+    #[t::instrument(skip(self, user_id, room_id))]
     pub(crate) fn user_can_see_state_events(
         &self,
         user_id: &UserId,
@@ -430,7 +429,7 @@ impl Service {
     }
 
     /// Returns the state hash for this pdu.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn pdu_shortstatehash(
         &self,
         event_id: &EventId,
@@ -439,7 +438,7 @@ impl Service {
     }
 
     /// Returns the full room state.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn room_state_full(
         &self,
         room_id: &RoomId,
@@ -455,7 +454,7 @@ impl Service {
 
     /// Returns a single PDU from `room_id` with key (`event_type`,
     /// `state_key`).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_state_get_id(
         &self,
         room_id: &RoomId,
@@ -473,7 +472,7 @@ impl Service {
 
     /// Returns a single PDU from `room_id` with key (`event_type`,
     /// `state_key`).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_state_get(
         &self,
         room_id: &RoomId,
@@ -489,7 +488,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_name(&self, room_id: &RoomId) -> Result<Option<String>> {
         self.room_state_get(room_id, &StateEventType::RoomName, "")?.map_or(
             Ok(None),
@@ -497,7 +496,10 @@ impl Service {
                 serde_json::from_str(s.content.get())
                     .map(|c: RoomNameEventContent| Some(c.name))
                     .map_err(|error| {
-                        error!(%error, "Invalid room name event in database");
+                        error_err!(
+                            error,
+                            "Invalid room name event in database"
+                        );
                         Error::BadDatabase(
                             "Invalid room name event in database.",
                         )
@@ -506,7 +508,7 @@ impl Service {
         )
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_avatar(
         &self,
         room_id: &RoomId,
@@ -525,7 +527,7 @@ impl Service {
 
     // Allowed because this function uses `services()`
     #[allow(clippy::unused_self)]
-    #[tracing::instrument(skip(self), ret(level = "trace"))]
+    #[t::instrument(skip(self), ret(level = "trace"))]
     pub(crate) fn user_can_invite(
         &self,
         room_id: &KeyToken<OwnedRoomId, marker::State>,
@@ -551,7 +553,7 @@ impl Service {
             .is_ok()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_member(
         &self,
         room_id: &RoomId,
@@ -574,7 +576,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))]
+    #[t::instrument(skip(self))]
     pub(crate) fn user_can_redact(
         &self,
         redacts: &EventId,

src/service/rooms/state_cache.rs

@@ -12,10 +12,9 @@ use ruma::{
     serde::Raw,
     OwnedRoomId, OwnedServerName, OwnedUserId, RoomId, ServerName, UserId,
 };
-use tracing::warn;
 
 use crate::{
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     service::appservice::RegistrationInfo,
     services, Error, Result,
 };
@@ -46,7 +45,7 @@ impl Service {
     }
 
     /// Update current membership data.
-    #[tracing::instrument(skip(self, last_state))]
+    #[t::instrument(skip(self, last_state))]
     pub(crate) fn update_membership(
         &self,
         room_id: &RoomId,
@@ -76,7 +75,7 @@ impl Service {
                         .state
                         .get_create_content::<ExtractPredecessor>(room_id)
                         .inspect_err(|error| {
-                            warn!(%error, "Failed to get room predecessor");
+                            warn_err!(error, "Failed to get room predecessor");
                         })
                         .ok()
                         .flatten()
@@ -111,8 +110,8 @@ impl Service {
                             event.get(),
                         )
                         .map_err(|error| {
-                            warn!(
+                            warn_err!(
-                                %error,
+                                error,
                                 %event_kind,
                                 "Invalid account data event",
                             );
@@ -151,7 +150,7 @@ impl Service {
     /// joining an upgraded room.
     ///
     /// References to the predecessor room are not removed.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     fn copy_upgraded_account_data(
         &self,
         user_id: &UserId,
@@ -216,7 +215,10 @@ impl Service {
             RoomAccountDataEventType::Tag,
             &event,
         ) {
-            warn!(%error, "error writing m.tag account data to upgraded room");
+            warn_err!(
+                error,
+                "error writing m.tag account data to upgraded room"
+            );
         }
 
         Ok(())
@@ -291,13 +293,17 @@ impl Service {
                 event_kind.clone(),
                 &event,
             ) {
-                warn!(%event_kind, %error, "error writing account data event after upgrading room");
+                warn_err!(
+                    error,
+                    %event_kind,
+                    "error writing account data event after upgrading room"
+                );
             }
         }
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, room_id))]
+    #[t::instrument(skip(self, room_id))]
     pub(crate) fn update_joined_count(
         &self,
         room_id: &RoomId,
@@ -313,7 +319,7 @@ impl Service {
         Ok(our_real_users)
     }
 
-    #[tracing::instrument(skip(self, room_id))]
+    #[t::instrument(skip(self, room_id))]
     pub(crate) fn get_our_real_users(
         &self,
         room_id: &RoomId,
@@ -334,7 +340,7 @@ impl Service {
         Ok(our_real_users)
     }
 
-    #[tracing::instrument(skip(self, room_id, appservice))]
+    #[t::instrument(skip(self, room_id, appservice))]
     pub(crate) fn appservice_in_room(
         &self,
         room_id: &RoomId,
@@ -368,7 +374,7 @@ impl Service {
     }
 
     /// Makes a user forget a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn forget(
         &self,
         room_id: &RoomId,
@@ -378,7 +384,7 @@ impl Service {
     }
 
     /// Returns an iterator of all servers participating in this room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_servers<'a>(
         &'a self,
         room_id: &RoomId,
@@ -386,7 +392,7 @@ impl Service {
         self.db.room_servers(room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn server_in_room(
         &self,
         server: &ServerName,
@@ -397,7 +403,7 @@ impl Service {
 
     /// Returns an iterator of all rooms a server participates in (as far as we
     /// know).
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn server_rooms<'a>(
         &'a self,
         server: &ServerName,
@@ -406,7 +412,7 @@ impl Service {
     }
 
     /// Returns an iterator over all joined members of a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_members<'a>(
         &'a self,
         room_id: &RoomId,
@@ -414,7 +420,7 @@ impl Service {
         self.db.room_members(room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_joined_count(
         &self,
         room_id: &RoomId,
@@ -422,7 +428,7 @@ impl Service {
         self.db.room_joined_count(room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_invited_count(
         &self,
         room_id: &RoomId,
@@ -431,7 +437,7 @@ impl Service {
     }
 
     /// Returns an iterator over all invited members of a room.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn room_members_invited<'a>(
         &'a self,
         room_id: &RoomId,
@@ -439,7 +445,7 @@ impl Service {
         self.db.room_members_invited(room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_invite_count(
         &self,
         room_id: &RoomId,
@@ -448,7 +454,7 @@ impl Service {
         self.db.get_invite_count(room_id, user_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_left_count(
         &self,
         room_id: &RoomId,
@@ -458,7 +464,7 @@ impl Service {
     }
 
     /// Returns an iterator over all rooms this user joined.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn rooms_joined<'a>(
         &'a self,
         user_id: &UserId,
@@ -467,7 +473,7 @@ impl Service {
     }
 
     /// Returns an iterator over all rooms a user was invited to.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn rooms_invited<'a>(
         &'a self,
         user_id: &UserId,
@@ -477,7 +483,7 @@ impl Service {
         self.db.rooms_invited(user_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn invite_state(
         &self,
         user_id: &UserId,
@@ -486,7 +492,7 @@ impl Service {
         self.db.invite_state(user_id, room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn left_state(
         &self,
         user_id: &UserId,
@@ -496,7 +502,7 @@ impl Service {
     }
 
     /// Returns an iterator over all rooms a user left.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn rooms_left<'a>(
         &'a self,
         user_id: &UserId,
@@ -504,7 +510,7 @@ impl Service {
         self.db.rooms_left(user_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn once_joined(
         &self,
         user_id: &UserId,
@@ -513,7 +519,7 @@ impl Service {
         self.db.once_joined(user_id, room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn is_joined(
         &self,
         user_id: &UserId,
@@ -522,7 +528,7 @@ impl Service {
         self.db.is_joined(user_id, room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn is_invited(
         &self,
         user_id: &UserId,
@@ -531,7 +537,7 @@ impl Service {
         self.db.is_invited(user_id, room_id)
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn is_left(
         &self,
         user_id: &UserId,

src/service/rooms/state_compressor.rs

@@ -10,7 +10,7 @@ use ruma::{EventId, RoomId};
 
 use super::short::{ShortEventId, ShortStateHash, ShortStateKey};
 use crate::{
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     services, utils, Result,
 };
 
@@ -86,7 +86,7 @@ impl Service {
     /// Returns a stack with info on shortstatehash, full state, added diff and
     /// removed diff for the selected shortstatehash and each parent layer.
     #[allow(clippy::type_complexity)]
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn load_shortstatehash_info(
         &self,
         shortstatehash: ShortStateHash,
@@ -191,7 +191,7 @@ impl Service {
     /// * `parent_states` - A stack with info on shortstatehash, full state,
     ///   added diff and removed diff for each parent layer
     #[allow(clippy::type_complexity)]
-    #[tracing::instrument(skip(
+    #[t::instrument(skip(
         self,
         statediffnew,
         statediffremoved,
@@ -314,7 +314,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))]
+    #[t::instrument(skip(self, new_state_ids_compressed))]
     pub(crate) fn save_state(
         &self,
         room_id: &RoomId,

src/service/rooms/timeline.rs

@@ -26,12 +26,11 @@ use ruma::{
 use serde::Deserialize;
 use serde_json::value::{to_raw_value, RawValue as RawJsonValue};
 use tokio::sync::RwLock;
-use tracing::{error, info, warn};
 
 use super::{short::ShortRoomId, state_compressor::CompressedStateEvent};
 use crate::{
     api::server_server,
-    observability::{FoundIn, Lookup, METRICS},
+    observability::{prelude::*, FoundIn, Lookup, METRICS},
     service::{
         appservice::NamespaceRegex,
         globals::{marker, SigningKeys},
@@ -131,7 +130,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn first_pdu_in_room(
         &self,
         room_id: &RoomId,
@@ -142,7 +141,7 @@ impl Service {
             .transpose()
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn last_timeline_count(
         &self,
         sender_user: &UserId,
@@ -162,7 +161,7 @@ impl Service {
                     .find_map(|x| match x {
                         Ok(x) => Some(x),
                         Err(error) => {
-                            error!(%error, "Bad pdu in pdus_since");
+                            error_err!(error, "Bad pdu in pdus_since");
                             None
                         }
                     })
@@ -259,7 +258,7 @@ impl Service {
     }
 
     /// Removes a pdu and creates a new one with the same id.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn replace_pdu(
         &self,
         pdu_id: &PduId,
@@ -277,7 +276,7 @@ impl Service {
     /// happens in `append_pdu`.
     ///
     /// Returns pdu id
-    #[tracing::instrument(skip(self, pdu, pdu_json, leaves))]
+    #[t::instrument(skip(self, pdu, pdu_json, leaves))]
     pub(crate) async fn append_pdu(
         &self,
         pdu: &PduEvent,
@@ -331,7 +330,7 @@ impl Service {
                     }
                 }
             } else {
-                error!("Invalid unsigned type in pdu");
+                t::error!("Invalid unsigned type in pdu");
             }
         }
 
@@ -555,7 +554,7 @@ impl Service {
                         if user.server_name()
                             == services().globals.server_name()
                         {
-                            info!(
+                            t::info!(
                                 %user,
                                 %room,
                                 reason,
@@ -880,7 +879,7 @@ impl Service {
             |k, s| auth_events.get(&(k.clone(), s.to_owned())),
         )
         .map_err(|error| {
-            error!(%error, "Auth check failed");
+            error_err!(error, "Auth check failed");
             Error::BadDatabase("Auth check failed.")
         })?;
 
@@ -948,7 +947,7 @@ impl Service {
     /// Creates a new persisted data unit and adds it to a room. This function
     /// takes a roomid_mutex_state, meaning that only this function is able
     /// to mutate the room state.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) async fn build_and_append_pdu(
         &self,
         pdu_builder: PduBuilder,
@@ -962,7 +961,9 @@ impl Service {
             if admin_room == **room_id {
                 match pdu.event_type() {
                     TimelineEventType::RoomEncryption => {
-                        warn!("Encryption is not allowed in the admins room");
+                        t::warn!(
+                            "Encryption is not allowed in the admins room"
+                        );
                         return Err(Error::BadRequest(
                             ErrorKind::forbidden(),
                             "Encryption is not allowed in the admins room.",
@@ -997,7 +998,7 @@ impl Service {
 
                         if content.membership == MembershipState::Leave {
                             if target == server_user {
-                                warn!(
+                                t::warn!(
                                     "Grapevine user cannot leave from admins \
                                      room"
                                 );
@@ -1017,7 +1018,7 @@ impl Service {
                                 .filter(|m| m != target)
                                 .count();
                             if count < 2 {
-                                warn!(
+                                t::warn!(
                                     "Last admin cannot leave from admins room"
                                 );
                                 return Err(Error::BadRequest(
@@ -1031,7 +1032,7 @@ impl Service {
                             && pdu.state_key().is_some()
                         {
                             if target == server_user {
-                                warn!(
+                                t::warn!(
                                     "Grapevine user cannot be banned in \
                                      admins room"
                                 );
@@ -1051,7 +1052,7 @@ impl Service {
                                 .filter(|m| m != target)
                                 .count();
                             if count < 2 {
-                                warn!(
+                                t::warn!(
                                     "Last admin cannot be banned in admins \
                                      room"
                                 );
@@ -1164,7 +1165,7 @@ impl Service {
 
     /// Append the incoming event setting the state snapshot to the state from
     /// the server that sent the event.
-    #[tracing::instrument(skip_all)]
+    #[t::instrument(skip_all)]
     pub(crate) async fn append_incoming_pdu(
         &self,
         pdu: &PduEvent,
@@ -1215,7 +1216,7 @@ impl Service {
     /// Returns an iterator over all events and their tokens in a room that
     /// happened before the event with id `until` in reverse-chronological
     /// order.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn pdus_until<'a>(
         &'a self,
         user_id: &UserId,
@@ -1227,7 +1228,7 @@ impl Service {
 
     /// Returns an iterator over all events and their token in a room that
     /// happened after the event with id `from` in chronological order.
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn pdus_after<'a>(
         &'a self,
         user_id: &UserId,
@@ -1238,7 +1239,7 @@ impl Service {
     }
 
     /// Replace a PDU with the redacted form.
-    #[tracing::instrument(skip(self, reason))]
+    #[t::instrument(skip(self, reason))]
     pub(crate) fn redact_pdu(
         &self,
         event_id: &EventId,
@@ -1282,7 +1283,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, room_id))]
+    #[t::instrument(skip(self, room_id))]
     pub(crate) async fn backfill_if_required(
         &self,
         room_id: &RoomId,
@@ -1319,7 +1320,7 @@ impl Service {
 
         // Request backfill
         for backfill_server in admin_servers {
-            info!(server = %backfill_server, "Asking server for backfill");
+            t::info!(server = %backfill_server, "Asking server for backfill");
             let response = services()
                 .sending
                 .send_federation_request(
@@ -1339,26 +1340,26 @@ impl Service {
                             .backfill_pdu(backfill_server, pdu, &pub_key_map)
                             .await
                         {
-                            warn!(%error, "Failed to add backfilled pdu");
+                            warn_err!(error, "Failed to add backfilled pdu");
                         }
                     }
                     return Ok(());
                 }
                 Err(error) => {
-                    warn!(
+                    warn_err!(
+                        error,
                         server = %backfill_server,
-                        %error,
                         "Server could not provide backfill",
                     );
                 }
             }
         }
 
-        info!("No servers could backfill");
+        t::info!("No servers could backfill");
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, pdu))]
+    #[t::instrument(skip(self, pdu))]
     pub(crate) async fn backfill_pdu(
         &self,
         origin: &ServerName,
@@ -1377,7 +1378,7 @@ impl Service {
 
         // Skip the PDU if we already have it as a timeline event
         if let Some(pdu_id) = self.get_pdu_id(&event_id)? {
-            info!(%event_id, ?pdu_id, "We already know this event");
+            t::info!(%event_id, ?pdu_id, "We already know this event");
             return Ok(());
         }
 
@@ -1442,7 +1443,7 @@ impl Service {
         }
         drop(federation_token);
 
-        info!("Prepended backfill pdu");
+        t::info!("Prepended backfill pdu");
         Ok(())
     }
 }

src/service/sending.rs

@@ -34,7 +34,7 @@ use tokio::{
     select,
     sync::{mpsc, Mutex, Semaphore},
 };
-use tracing::{debug, error, warn, Span};
+use tracing::Span;
 
 use super::rooms::timeline::PduId;
 use crate::{
@@ -42,6 +42,7 @@ use crate::{
         appservice_server,
         server_server::{self, AllowLoopbackRequests, LogRequestError},
     },
+    observability::prelude::*,
     services,
     utils::{calculate_hash, debug_slice_truncated},
     Config, Error, PduEvent, Result,
@@ -60,7 +61,7 @@ pub(crate) enum Destination {
 }
 
 impl Destination {
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn get_prefix(&self) -> Vec<u8> {
         let mut prefix = match self {
             Destination::Appservice(server) => {
@@ -196,7 +197,7 @@ impl Service {
                 initial_transactions.entry(destination.clone()).or_default();
 
             if entry.len() > 30 {
-                warn!(
+                t::warn!(
                     ?key,
                     ?destination,
                     ?event,
@@ -240,7 +241,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, result, handler_span, current_transaction_status),
         fields(
             current_status = ?current_transaction_status.get(
@@ -266,7 +267,7 @@ impl Service {
         }
 
         if let Err(error) = result {
-            warn!(%error, "Marking transaction as failed");
+            warn_err!(error, "Marking transaction as failed");
             current_transaction_status.entry(destination).and_modify(|e| {
                 use TransactionStatus::{Failed, Retrying, Running};
 
@@ -274,7 +275,7 @@ impl Service {
                     Running => Failed(1, Instant::now()),
                     Retrying(n) => Failed(*n + 1, Instant::now()),
                     Failed(..) => {
-                        error!("Request that was not even running failed?!");
+                        t::error!("Request that was not even running failed?!");
                         return;
                     }
                 }
@@ -308,7 +309,7 @@ impl Service {
         }))
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, event_type, key, requester_span, current_transaction_status),
         fields(
             current_status = ?current_transaction_status.get(&destination),
@@ -333,7 +334,7 @@ impl Service {
             current_transaction_status,
         ) {
             Ok(SelectedEvents::Retries(events)) => {
-                debug!("Retrying old events");
+                t::debug!("Retrying old events");
                 Some(HandlerInputs {
                     destination,
                     events,
@@ -341,7 +342,7 @@ impl Service {
                 })
             }
             Ok(SelectedEvents::New(events)) => {
-                debug!("Sending new event");
+                t::debug!("Sending new event");
                 Some(HandlerInputs {
                     destination,
                     events,
@@ -349,17 +350,17 @@ impl Service {
                 })
             }
             Ok(SelectedEvents::None) => {
-                debug!("Holding off from sending any events");
+                t::debug!("Holding off from sending any events");
                 None
             }
             Err(error) => {
-                error!(%error, "Failed to select events to send");
+                error_err!(error, "Failed to select events to send");
                 None
             }
         }
     }
 
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, new_events, current_transaction_status),
         fields(
             new_events = debug_slice_truncated(&new_events, 3),
@@ -446,7 +447,7 @@ impl Service {
         }
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn select_edus(
         &self,
         server_name: &ServerName,
@@ -567,7 +568,7 @@ impl Service {
         Ok((events, max_edu_count))
     }
 
-    #[tracing::instrument(skip(self, pdu_id, user, pushkey))]
+    #[t::instrument(skip(self, pdu_id, user, pushkey))]
     pub(crate) fn send_push_pdu(
         &self,
         pdu_id: &PduId,
@@ -590,7 +591,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, servers, pdu_id))]
+    #[t::instrument(skip(self, servers, pdu_id))]
     pub(crate) fn send_pdu<I: Iterator<Item = OwnedServerName>>(
         &self,
         servers: I,
@@ -622,7 +623,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, server, serialized))]
+    #[t::instrument(skip(self, server, serialized))]
     pub(crate) fn send_reliable_edu(
         &self,
         server: &ServerName,
@@ -645,7 +646,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self))]
+    #[t::instrument(skip(self))]
     pub(crate) fn send_pdu_appservice(
         &self,
         appservice_id: String,
@@ -667,7 +668,7 @@ impl Service {
         Ok(())
     }
 
-    #[tracing::instrument(skip(self, request))]
+    #[t::instrument(skip(self, request))]
     pub(crate) async fn send_federation_request<T>(
         &self,
         destination: &ServerName,
@@ -676,9 +677,9 @@ impl Service {
     where
         T: OutgoingRequest + Debug,
     {
-        debug!("Waiting for permit");
+        t::debug!("Waiting for permit");
         let permit = self.maximum_requests.acquire().await;
-        debug!("Got permit");
+        t::debug!("Got permit");
         let response = tokio::time::timeout(
             Duration::from_secs(2 * 60),
             server_server::send_request(
@@ -690,7 +691,7 @@ impl Service {
         )
         .await
         .map_err(|_| {
-            warn!("Timeout waiting for server response");
+            t::warn!("Timeout waiting for server response");
             Error::BadServerResponse("Timeout waiting for server response")
         })?;
         drop(permit);
@@ -702,7 +703,7 @@ impl Service {
     ///
     /// Only returns None if there is no url specified in the appservice
     /// registration file
-    #[tracing::instrument(
+    #[t::instrument(
         skip(self, registration, request),
         fields(appservice_id = registration.id),
     )]
@@ -723,7 +724,7 @@ impl Service {
     }
 }
 
-#[tracing::instrument(skip(events))]
+#[t::instrument(skip(events))]
 async fn handle_appservice_event(
     id: &str,
     events: Vec<SendingEventType>,
@@ -778,7 +779,7 @@ async fn handle_appservice_event(
     Ok(())
 }
 
-#[tracing::instrument(skip(events))]
+#[t::instrument(skip(events))]
 async fn handle_push_event(
     userid: &UserId,
     pushkey: &str,
@@ -861,7 +862,7 @@ async fn handle_push_event(
     Ok(())
 }
 
-#[tracing::instrument(skip(events))]
+#[t::instrument(skip(events))]
 async fn handle_federation_event(
     server: &ServerName,
     events: Vec<SendingEventType>,
@@ -880,7 +881,7 @@ async fn handle_federation_event(
                         .timeline
                         .get_pdu_json_from_id(pdu_id)?
                         .ok_or_else(|| {
-                            error!(pdu_id = ?pdu_id, "PDU not found");
+                            t::error!(pdu_id = ?pdu_id, "PDU not found");
                             Error::bad_database(
                                 "[Normal] Event in servernamevent_datas not \
                                  found in db.",
@@ -917,7 +918,12 @@ async fn handle_federation_event(
 
     for pdu in response.pdus {
         if let (event_id, Err(error)) = pdu {
-            warn!(%server, %event_id, %error, "Failed to send event to server");
+            t::warn!(
+                %server,
+                %event_id,
+                %error,
+                "Failed to send event to server"
+            );
         }
     }
 
@@ -926,7 +932,7 @@ async fn handle_federation_event(
     Ok(())
 }
 
-#[tracing::instrument(skip_all)]
+#[t::instrument(skip_all)]
 async fn handle_events(
     HandlerInputs {
         destination,

src/service/uiaa.rs

@@ -7,10 +7,10 @@ use ruma::{
     },
     CanonicalJsonValue, DeviceId, OwnedDeviceId, OwnedUserId, UserId,
 };
-use tracing::error;
 
 use crate::{
-    api::client_server::SESSION_ID_LENGTH, services, utils, Error, Result,
+    api::client_server::SESSION_ID_LENGTH, observability::prelude::*, services,
+    utils, Error, Result,
 };
 
 mod data;
@@ -137,7 +137,7 @@ impl Service {
             AuthData::Dummy(_) => {
                 uiaainfo.completed.push(AuthType::Dummy);
             }
-            kind => error!(?kind, "Auth kind not supported"),
+            kind => t::error!(?kind, "Auth kind not supported"),
         }
 
         // Check if a flow now succeeds

src/utils.rs

@@ -15,7 +15,7 @@ use ruma::{
     CanonicalJsonError, CanonicalJsonObject, MxcUri, MxcUriError, OwnedMxcUri,
 };
 
-use crate::{Error, Result};
+use crate::{observability::prelude::*, Error, Result};
 
 pub(crate) mod error;
 pub(crate) mod on_demand_hashmap;
@@ -108,7 +108,7 @@ where
     Argon2::default().verify_password(password.as_ref(), &hash).is_ok()
 }
 
-#[tracing::instrument(skip(keys))]
+#[t::instrument(skip(keys))]
 pub(crate) fn calculate_hash<'a, I, T>(keys: I) -> Vec<u8>
 where
     I: IntoIterator<Item = T>,
@@ -234,8 +234,8 @@ impl<T: fmt::Debug> fmt::Debug for TruncatedDebugSlice<'_, T> {
 pub(crate) fn debug_slice_truncated<T: fmt::Debug>(
     slice: &[T],
     max_len: usize,
-) -> tracing::field::DebugValue<TruncatedDebugSlice<'_, T>> {
+) -> t::field::DebugValue<TruncatedDebugSlice<'_, T>> {
-    tracing::field::debug(TruncatedDebugSlice {
+    t::field::debug(TruncatedDebugSlice {
         inner: slice,
         max_len,
     })

src/utils/error.rs

@@ -9,9 +9,9 @@ use ruma::{
     OwnedServerName,
 };
 use thiserror::Error;
-use tracing::{error, warn};
+use wee_woo::ErrorExt;
 
-use crate::Ra;
+use crate::{observability::prelude::*, Ra};
 
 pub(crate) type Result<T, E = Error> = std::result::Result<T, E>;
 
@@ -19,81 +19,71 @@ pub(crate) type Result<T, E = Error> = std::result::Result<T, E>;
 #[allow(clippy::error_impl_error)]
 pub(crate) enum Error {
     #[cfg(feature = "sqlite")]
-    #[error(
+    #[error("error connecting to sqlite database")]
-        "There was a problem with the connection to the sqlite database: \
-         {source}"
-    )]
     Sqlite {
         #[from]
         source: rusqlite::Error,
     },
     #[cfg(feature = "rocksdb")]
-    #[error(
+    #[error("error connecting to rocksdb database")]
-        "There was a problem with the connection to the rocksdb database: \
-         {source}"
-    )]
     RocksDb {
         #[from]
         source: rocksdb::Error,
     },
-    #[error("Could not generate an image.")]
+    #[error("error generating image thumbnail")]
-    Image {
+    GenerateThumbnail(#[source] image::error::ImageError),
-        #[from]
+    #[error("error making request to server")]
-        source: image::error::ImageError,
-    },
-    #[error("Could not connect to server: {source}")]
     Reqwest {
         #[from]
         source: reqwest::Error,
     },
-    #[error("Could build regular expression: {source}")]
+    #[error("error building regular expression")]
     Regex {
         #[from]
         source: regex::Error,
     },
-    #[error("{0}")]
+    #[error("federation request to {0} returned an error")]
-    Federation(OwnedServerName, RumaError),
+    Federation(OwnedServerName, #[source] RumaError),
-    #[error("Could not do this io: {source}")]
+    #[error("IO error")]
     Io {
         #[from]
         source: std::io::Error,
     },
-    #[error("{0}")]
+    #[error("invalid server response: {0}")]
     BadServerResponse(&'static str),
-    #[error("{0}")]
+    #[error("config error: {0}")]
     BadConfig(&'static str),
-    #[error("{0}")]
+    #[error("invalid data in database: {0}")]
     /// Don't create this directly. Use [`Error::bad_database`] instead.
     BadDatabase(&'static str),
-    #[error("uiaa")]
+    #[error("UIAA error")]
     Uiaa(UiaaInfo),
-    #[error("{0}: {1}")]
+    #[error("invalid request ({0}): {1}")]
     BadRequest(ErrorKind, &'static str),
-    // This is only needed for when a room alias already exists
+    #[error("alias already exists")]
-    #[error("{0}")]
+    AliasConflict,
-    Conflict(&'static str),
     #[error("{0}")]
     Extension(#[from] axum::extract::rejection::ExtensionRejection),
     #[error("{0}")]
     Path(#[from] axum::extract::rejection::PathRejection),
     #[error("{0}")]
     AdminCommand(&'static str),
-    #[error("from {0}: {1}")]
+    #[error("error redacting event from {0}: {1}")]
     Redaction(OwnedServerName, ruma::canonical_json::RedactionError),
     #[error("unsupported room version {0}")]
     UnsupportedRoomVersion(ruma::RoomVersionId),
-    #[error("{0} in {1}")]
+    #[error("inconsistent room state in {1}: {0}")]
     InconsistentRoomState(&'static str, ruma::OwnedRoomId),
 }
 
 impl Error {
     pub(crate) fn bad_database(message: &'static str) -> Self {
-        error!(message, "Bad database");
+        t::error!(message, "Bad database");
         Self::BadDatabase(message)
     }
 
     pub(crate) fn bad_config(message: &'static str) -> Self {
-        error!(message, "Bad config");
+        t::error!(message, "Bad config");
         Self::BadConfig(message)
     }
 
@@ -109,16 +99,7 @@ impl Error {
             return Ra(UiaaResponse::AuthResponse(uiaainfo.clone()));
         }
 
-        if let Self::Federation(origin, error) = self {
+        let message = format!("{}", self.display_with_sources(" -> "));
-            let mut error = error.clone();
-            error.body = ErrorBody::Standard {
-                kind: Unknown,
-                message: format!("Answer from {origin}: {error}"),
-            };
-            return Ra(UiaaResponse::MatrixError(error));
-        }
-
-        let message = format!("{self}");
 
         let (kind, status_code) = match self {
             Self::BadRequest(kind, _) => (
@@ -148,15 +129,20 @@ impl Error {
                     _ => StatusCode::BAD_REQUEST,
                 },
             ),
+            // Propagate the status code and error code from the remote response
+            Self::Federation(_, error) => (
+                error.error_kind().cloned().unwrap_or(Unknown),
+                error.status_code,
+            ),
             Self::UnsupportedRoomVersion(_) => (
                 ErrorKind::UnsupportedRoomVersion,
                 StatusCode::INTERNAL_SERVER_ERROR,
             ),
-            Self::Conflict(_) => (Unknown, StatusCode::CONFLICT),
+            Self::AliasConflict => (Unknown, StatusCode::CONFLICT),
             _ => (Unknown, StatusCode::INTERNAL_SERVER_ERROR),
         };
 
-        warn!(%status_code, error = %message, "Responding with an error");
+        t::warn!(%status_code, error = %message, "Responding with an error");
 
         Ra(UiaaResponse::MatrixError(RumaError {
             body: ErrorBody::Standard {

src/utils/on_demand_hashmap.rs

@@ -8,9 +8,8 @@ use std::{
 };
 
 use tokio::sync::{mpsc, Mutex, OwnedMutexGuard, RwLock};
-use tracing::{trace, warn, Level};
 
-use crate::observability::METRICS;
+use crate::observability::{prelude::*, METRICS};
 
 /// Data shared between [`OnDemandHashMap`] and the cleanup task
 ///
@@ -28,8 +27,8 @@ impl<K, V> SharedData<K, V>
 where
     K: Hash + Eq + Clone + fmt::Debug,
 {
-    #[tracing::instrument(
+    #[t::instrument(
-        level = Level::TRACE,
+        level = t::Level::TRACE,
         skip(self),
         fields(name = self.name.as_ref()),
     )]
@@ -37,21 +36,21 @@ where
         let mut map = self.entries.write().await;
 
         let Some(weak) = map.get(&key) else {
-            trace!("Entry has already been cleaned up");
+            t::trace!("Entry has already been cleaned up");
             return;
         };
 
         if weak.strong_count() != 0 {
-            trace!("Entry is in use");
+            t::trace!("Entry is in use");
             return;
         }
 
-        trace!("Cleaning up unused entry");
+        t::trace!("Cleaning up unused entry");
         map.remove(&key);
         METRICS.record_on_demand_hashmap_size(self.name.clone(), map.len());
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip(map))]
+    #[t::instrument(level = t::Level::TRACE, skip(map))]
     fn try_get_live_value(
         pass: usize,
         map: &HashMap<K, Weak<V>>,
@@ -59,16 +58,16 @@ where
     ) -> Option<Arc<V>> {
         if let Some(value) = map.get(key) {
             if let Some(value) = value.upgrade() {
-                trace!(pass, "Using existing value");
+                t::trace!(pass, "Using existing value");
                 return Some(value);
             }
 
-            trace!(
+            t::trace!(
                 pass,
                 "Existing value is stale and needs cleanup, creating new"
             );
         } else {
-            trace!(pass, "No existing value, creating new");
+            t::trace!(pass, "No existing value, creating new");
         }
 
         None
@@ -76,7 +75,7 @@ where
 
     /// Either returns an existing live value, or creates a new one and inserts
     /// it into the map.
-    #[tracing::instrument(level = Level::TRACE, skip(self, create))]
+    #[t::instrument(level = t::Level::TRACE, skip(self, create))]
     async fn get_or_insert_with<F>(&self, key: &K, create: F) -> Arc<V>
     where
         F: FnOnce() -> V,
@@ -145,7 +144,7 @@ where
             tokio::task::spawn(async move {
                 loop {
                     let Some(key) = receiver.recv().await else {
-                        trace!(
+                        t::trace!(
                             name = shared.name.as_ref(),
                             "Channel has died, exiting cleanup task"
                         );
@@ -163,7 +162,7 @@ where
         }
     }
 
-    #[tracing::instrument(level = Level::TRACE, skip(self, create))]
+    #[t::instrument(level = t::Level::TRACE, skip(self, create))]
     pub(crate) async fn get_or_insert_with<F>(
         &self,
         key: K,
@@ -193,14 +192,14 @@ struct EntryDropGuard<K> {
 impl<K> Drop for EntryDropGuard<K> {
     fn drop(&mut self) {
         let Some(cleanup_sender) = self.cleanup_sender.upgrade() else {
-            trace!("Backing map has already been dropped");
+            t::trace!("Backing map has already been dropped");
             return;
         };
 
         if let Err(error) = cleanup_sender
             .send(self.key.take().expect("drop should only be called once"))
         {
-            warn!(%error, "Failed to send cleanup message");
+            warn_err!(error, "Failed to send cleanup message");
         };
     }
 }
@@ -252,7 +251,7 @@ where
 
     /// Locks this key in the `TokenSet`, returning a token proving
     /// unique access.
-    #[tracing::instrument(level = Level::TRACE, skip(self))]
+    #[t::instrument(level = t::Level::TRACE, skip(self))]
     pub(crate) async fn lock_key(&self, key: K) -> KeyToken<K, M> {
         let Entry {
             drop_guard,

src/utils/proxy_protocol.rs

@@ -11,7 +11,8 @@ use tokio::{
     time::{timeout, Timeout},
 };
 use tower::Layer;
-use tracing::warn;
+
+use crate::observability::prelude::*;
 
 #[derive(Debug, Clone)]
 pub(crate) struct ProxyAcceptorConfig {
@@ -138,13 +139,16 @@ where
 
                     let stream = ret
                         .map_err(|e| {
-                            warn!(
+                            t::warn!(
                                 "Timed out waiting for HAProxy protocol header"
                             );
                             std::io::Error::new(ErrorKind::TimedOut, e)
                         })?
                         .inspect_err(|error| {
-                            warn!(%error, "Failed to parse HAProxy protocol header");
+                            warn_err!(
+                                error,
+                                "Failed to parse HAProxy protocol header"
+                            );
                         })?;
 
                     let service =