2017-03-27 08:42:07 -06:00
|
|
|
# Copyright 2017 Vector Creations Ltd
|
|
|
|
#
|
|
|
|
# Licensed under the Apache License, Version 2.0 (the "License");
|
|
|
|
# you may not use this file except in compliance with the License.
|
|
|
|
# You may obtain a copy of the License at
|
|
|
|
#
|
|
|
|
# http://www.apache.org/licenses/LICENSE-2.0
|
|
|
|
#
|
|
|
|
# Unless required by applicable law or agreed to in writing, software
|
|
|
|
# distributed under the License is distributed on an "AS IS" BASIS,
|
|
|
|
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
|
|
# See the License for the specific language governing permissions and
|
|
|
|
# limitations under the License.
|
|
|
|
"""The server side of the replication stream.
|
|
|
|
"""
|
|
|
|
|
2018-07-09 00:09:20 -06:00
|
|
|
import logging
|
2019-03-20 10:04:35 -06:00
|
|
|
import random
|
2022-02-08 09:03:08 -07:00
|
|
|
from typing import TYPE_CHECKING, List, Optional, Tuple
|
2018-07-09 00:09:20 -06:00
|
|
|
|
|
|
|
from prometheus_client import Counter
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
from twisted.internet.interfaces import IAddress
|
2021-11-10 13:06:54 -07:00
|
|
|
from twisted.internet.protocol import ServerFactory
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2018-07-25 02:41:12 -06:00
|
|
|
from synapse.metrics.background_process_metrics import run_as_background_process
|
2020-10-12 08:51:41 -06:00
|
|
|
from synapse.replication.tcp.commands import PositionCommand
|
2020-04-07 03:51:07 -06:00
|
|
|
from synapse.replication.tcp.protocol import ServerReplicationStreamProtocol
|
2020-10-12 08:51:41 -06:00
|
|
|
from synapse.replication.tcp.streams import EventsStream
|
2023-10-27 05:51:08 -06:00
|
|
|
from synapse.replication.tcp.streams._base import CachesStream, StreamRow, Token
|
2020-04-07 03:51:07 -06:00
|
|
|
from synapse.util.metrics import Measure
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2021-10-22 11:15:41 -06:00
|
|
|
if TYPE_CHECKING:
|
|
|
|
from synapse.server import HomeServer
|
|
|
|
|
2018-05-22 16:36:20 -06:00
|
|
|
stream_updates_counter = Counter(
|
|
|
|
"synapse_replication_tcp_resource_stream_updates", "", ["stream_name"]
|
|
|
|
)
|
2017-03-27 08:42:07 -06:00
|
|
|
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
|
|
|
|
|
2021-11-10 13:06:54 -07:00
|
|
|
class ReplicationStreamProtocolFactory(ServerFactory):
|
2017-03-27 08:42:07 -06:00
|
|
|
"""Factory for new replication connections."""
|
2019-06-20 03:32:02 -06:00
|
|
|
|
2021-10-22 11:15:41 -06:00
|
|
|
def __init__(self, hs: "HomeServer"):
|
2022-03-10 06:01:56 -07:00
|
|
|
self.command_handler = hs.get_replication_command_handler()
|
2017-03-27 08:42:07 -06:00
|
|
|
self.clock = hs.get_clock()
|
2021-09-13 11:07:12 -06:00
|
|
|
self.server_name = hs.config.server.server_name
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2020-04-07 03:51:07 -06:00
|
|
|
# If we've created a `ReplicationStreamProtocolFactory` then we're
|
|
|
|
# almost certainly registering a replication listener, so let's ensure
|
|
|
|
# that we've started a `ReplicationStreamer` instance to actually push
|
|
|
|
# data.
|
|
|
|
#
|
|
|
|
# (This is a bit of a weird place to do this, but the alternatives such
|
|
|
|
# as putting this in `HomeServer.setup()`, requires either passing the
|
|
|
|
# listener config again or always starting a `ReplicationStreamer`.)
|
|
|
|
hs.get_replication_streamer()
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
def buildProtocol(self, addr: IAddress) -> ServerReplicationStreamProtocol:
|
2017-03-27 08:42:07 -06:00
|
|
|
return ServerReplicationStreamProtocol(
|
2020-04-07 03:51:07 -06:00
|
|
|
self.server_name, self.clock, self.command_handler
|
2017-03-27 08:42:07 -06:00
|
|
|
)
|
|
|
|
|
|
|
|
|
2020-09-04 04:54:56 -06:00
|
|
|
class ReplicationStreamer:
|
2017-03-27 08:42:07 -06:00
|
|
|
"""Handles replication connections.
|
|
|
|
|
2022-03-11 07:00:15 -07:00
|
|
|
This needs to be poked when new replication data may be available.
|
|
|
|
When new data is available it will propagate to all Redis subscribers.
|
2017-03-27 08:42:07 -06:00
|
|
|
"""
|
|
|
|
|
2021-10-22 11:15:41 -06:00
|
|
|
def __init__(self, hs: "HomeServer"):
|
2022-02-23 04:04:02 -07:00
|
|
|
self.store = hs.get_datastores().main
|
2017-03-27 08:42:07 -06:00
|
|
|
self.clock = hs.get_clock()
|
2017-06-09 04:24:41 -06:00
|
|
|
self.notifier = hs.get_notifier()
|
2020-05-07 06:51:08 -06:00
|
|
|
self._instance_name = hs.get_instance_name()
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2021-09-29 04:44:15 -06:00
|
|
|
self._replication_torture_level = hs.config.server.replication_torture_level
|
2019-03-20 10:04:35 -06:00
|
|
|
|
2020-05-13 03:27:02 -06:00
|
|
|
self.notifier.add_replication_callback(self.on_notifier_poke)
|
2017-03-27 08:42:07 -06:00
|
|
|
|
|
|
|
# Keeps track of whether we are currently checking for updates
|
|
|
|
self.is_looping = False
|
|
|
|
self.pending_updates = False
|
|
|
|
|
2022-03-10 06:01:56 -07:00
|
|
|
self.command_handler = hs.get_replication_command_handler()
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2020-05-13 03:27:02 -06:00
|
|
|
# Set of streams to replicate.
|
|
|
|
self.streams = self.command_handler.get_streams_to_replicate()
|
2020-03-25 08:54:01 -06:00
|
|
|
|
2020-10-12 08:51:41 -06:00
|
|
|
# If we have streams then we must have redis enabled or on master
|
|
|
|
assert (
|
|
|
|
not self.streams
|
|
|
|
or hs.config.redis.redis_enabled
|
|
|
|
or not hs.config.worker.worker_app
|
|
|
|
)
|
|
|
|
|
|
|
|
# If we are replicating an event stream we want to periodically check if
|
|
|
|
# we should send updated POSITIONs. We do this as a looping call rather
|
|
|
|
# explicitly poking when the position advances (without new data to
|
|
|
|
# replicate) to reduce replication traffic (otherwise each writer would
|
|
|
|
# likely send a POSITION for each new event received over replication).
|
|
|
|
#
|
|
|
|
# Note that if the position hasn't advanced then we won't send anything.
|
|
|
|
if any(EventsStream.NAME == s.NAME for s in self.streams):
|
|
|
|
self.clock.looping_call(self.on_notifier_poke, 1000)
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
def on_notifier_poke(self) -> None:
|
2017-03-27 08:42:07 -06:00
|
|
|
"""Checks if there is actually any new data and sends it to the
|
2022-03-11 07:00:15 -07:00
|
|
|
Redis subscribers if there are.
|
2017-03-27 08:42:07 -06:00
|
|
|
|
|
|
|
This should get called each time new data is available, even if it
|
|
|
|
is currently being executed, so that nothing gets missed
|
|
|
|
"""
|
2020-10-12 08:51:41 -06:00
|
|
|
if not self.command_handler.connected() or not self.streams:
|
2017-04-03 08:22:56 -06:00
|
|
|
# Don't bother if nothing is listening. We still need to advance
|
2020-09-14 09:46:58 -06:00
|
|
|
# the stream tokens otherwise they'll fall behind forever
|
2017-04-03 08:22:56 -06:00
|
|
|
for stream in self.streams:
|
2017-04-04 06:19:26 -06:00
|
|
|
stream.discard_updates_and_advance()
|
2017-03-27 08:42:07 -06:00
|
|
|
return
|
|
|
|
|
2020-10-27 11:37:08 -06:00
|
|
|
# We check up front to see if anything has actually changed, as we get
|
|
|
|
# poked because of changes that happened on other instances.
|
2023-11-16 06:05:09 -07:00
|
|
|
if not self.command_handler.should_announce_positions() and all(
|
2020-10-27 11:37:08 -06:00
|
|
|
stream.last_token == stream.current_token(self._instance_name)
|
|
|
|
for stream in self.streams
|
|
|
|
):
|
|
|
|
return
|
|
|
|
|
|
|
|
# If there are updates then we need to set this even if we're already
|
|
|
|
# looping, as the loop needs to know that he might need to loop again.
|
2018-07-25 02:41:12 -06:00
|
|
|
self.pending_updates = True
|
|
|
|
|
2017-03-27 08:42:07 -06:00
|
|
|
if self.is_looping:
|
2018-07-25 02:41:12 -06:00
|
|
|
logger.debug("Notifier poke loop already running")
|
2017-03-27 08:42:07 -06:00
|
|
|
return
|
|
|
|
|
2018-07-25 02:41:12 -06:00
|
|
|
run_as_background_process("replication_notifier", self._run_notifier_loop)
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
async def _run_notifier_loop(self) -> None:
|
2017-03-27 08:42:07 -06:00
|
|
|
self.is_looping = True
|
|
|
|
|
|
|
|
try:
|
|
|
|
# Keep looping while there have been pokes about potential updates.
|
|
|
|
# This protects against the race where a stream we already checked
|
|
|
|
# gets an update while we're handling other streams.
|
|
|
|
while self.pending_updates:
|
|
|
|
self.pending_updates = False
|
|
|
|
|
|
|
|
with Measure(self.clock, "repl.stream.get_updates"):
|
2019-03-20 10:04:35 -06:00
|
|
|
all_streams = self.streams
|
|
|
|
|
|
|
|
if self._replication_torture_level is not None:
|
|
|
|
# there is no guarantee about ordering between the streams,
|
|
|
|
# so let's shuffle them around a bit when we are in torture mode.
|
|
|
|
all_streams = list(all_streams)
|
|
|
|
random.shuffle(all_streams)
|
|
|
|
|
2023-11-16 06:05:09 -07:00
|
|
|
if self.command_handler.should_announce_positions():
|
|
|
|
# We need to send out POSITIONs for all streams, usually
|
|
|
|
# because a worker has reconnected.
|
|
|
|
self.command_handler.will_announce_positions()
|
|
|
|
|
|
|
|
for stream in all_streams:
|
|
|
|
self.command_handler.send_command(
|
|
|
|
PositionCommand(
|
|
|
|
stream.NAME,
|
|
|
|
self._instance_name,
|
|
|
|
stream.last_token,
|
|
|
|
stream.last_token,
|
|
|
|
)
|
|
|
|
)
|
|
|
|
|
2019-03-20 10:04:35 -06:00
|
|
|
for stream in all_streams:
|
2020-05-07 06:51:08 -06:00
|
|
|
if stream.last_token == stream.current_token(
|
|
|
|
self._instance_name
|
|
|
|
):
|
2017-03-27 08:42:07 -06:00
|
|
|
continue
|
|
|
|
|
2019-03-20 10:04:35 -06:00
|
|
|
if self._replication_torture_level:
|
2020-01-16 02:16:12 -07:00
|
|
|
await self.clock.sleep(
|
2019-03-20 10:04:35 -06:00
|
|
|
self._replication_torture_level / 1000.0
|
|
|
|
)
|
|
|
|
|
2020-10-12 08:51:41 -06:00
|
|
|
last_token = stream.last_token
|
|
|
|
|
2017-03-27 08:42:07 -06:00
|
|
|
logger.debug(
|
|
|
|
"Getting stream: %s: %s -> %s",
|
|
|
|
stream.NAME,
|
|
|
|
stream.last_token,
|
2020-05-07 06:51:08 -06:00
|
|
|
stream.current_token(self._instance_name),
|
2017-03-27 08:42:07 -06:00
|
|
|
)
|
2017-10-12 04:50:44 -06:00
|
|
|
try:
|
2020-03-25 08:54:01 -06:00
|
|
|
updates, current_token, limited = await stream.get_updates()
|
|
|
|
self.pending_updates |= limited
|
2017-10-23 08:52:32 -06:00
|
|
|
except Exception:
|
2017-10-12 04:50:44 -06:00
|
|
|
logger.info("Failed to handle stream %s", stream.NAME)
|
|
|
|
raise
|
2017-03-27 08:42:07 -06:00
|
|
|
|
|
|
|
logger.debug(
|
2020-04-07 03:51:07 -06:00
|
|
|
"Sending %d updates",
|
|
|
|
len(updates),
|
2017-03-27 08:42:07 -06:00
|
|
|
)
|
|
|
|
|
|
|
|
if updates:
|
|
|
|
logger.info(
|
2023-09-13 03:51:50 -06:00
|
|
|
"Streaming: %s -> %s (limited: %s, updates: %s, max token: %s)",
|
|
|
|
stream.NAME,
|
|
|
|
updates[-1][0],
|
|
|
|
limited,
|
|
|
|
len(updates),
|
|
|
|
current_token,
|
2017-03-27 08:42:07 -06:00
|
|
|
)
|
2018-05-21 18:48:57 -06:00
|
|
|
stream_updates_counter.labels(stream.NAME).inc(len(updates))
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2020-10-12 08:51:41 -06:00
|
|
|
else:
|
|
|
|
# The token has advanced but there is no data to
|
|
|
|
# send, so we send a `POSITION` to inform other
|
|
|
|
# workers of the updated position.
|
2023-10-27 05:51:08 -06:00
|
|
|
#
|
|
|
|
# There are two reasons for this: 1) this instance
|
|
|
|
# requested a stream ID but didn't use it, or 2)
|
|
|
|
# this instance advanced its own stream position due
|
|
|
|
# to receiving notifications about other instances
|
|
|
|
# advancing their stream position.
|
|
|
|
|
|
|
|
# We skip sending `POSITION` for the `caches` stream
|
|
|
|
# for the second case as a) it generates a lot of
|
|
|
|
# traffic as every worker would echo each write, and
|
|
|
|
# b) nothing cares if a given worker's caches stream
|
|
|
|
# position lags.
|
|
|
|
if stream.NAME == CachesStream.NAME:
|
|
|
|
# If there haven't been any writes since the
|
|
|
|
# `last_token` then we're in the second case.
|
|
|
|
if stream.minimal_local_current_token() <= last_token:
|
|
|
|
continue
|
2023-01-18 12:35:29 -07:00
|
|
|
|
|
|
|
# Note: `last_token` may not *actually* be the
|
|
|
|
# last token we sent out in a RDATA or POSITION.
|
|
|
|
# This can happen if we sent out an RDATA for
|
|
|
|
# position X when our current token was say X+1.
|
|
|
|
# Other workers will see RDATA for X and then a
|
|
|
|
# POSITION with last token of X+1, which will
|
|
|
|
# cause them to check if there were any missing
|
|
|
|
# updates between X and X+1.
|
|
|
|
logger.info(
|
|
|
|
"Sending position: %s -> %s",
|
|
|
|
stream.NAME,
|
|
|
|
current_token,
|
|
|
|
)
|
|
|
|
self.command_handler.send_command(
|
|
|
|
PositionCommand(
|
2020-10-12 08:51:41 -06:00
|
|
|
stream.NAME,
|
2023-01-18 12:35:29 -07:00
|
|
|
self._instance_name,
|
|
|
|
last_token,
|
2020-10-12 08:51:41 -06:00
|
|
|
current_token,
|
|
|
|
)
|
2023-01-18 12:35:29 -07:00
|
|
|
)
|
2020-10-12 08:51:41 -06:00
|
|
|
continue
|
|
|
|
|
2017-03-27 08:42:07 -06:00
|
|
|
# Some streams return multiple rows with the same stream IDs,
|
|
|
|
# we need to make sure they get sent out in batches. We do
|
|
|
|
# this by setting the current token to all but the last of
|
|
|
|
# a series of updates with the same token to have a None
|
|
|
|
# token. See RdataCommand for more details.
|
|
|
|
batched_updates = _batch_updates(updates)
|
|
|
|
|
2020-04-07 03:51:07 -06:00
|
|
|
for token, row in batched_updates:
|
|
|
|
try:
|
|
|
|
self.command_handler.stream_update(
|
|
|
|
stream.NAME, token, row
|
|
|
|
)
|
|
|
|
except Exception:
|
|
|
|
logger.exception("Failed to replicate")
|
2017-03-27 08:42:07 -06:00
|
|
|
|
2023-02-24 07:39:50 -07:00
|
|
|
# The last token we send may not match the current
|
|
|
|
# token, in which case we want to send out a `POSITION`
|
|
|
|
# to tell other workers the actual current position.
|
|
|
|
if updates[-1][0] < current_token:
|
|
|
|
logger.info(
|
|
|
|
"Sending position: %s -> %s",
|
|
|
|
stream.NAME,
|
|
|
|
current_token,
|
|
|
|
)
|
|
|
|
self.command_handler.send_command(
|
|
|
|
PositionCommand(
|
|
|
|
stream.NAME,
|
|
|
|
self._instance_name,
|
|
|
|
updates[-1][0],
|
|
|
|
current_token,
|
|
|
|
)
|
|
|
|
)
|
|
|
|
|
2017-03-27 08:42:07 -06:00
|
|
|
logger.debug("No more pending updates, breaking poke loop")
|
|
|
|
finally:
|
|
|
|
self.pending_updates = False
|
|
|
|
self.is_looping = False
|
|
|
|
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
def _batch_updates(
|
|
|
|
updates: List[Tuple[Token, StreamRow]]
|
|
|
|
) -> List[Tuple[Optional[Token], StreamRow]]:
|
2017-03-27 08:42:07 -06:00
|
|
|
"""Takes a list of updates of form [(token, row)] and sets the token to
|
|
|
|
None for all rows where the next row has the same token. This is used to
|
|
|
|
implement batching.
|
|
|
|
|
|
|
|
For example:
|
|
|
|
|
|
|
|
[(1, _), (1, _), (2, _), (3, _), (3, _)]
|
|
|
|
|
|
|
|
becomes:
|
|
|
|
|
|
|
|
[(None, _), (1, _), (2, _), (None, _), (3, _)]
|
|
|
|
"""
|
|
|
|
if not updates:
|
|
|
|
return []
|
|
|
|
|
2022-02-08 09:03:08 -07:00
|
|
|
new_updates: List[Tuple[Optional[Token], StreamRow]] = []
|
2017-03-27 08:42:07 -06:00
|
|
|
for i, update in enumerate(updates[:-1]):
|
|
|
|
if update[0] == updates[i + 1][0]:
|
|
|
|
new_updates.append((None, update[1]))
|
|
|
|
else:
|
|
|
|
new_updates.append(update)
|
|
|
|
|
|
|
|
new_updates.append(updates[-1])
|
|
|
|
return new_updates
|