style: Improve logging and comments

Cargo.lock

@@ -3900,7 +3900,7 @@ checksum = "88f8660c1ff60292143c98d08fc6e2f654d722db50410e3f3797d40baaf9d8f3"
 [[package]]
 name = "ruma"
 version = "0.10.1"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "assign",
  "js_int",
@@ -3920,7 +3920,7 @@ dependencies = [
 [[package]]
 name = "ruma-appservice-api"
 version = "0.10.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "js_int",
  "ruma-common",
@@ -3932,7 +3932,7 @@ dependencies = [
 [[package]]
 name = "ruma-client-api"
 version = "0.18.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "as_variant",
  "assign",
@@ -3955,7 +3955,7 @@ dependencies = [
 [[package]]
 name = "ruma-common"
 version = "0.13.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "as_variant",
  "base64 0.22.1",
@@ -3987,7 +3987,7 @@ dependencies = [
 [[package]]
 name = "ruma-events"
 version = "0.28.1"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "as_variant",
  "indexmap 2.9.0",
@@ -4012,7 +4012,7 @@ dependencies = [
 [[package]]
 name = "ruma-federation-api"
 version = "0.9.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "bytes",
  "headers",
@@ -4034,7 +4034,7 @@ dependencies = [
 [[package]]
 name = "ruma-identifiers-validation"
 version = "0.9.5"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "js_int",
  "thiserror 2.0.12",
@@ -4043,7 +4043,7 @@ dependencies = [
 [[package]]
 name = "ruma-identity-service-api"
 version = "0.9.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "js_int",
  "ruma-common",
@@ -4053,7 +4053,7 @@ dependencies = [
 [[package]]
 name = "ruma-macros"
 version = "0.13.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "cfg-if",
  "proc-macro-crate",
@@ -4068,7 +4068,7 @@ dependencies = [
 [[package]]
 name = "ruma-push-gateway-api"
 version = "0.9.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "js_int",
  "ruma-common",
@@ -4080,7 +4080,7 @@ dependencies = [
 [[package]]
 name = "ruma-signatures"
 version = "0.15.0"
-source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=a4b948b40417a65ab0282ae47cc50035dd455e02#a4b948b40417a65ab0282ae47cc50035dd455e02"
+source = "git+https://forgejo.ellis.link/continuwuation/ruwuma?rev=b753738047d1f443aca870896ef27ecaacf027da#b753738047d1f443aca870896ef27ecaacf027da"
 dependencies = [
  "base64 0.22.1",
  "ed25519-dalek",

Cargo.toml

@@ -352,7 +352,7 @@ version = "0.1.2"
 [workspace.dependencies.ruma]
 git = "https://forgejo.ellis.link/continuwuation/ruwuma"
 #branch = "conduwuit-changes"
-rev = "a4b948b40417a65ab0282ae47cc50035dd455e02"
+rev = "b753738047d1f443aca870896ef27ecaacf027da"
 features = [
     "compat",
     "rand",

src/core/matrix/state_res/event_auth.rs

@@ -149,8 +149,8 @@ where
 	for<'a> &'a E: Event + Send,
 {
 	debug!(
-		event_id = format!("{}", incoming_event.event_id()),
+		event_id = %incoming_event.event_id(),
-		event_type = format!("{}", incoming_event.event_type()),
+		event_type = ?incoming_event.event_type(),
 		"auth_check beginning"
 	);
 
@@ -217,8 +217,9 @@ where
 	}
 
 	/*
-	// TODO: In the past this code caused problems federating with synapse, maybe this has been
+	// TODO: In the past this code was commented as it caused problems with Synapse. This is no
-	// resolved already. Needs testing.
+	// longer the case. This needs to be implemented.
+	// See also: https://github.com/ruma/ruma/pull/2064
 	//
 	// 2. Reject if auth_events
 	// a. auth_events cannot have duplicate keys since it's a BTree

src/service/rooms/event_handler/call_policyserv.rs

@@ -0,0 +1,111 @@
+//! Policy server integration for event spam checking in Matrix rooms.
+//!
+//! This module implements a check against a room-specific policy server, as
+//! described in the relevant Matrix spec proposal (see: https://github.com/matrix-org/matrix-spec-proposals/pull/4284).
+
+use std::time::Duration;
+
+use conduwuit::{Err, Event, PduEvent, Result, debug, implement, warn};
+use ruma::{
+	RoomId, ServerName,
+	api::federation::room::policy::v1::Request as PolicyRequest,
+	events::{StateEventType, room::policy::RoomPolicyEventContent},
+};
+
+/// Returns Ok if the policy server allows the event
+#[implement(super::Service)]
+#[tracing::instrument(skip_all, level = "debug")]
+pub async fn policyserv_check(&self, pdu: &PduEvent, room_id: &RoomId) -> Result {
+	if *pdu.event_type() == StateEventType::RoomPolicy.into() {
+		debug!(
+			room_id = %room_id,
+			event_type = ?pdu.event_type(),
+			"Skipping spam check for policy server meta-event"
+		);
+		return Ok(());
+	}
+	let Ok(policyserver) = self
+		.services
+		.state_accessor
+		.room_state_get_content(room_id, &StateEventType::RoomPolicy, "")
+		.await
+		.map(|c: RoomPolicyEventContent| c)
+	else {
+		return Ok(());
+	};
+
+	let via = match policyserver.via {
+		| Some(ref via) => ServerName::parse(via)?,
+		| None => {
+			debug!("No policy server configured for room {room_id}");
+			return Ok(());
+		},
+	};
+	if via.is_empty() {
+		debug!("Policy server is empty for room {room_id}, skipping spam check");
+		return Ok(());
+	}
+	if !self.services.state_cache.server_in_room(via, room_id).await {
+		debug!(
+			room_id = %room_id,
+			via = %via,
+			"Policy server is not in the room, skipping spam check"
+		);
+		return Ok(());
+	}
+	let outgoing = self
+		.services
+		.sending
+		.convert_to_outgoing_federation_event(pdu.to_canonical_object())
+		.await;
+	debug!(
+		room_id = %room_id,
+		via = %via,
+		outgoing = ?outgoing,
+		"Checking event for spam with policy server"
+	);
+	let response = tokio::time::timeout(
+		Duration::from_secs(10),
+		self.services
+			.sending
+			.send_federation_request(via, PolicyRequest {
+				event_id: pdu.event_id().to_owned(),
+				pdu: Some(outgoing),
+			}),
+	)
+	.await;
+	let response = match response {
+		| Ok(Ok(response)) => response,
+		| Ok(Err(e)) => {
+			warn!(
+				via = %via,
+				event_id = %pdu.event_id(),
+				room_id = %room_id,
+				"Failed to contact policy server: {e}"
+			);
+			// Network or policy server errors are treated as non-fatal: event is allowed by
+			// default.
+			return Ok(());
+		},
+		| Err(_) => {
+			warn!(
+				via = %via,
+				event_id = %pdu.event_id(),
+				room_id = %room_id,
+				"Policy server request timed out after 10 seconds"
+			);
+			return Ok(());
+		},
+	};
+	if response.recommendation == "spam" {
+		warn!(
+			via = %via,
+			event_id = %pdu.event_id(),
+			room_id = %room_id,
+			"Event was marked as spam by policy server",
+		);
+		return Err!(Request(Forbidden("Event was marked as spam by policy server")));
+	}
+
+	Ok(())
+}

src/service/rooms/event_handler/mod.rs

@@ -1,4 +1,5 @@
 mod acl_check;
+mod call_policyserv;
 mod fetch_and_handle_outliers;
 mod fetch_prev;
 mod fetch_state;
@@ -42,6 +43,7 @@ struct Services {
 	server_keys: Dep<server_keys::Service>,
 	short: Dep<rooms::short::Service>,
 	state: Dep<rooms::state::Service>,
+	state_cache: Dep<rooms::state_cache::Service>,
 	state_accessor: Dep<rooms::state_accessor::Service>,
 	state_compressor: Dep<rooms::state_compressor::Service>,
 	timeline: Dep<rooms::timeline::Service>,
@@ -67,6 +69,7 @@ impl crate::Service for Service {
 				pdu_metadata: args.depend::<rooms::pdu_metadata::Service>("rooms::pdu_metadata"),
 				short: args.depend::<rooms::short::Service>("rooms::short"),
 				state: args.depend::<rooms::state::Service>("rooms::state"),
+				state_cache: args.depend::<rooms::state_cache::Service>("rooms::state_cache"),
 				state_accessor: args
 					.depend::<rooms::state_accessor::Service>("rooms::state_accessor"),
 				state_compressor: args

src/service/rooms/event_handler/upgrade_outlier_pdu.rs

@@ -1,7 +1,7 @@
 use std::{borrow::Borrow, collections::BTreeMap, iter::once, sync::Arc, time::Instant};
 
 use conduwuit::{
-	Err, Result, debug, debug_info, err, implement, is_equal_to,
+	Err, Result, debug, debug_info, err, implement, info, is_equal_to,
 	matrix::{Event, EventTypeExt, PduEvent, StateKey, state_res},
 	trace,
 	utils::stream::{BroadbandExt, ReadyExt},
@@ -47,7 +47,10 @@ where
 		return Err!(Request(InvalidParam("Event has been soft failed")));
 	}
 
-	debug!("Upgrading to timeline pdu");
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Upgrading PDU from outlier to timeline"
+	);
 	let timer = Instant::now();
 	let room_version_id = get_room_version_id(create_event)?;
 
@@ -55,7 +58,10 @@ where
 	//     backwards extremities doing all the checks in this list starting at 1.
 	//     These are not timeline events.
 
-	debug!("Resolving state at event");
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Resolving state at event"
+	);
 	let mut state_at_incoming_event = if incoming_pdu.prev_events().count() == 1 {
 		self.state_at_incoming_degree_one(&incoming_pdu).await?
 	} else {
@@ -74,7 +80,10 @@ where
 
 	let room_version = to_room_version(&room_version_id);
 
-	debug!("Performing auth check");
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Performing auth check to upgrade"
+	);
 	// 11. Check the auth of the event passes based on the state of the event
 	let state_fetch_state = &state_at_incoming_event;
 	let state_fetch = |k: StateEventType, s: StateKey| async move {
@@ -84,6 +93,10 @@ where
 		self.services.timeline.get_pdu(event_id).await.ok()
 	};
 
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Running initial auth check"
+	);
 	let auth_check = state_res::event_auth::auth_check(
 		&room_version,
 		&incoming_pdu,
@@ -97,7 +110,10 @@ where
 		return Err!(Request(Forbidden("Event has failed auth check with state at the event.")));
 	}
 
-	debug!("Gathering auth events");
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Gathering auth events"
+	);
 	let auth_events = self
 		.services
 		.state
@@ -115,6 +131,10 @@ where
 		ready(auth_events.get(&key).map(ToOwned::to_owned))
 	};
 
+	debug!(
+		event_id = %incoming_pdu.event_id,
+		"Running auth check with claimed state auth"
+	);
 	let auth_check = state_res::event_auth::auth_check(
 		&room_version,
 		&incoming_pdu,
@@ -125,8 +145,11 @@ where
 	.map_err(|e| err!(Request(Forbidden("Auth check failed: {e:?}"))))?;
 
 	// Soft fail check before doing state res
-	debug!("Performing soft-fail check");
+	debug!(
-	let soft_fail = match (auth_check, incoming_pdu.redacts_id(&room_version_id)) {
+		event_id = %incoming_pdu.event_id,
+		"Performing soft-fail check"
+	);
+	let mut soft_fail = match (auth_check, incoming_pdu.redacts_id(&room_version_id)) {
 		| (false, _) => true,
 		| (true, None) => false,
 		| (true, Some(redact_id)) =>
@@ -140,7 +163,10 @@ where
 	// 13. Use state resolution to find new room state
 
 	// We start looking at current room state now, so lets lock the room
-	trace!("Locking the room");
+	trace!(
+		room_id = %room_id,
+		"Locking the room"
+	);
 	let state_lock = self.services.state.mutex.lock(room_id).await;
 
 	// Now we calculate the set of extremities this room has after the incoming
@@ -219,10 +245,56 @@ where
 			.await?;
 	}
 
+	// 14-pre. If the event is not a state event, ask the policy server about it
+	if incoming_pdu.state_key.is_none() {
+		debug!(
+			event_id = %incoming_pdu.event_id,"Checking policy server for event");
+		let policy = self.policyserv_check(&incoming_pdu, room_id);
+		if let Err(e) = policy.await {
+			warn!(
+				event_id = %incoming_pdu.event_id,
+				error = ?e,
+				"Policy server check failed for event"
+			);
+			if !soft_fail {
+				soft_fail = true;
+			}
+		}
+		debug!(
+			event_id = %incoming_pdu.event_id,
+			"Policy server check passed for event"
+		);
+	}
+
+	// Additionally, if this is a redaction for a soft-failed event, we soft-fail it
+	// also
+	if let Some(redact_id) = incoming_pdu.redacts_id(&room_version_id) {
+		debug!(
+			redact_id = %redact_id,
+			"Checking if redaction is for a soft-failed event"
+		);
+		if self
+			.services
+			.pdu_metadata
+			.is_event_soft_failed(&redact_id)
+			.await
+		{
+			warn!(
+				redact_id = %redact_id,
+				"Redaction is for a soft-failed event, soft failing the redaction"
+			);
+			soft_fail = true;
+		}
+	}
+
 	// 14. Check if the event passes auth based on the "current state" of the room,
 	//     if not soft fail it
 	if soft_fail {
-		debug!("Soft failing event");
+		info!(
+			event_id = %incoming_pdu.event_id,
+			"Soft failing event"
+		);
+		// assert!(extremities.is_empty(), "soft_fail extremities empty");
 		let extremities = extremities.iter().map(Borrow::borrow);
 
 		self.services
@@ -242,7 +314,10 @@ where
 			.pdu_metadata
 			.mark_event_soft_failed(incoming_pdu.event_id());
 
-		warn!("Event was soft failed: {:?}", incoming_pdu.event_id());
+		warn!(
+			event_id = %incoming_pdu.event_id,
+			"Event was soft failed"
+		);
 		return Err!(Request(InvalidParam("Event has been soft failed")));
 	}
 

src/service/rooms/timeline/create.rs

@@ -165,6 +165,17 @@ pub async fn create_hash_and_sign_event(
 		return Err!(Request(Forbidden("Event is not authorized.")));
 	}
 
+	// Check with the policy server
+	if self
+		.services
+		.event_handler
+		.policyserv_check(&pdu, room_id)
+		.await
+		.is_err()
+	{
+		return Err!(Request(Forbidden(debug_warn!("Policy server marked this event as spam"))));
+	}
+
 	// Hash and sign
 	let mut pdu_json = utils::to_canonical_object(&pdu).map_err(|e| {
 		err!(Request(BadJson(warn!("Failed to convert PDU to canonical JSON: {e}"))))