feat(fed): Handle EDUs before PDUs

Aranje needs his crypto keys

.forgejo/workflows/release-image.yml

@@ -3,6 +3,15 @@ concurrency:
   group: "release-image-${{ github.ref }}"
 
 on:
+  pull_request:
+    paths-ignore:
+      - "*.md"
+      - "**/*.md"
+      - ".gitlab-ci.yml"
+      - ".gitignore"
+      - "renovate.json"
+      - "pkg/**"
+      - "docs/**"
   push:
     branches:
       - main

.forgejo/workflows/renovate.yml

@@ -43,7 +43,7 @@ jobs:
     name: Renovate
     runs-on: ubuntu-latest
     container:
-      image: ghcr.io/renovatebot/renovate:42.11.0@sha256:656c1e5b808279eac16c37b89562fb4c699e02fc7e219244f4a1fc2f0a7ce367
+      image: ghcr.io/renovatebot/renovate:41.146.4@sha256:bb70194b7405faf10a6f279b60caa10403a440ba37d158c5a4ef0ae7b67a0f92
       options: --tmpfs /tmp:exec
     steps:
       - name: Checkout

.pre-commit-config.yaml

@@ -23,7 +23,7 @@ repos:
         - id: check-added-large-files
 
   - repo: https://github.com/crate-ci/typos
-    rev: v1.39.2
+    rev: v1.39.0
     hooks:
       - id: typos
       - id: typos

Cargo.lock

@@ -695,9 +695,9 @@ checksum = "d71b6127be86fdcfddb610f7182ac57211d4b18a3e9c82eb2d17662f2227ad6a"
 
 [[package]]
 name = "bytesize"
-version = "2.2.0"
+version = "2.1.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c99fa31e08a43eaa5913ef68d7e01c37a2bdce6ed648168239ad33b7d30a9cd8"
+checksum = "f5c434ae3cf0089ca203e9019ebe529c47ff45cefe8af7c85ecb734ef541822f"
 
 [[package]]
 name = "bzip2-sys"
@@ -902,7 +902,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "clap",
  "conduwuit_admin",
@@ -934,7 +934,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_admin"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "clap",
  "conduwuit_api",
@@ -956,7 +956,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_api"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "async-trait",
  "axum 0.7.9",
@@ -989,14 +989,14 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_build_metadata"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "built 0.8.0",
 ]
 
 [[package]]
 name = "conduwuit_core"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "argon2",
  "arrayvec",
@@ -1057,7 +1057,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_database"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "async-channel",
  "conduwuit_core",
@@ -1076,7 +1076,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_macros"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "itertools 0.14.0",
  "proc-macro2",
@@ -1086,7 +1086,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_router"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "axum 0.7.9",
  "axum-client-ip",
@@ -1121,7 +1121,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_service"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "async-trait",
  "base64 0.22.1",
@@ -1162,7 +1162,7 @@ dependencies = [
 
 [[package]]
 name = "conduwuit_web"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "askama",
  "axum 0.7.9",
@@ -1431,9 +1431,9 @@ dependencies = [
 
 [[package]]
 name = "ctor"
-version = "0.6.1"
+version = "0.5.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "3ffc71fcdcdb40d6f087edddf7f8f1f8f79e6cf922f555a9ee8779752d4819bd"
+checksum = "67773048316103656a637612c4a62477603b777d91d9c62ff2290f9cde178fdb"
 dependencies = [
  "ctor-proc-macro",
  "dtor",
@@ -1441,9 +1441,9 @@ dependencies = [
 
 [[package]]
 name = "ctor-proc-macro"
-version = "0.0.7"
+version = "0.0.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "52560adf09603e58c9a7ee1fe1dcb95a16927b17c127f0ac02d6e768a0e25bc1"
+checksum = "e2931af7e13dc045d8e9d26afccc6fa115d64e115c9c84b1166288b46f6782c2"
 
 [[package]]
 name = "curve25519-dalek"
@@ -1685,7 +1685,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "39cab71617ae0d63f51a36d69f866391735b51691dbda63cf6f96d042b63efeb"
 dependencies = [
  "libc",
- "windows-sys 0.61.2",
+ "windows-sys 0.52.0",
 ]
 
 [[package]]
@@ -2340,7 +2340,7 @@ dependencies = [
  "libc",
  "percent-encoding",
  "pin-project-lite",
- "socket2 0.6.1",
+ "socket2 0.5.10",
  "tokio",
  "tower-service",
  "tracing",
@@ -3611,7 +3611,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "9120690fafc389a67ba3803df527d0ec9cbbc9cc45e4cc20b332996dfb672425"
 dependencies = [
  "anyhow",
- "itertools 0.14.0",
+ "itertools 0.12.1",
  "proc-macro2",
  "quote",
  "syn",
@@ -3690,7 +3690,7 @@ dependencies = [
  "quinn-udp",
  "rustc-hash",
  "rustls",
- "socket2 0.6.1",
+ "socket2 0.5.10",
  "thiserror 2.0.17",
  "tokio",
  "tracing",
@@ -3727,9 +3727,9 @@ dependencies = [
  "cfg_aliases",
  "libc",
  "once_cell",
- "socket2 0.6.1",
+ "socket2 0.5.10",
  "tracing",
- "windows-sys 0.60.2",
+ "windows-sys 0.52.0",
 ]
 
 [[package]]
@@ -4266,7 +4266,7 @@ dependencies = [
  "errno",
  "libc",
  "linux-raw-sys",
- "windows-sys 0.61.2",
+ "windows-sys 0.52.0",
 ]
 
 [[package]]
@@ -6170,7 +6170,7 @@ dependencies = [
 
 [[package]]
 name = "xtask"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "clap",
  "serde",
@@ -6179,7 +6179,7 @@ dependencies = [
 
 [[package]]
 name = "xtask-generate-commands"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 dependencies = [
  "clap-markdown",
  "clap_builder",

Cargo.toml

@@ -21,7 +21,7 @@ license = "Apache-2.0"
 readme = "README.md"
 repository = "https://forgejo.ellis.link/continuwuation/continuwuity"
 rust-version = "1.86.0"
-version = "0.5.0-rc.8.1"
+version = "0.5.0-rc.8"
 
 [workspace.metadata.crane]
 name = "conduwuit"
@@ -48,7 +48,7 @@ features = ["ffi", "std", "union"]
 version = "0.7.0"
 
 [workspace.dependencies.ctor]
-version = "0.6.0"
+version = "0.5.0"
 
 [workspace.dependencies.cargo_toml]
 version = "0.22"

README.md

@@ -11,7 +11,7 @@
 <!-- ANCHOR_END: catchphrase -->
 
 [continuwuity] is a Matrix homeserver written in Rust.
-It's the official community continuation of the [conduwuit](https://github.com/girlbossceo/conduwuit) homeserver.
+It's a community continuation of the [conduwuit](https://github.com/girlbossceo/conduwuit) homeserver.
 
 <!-- ANCHOR: body -->
 

docs/static/announcements.json

@@ -8,10 +8,6 @@
         {
             "id": 3,
             "message": "_taps microphone_ The Continuwuity 0.5.0-rc.7 release is now available, and it's better than ever! **177 commits**, **35 pull requests**, **11 contributors,** and a lot of new stuff!\n\nFor highlights, we've got:\n\n* 🕵️ Full Policy Server support to fight spam!\n* 🚀 Smarter room & space upgrades.\n* 🚫 User suspension tools for better moderation.\n* 🤖 reCaptcha support for safer open registration.\n* 🔍 Ability to disable read receipts & typing indicators.\n* ⚡ Sweeping performance improvements!\n\nGet the [full changelog and downloads on our Forgejo](https://forgejo.ellis.link/continuwuation/continuwuity/releases/tag/v0.5.0-rc.7) - and make sure you're in the [Announcements room](https://matrix.to/#/!releases:continuwuity.org/$hN9z6L2_dTAlPxFLAoXVfo_g8DyYXu4cpvWsSrWhmB0) to get stuff like this sooner."
-        },
-        {
-            "id": 5,
-            "message": "It's a bird! It's a plane! No, it's 0.5.0-rc.8.1!\n\nThis is a minor bugfix update to the rc8 which backports some important fixes from the latest main branch. If you still haven't updated to rc8, you should skip to main. Otherwise, you should upgrade to this bugfix release as soon as possible.\n\nBugfixes backported to this version:\n\n- Resolved several issues with state resolution v2.1 (room version 12)\n- Fixed issues with the `restricted` and `knock_restricted` join rules that would sometimes incorrectly disallow a valid join\n- Fixed the automatic support contact listing being a no-op\n- Fixed upgrading pre-v12 rooms to v12 rooms\n- Fixed policy servers sending the incorrect JSON objects (resulted in false positives)\n- Fixed debug build panic during MSC4133 migration\n\nIt is recommended, if you can and are comfortable with doing so, following updates to the main branch - we're in the run up to the full 0.5.0 release, and more and more bugfixes and new features are being pushed constantly. Please don't forget to join [#announcements:continuwuity.org](https://matrix.to/#/#announcements:continuwuity.org) to receive this news faster and be alerted to other important updates!"
         }
     ]
 }

src/api/server/send.rs

@@ -5,7 +5,7 @@ use axum_client_ip::InsecureClientIp;
 use conduwuit::{
 	Err, Error, Result, debug,
 	debug::INFO_SPAN_LEVEL,
-	debug_warn, err, error,
+	debug_warn, err, error, info,
 	result::LogErr,
 	trace,
 	utils::{
@@ -79,13 +79,11 @@ pub(crate) async fn send_transaction_message_route(
 	}
 
 	let txn_start_time = Instant::now();
-	trace!(
+	info!(
 		pdus = body.pdus.len(),
 		edus = body.edus.len(),
-		elapsed = ?txn_start_time.elapsed(),
 		id = ?body.transaction_id,
-		origin =?body.origin(),
-		"Starting txn",
+		"Processing transaction",
 	);
 
 	let pdus = body
@@ -104,14 +102,21 @@ pub(crate) async fn send_transaction_message_route(
 		.filter_map(Result::ok)
 		.stream();
 
-	let results = handle(&services, &client, body.origin(), txn_start_time, pdus, edus).await?;
-
-	debug!(
+	info!(
+		pdus = body.pdus.len(),
+		edus = body.edus.len(),
+		elapsed = ?txn_start_time.elapsed(),
+		id = ?body.transaction_id,
+		"Validated transaction",
+	);
+
+	let results = handle(&services, &client, body.origin(), txn_start_time, pdus, edus).await?;
+
+	info!(
 		pdus = body.pdus.len(),
 		edus = body.edus.len(),
 		elapsed = ?txn_start_time.elapsed(),
 		id = ?body.transaction_id,
-		origin =?body.origin(),
 		"Finished txn",
 	);
 	for (id, result) in &results {
@@ -138,6 +143,10 @@ async fn handle(
 	pdus: impl Stream<Item = Pdu> + Send,
 	edus: impl Stream<Item = Edu> + Send,
 ) -> Result<ResolvedMap> {
+	edus.for_each_concurrent(automatic_width(), |edu| handle_edu(services, client, origin, edu))
+		.boxed()
+		.await;
+
 	// group pdus by room
 	let pdus = pdus
 		.collect()
@@ -154,7 +163,8 @@ async fn handle(
 		.into_iter()
 		.try_stream()
 		.broad_and_then(|(room_id, pdus): (_, Vec<_>)| {
-			handle_room(services, client, origin, started, room_id, pdus.into_iter())
+			let count = pdus.len();
+			handle_room(services, client, origin, started, room_id, pdus.into_iter(), count)
 				.map_ok(Vec::into_iter)
 				.map_ok(IterStream::try_stream)
 		})
@@ -163,11 +173,6 @@ async fn handle(
 		.boxed()
 		.await?;
 
-	// evaluate edus after pdus, at least for now.
-	edus.for_each_concurrent(automatic_width(), |edu| handle_edu(services, client, origin, edu))
-		.boxed()
-		.await;
-
 	Ok(results)
 }
 
@@ -178,6 +183,7 @@ async fn handle_room(
 	txn_start_time: Instant,
 	room_id: OwnedRoomId,
 	pdus: impl Iterator<Item = Pdu> + Send,
+	count: usize,
 ) -> Result<Vec<(OwnedEventId, Result)>> {
 	let _room_lock = services
 		.rooms
@@ -187,10 +193,20 @@ async fn handle_room(
 		.await;
 
 	let room_id = &room_id;
+	let mut n = 0;
 	pdus.try_stream()
 		.and_then(|(_, event_id, value)| async move {
 			services.server.check_running()?;
 			let pdu_start_time = Instant::now();
+			info!(
+				%room_id,
+				%event_id,
+				pdu = n + 1,
+				total = count,
+				pdu_elapsed = ?pdu_start_time.elapsed(),
+				txn_elapsed = ?txn_start_time.elapsed(),
+				"Handling PDU",
+			);
 			let result = services
 				.rooms
 				.event_handler
@@ -198,11 +214,16 @@ async fn handle_room(
 				.await
 				.map(|_| ());
 
-			debug!(
+			info!(
+				%room_id,
+				%event_id,
+				pdu = n + 1,
+				total = count,
 				pdu_elapsed = ?pdu_start_time.elapsed(),
 				txn_elapsed = ?txn_start_time.elapsed(),
-				"Finished PDU {event_id}",
+				"Finished handling PDU {event_id}",
 			);
+			n += 1;
 
 			Ok((event_id, result))
 		})

src/core/matrix/state_res/mod.rs

@@ -101,40 +101,40 @@ where
 	debug!(version = ?stateres_version, "State resolution starting");
 
 	// Split non-conflicting and conflicting state
-	let (unconflicted, conflicting) = separate(state_sets.into_iter());
+	let (clean, conflicting) = separate(state_sets.into_iter());
 
-	debug!(count = unconflicted.len(), "non-conflicting events");
-	trace!(map = ?unconflicted, "non-conflicting events");
+	debug!(count = clean.len(), "non-conflicting events");
+	trace!(map = ?clean, "non-conflicting events");
 
 	if conflicting.is_empty() {
 		debug!("no conflicting state found");
-		return Ok(unconflicted);
+		return Ok(clean);
 	}
 
 	debug!(count = conflicting.len(), "conflicting events");
 	trace!(map = ?conflicting, "conflicting events");
-	let (conflicted_state_subgraph, initial_state) =
-		if stateres_version == StateResolutionVersion::V2_1 {
-			let csg = calculate_conflicted_subgraph(&conflicting, event_fetch)
+	let conflicted_state_subgraph: HashSet<_> = match stateres_version {
+		| StateResolutionVersion::V2_1 =>
+			calculate_conflicted_subgraph(&conflicting, event_fetch)
 				.await
 				.ok_or_else(|| {
 					Error::InvalidPdu("Failed to calculate conflicted subgraph".to_owned())
-				})?;
-			debug!(count = csg.len(), "conflicted subgraph");
-			trace!(set = ?csg, "conflicted subgraph");
-			(csg, HashMap::new())
-		} else {
-			(HashSet::new(), unconflicted.clone())
-		};
+				})?,
+		| _ => HashSet::new(),
+	};
+	debug!(count = conflicted_state_subgraph.len(), "conflicted subgraph");
+	trace!(set = ?conflicted_state_subgraph, "conflicted subgraph");
+
+	let conflicting_values = conflicting.into_values().flatten().stream();
 
 	// `all_conflicted` contains unique items
 	// synapse says `full_set = {eid for eid in full_conflicted_set if eid in
 	// event_map}`
 	// Hydra: Also consider the conflicted state subgraph
 	let all_conflicted: HashSet<_> = get_auth_chain_diff(auth_chain_sets)
-		.chain(conflicting.into_values().flatten().stream())
-		.broad_filter_map(async |id| event_exists(id.clone()).await.then_some(id))
+		.chain(conflicting_values)
 		.chain(conflicted_state_subgraph.into_iter().stream())
+		.broad_filter_map(async |id| event_exists(id.clone()).await.then_some(id))
 		.collect()
 		.await;
 
@@ -169,8 +169,9 @@ where
 	// Sequentially auth check each control event.
 	let resolved_control = iterative_auth_check(
 		&room_version,
+		&stateres_version,
 		sorted_control_levels.iter().stream().map(AsRef::as_ref),
-		initial_state,
+		clean.clone(),
 		&event_fetch,
 	)
 	.await?;
@@ -200,7 +201,7 @@ where
 	let power_levels_ty_sk = (StateEventType::RoomPowerLevels, StateKey::new());
 	let power_event = resolved_control.get(&power_levels_ty_sk);
 
-	trace!(event_id = ?power_event, "power event");
+	debug!(event_id = ?power_event, "power event");
 
 	let sorted_left_events =
 		mainline_sort(&events_to_resolve, power_event.cloned(), &event_fetch).await?;
@@ -209,14 +210,15 @@ where
 
 	let mut resolved_state = iterative_auth_check(
 		&room_version,
+		&stateres_version,
 		sorted_left_events.iter().stream().map(AsRef::as_ref),
-		resolved_control, // The control events are added to the final resolved state
+		resolved_control.clone(), // The control events are added to the final resolved state
 		&event_fetch,
 	)
 	.await?;
 
 	// Ensure unconflicting state is in the final state
-	resolved_state.extend(unconflicted);
+	resolved_state.extend(clean);
 
 	debug!("state resolution finished");
 	trace!( map = ?resolved_state, "final resolved state" );
@@ -596,6 +598,7 @@ where
 #[tracing::instrument(level = "trace", skip_all)]
 async fn iterative_auth_check<'a, E, F, Fut, S>(
 	room_version: &RoomVersion,
+	stateres_version: &StateResolutionVersion,
 	events_to_check: S,
 	unconflicted_state: StateMap<OwnedEventId>,
 	fetch_event: &F,
@@ -620,10 +623,6 @@ where
 		.boxed()
 		.await?;
 	trace!(list = ?events_to_check, "events to check");
-	if events_to_check.is_empty() {
-		debug!("no events to check, returning unconflicted state");
-		return Ok(unconflicted_state);
-	}
 
 	let auth_event_ids: HashSet<OwnedEventId> = events_to_check
 		.iter()
@@ -644,11 +643,10 @@ where
 	trace!(map = ?auth_events.keys().collect::<Vec<_>>(), "fetched auth events");
 
 	let auth_events = &auth_events;
-	// NOTE: in state resolution v2.1, auth checks should start with an empty state
-	// map. It is the caller's job to do this. Previously, this function would
-	// force an empty state map in this case, and this resulted in power events
-	// going missing from the resolved state as they'd be discarded here.
-	let mut resolved_state = unconflicted_state;
+	let mut resolved_state = match stateres_version {
+		| StateResolutionVersion::V2_1 => StateMap::new(),
+		| _ => unconflicted_state,
+	};
 	for event in events_to_check {
 		trace!(event_id = event.event_id().as_str(), "checking event");
 		let state_key = event
@@ -1036,6 +1034,7 @@ mod tests {
 
 		let resolved_power = super::iterative_auth_check(
 			&RoomVersion::V6,
+			&StateResolutionVersion::V2,
 			sorted_power_events.iter().map(AsRef::as_ref).stream(),
 			HashMap::new(), // unconflicted events
 			&fetcher,

src/core/utils/debug.rs

@@ -28,7 +28,7 @@ impl<T: fmt::Debug> fmt::Debug for TruncatedSlice<'_, T> {
 /// use conduwuit_core::utils::debug::slice_truncated;
 ///
 /// #[tracing::instrument(fields(foos = slice_truncated(foos, 42)))]
-/// fn bar(foos: &[&str]) {};
+/// fn bar(foos: &[&str]);
 /// ```
 pub fn slice_truncated<T: fmt::Debug>(
 	slice: &[T],

src/service/federation/execute.rs

@@ -1,9 +1,13 @@
-use std::{fmt::Debug, mem};
+use std::{
+	error::Error as _,
+	fmt::{Debug, Write},
+	mem,
+};
 
 use bytes::Bytes;
 use conduwuit::{
 	Err, Error, Result, debug, debug::INFO_SPAN_LEVEL, debug_error, debug_warn, err,
-	error::inspect_debug_log, implement, trace, utils::string::EMPTY,
+	error::inspect_debug_log, implement, trace, utils::string::EMPTY, warn,
 };
 use http::{HeaderValue, header::AUTHORIZATION};
 use ipaddress::IPAddress;
@@ -193,9 +197,9 @@ fn handle_error(
 ) -> Result {
 	if e.is_timeout() || e.is_connect() {
 		e = e.without_url();
-		debug_warn!("{e:?}");
+		warn!(?url, "network error while sending federation request: {e:?}");
 	} else if e.is_redirect() {
-		debug_error!(
+		warn!(
 			method = ?method,
 			url = ?url,
 			final_url = ?e.url(),
@@ -204,9 +208,17 @@ fn handle_error(
 			e,
 		);
 	} else {
-		debug_error!("{e:?}");
+		warn!(?url, "failed to send federation request: {e:?}");
 	}
 
+	let mut nice_error = "Request failed".to_owned();
+	let mut src = e.source();
+	while let Some(source) = src {
+		write!(nice_error, ": {source:?}").expect("writing to string should not fail");
+		src = source.source();
+	}
+	warn!(nice_error, "Federation request error");
+
 	Err(e.into())
 }
 

src/service/sending/sender.rs

@@ -10,7 +10,7 @@ use std::{
 
 use base64::{Engine as _, engine::general_purpose::URL_SAFE_NO_PAD};
 use conduwuit_core::{
-	Error, Event, Result, debug, err, error,
+	Error, Event, Result, debug, err, error, info,
 	result::LogErr,
 	trace,
 	utils::{
@@ -142,7 +142,7 @@ impl Service {
 	}
 
 	fn handle_response_err(dest: Destination, statuses: &mut CurTransactionStatus, e: &Error) {
-		debug!(dest = ?dest, "{e:?}");
+		debug!(dest = ?dest, "error response: {e:?}");
 		statuses.entry(dest).and_modify(|e| {
 			*e = match e {
 				| TransactionStatus::Running => TransactionStatus::Failed(1, Instant::now()),
@@ -177,7 +177,21 @@ impl Service {
 		if !new_events.is_empty() {
 			self.db.mark_as_active(new_events.iter());
 
-			let new_events_vec = new_events.into_iter().map(|(_, event)| event).collect();
+			let new_events_vec: Vec<SendingEvent> =
+				new_events.into_iter().map(|(_, event)| event).collect();
+
+			if let Some(status) = statuses.get(&dest.clone()) {
+				if matches!(status, TransactionStatus::Running) {
+					// If the server is in backoff, clear it
+					info!(
+						?dest,
+						"Catching up previously failed destination with {}+ new events",
+						new_events_vec.len()
+					);
+					statuses.insert(dest.clone(), TransactionStatus::Running);
+				}
+			}
+
 			futures.push(self.send_events(dest.clone(), new_events_vec));
 		} else {
 			statuses.remove(dest);
@@ -859,12 +873,20 @@ impl Service {
 			pdus,
 			edus,
 		};
+		let pdu_count = request.pdus.len();
+		let edu_count = request.edus.len();
 
 		let result = self
 			.services
 			.federation
 			.execute_on(&self.services.client.sender, &server, request)
-			.await;
+			.await
+			.inspect(|_| {
+				info!(%txn_id, %server, "Sent {} PDUs, {} EDUs", pdu_count, edu_count);
+			})
+			.inspect_err(|e| {
+				info!(%txn_id, %server, "Failed to send transaction ({} PDUs, {} EDUs): {e:?}", pdu_count, edu_count);
+			});
 
 		for (event_id, result) in result.iter().flat_map(|resp| resp.pdus.iter()) {
 			if let Err(e) = result {