synapse-old/synapse/notifier.py

562 lines
20 KiB
Python
Raw Normal View History

# -*- coding: utf-8 -*-
# Copyright 2014 - 2016 OpenMarket 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.
2014-11-19 09:40:01 -07:00
from twisted.internet import defer
from synapse.api.constants import EventTypes, Membership
from synapse.api.errors import AuthError
from synapse.handlers.presence import format_user_presence_state
2016-12-09 09:30:29 -07:00
from synapse.util import DeferredTimedOutError
2014-08-28 11:45:00 -06:00
from synapse.util.logutils import log_function
2016-02-04 03:22:44 -07:00
from synapse.util.async import ObservableDeferred
2016-08-23 08:23:39 -06:00
from synapse.util.logcontext import PreserveLoggingContext, preserve_fn
2016-08-19 10:33:12 -06:00
from synapse.util.metrics import Measure
from synapse.types import StreamToken
from synapse.visibility import filter_events_for_client
import synapse.metrics
from collections import namedtuple
import logging
logger = logging.getLogger(__name__)
metrics = synapse.metrics.get_metrics_for(__name__)
notified_events_counter = metrics.register_counter("notified_events")
2017-03-15 04:56:51 -06:00
users_woken_by_stream_counter = metrics.register_counter(
"users_woken_by_stream", labels=["stream"]
)
# TODO(paul): Should be shared somewhere
def count(func, l):
"""Return the number of items in l for which func returns true."""
n = 0
for x in l:
if func(x):
n += 1
return n
class _NotificationListener(object):
2014-08-27 10:04:47 -06:00
""" This represents a single client connection to the events stream.
The events stream handler will have yielded to the deferred, so to
notify the handler it is sufficient to resolve the deferred.
"""
__slots__ = ["deferred"]
2014-08-27 10:04:47 -06:00
def __init__(self, deferred):
self.deferred = deferred
class _NotifierUserStream(object):
"""This represents a user connected to the event stream.
It tracks the most recent stream token for that user.
At a given point a user may have a number of streams listening for
events.
This listener will also keep track of which rooms it is listening in
so that it can remove itself from the indexes in the Notifier class.
"""
2016-08-17 04:48:23 -06:00
def __init__(self, user_id, rooms, current_token, time_now_ms):
self.user_id = user_id
self.rooms = set(rooms)
self.current_token = current_token
2017-03-14 09:03:46 -06:00
# The last token for which we should wake up any streams that have a
# token that comes before it. This gets updated everytime we get poked.
# We start it at the current token since if we get any streams
# that have a token from before we have no idea whether they should be
# woken up or not, so lets just wake them up.
self.last_notified_token = current_token
2015-05-13 09:54:02 -06:00
self.last_notified_ms = time_now_ms
2016-02-04 03:22:44 -07:00
with PreserveLoggingContext():
self.notify_deferred = ObservableDeferred(defer.Deferred())
2015-05-13 09:54:02 -06:00
def notify(self, stream_key, stream_id, time_now_ms):
2015-05-14 07:35:07 -06:00
"""Notify any listeners for this user of a new event from an
event source.
Args:
stream_key(str): The stream the event came from.
stream_id(str): The new id for the stream the event came from.
time_now_ms(int): The current time in milliseconds.
"""
self.current_token = self.current_token.copy_and_advance(
stream_key, stream_id
)
2017-03-14 09:03:46 -06:00
self.last_notified_token = self.current_token
self.last_notified_ms = time_now_ms
noify_deferred = self.notify_deferred
2016-02-04 03:22:44 -07:00
2017-03-15 04:56:51 -06:00
users_woken_by_stream_counter.inc(stream_key)
2016-02-04 03:22:44 -07:00
with PreserveLoggingContext():
self.notify_deferred = ObservableDeferred(defer.Deferred())
noify_deferred.callback(self.current_token)
def remove(self, notifier):
""" Remove this listener from all the indexes in the Notifier
it knows about.
"""
for room in self.rooms:
lst = notifier.room_to_user_streams.get(room, set())
lst.discard(self)
notifier.user_to_user_stream.pop(self.user_id)
def count_listeners(self):
2015-06-19 09:22:53 -06:00
return len(self.notify_deferred.observers())
def new_listener(self, token):
"""Returns a deferred that is resolved when there is a new token
greater than the given token.
2017-03-14 09:03:46 -06:00
Args:
token: The token from which we are streaming from, i.e. we shouldn't
notify for things that happened before this.
"""
2017-03-14 09:03:46 -06:00
# Immediately wake up stream if something has already since happened
# since their last token.
if self.last_notified_token.is_after(token):
return _NotificationListener(defer.succeed(self.current_token))
else:
return _NotificationListener(self.notify_deferred.observe())
class EventStreamResult(namedtuple("EventStreamResult", ("events", "tokens"))):
def __nonzero__(self):
return bool(self.events)
class Notifier(object):
2014-08-27 10:04:47 -06:00
""" This class is responsible for notifying any listeners when there are
new events available for it.
Primarily used from the /events stream.
"""
2015-05-13 09:54:02 -06:00
UNUSED_STREAM_EXPIRY_MS = 10 * 60 * 1000
def __init__(self, hs):
self.user_to_user_stream = {}
self.room_to_user_streams = {}
self.event_sources = hs.get_event_sources()
self.store = hs.get_datastore()
self.pending_new_room_events = []
self.replication_callbacks = []
self.clock = hs.get_clock()
self.appservice_handler = hs.get_application_service_handler()
if hs.should_send_federation():
self.federation_sender = hs.get_federation_sender()
else:
self.federation_sender = None
self.state_handler = hs.get_state_handler()
2015-05-13 09:54:02 -06:00
self.clock.looping_call(
self.remove_expired_streams, self.UNUSED_STREAM_EXPIRY_MS
)
self.replication_deferred = ObservableDeferred(defer.Deferred())
# This is not a very cheap test to perform, but it's only executed
# when rendering the metrics page, which is likely once per minute at
# most when scraping it.
def count_listeners():
all_user_streams = set()
for x in self.room_to_user_streams.values():
all_user_streams |= x
for x in self.user_to_user_stream.values():
2015-05-13 10:20:28 -06:00
all_user_streams.add(x)
return sum(stream.count_listeners() for stream in all_user_streams)
metrics.register_callback("listeners", count_listeners)
2015-03-12 10:24:38 -06:00
metrics.register_callback(
"rooms",
lambda: count(bool, self.room_to_user_streams.values()),
)
2015-03-12 10:24:38 -06:00
metrics.register_callback(
"users",
lambda: len(self.user_to_user_stream),
)
def add_replication_callback(self, cb):
"""Add a callback that will be called when some new data is available.
Callback is not given any arguments.
"""
self.replication_callbacks.append(cb)
def on_new_room_event(self, event, room_stream_id, max_room_stream_id,
extra_users=[]):
2014-08-27 10:04:47 -06:00
""" Used by handlers to inform the notifier something has happened
in the room, room event wise.
This triggers the notifier to wake up any listeners that are
listening to the room, and any listeners for the users in the
`extra_users` param.
2015-05-14 07:35:07 -06:00
The events can be peristed out of order. The notifier will wait
until all previous events have been persisted before notifying
the client streams.
2014-08-27 10:04:47 -06:00
"""
self.pending_new_room_events.append((
room_stream_id, event, extra_users
))
self._notify_pending_new_room_events(max_room_stream_id)
2015-05-14 07:35:07 -06:00
self.notify_replication()
2015-05-14 07:35:07 -06:00
def _notify_pending_new_room_events(self, max_room_stream_id):
"""Notify for the room events that were queued waiting for a previous
event to be persisted.
Args:
max_room_stream_id(int): The highest stream_id below which all
events have been persisted.
"""
pending = self.pending_new_room_events
2015-05-14 07:35:07 -06:00
self.pending_new_room_events = []
for room_stream_id, event, extra_users in pending:
2015-05-14 07:35:07 -06:00
if room_stream_id > max_room_stream_id:
self.pending_new_room_events.append((
room_stream_id, event, extra_users
2015-05-14 07:35:07 -06:00
))
else:
self._on_new_room_event(event, room_stream_id, extra_users)
def _on_new_room_event(self, event, room_stream_id, extra_users=[]):
2015-05-14 07:35:07 -06:00
"""Notify any user streams that are interested in this room event"""
# poke any interested application service.
preserve_fn(self.appservice_handler.notify_interested_services)(
2017-05-31 04:51:01 -06:00
room_stream_id
)
if self.federation_sender:
preserve_fn(self.federation_sender.notify_new_events)(
room_stream_id
)
if event.type == EventTypes.Member and event.membership == Membership.JOIN:
self._user_joined_room(event.state_key, event.room_id)
2015-07-02 04:40:56 -06:00
self.on_new_event(
"room_key", room_stream_id,
users=extra_users,
rooms=[event.room_id],
)
2016-08-17 04:48:23 -06:00
def on_new_event(self, stream_key, new_token, users=[], rooms=[]):
2015-07-02 04:40:56 -06:00
""" Used to inform listeners that something has happend event wise.
2014-08-27 10:04:47 -06:00
Will wake up all listeners for the given users and rooms.
"""
2016-02-04 03:22:44 -07:00
with PreserveLoggingContext():
2016-08-19 10:33:12 -06:00
with Measure(self.clock, "on_new_event"):
user_streams = set()
2016-08-19 10:33:12 -06:00
for user in users:
user_stream = self.user_to_user_stream.get(str(user))
if user_stream is not None:
user_streams.add(user_stream)
2016-08-19 10:33:12 -06:00
for room in rooms:
user_streams |= self.room_to_user_streams.get(room, set())
2016-08-19 10:33:12 -06:00
time_now_ms = self.clock.time_msec()
for user_stream in user_streams:
try:
user_stream.notify(stream_key, new_token, time_now_ms)
except:
logger.exception("Failed to notify listener")
2016-08-19 10:33:12 -06:00
self.notify_replication()
def on_new_replication_data(self):
"""Used to inform replication listeners that something has happend
without waking up any of the normal user event streams"""
with PreserveLoggingContext():
self.notify_replication()
@defer.inlineCallbacks
def wait_for_events(self, user_id, timeout, callback, room_ids=None,
2016-03-03 07:57:45 -07:00
from_token=StreamToken.START):
"""Wait until the callback returns a non empty response or the
timeout fires.
"""
user_stream = self.user_to_user_stream.get(user_id)
if user_stream is None:
current_token = yield self.event_sources.get_current_token()
if room_ids is None:
2017-03-16 05:51:46 -06:00
room_ids = yield self.store.get_rooms_for_user(user_id)
user_stream = _NotifierUserStream(
user_id=user_id,
rooms=room_ids,
current_token=current_token,
time_now_ms=self.clock.time_msec(),
)
self._register_with_keys(user_stream)
2015-06-18 04:36:26 -06:00
result = None
2017-03-14 09:03:46 -06:00
prev_token = from_token
if timeout:
end_time = self.clock.time_msec() + timeout
while not result:
2015-06-18 04:36:26 -06:00
try:
now = self.clock.time_msec()
if end_time <= now:
break
2015-06-18 09:15:10 -06:00
# Now we wait for the _NotifierUserStream to be told there
# is a new token.
listener = user_stream.new_listener(prev_token)
2016-02-04 03:22:44 -07:00
with PreserveLoggingContext():
yield self.clock.time_bound_deferred(
listener.deferred,
time_out=(end_time - now) / 1000.
)
2017-03-14 09:03:46 -06:00
current_token = user_stream.current_token
result = yield callback(prev_token, current_token)
if result:
break
# Update the prev_token to the current_token since nothing
# has happened between the old prev_token and the current_token
prev_token = current_token
2016-12-09 09:30:29 -07:00
except DeferredTimedOutError:
break
except defer.CancelledError:
break
2017-03-14 09:03:46 -06:00
if result is None:
# This happened if there was no timeout or if the timeout had
# already expired.
current_token = user_stream.current_token
2017-03-14 09:03:46 -06:00
result = yield callback(prev_token, current_token)
defer.returnValue(result)
@defer.inlineCallbacks
2015-11-02 08:10:59 -07:00
def get_events_for(self, user, pagination_config, timeout,
only_keys=None,
is_guest=False, explicit_room_id=None):
2014-08-27 10:04:47 -06:00
""" For the given user and rooms, return any new events for them. If
there are no new events wait for up to `timeout` milliseconds for any
new events to happen before returning.
If `only_keys` is not None, events from keys will be sent down.
If explicit_room_id is not set, the user's joined rooms will be polled
for events.
If explicit_room_id is set, that room will be polled for events only if
it is world readable or the user has joined the room.
2014-08-27 10:04:47 -06:00
"""
from_token = pagination_config.from_token
if not from_token:
from_token = yield self.event_sources.get_current_token()
limit = pagination_config.limit
room_ids, is_joined = yield self._get_room_ids(user, explicit_room_id)
is_peeking = not is_joined
@defer.inlineCallbacks
def check_for_updates(before_token, after_token):
if not after_token.is_after(before_token):
defer.returnValue(EventStreamResult([], (from_token, from_token)))
events = []
end_token = from_token
for name, source in self.event_sources.sources.items():
keyname = "%s_key" % name
before_id = getattr(before_token, keyname)
after_id = getattr(after_token, keyname)
if before_id == after_id:
continue
if only_keys and name not in only_keys:
continue
new_events, new_key = yield source.get_new_events(
user=user,
from_key=getattr(from_token, keyname),
limit=limit,
is_guest=is_peeking,
room_ids=room_ids,
explicit_room_id=explicit_room_id,
)
if name == "room":
new_events = yield filter_events_for_client(
self.store,
user.to_string(),
new_events,
is_peeking=is_peeking,
)
elif name == "presence":
now = self.clock.time_msec()
new_events[:] = [
{
"type": "m.presence",
"content": format_user_presence_state(event, now),
}
for event in new_events
]
2015-07-20 07:32:12 -06:00
events.extend(new_events)
end_token = end_token.copy_and_replace(keyname, new_key)
2014-11-20 10:26:36 -07:00
defer.returnValue(EventStreamResult(events, (from_token, end_token)))
user_id_for_stream = user.to_string()
if is_peeking:
# Internally, the notifier keeps an event stream per user_id.
# This is used by both /sync and /events.
# We want /events to be used for peeking independently of /sync,
# without polluting its contents. So we invent an illegal user ID
# (which thus cannot clash with any real users) for keying peeking
# over /events.
#
# I am sorry for what I have done.
user_id_for_stream = "_PEEKING_%s_%s" % (
explicit_room_id, user_id_for_stream
)
result = yield self.wait_for_events(
user_id_for_stream,
timeout,
check_for_updates,
room_ids=room_ids,
from_token=from_token,
)
2014-08-27 10:21:30 -06:00
defer.returnValue(result)
@defer.inlineCallbacks
def _get_room_ids(self, user, explicit_room_id):
2017-03-16 05:51:46 -06:00
joined_room_ids = yield self.store.get_rooms_for_user(user.to_string())
if explicit_room_id:
if explicit_room_id in joined_room_ids:
defer.returnValue(([explicit_room_id], True))
if (yield self._is_world_readable(explicit_room_id)):
defer.returnValue(([explicit_room_id], False))
raise AuthError(403, "Non-joined access not allowed")
defer.returnValue((joined_room_ids, True))
@defer.inlineCallbacks
def _is_world_readable(self, room_id):
state = yield self.state_handler.get_current_state(
room_id,
EventTypes.RoomHistoryVisibility,
"",
)
if state and "history_visibility" in state.content:
defer.returnValue(state.content["history_visibility"] == "world_readable")
else:
defer.returnValue(False)
2015-05-13 09:54:02 -06:00
@log_function
def remove_expired_streams(self):
time_now_ms = self.clock.time_msec()
expired_streams = []
expire_before_ts = time_now_ms - self.UNUSED_STREAM_EXPIRY_MS
for stream in self.user_to_user_stream.values():
if stream.count_listeners():
2015-05-13 09:54:02 -06:00
continue
if stream.last_notified_ms < expire_before_ts:
expired_streams.append(stream)
for expired_stream in expired_streams:
expired_stream.remove(self)
@log_function
def _register_with_keys(self, user_stream):
self.user_to_user_stream[user_stream.user_id] = user_stream
for room in user_stream.rooms:
s = self.room_to_user_streams.setdefault(room, set())
s.add(user_stream)
def _user_joined_room(self, user_id, room_id):
new_user_stream = self.user_to_user_stream.get(user_id)
if new_user_stream is not None:
room_streams = self.room_to_user_streams.setdefault(room_id, set())
room_streams.add(new_user_stream)
new_user_stream.rooms.add(room_id)
def notify_replication(self):
"""Notify the any replication listeners that there's a new event"""
with PreserveLoggingContext():
deferred = self.replication_deferred
self.replication_deferred = ObservableDeferred(defer.Deferred())
deferred.callback(None)
for cb in self.replication_callbacks:
preserve_fn(cb)()
@defer.inlineCallbacks
def wait_for_replication(self, callback, timeout):
"""Wait for an event to happen.
Args:
callback: Gets called whenever an event happens. If this returns a
truthy value then ``wait_for_replication`` returns, otherwise
it waits for another event.
timeout: How many milliseconds to wait for callback return a truthy
value.
Returns:
A deferred that resolves with the value returned by the callback.
"""
listener = _NotificationListener(None)
2016-12-09 09:30:29 -07:00
end_time = self.clock.time_msec() + timeout
while True:
listener.deferred = self.replication_deferred.observe()
result = yield callback()
if result:
break
2016-12-09 09:30:29 -07:00
now = self.clock.time_msec()
if end_time <= now:
break
try:
with PreserveLoggingContext():
2016-12-09 09:30:29 -07:00
yield self.clock.time_bound_deferred(
listener.deferred,
time_out=(end_time - now) / 1000.
)
except DeferredTimedOutError:
break
except defer.CancelledError:
break
defer.returnValue(result)