test_federation_catch_up.py 22 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582
  1. from typing import Callable, Collection, List, Optional, Tuple
  2. from unittest import mock
  3. from unittest.mock import AsyncMock, Mock
  4. from twisted.test.proto_helpers import MemoryReactor
  5. from synapse.api.constants import EventTypes
  6. from synapse.events import EventBase
  7. from synapse.federation.sender import (
  8. FederationSender,
  9. PerDestinationQueue,
  10. TransactionManager,
  11. )
  12. from synapse.federation.units import Edu, Transaction
  13. from synapse.rest import admin
  14. from synapse.rest.client import login, room
  15. from synapse.server import HomeServer
  16. from synapse.types import JsonDict
  17. from synapse.util import Clock
  18. from synapse.util.retryutils import NotRetryingDestination
  19. from tests.test_utils import event_injection
  20. from tests.unittest import FederatingHomeserverTestCase
  21. class FederationCatchUpTestCases(FederatingHomeserverTestCase):
  22. """
  23. Tests cases of catching up over federation.
  24. By default for test cases federation sending is disabled. This Test class has it
  25. re-enabled for the main process.
  26. """
  27. servlets = [
  28. admin.register_servlets,
  29. room.register_servlets,
  30. login.register_servlets,
  31. ]
  32. def make_homeserver(self, reactor: MemoryReactor, clock: Clock) -> HomeServer:
  33. self.federation_transport_client = Mock(spec=["send_transaction"])
  34. return self.setup_test_homeserver(
  35. federation_transport_client=self.federation_transport_client,
  36. )
  37. def prepare(self, reactor: MemoryReactor, clock: Clock, hs: HomeServer) -> None:
  38. # stub out get_current_hosts_in_room
  39. state_storage_controller = hs.get_storage_controllers().state
  40. # This mock is crucial for destination_rooms to be populated.
  41. # TODO: this seems to no longer be the case---tests pass with this mock
  42. # commented out.
  43. state_storage_controller.get_current_hosts_in_room = AsyncMock( # type: ignore[method-assign]
  44. return_value={"test", "host2"}
  45. )
  46. # whenever send_transaction is called, record the pdu data
  47. self.pdus: List[JsonDict] = []
  48. self.failed_pdus: List[JsonDict] = []
  49. self.is_online = True
  50. self.federation_transport_client.send_transaction.side_effect = (
  51. self.record_transaction
  52. )
  53. federation_sender = hs.get_federation_sender()
  54. assert isinstance(federation_sender, FederationSender)
  55. self.federation_sender = federation_sender
  56. def default_config(self) -> JsonDict:
  57. config = super().default_config()
  58. config["federation_sender_instances"] = None
  59. return config
  60. async def record_transaction(
  61. self, txn: Transaction, json_cb: Optional[Callable[[], JsonDict]]
  62. ) -> JsonDict:
  63. if json_cb is None:
  64. # The tests seem to expect that this method raises in this situation.
  65. raise Exception("Blank json_cb")
  66. elif self.is_online:
  67. data = json_cb()
  68. self.pdus.extend(data["pdus"])
  69. return {}
  70. else:
  71. data = json_cb()
  72. self.failed_pdus.extend(data["pdus"])
  73. raise NotRetryingDestination(0, 24 * 60 * 60 * 1000, txn.destination)
  74. def get_destination_room(self, room: str, destination: str = "host2") -> dict:
  75. """
  76. Gets the destination_rooms entry for a (destination, room_id) pair.
  77. Args:
  78. room: room ID
  79. destination: what destination, default is "host2"
  80. Returns:
  81. Dictionary of { event_id: str, stream_ordering: int }
  82. """
  83. event_id, stream_ordering = self.get_success(
  84. self.hs.get_datastores().main.db_pool.execute(
  85. "test:get_destination_rooms",
  86. """
  87. SELECT event_id, stream_ordering
  88. FROM destination_rooms dr
  89. JOIN events USING (stream_ordering)
  90. WHERE dr.destination = ? AND dr.room_id = ?
  91. """,
  92. destination,
  93. room,
  94. )
  95. )[0]
  96. return {"event_id": event_id, "stream_ordering": stream_ordering}
  97. def test_catch_up_destination_rooms_tracking(self) -> None:
  98. """
  99. Tests that we populate the `destination_rooms` table as needed.
  100. """
  101. self.register_user("u1", "you the one")
  102. u1_token = self.login("u1", "you the one")
  103. room = self.helper.create_room_as("u1", tok=u1_token)
  104. self.get_success(
  105. event_injection.inject_member_event(self.hs, room, "@user:host2", "join")
  106. )
  107. event_id_1 = self.helper.send(room, "wombats!", tok=u1_token)["event_id"]
  108. row_1 = self.get_destination_room(room)
  109. event_id_2 = self.helper.send(room, "rabbits!", tok=u1_token)["event_id"]
  110. row_2 = self.get_destination_room(room)
  111. # check: events correctly registered in order
  112. self.assertEqual(row_1["event_id"], event_id_1)
  113. self.assertEqual(row_2["event_id"], event_id_2)
  114. self.assertEqual(row_1["stream_ordering"], row_2["stream_ordering"] - 1)
  115. def test_catch_up_last_successful_stream_ordering_tracking(self) -> None:
  116. """
  117. Tests that we populate the `destination_rooms` table as needed.
  118. """
  119. self.register_user("u1", "you the one")
  120. u1_token = self.login("u1", "you the one")
  121. room = self.helper.create_room_as("u1", tok=u1_token)
  122. # take the remote offline
  123. self.is_online = False
  124. self.get_success(
  125. event_injection.inject_member_event(self.hs, room, "@user:host2", "join")
  126. )
  127. self.helper.send(room, "wombats!", tok=u1_token)
  128. self.pump()
  129. lsso_1 = self.get_success(
  130. self.hs.get_datastores().main.get_destination_last_successful_stream_ordering(
  131. "host2"
  132. )
  133. )
  134. self.assertIsNone(
  135. lsso_1,
  136. "There should be no last successful stream ordering for an always-offline destination",
  137. )
  138. # bring the remote online
  139. self.is_online = True
  140. event_id_2 = self.helper.send(room, "rabbits!", tok=u1_token)["event_id"]
  141. lsso_2 = self.get_success(
  142. self.hs.get_datastores().main.get_destination_last_successful_stream_ordering(
  143. "host2"
  144. )
  145. )
  146. row_2 = self.get_destination_room(room)
  147. self.assertEqual(
  148. self.pdus[0]["content"]["body"],
  149. "rabbits!",
  150. "Test fault: didn't receive the right PDU",
  151. )
  152. self.assertEqual(
  153. row_2["event_id"],
  154. event_id_2,
  155. "Test fault: destination_rooms not updated correctly",
  156. )
  157. self.assertEqual(
  158. lsso_2,
  159. row_2["stream_ordering"],
  160. "Send succeeded but not marked as last_successful_stream_ordering",
  161. )
  162. def test_catch_up_from_blank_state(self) -> None:
  163. """
  164. Runs an overall test of federation catch-up from scratch.
  165. Further tests will focus on more narrow aspects and edge-cases, but I
  166. hope to provide an overall view with this test.
  167. """
  168. # bring the other server online
  169. self.is_online = True
  170. # let's make some events for the other server to receive
  171. self.register_user("u1", "you the one")
  172. u1_token = self.login("u1", "you the one")
  173. room_1 = self.helper.create_room_as("u1", tok=u1_token)
  174. room_2 = self.helper.create_room_as("u1", tok=u1_token)
  175. # also critical to federate
  176. self.get_success(
  177. event_injection.inject_member_event(self.hs, room_1, "@user:host2", "join")
  178. )
  179. self.get_success(
  180. event_injection.inject_member_event(self.hs, room_2, "@user:host2", "join")
  181. )
  182. self.helper.send_state(
  183. room_1, event_type="m.room.topic", body={"topic": "wombat"}, tok=u1_token
  184. )
  185. # check: PDU received for topic event
  186. self.assertEqual(len(self.pdus), 1)
  187. self.assertEqual(self.pdus[0]["type"], "m.room.topic")
  188. # take the remote offline
  189. self.is_online = False
  190. # send another event
  191. self.helper.send(room_1, "hi user!", tok=u1_token)
  192. # check: things didn't go well since the remote is down
  193. self.assertEqual(len(self.failed_pdus), 1)
  194. self.assertEqual(self.failed_pdus[0]["content"]["body"], "hi user!")
  195. # let's delete the federation transmission queue
  196. # (this pretends we are starting up fresh.)
  197. self.assertFalse(
  198. self.federation_sender._per_destination_queues[
  199. "host2"
  200. ].transmission_loop_running
  201. )
  202. del self.federation_sender._per_destination_queues["host2"]
  203. # let's also clear any backoffs
  204. self.get_success(
  205. self.hs.get_datastores().main.set_destination_retry_timings(
  206. "host2", None, 0, 0
  207. )
  208. )
  209. # bring the remote online and clear the received pdu list
  210. self.is_online = True
  211. self.pdus = []
  212. # now we need to initiate a federation transaction somehow…
  213. # to do that, let's send another event (because it's simple to do)
  214. # (do it to another room otherwise the catch-up logic decides it doesn't
  215. # need to catch up room_1 — something I overlooked when first writing
  216. # this test)
  217. self.helper.send(room_2, "wombats!", tok=u1_token)
  218. # we should now have received both PDUs
  219. self.assertEqual(len(self.pdus), 2)
  220. self.assertEqual(self.pdus[0]["content"]["body"], "hi user!")
  221. self.assertEqual(self.pdus[1]["content"]["body"], "wombats!")
  222. def make_fake_destination_queue(
  223. self, destination: str = "host2"
  224. ) -> Tuple[PerDestinationQueue, List[EventBase]]:
  225. """
  226. Makes a fake per-destination queue.
  227. """
  228. transaction_manager = TransactionManager(self.hs)
  229. per_dest_queue = PerDestinationQueue(self.hs, transaction_manager, destination)
  230. results_list = []
  231. async def fake_send(
  232. destination_tm: str,
  233. pending_pdus: List[EventBase],
  234. _pending_edus: List[Edu],
  235. ) -> None:
  236. assert destination == destination_tm
  237. results_list.extend(pending_pdus)
  238. transaction_manager.send_new_transaction = fake_send # type: ignore[assignment]
  239. return per_dest_queue, results_list
  240. def test_catch_up_loop(self) -> None:
  241. """
  242. Tests the behaviour of _catch_up_transmission_loop.
  243. """
  244. # ARRANGE:
  245. # - a local user (u1)
  246. # - 3 rooms which u1 is joined to (and remote user @user:host2 is
  247. # joined to)
  248. # - some events (1 to 5) in those rooms
  249. # we have 'already sent' events 1 and 2 to host2
  250. per_dest_queue, sent_pdus = self.make_fake_destination_queue()
  251. self.register_user("u1", "you the one")
  252. u1_token = self.login("u1", "you the one")
  253. room_1 = self.helper.create_room_as("u1", tok=u1_token)
  254. room_2 = self.helper.create_room_as("u1", tok=u1_token)
  255. room_3 = self.helper.create_room_as("u1", tok=u1_token)
  256. self.get_success(
  257. event_injection.inject_member_event(self.hs, room_1, "@user:host2", "join")
  258. )
  259. self.get_success(
  260. event_injection.inject_member_event(self.hs, room_2, "@user:host2", "join")
  261. )
  262. self.get_success(
  263. event_injection.inject_member_event(self.hs, room_3, "@user:host2", "join")
  264. )
  265. # create some events
  266. self.helper.send(room_1, "you hear me!!", tok=u1_token)
  267. event_id_2 = self.helper.send(room_2, "wombats!", tok=u1_token)["event_id"]
  268. self.helper.send(room_3, "Matrix!", tok=u1_token)
  269. event_id_4 = self.helper.send(room_2, "rabbits!", tok=u1_token)["event_id"]
  270. event_id_5 = self.helper.send(room_3, "Synapse!", tok=u1_token)["event_id"]
  271. # destination_rooms should already be populated, but let us pretend that we already
  272. # sent (successfully) up to and including event id 2
  273. event_2 = self.get_success(self.hs.get_datastores().main.get_event(event_id_2))
  274. # also fetch event 5 so we know its last_successful_stream_ordering later
  275. event_5 = self.get_success(self.hs.get_datastores().main.get_event(event_id_5))
  276. assert event_2.internal_metadata.stream_ordering is not None
  277. self.get_success(
  278. self.hs.get_datastores().main.set_destination_last_successful_stream_ordering(
  279. "host2", event_2.internal_metadata.stream_ordering
  280. )
  281. )
  282. # ACT
  283. self.get_success(per_dest_queue._catch_up_transmission_loop())
  284. # ASSERT, noticing in particular:
  285. # - event 3 not sent out, because event 5 replaces it
  286. # - order is least recent first, so event 5 comes after event 4
  287. # - catch-up is completed
  288. self.assertEqual(len(sent_pdus), 2)
  289. self.assertEqual(sent_pdus[0].event_id, event_id_4)
  290. self.assertEqual(sent_pdus[1].event_id, event_id_5)
  291. self.assertFalse(per_dest_queue._catching_up)
  292. self.assertEqual(
  293. per_dest_queue._last_successful_stream_ordering,
  294. event_5.internal_metadata.stream_ordering,
  295. )
  296. def test_catch_up_on_synapse_startup(self) -> None:
  297. """
  298. Tests the behaviour of get_catch_up_outstanding_destinations and
  299. _wake_destinations_needing_catchup.
  300. """
  301. # list of sorted server names (note that there are more servers than the batch
  302. # size used in get_catch_up_outstanding_destinations).
  303. server_names = ["server%02d" % number for number in range(42)] + ["zzzerver"]
  304. # ARRANGE:
  305. # - a local user (u1)
  306. # - a room which u1 is joined to (and remote users @user:serverXX are
  307. # joined to)
  308. # mark the remotes as online
  309. self.is_online = True
  310. self.register_user("u1", "you the one")
  311. u1_token = self.login("u1", "you the one")
  312. room_id = self.helper.create_room_as("u1", tok=u1_token)
  313. for server_name in server_names:
  314. self.get_success(
  315. event_injection.inject_member_event(
  316. self.hs, room_id, "@user:%s" % server_name, "join"
  317. )
  318. )
  319. # create an event
  320. self.helper.send(room_id, "deary me!", tok=u1_token)
  321. # ASSERT:
  322. # - All servers are up to date so none should have outstanding catch-up
  323. outstanding_when_successful = self.get_success(
  324. self.hs.get_datastores().main.get_catch_up_outstanding_destinations(None)
  325. )
  326. self.assertEqual(outstanding_when_successful, [])
  327. # ACT:
  328. # - Make the remote servers unreachable
  329. self.is_online = False
  330. # - Mark zzzerver as being backed-off from
  331. now = self.clock.time_msec()
  332. self.get_success(
  333. self.hs.get_datastores().main.set_destination_retry_timings(
  334. "zzzerver", now, now, 24 * 60 * 60 * 1000 # retry in 1 day
  335. )
  336. )
  337. # - Send an event
  338. self.helper.send(room_id, "can anyone hear me?", tok=u1_token)
  339. # ASSERT (get_catch_up_outstanding_destinations):
  340. # - all remotes are outstanding
  341. # - they are returned in batches of 25, in order
  342. outstanding_1 = self.get_success(
  343. self.hs.get_datastores().main.get_catch_up_outstanding_destinations(None)
  344. )
  345. self.assertEqual(len(outstanding_1), 25)
  346. self.assertEqual(outstanding_1, server_names[0:25])
  347. outstanding_2 = self.get_success(
  348. self.hs.get_datastores().main.get_catch_up_outstanding_destinations(
  349. outstanding_1[-1]
  350. )
  351. )
  352. self.assertNotIn("zzzerver", outstanding_2)
  353. self.assertEqual(len(outstanding_2), 17)
  354. self.assertEqual(outstanding_2, server_names[25:-1])
  355. # ACT: call _wake_destinations_needing_catchup
  356. # patch wake_destination to just count the destinations instead
  357. woken = set()
  358. def wake_destination_track(destination: str) -> None:
  359. woken.add(destination)
  360. self.federation_sender.wake_destination = wake_destination_track # type: ignore[method-assign]
  361. # We wait quite long so that all dests can be woken up, since there is a delay
  362. # between them.
  363. self.pump(by=5.0)
  364. # ASSERT (_wake_destinations_needing_catchup):
  365. # - all remotes are woken up, save for zzzerver
  366. self.assertNotIn("zzzerver", woken)
  367. # - all destinations are woken, potentially more than once, since the
  368. # wake up is called regularly and we don't ack in this test that a transaction
  369. # has been successfully sent.
  370. self.assertCountEqual(woken, set(server_names[:-1]))
  371. def test_not_latest_event(self) -> None:
  372. """Test that we send the latest event in the room even if its not ours."""
  373. per_dest_queue, sent_pdus = self.make_fake_destination_queue()
  374. # Make a room with a local user, and two servers. One will go offline
  375. # and one will send some events.
  376. self.register_user("u1", "you the one")
  377. u1_token = self.login("u1", "you the one")
  378. room_1 = self.helper.create_room_as("u1", tok=u1_token)
  379. self.get_success(
  380. event_injection.inject_member_event(self.hs, room_1, "@user:host2", "join")
  381. )
  382. event_1 = self.get_success(
  383. event_injection.inject_member_event(self.hs, room_1, "@user:host3", "join")
  384. )
  385. # First we send something from the local server, so that we notice the
  386. # remote is down and go into catchup mode.
  387. self.helper.send(room_1, "you hear me!!", tok=u1_token)
  388. # Now simulate us receiving an event from the still online remote.
  389. event_2 = self.get_success(
  390. event_injection.inject_event(
  391. self.hs,
  392. type=EventTypes.Message,
  393. sender="@user:host3",
  394. room_id=room_1,
  395. content={"msgtype": "m.text", "body": "Hello"},
  396. )
  397. )
  398. assert event_1.internal_metadata.stream_ordering is not None
  399. self.get_success(
  400. self.hs.get_datastores().main.set_destination_last_successful_stream_ordering(
  401. "host2", event_1.internal_metadata.stream_ordering
  402. )
  403. )
  404. self.get_success(per_dest_queue._catch_up_transmission_loop())
  405. # We expect only the last message from the remote, event_2, to have been
  406. # sent, rather than the last *local* event that was sent.
  407. self.assertEqual(len(sent_pdus), 1)
  408. self.assertEqual(sent_pdus[0].event_id, event_2.event_id)
  409. self.assertFalse(per_dest_queue._catching_up)
  410. def test_catch_up_is_not_blocked_by_remote_event_in_partial_state_room(
  411. self,
  412. ) -> None:
  413. """Detects (part of?) https://github.com/matrix-org/synapse/issues/15220."""
  414. # ARRANGE:
  415. # - a local user (u1)
  416. # - a room which contains u1 and two remote users, @u2:host2 and @u3:other
  417. # - events in that room such that
  418. # - history visibility is restricted
  419. # - u1 sent message events e1 and e2
  420. # - afterwards, u3 sent a remote event e3
  421. # - catchup to begin for host2; last successfully sent event was e1
  422. per_dest_queue, sent_pdus = self.make_fake_destination_queue()
  423. self.register_user("u1", "you the one")
  424. u1_token = self.login("u1", "you the one")
  425. room = self.helper.create_room_as("u1", tok=u1_token)
  426. self.helper.send_state(
  427. room_id=room,
  428. event_type="m.room.history_visibility",
  429. body={"history_visibility": "joined"},
  430. tok=u1_token,
  431. )
  432. self.get_success(
  433. event_injection.inject_member_event(self.hs, room, "@u2:host2", "join")
  434. )
  435. self.get_success(
  436. event_injection.inject_member_event(self.hs, room, "@u3:other", "join")
  437. )
  438. # create some events
  439. event_id_1 = self.helper.send(room, "hello", tok=u1_token)["event_id"]
  440. event_id_2 = self.helper.send(room, "world", tok=u1_token)["event_id"]
  441. # pretend that u3 changes their displayname
  442. event_id_3 = self.get_success(
  443. event_injection.inject_member_event(self.hs, room, "@u3:other", "join")
  444. ).event_id
  445. # destination_rooms should already be populated, but let us pretend that we already
  446. # sent (successfully) up to and including event id 1
  447. event_1 = self.get_success(self.hs.get_datastores().main.get_event(event_id_1))
  448. assert event_1.internal_metadata.stream_ordering is not None
  449. self.get_success(
  450. self.hs.get_datastores().main.set_destination_last_successful_stream_ordering(
  451. "host2", event_1.internal_metadata.stream_ordering
  452. )
  453. )
  454. # also fetch event 2 so we can compare its stream ordering to the sender's
  455. # last_successful_stream_ordering later
  456. event_2 = self.get_success(self.hs.get_datastores().main.get_event(event_id_2))
  457. # Mock event 3 as having partial state
  458. self.get_success(
  459. event_injection.mark_event_as_partial_state(self.hs, event_id_3, room)
  460. )
  461. # Fail the test if we block on full state for event 3.
  462. async def mock_await_full_state(event_ids: Collection[str]) -> None:
  463. if event_id_3 in event_ids:
  464. raise AssertionError("Tried to await full state for event_id_3")
  465. # ACT
  466. with mock.patch.object(
  467. self.hs.get_storage_controllers().state._partial_state_events_tracker,
  468. "await_full_state",
  469. mock_await_full_state,
  470. ):
  471. self.get_success(per_dest_queue._catch_up_transmission_loop())
  472. # ASSERT
  473. # We should have:
  474. # - not sent event 3: it's not ours, and the room is partial stated
  475. # - fallen back to sending event 2: it's the most recent event in the room
  476. # we tried to send to host2
  477. # - completed catch-up
  478. self.assertEqual(len(sent_pdus), 1)
  479. self.assertEqual(sent_pdus[0].event_id, event_id_2)
  480. self.assertFalse(per_dest_queue._catching_up)
  481. self.assertEqual(
  482. per_dest_queue._last_successful_stream_ordering,
  483. event_2.internal_metadata.stream_ordering,
  484. )