misc tracing span tweaks

Signed-off-by: Jason Volk <jason@zemos.net>

src/api/client/media.rs

@@ -39,7 +39,12 @@ pub(crate) async fn get_media_config_route(
 ///
 /// - Some metadata will be saved in the database
 /// - Media will be saved in the media/ directory
-#[tracing::instrument(skip_all, fields(%client), name = "media_upload")]
+#[tracing::instrument(
+	name = "media_upload",
+	level = "debug",
+	skip_all,
+	fields(%client),
+)]
 pub(crate) async fn create_content_route(
 	State(services): State<crate::State>, InsecureClientIp(client): InsecureClientIp,
 	body: Ruma<create_content::v3::Request>,
@@ -67,7 +72,12 @@ pub(crate) async fn create_content_route(
 /// # `GET /_matrix/client/v1/media/thumbnail/{serverName}/{mediaId}`
 ///
 /// Load media thumbnail from our server or over federation.
-#[tracing::instrument(skip_all, fields(%client), name = "media_thumbnail_get")]
+#[tracing::instrument(
+	name = "media_thumbnail_get",
+	level = "debug",
+	skip_all,
+	fields(%client),
+)]
 pub(crate) async fn get_content_thumbnail_route(
 	State(services): State<crate::State>, InsecureClientIp(client): InsecureClientIp,
 	body: Ruma<get_content_thumbnail::v1::Request>,
@@ -98,7 +108,12 @@ pub(crate) async fn get_content_thumbnail_route(
 /// # `GET /_matrix/client/v1/media/download/{serverName}/{mediaId}`
 ///
 /// Load media from our server or over federation.
-#[tracing::instrument(skip_all, fields(%client), name = "media_get")]
+#[tracing::instrument(
+	name = "media_get",
+	level = "debug",
+	skip_all,
+	fields(%client),
+)]
 pub(crate) async fn get_content_route(
 	State(services): State<crate::State>, InsecureClientIp(client): InsecureClientIp,
 	body: Ruma<get_content::v1::Request>,
@@ -128,7 +143,12 @@ pub(crate) async fn get_content_route(
 /// # `GET /_matrix/client/v1/media/download/{serverName}/{mediaId}/{fileName}`
 ///
 /// Load media from our server or over federation as fileName.
-#[tracing::instrument(skip_all, fields(%client), name = "media_get_af")]
+#[tracing::instrument(
+	name = "media_get_af",
+	level = "debug",
+	skip_all,
+	fields(%client),
+)]
 pub(crate) async fn get_content_as_filename_route(
 	State(services): State<crate::State>, InsecureClientIp(client): InsecureClientIp,
 	body: Ruma<get_content_as_filename::v1::Request>,
@@ -158,7 +178,12 @@ pub(crate) async fn get_content_as_filename_route(
 /// # `GET /_matrix/client/v1/media/preview_url`
 ///
 /// Returns URL preview.
-#[tracing::instrument(skip_all, fields(%client), name = "url_preview")]
+#[tracing::instrument(
+	name = "url_preview",
+	level = "debug",
+	skip_all,
+	fields(%client),
+)]
 pub(crate) async fn get_media_preview_route(
 	State(services): State<crate::State>, InsecureClientIp(client): InsecureClientIp,
 	body: Ruma<get_media_preview::v1::Request>,

src/api/client/sync/v3.rs

@@ -97,6 +97,14 @@ type PresenceUpdates = HashMap<OwnedUserId, PresenceEvent>;
 /// For left rooms:
 /// - If the user left after `since`: `prev_batch` token, empty state (TODO:
 ///   subset of the state at the point of the leave)
+#[tracing::instrument(
+	name = "sync",
+	level = "debug",
+	skip_all,
+	fields(
+		since = %body.body.since.as_deref().unwrap_or_default(),
+    )
+)]
 pub(crate) async fn sync_events_route(
 	State(services): State<crate::State>, body: Ruma<sync_events::v3::Request>,
 ) -> Result<sync_events::v3::Response, RumaResponse<UiaaResponse>> {
@@ -391,8 +399,17 @@ async fn process_presence_updates(services: &Services, since: u64, syncing_user:
 		.await
 }
 
+#[tracing::instrument(
+	name = "left",
+	level = "debug",
+	skip_all,
+	fields(
+		room_id = %room_id,
+		full = %full_state,
+		ll = %lazy_load_enabled,
+	),
+)]
 #[allow(clippy::too_many_arguments)]
-#[tracing::instrument(skip_all, fields(user_id = %sender_user, room_id = %room_id), name = "left_room")]
 async fn handle_left_room(
 	services: &Services, since: u64, room_id: OwnedRoomId, sender_user: &UserId, next_batch_string: &str,
 	full_state: bool, lazy_load_enabled: bool,

src/database/engine.rs

@@ -307,7 +307,12 @@ pub(crate) fn repair(db_opts: &Options, path: &PathBuf) -> Result<()> {
 	Ok(())
 }
 
-#[tracing::instrument(skip(msg), name = "rocksdb", level = "trace")]
+#[tracing::instrument(
+	parent = None,
+	name = "rocksdb",
+	level = "trace"
+	skip(msg),
+)]
 pub(crate) fn handle_log(level: LogLevel, msg: &str) {
 	let msg = msg.trim();
 	if msg.starts_with("Options") {

src/database/map/get_batch.rs

@@ -33,7 +33,7 @@ where
 }
 
 #[implement(super::Map)]
-#[tracing::instrument(skip(self, keys), name = "batch_blocking", level = "trace")]
+#[tracing::instrument(name = "batch_blocking", level = "trace", skip_all)]
 pub(crate) fn get_batch_blocking<'a, I, K>(&self, keys: I) -> impl Iterator<Item = Result<Handle<'_>>> + Send
 where
 	I: Iterator<Item = &'a K> + ExactSizeIterator + Debug + Send,

src/database/maps.rs

@@ -10,7 +10,7 @@ pub(crate) type MapsKey = String;
 
 pub(crate) fn open(db: &Arc<Engine>) -> Result<Maps> { open_list(db, MAPS) }
 
-#[tracing::instrument(skip_all, level = "debug")]
+#[tracing::instrument(name = "maps", level = "debug", skip_all)]
 pub(crate) fn open_list(db: &Arc<Engine>, maps: &[&str]) -> Result<Maps> {
 	Ok(maps
 		.iter()

src/database/pool.rs

@@ -113,10 +113,14 @@ async fn spawn_until(self: &Arc<Self>, recv: Receiver<Cmd>, max: usize) -> Resul
 }
 
 #[implement(Pool)]
+#[tracing::instrument(
+	name = "spawn",
+	level = "trace",
+	skip_all,
+	fields(id = %workers.len())
+)]
 fn spawn_one(self: &Arc<Self>, workers: &mut JoinSet<()>, recv: Receiver<Cmd>) -> Result {
 	let id = workers.len();
-
-	debug!(?id, "spawning");
 	let self_ = self.clone();
 	let _abort = workers.spawn_blocking_on(move || self_.worker(id, recv), self.server.runtime());
 
@@ -181,7 +185,14 @@ async fn execute(&self, cmd: Cmd) -> Result {
 }
 
 #[implement(Pool)]
-#[tracing::instrument(skip(self, recv))]
+#[tracing::instrument(
+	parent = None,
+	level = "debug",
+	skip(self, recv),
+	fields(
+		tid = ?std::thread::current().id(),
+	),
+)]
 fn worker(self: Arc<Self>, id: usize, recv: Receiver<Cmd>) {
 	debug!("worker spawned");
 	defer! {{ debug!("worker finished"); }}

src/main/main.rs

@@ -59,6 +59,11 @@ fn main() -> Result<(), Error> {
 /// Operate the server normally in release-mode static builds. This will start,
 /// run and stop the server within the asynchronous runtime.
 #[cfg(not(conduit_mods))]
+#[tracing::instrument(
+	name = "main",
+	parent = None,
+	skip_all
+)]
 async fn async_main(server: &Arc<Server>) -> Result<(), Error> {
 	extern crate conduit_router as router;
 

src/router/layers.rs

@@ -150,8 +150,8 @@ fn cors_layer(_server: &Server) -> CorsLayer {
 
 fn body_limit_layer(server: &Server) -> DefaultBodyLimit { DefaultBodyLimit::max(server.config.max_request_size) }
 
+#[tracing::instrument(name = "panic", level = "error", skip_all)]
 #[allow(clippy::needless_pass_by_value)]
-#[tracing::instrument(skip_all, name = "panic")]
 fn catch_panic(err: Box<dyn Any + Send + 'static>) -> http::Response<http_body_util::Full<bytes::Bytes>> {
 	//TODO: XXX
 	/*
@@ -197,7 +197,7 @@ fn tracing_span<T>(request: &http::Request<T>) -> tracing::Span {
 
 	let method = request.method();
 
-	tracing::info_span!("router:", %method, %path)
+	tracing::debug_span!(parent: None, "router", %method, %path)
 }
 
 fn truncated_matched_path(path: &MatchedPath) -> &str {

src/router/request.rs

@@ -8,7 +8,11 @@ use conduit::{debug, debug_error, debug_warn, defer, err, error, trace, Result};
 use conduit_service::Services;
 use http::{Method, StatusCode, Uri};
 
-#[tracing::instrument(skip_all, level = "debug")]
+#[tracing::instrument(
+	parent = None,
+	level = "trace",
+	skip_all,
+)]
 pub(crate) async fn spawn(
 	State(services): State<Arc<Services>>, req: http::Request<axum::body::Body>, next: axum::middleware::Next,
 ) -> Result<Response, StatusCode> {
@@ -34,7 +38,7 @@ pub(crate) async fn spawn(
 	task.await.map_err(|_| StatusCode::INTERNAL_SERVER_ERROR)
 }
 
-#[tracing::instrument(skip_all, name = "handle")]
+#[tracing::instrument(level = "debug", skip_all)]
 pub(crate) async fn handle(
 	State(services): State<Arc<Services>>, req: http::Request<axum::body::Body>, next: axum::middleware::Next,
 ) -> Result<Response, StatusCode> {

src/router/serve/unix.rs

@@ -30,7 +30,7 @@ type MakeService = IntoMakeServiceWithConnectInfo<Router, net::SocketAddr>;
 const NULL_ADDR: net::SocketAddr = net::SocketAddr::new(IpAddr::V4(Ipv4Addr::new(0, 0, 0, 0)), 0);
 const FINI_POLL_INTERVAL: Duration = Duration::from_millis(750);
 
-#[tracing::instrument(skip_all)]
+#[tracing::instrument(skip_all, level = "debug")]
 pub(super) async fn serve(server: &Arc<Server>, app: Router, mut shutdown: broadcast::Receiver<()>) -> Result<()> {
 	let mut tasks = JoinSet::<()>::new();
 	let executor = TokioExecutor::new();

src/service/manager.rs

@@ -155,6 +155,12 @@ impl Manager {
 /// should never error with a panic, and if so it should propagate, but it may
 /// error with an Abort which the manager should handle along with results to
 /// determine if the worker should be restarted.
+#[tracing::instrument(
+	parent = None,
+	level = "trace",
+	skip_all,
+	fields(service = %service.name()),
+)]
 async fn worker(service: Arc<dyn Service>) -> WorkerResult {
 	let service_ = Arc::clone(&service);
 	let result = AssertUnwindSafe(service_.worker())

src/service/resolver/actual.rs

@@ -26,7 +26,7 @@ impl ActualDest {
 }
 
 impl super::Service {
-	#[tracing::instrument(skip_all, name = "resolve")]
+	#[tracing::instrument(skip_all, level = "debug", name = "resolve")]
 	pub(crate) async fn get_actual_dest(&self, server_name: &ServerName) -> Result<ActualDest> {
 		let (result, cached) = if let Some(result) = self.get_cached_destination(server_name) {
 			(result, true)

src/service/rooms/state_accessor/mod.rs

@@ -184,7 +184,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, origin, room_id, event_id))]
+	#[tracing::instrument(skip_all, level = "trace")]
 	pub async fn server_can_see_event(&self, origin: &ServerName, room_id: &RoomId, event_id: &EventId) -> bool {
 		let Ok(shortstatehash) = self.pdu_shortstatehash(event_id).await else {
 			return true;
@@ -242,7 +242,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, event_id))]
+	#[tracing::instrument(skip_all, level = "trace")]
 	pub async fn user_can_see_event(&self, user_id: &UserId, room_id: &RoomId, event_id: &EventId) -> bool {
 		let Ok(shortstatehash) = self.pdu_shortstatehash(event_id).await else {
 			return true;
@@ -293,7 +293,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))]
+	#[tracing::instrument(skip_all, level = "trace")]
 	pub async fn user_can_see_state_events(&self, user_id: &UserId, room_id: &RoomId) -> bool {
 		if self.services.state_cache.is_joined(user_id, room_id).await {
 			return true;

src/service/sending/data.rs

@@ -176,7 +176,6 @@ impl Data {
 	}
 }
 
-#[tracing::instrument(skip(key), level = "debug")]
 fn parse_servercurrentevent(key: &[u8], value: &[u8]) -> Result<(Destination, SendingEvent)> {
 	// Appservices start with a plus
 	Ok::<_, Error>(if key.starts_with(b"+") {

src/service/sending/send.rs

@@ -24,7 +24,7 @@ use crate::{
 };
 
 impl super::Service {
-	#[tracing::instrument(skip(self, client, request), name = "send")]
+	#[tracing::instrument(skip_all, level = "debug")]
 	pub async fn send<T>(&self, client: &Client, dest: &ServerName, request: T) -> Result<T::IncomingResponse>
 	where
 		T: OutgoingRequest + Send,

src/service/sending/sender.rs

@@ -62,7 +62,7 @@ pub const PDU_LIMIT: usize = 50;
 pub const EDU_LIMIT: usize = 100;
 
 impl Service {
-	#[tracing::instrument(skip_all, name = "sender")]
+	#[tracing::instrument(skip_all, level = "debug")]
 	pub(super) async fn sender(&self) -> Result<()> {
 		let mut statuses: CurTransactionStatus = CurTransactionStatus::new();
 		let mut futures: SendingFutures<'_> = FuturesUnordered::new();