def start_purge_history(self, room_id, token, delete_local_events=False): """Start off a history purge on a room. Args: room_id (str): The room to purge from token (str): topological token to delete events before delete_local_events (bool): True to delete local events as well as remote ones Returns: str: unique ID for this purge transaction. """ if room_id in self._purges_in_progress_by_room: raise SynapseError( 400, "History purge already in progress for %s" % (room_id, ), ) purge_id = random_string(16) # we log the purge_id here so that it can be tied back to the # request id in the log lines. logger.info("[purge] starting purge_id %s", purge_id) self._purges_by_id[purge_id] = PurgeStatus() run_in_background( self._purge_history, purge_id, room_id, token, delete_local_events, ) return purge_id
def verify_json_objects_for_server(self, server_and_json): """Bulk verifies signatures of json objects, bulk fetching keys as necessary. Args: server_and_json (list): List of pairs of (server_name, json_object) Returns: List<Deferred>: for each input pair, a deferred indicating success or failure to verify each json object's signature for the given server_name. The deferreds run their callbacks in the sentinel logcontext. """ # a list of VerifyKeyRequests verify_requests = [] handle = preserve_fn(_handle_key_deferred) def process(server_name, json_object): """Process an entry in the request list Given a (server_name, json_object) pair from the request list, adds a key request to verify_requests, and returns a deferred which will complete or fail (in the sentinel context) when verification completes. """ key_ids = signature_ids(json_object, server_name) if not key_ids: return defer.fail( SynapseError( 400, "Not signed by %s" % (server_name,), Codes.UNAUTHORIZED, ) ) logger.debug("Verifying for %s with key_ids %s", server_name, key_ids) # add the key request to the queue, but don't start it off yet. verify_request = VerifyKeyRequest( server_name, key_ids, json_object, defer.Deferred(), ) verify_requests.append(verify_request) # now run _handle_key_deferred, which will wait for the key request # to complete and then do the verification. # # We want _handle_key_request to log to the right context, so we # wrap it with preserve_fn (aka run_in_background) return handle(verify_request) results = [ process(server_name, json_object) for server_name, json_object in server_and_json ] if verify_requests: run_in_background(self._start_key_lookups, verify_requests) return results
def _push_update(self, member, typing): if self.hs.is_mine_id(member.user_id): # Only send updates for changes to our own users. run_in_background(self._push_remote, member, typing) self._push_update_local( member=member, typing=typing )
def process_replication_rows(self, stream_name, token, rows): # The federation stream contains things that we want to send out, e.g. # presence, typing, etc. if stream_name == "federation": send_queue.process_rows_for_federation(self.federation_sender, rows) run_in_background(self.update_token, token) # We also need to poke the federation sender when new events happen elif stream_name == "events": self.federation_sender.notify_new_events(token)
def _start_user_parting(self): """ Start the process that goes through the table of users pending deactivation, if it isn't already running. Returns: None """ if not self._user_parter_running: run_in_background(self._user_parter_loop)
def authenticate_request(self, request, content): json_request = { "method": request.method.decode('ascii'), "uri": request.uri.decode('ascii'), "destination": self.server_name, "signatures": {}, } if content is not None: json_request["content"] = content origin = None auth_headers = request.requestHeaders.getRawHeaders(b"Authorization") if not auth_headers: raise NoAuthenticationError( 401, "Missing Authorization headers", Codes.UNAUTHORIZED, ) for auth in auth_headers: if auth.startswith(b"X-Matrix"): (origin, key, sig) = _parse_auth_header(auth) json_request["origin"] = origin json_request["signatures"].setdefault(origin, {})[key] = sig if ( self.federation_domain_whitelist is not None and origin not in self.federation_domain_whitelist ): raise FederationDeniedError(origin) if not json_request["signatures"]: raise NoAuthenticationError( 401, "Missing Authorization headers", Codes.UNAUTHORIZED, ) yield self.keyring.verify_json_for_server(origin, json_request) logger.info("Request from %s", origin) request.authenticated_entity = origin # If we get a valid signed request from the other side, its probably # alive retry_timings = yield self.store.get_destination_retry_timings(origin) if retry_timings and retry_timings["retry_last_ts"]: run_in_background(self._reset_retry_timings, origin) defer.returnValue(origin)
def _renew_attestations(self): """Called periodically to check if we need to update any of our attestations """ now = self.clock.time_msec() rows = yield self.store.get_attestations_need_renewals( now + UPDATE_ATTESTATION_TIME_MS ) @defer.inlineCallbacks def _renew_attestation(group_id, user_id): try: if not self.is_mine_id(group_id): destination = get_domain_from_id(group_id) elif not self.is_mine_id(user_id): destination = get_domain_from_id(user_id) else: logger.warn( "Incorrectly trying to do attestations for user: %r in %r", user_id, group_id, ) yield self.store.remove_attestation_renewal(group_id, user_id) return attestation = self.attestations.create_attestation(group_id, user_id) yield self.transport_client.renew_group_attestation( destination, group_id, user_id, content={"attestation": attestation}, ) yield self.store.update_attestation_renewal( group_id, user_id, attestation ) except RequestSendFailed as e: logger.warning( "Failed to renew attestation of %r in %r: %s", user_id, group_id, e, ) except Exception: logger.exception("Error renewing attestation of %r in %r", user_id, group_id) for row in rows: group_id = row["group_id"] user_id = row["user_id"] run_in_background(_renew_attestation, group_id, user_id)
def send(self, service, events): try: txn = yield self.store.create_appservice_txn( service=service, events=events ) service_is_up = yield self._is_service_up(service) if service_is_up: sent = yield txn.send(self.as_api) if sent: yield txn.complete(self.store) else: run_in_background(self._start_recoverer, service) except Exception: logger.exception("Error creating appservice transaction") run_in_background(self._start_recoverer, service)
def get_keys_from_perspectives(self, server_name_and_key_ids): @defer.inlineCallbacks def get_key(perspective_name, perspective_keys): try: result = yield self.get_server_verify_key_v2_indirect( server_name_and_key_ids, perspective_name, perspective_keys ) defer.returnValue(result) except KeyLookupError as e: logger.warning( "Key lookup failed from %r: %s", perspective_name, e, ) except Exception as e: logger.exception( "Unable to get key from %r: %s %s", perspective_name, type(e).__name__, str(e), ) defer.returnValue({}) results = yield logcontext.make_deferred_yieldable(defer.gatherResults( [ run_in_background(get_key, p_name, p_keys) for p_name, p_keys in self.perspective_servers.items() ], consumeErrors=True, ).addErrback(unwrapFirstError)) union_of_keys = {} for result in results: for server_name, keys in result.items(): union_of_keys.setdefault(server_name, {}).update(keys) defer.returnValue(union_of_keys)
def on_new_receipts(self, min_stream_id, max_stream_id, affected_room_ids): yield run_on_reactor() try: # Need to subtract 1 from the minimum because the lower bound here # is not inclusive updated_receipts = yield self.store.get_all_updated_receipts( min_stream_id - 1, max_stream_id ) # This returns a tuple, user_id is at index 3 users_affected = set([r[3] for r in updated_receipts]) deferreds = [] for u in users_affected: if u in self.pushers: for p in self.pushers[u].values(): deferreds.append( run_in_background( p.on_new_receipts, min_stream_id, max_stream_id, ) ) yield make_deferred_yieldable( defer.gatherResults(deferreds, consumeErrors=True), ) except Exception: logger.exception("Exception in pusher on_new_receipts")
def fire(self, *args, **kwargs): """Invokes every callable in the observer list, passing in the args and kwargs. Exceptions thrown by observers are logged but ignored. It is not an error to fire a signal with no observers. Returns a Deferred that will complete when all the observers have completed.""" def do(observer): def eb(failure): logger.warning( "%s signal observer %s failed: %r", self.name, observer, failure, exc_info=( failure.type, failure.value, failure.getTracebackObject())) return defer.maybeDeferred(observer, *args, **kwargs).addErrback(eb) deferreds = [ run_in_background(do, o) for o in self.observers ] return make_deferred_yieldable(defer.gatherResults( deferreds, consumeErrors=True, ))
def _on_new_room_event(self, event, room_stream_id, extra_users=[]): """Notify any user streams that are interested in this room event""" # poke any interested application service. run_in_background(self._notify_app_services, room_stream_id) if self.federation_sender: 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) self.on_new_event( "room_key", room_stream_id, users=extra_users, rooms=[event.room_id], )
def fetch_or_execute(self, txn_key, fn, *args, **kwargs): """Fetches the response for this transaction, or executes the given function to produce a response for this transaction. Args: txn_key (str): A key to ensure idempotency should fetch_or_execute be called again at a later point in time. fn (function): A function which returns a tuple of (response_code, response_dict). *args: Arguments to pass to fn. **kwargs: Keyword arguments to pass to fn. Returns: Deferred which resolves to a tuple of (response_code, response_dict). """ if txn_key in self.transactions: observable = self.transactions[txn_key][0] else: # execute the function instead. deferred = run_in_background(fn, *args, **kwargs) observable = ObservableDeferred(deferred) self.transactions[txn_key] = (observable, self.clock.time_msec()) # if the request fails with an exception, remove it # from the transaction map. This is done to ensure that we don't # cache transient errors like rate-limiting errors, etc. def remove_from_map(err): self.transactions.pop(txn_key, None) # we deliberately do not propagate the error any further, as we # expect the observers to have reported it. deferred.addErrback(remove_from_map) return make_deferred_yieldable(observable.observe())
def _test_run_in_background(self, function): sentinel_context = LoggingContext.current_context() callback_completed = [False] def test(): context_one.request = "one" d = function() def cb(res): self._check_test_key("one") callback_completed[0] = True return res d.addCallback(cb) return d with LoggingContext() as context_one: context_one.request = "one" # fire off function, but don't wait on it. logcontext.run_in_background(test) self._check_test_key("one") # now wait for the function under test to have run, and check that # the logcontext is left in a sane state. d2 = defer.Deferred() def check_logcontext(): if not callback_completed[0]: reactor.callLater(0.01, check_logcontext) return # make sure that the context was reset before it got thrown back # into the reactor try: self.assertIs(LoggingContext.current_context(), sentinel_context) d2.callback(None) except BaseException: d2.errback(twisted.python.failure.Failure()) reactor.callLater(0.01, check_logcontext) # test is done once d2 finishes return d2
def verify_json_objects_for_server(self, server_and_json): """Bulk verifies signatures of json objects, bulk fetching keys as necessary. Args: server_and_json (list): List of pairs of (server_name, json_object) Returns: List<Deferred>: for each input pair, a deferred indicating success or failure to verify each json object's signature for the given server_name. The deferreds run their callbacks in the sentinel logcontext. """ verify_requests = [] for server_name, json_object in server_and_json: key_ids = signature_ids(json_object, server_name) if not key_ids: logger.warn("Request from %s: no supported signature keys", server_name) deferred = defer.fail(SynapseError( 400, "Not signed with a supported algorithm", Codes.UNAUTHORIZED, )) else: deferred = defer.Deferred() logger.debug("Verifying for %s with key_ids %s", server_name, key_ids) verify_request = VerifyKeyRequest( server_name, key_ids, json_object, deferred ) verify_requests.append(verify_request) run_in_background(self._start_key_lookups, verify_requests) # Pass those keys to handle_key_deferred so that the json object # signatures can be verified handle = preserve_fn(_handle_key_deferred) return [ handle(rq) for rq in verify_requests ]
def _handle_timeouts(self): """Checks the presence of users that have timed out and updates as appropriate. """ logger.info("Handling presence timeouts") now = self.clock.time_msec() try: with Measure(self.clock, "presence_handle_timeouts"): # Fetch the list of users that *may* have timed out. Things may have # changed since the timeout was set, so we won't necessarily have to # take any action. users_to_check = set(self.wheel_timer.fetch(now)) # Check whether the lists of syncing processes from an external # process have expired. expired_process_ids = [ process_id for process_id, last_update in self.external_process_last_updated_ms.items() if now - last_update > EXTERNAL_PROCESS_EXPIRY ] for process_id in expired_process_ids: users_to_check.update( self.external_process_last_updated_ms.pop(process_id, ()) ) self.external_process_last_update.pop(process_id) states = [ self.user_to_current_state.get( user_id, UserPresenceState.default(user_id) ) for user_id in users_to_check ] timers_fired_counter.inc(len(states)) changes = handle_timeouts( states, is_mine_fn=self.is_mine_id, syncing_user_ids=self.get_currently_syncing_users(), now=now, ) run_in_background(self._update_states_and_catch_exception, changes) except Exception: logger.exception("Exception in _handle_timeouts loop")
def claim_one_time_keys(self, query, timeout): local_query = [] remote_queries = {} for user_id, device_keys in query.get("one_time_keys", {}).items(): # we use UserID.from_string to catch invalid user ids if self.is_mine(UserID.from_string(user_id)): for device_id, algorithm in device_keys.items(): local_query.append((user_id, device_id, algorithm)) else: domain = get_domain_from_id(user_id) remote_queries.setdefault(domain, {})[user_id] = device_keys results = yield self.store.claim_e2e_one_time_keys(local_query) json_result = {} failures = {} for user_id, device_keys in results.items(): for device_id, keys in device_keys.items(): for key_id, json_bytes in keys.items(): json_result.setdefault(user_id, {})[device_id] = { key_id: json.loads(json_bytes) } @defer.inlineCallbacks def claim_client_keys(destination): device_keys = remote_queries[destination] try: remote_result = yield self.federation.claim_client_keys( destination, {"one_time_keys": device_keys}, timeout=timeout ) for user_id, keys in remote_result["one_time_keys"].items(): if user_id in device_keys: json_result[user_id] = keys except Exception as e: failures[destination] = _exception_to_failure(e) yield make_deferred_yieldable(defer.gatherResults([ run_in_background(claim_client_keys, destination) for destination in remote_queries ], consumeErrors=True)) logger.info( "Claimed one-time-keys: %s", ",".join(( "%s for %s:%s" % (key_id, user_id, device_id) for user_id, user_keys in iteritems(json_result) for device_id, device_keys in iteritems(user_keys) for key_id, _ in iteritems(device_keys) )), ) defer.returnValue({ "one_time_keys": json_result, "failures": failures })
def store_file(self, path, file_info): if not file_info.server_name and not self.store_local: return defer.succeed(None) if file_info.server_name and not self.store_remote: return defer.succeed(None) if self.store_synchronous: return self.backend.store_file(path, file_info) else: # TODO: Handle errors. def store(): try: return self.backend.store_file(path, file_info) except Exception: logger.exception("Error storing file") run_in_background(store) return defer.succeed(None)
def get_server_verify_key_v2_direct(self, server_name, key_ids): keys = {} for requested_key_id in key_ids: if requested_key_id in keys: continue (response, tls_certificate) = yield fetch_server_key( server_name, self.hs.tls_server_context_factory, path=(b"/_matrix/key/v2/server/%s" % ( urllib.quote(requested_key_id), )).encode("ascii"), ) if (u"signatures" not in response or server_name not in response[u"signatures"]): raise KeyLookupError("Key response not signed by remote server") if "tls_fingerprints" not in response: raise KeyLookupError("Key response missing TLS fingerprints") certificate_bytes = crypto.dump_certificate( crypto.FILETYPE_ASN1, tls_certificate ) sha256_fingerprint = hashlib.sha256(certificate_bytes).digest() sha256_fingerprint_b64 = encode_base64(sha256_fingerprint) response_sha256_fingerprints = set() for fingerprint in response[u"tls_fingerprints"]: if u"sha256" in fingerprint: response_sha256_fingerprints.add(fingerprint[u"sha256"]) if sha256_fingerprint_b64 not in response_sha256_fingerprints: raise KeyLookupError("TLS certificate not allowed by fingerprints") response_keys = yield self.process_v2_response( from_server=server_name, requested_ids=[requested_key_id], response_json=response, ) keys.update(response_keys) yield logcontext.make_deferred_yieldable(defer.gatherResults( [ run_in_background( self.store_keys, server_name=key_server_name, from_server=server_name, verify_keys=verify_keys, ) for key_server_name, verify_keys in keys.items() ], consumeErrors=True ).addErrback(unwrapFirstError)) defer.returnValue(keys)
def _enqueue_events(self, events, check_redacted=True, allow_rejected=False): """Fetches events from the database using the _event_fetch_list. This allows batch and bulk fetching of events - it allows us to fetch events without having to create a new transaction for each request for events. """ if not events: defer.returnValue({}) events_d = defer.Deferred() with self._event_fetch_lock: self._event_fetch_list.append( (events, events_d) ) self._event_fetch_lock.notify() if self._event_fetch_ongoing < EVENT_QUEUE_THREADS: self._event_fetch_ongoing += 1 should_start = True else: should_start = False if should_start: run_as_background_process( "fetch_events", self.runWithConnection, self._do_fetch, ) logger.debug("Loading %d events", len(events)) with PreserveLoggingContext(): rows = yield events_d logger.debug("Loaded %d events (%d rows)", len(events), len(rows)) if not allow_rejected: rows[:] = [r for r in rows if not r["rejects"]] res = yield make_deferred_yieldable(defer.gatherResults( [ run_in_background( self._get_event_from_row, row["internal_metadata"], row["json"], row["redacts"], rejected_reason=row["rejects"], ) for row in rows ], consumeErrors=True )) defer.returnValue({ e.event.event_id: e for e in res if e })
def _handle_timeouts(self): logger.info("Checking for typing timeouts") now = self.clock.time_msec() members = set(self.wheel_timer.fetch(now)) for member in members: if not self.is_typing(member): # Nothing to do if they're no longer typing continue until = self._member_typing_until.get(member, None) if not until or until <= now: logger.info("Timing out typing for: %s", member.user_id) self._stopped_typing(member) continue # Check if we need to resend a keep alive over federation for this # user. if self.hs.is_mine_id(member.user_id): last_fed_poke = self._member_last_federation_poke.get(member, None) if not last_fed_poke or last_fed_poke + FEDERATION_PING_INTERVAL <= now: run_in_background( self._push_remote, member=member, typing=True ) # Add a paranoia timer to ensure that we always have a timer for # each person typing. self.wheel_timer.insert( now=now, obj=member, then=now + 60 * 1000, )
def _start_pushers(self, pushers): if not self.start_pushers: logger.info("Not starting pushers because they are disabled in the config") return logger.info("Starting %d pushers", len(pushers)) for pusherdict in pushers: try: p = self.pusher_factory.create_pusher(pusherdict) except Exception: logger.exception("Couldn't start a pusher: caught Exception") continue if p: appid_pushkey = "%s:%s" % ( pusherdict['app_id'], pusherdict['pushkey'], ) byuser = self.pushers.setdefault(pusherdict['user_name'], {}) if appid_pushkey in byuser: byuser[appid_pushkey].on_stop() byuser[appid_pushkey] = p run_in_background(p.on_started) logger.info("Started pushers")
def wrap(self, key, callback, *args, **kwargs): """Wrap together a *get* and *set* call, taking care of logcontexts First looks up the key in the cache, and if it is present makes it follow the synapse logcontext rules and returns it. Otherwise, makes a call to *callback(*args, **kwargs)*, which should follow the synapse logcontext rules, and adds the result to the cache. Example usage: @defer.inlineCallbacks def handle_request(request): # etc defer.returnValue(result) result = yield response_cache.wrap( key, handle_request, request, ) Args: key (hashable): key to get/set in the cache callback (callable): function to call if the key is not found in the cache *args: positional parameters to pass to the callback, if it is used **kwargs: named paramters to pass to the callback, if it is used Returns: twisted.internet.defer.Deferred: yieldable result """ result = self.get(key) if not result: logger.info("[%s]: no cached result for [%s], calculating new one", self._name, key) d = run_in_background(callback, *args, **kwargs) result = self.set(key, d) elif not isinstance(result, defer.Deferred) or result.called: logger.info("[%s]: using completed cached result for [%s]", self._name, key) else: logger.info("[%s]: using incomplete cached result for [%s]", self._name, key) return make_deferred_yieldable(result)
def get_prev_state_ids(self, store): """Gets the prev state IDs Returns: Deferred[dict[(str, str), str]|None]: Returns None if state_group is None, which happens when the associated event is an outlier. """ if not self._fetching_state_deferred: self._fetching_state_deferred = run_in_background( self._fill_out_state, store, ) yield make_deferred_yieldable(self._fetching_state_deferred) defer.returnValue(self._prev_state_ids)
def query_3pe(self, kind, protocol, fields): services = yield self._get_services_for_3pn(protocol) results = yield make_deferred_yieldable(defer.DeferredList([ run_in_background( self.appservice_api.query_3pe, service, kind, protocol, fields, ) for service in services ], consumeErrors=True)) ret = [] for (success, result) in results: if success: ret.extend(result) defer.returnValue(ret)
def registerProducer(self, producer, streaming): """Part of IConsumer interface Args: producer (IProducer) streaming (bool): True if push based producer, False if pull based. """ if self._producer: raise Exception("registerProducer called twice") self._producer = producer self.streaming = streaming self._finished_deferred = run_in_background( threads.deferToThread, self._writer ) if not streaming: self._producer.resumeProducing()
def get_current_state_ids(self, store): """Gets the current state IDs Returns: Deferred[dict[(str, str), str]|None]: Returns None if state_group is None, which happens when the associated event is an outlier. Maps a (type, state_key) to the event ID of the state event matching this tuple. """ if not self._fetching_state_deferred: self._fetching_state_deferred = run_in_background( self._fill_out_state, store, ) yield make_deferred_yieldable(self._fetching_state_deferred) defer.returnValue(self._current_state_ids)
def on_REPLICATE(self, cmd): stream_name = cmd.stream_name token = cmd.token if stream_name == "ALL": # Subscribe to all streams we're publishing to. deferreds = [ run_in_background( self.subscribe_to_stream, stream, token, ) for stream in iterkeys(self.streamer.streams_by_name) ] return make_deferred_yieldable( defer.gatherResults(deferreds, consumeErrors=True) ) else: return self.subscribe_to_stream(stream_name, token)
def store_keys(self, server_name, from_server, verify_keys): """Store a collection of verify keys for a given server Args: server_name(str): The name of the server the keys are for. from_server(str): The server the keys were downloaded from. verify_keys(dict): A mapping of key_id to VerifyKey. Returns: A deferred that completes when the keys are stored. """ # TODO(markjh): Store whether the keys have expired. return logcontext.make_deferred_yieldable(defer.gatherResults( [ run_in_background( self.store.store_server_verify_key, server_name, server_name, key.time_added, key ) for key_id, key in verify_keys.items() ], consumeErrors=True, ).addErrback(unwrapFirstError))
def get_keys_from_server(self, server_name_and_key_ids): @defer.inlineCallbacks def get_key(server_name, key_ids): keys = None try: keys = yield self.get_server_verify_key_v2_direct( server_name, key_ids ) except Exception as e: logger.info( "Unable to get key %r for %r directly: %s %s", key_ids, server_name, type(e).__name__, str(e), ) if not keys: keys = yield self.get_server_verify_key_v1_direct( server_name, key_ids ) keys = {server_name: keys} defer.returnValue(keys) results = yield logcontext.make_deferred_yieldable(defer.gatherResults( [ run_in_background(get_key, server_name, key_ids) for server_name, key_ids in server_name_and_key_ids ], consumeErrors=True, ).addErrback(unwrapFirstError)) merged = {} for result in results: merged.update(result) defer.returnValue({ server_name: keys for server_name, keys in merged.items() if keys })
def on_rdata(self, stream_name, token, rows): yield super(UserDirectoryReplicationHandler, self).on_rdata( stream_name, token, rows ) if stream_name == "current_state_deltas": run_in_background(self._notify_directory)
def _user_syncing(): try: yield finally: if affect_presence: run_in_background(_end)
def _on_enter(self, request_id): time_now = self.clock.time_msec() # remove any entries from request_times which aren't within the window self.request_times[:] = [ r for r in self.request_times if time_now - r < self.window_size ] # reject the request if we already have too many queued up (either # sleeping or in the ready queue). queue_size = len(self.ready_request_queue) + len( self.sleeping_requests) if queue_size > self.reject_limit: raise LimitExceededError(retry_after_ms=int(self.window_size / self.sleep_limit), ) self.request_times.append(time_now) def queue_request(): if len(self.current_processing) > self.concurrent_requests: queue_defer = defer.Deferred() self.ready_request_queue[request_id] = queue_defer logger.info( "Ratelimiter: queueing request (queue now %i items)", len(self.ready_request_queue), ) return queue_defer else: return defer.succeed(None) logger.debug( "Ratelimit [%s]: len(self.request_times)=%d", id(request_id), len(self.request_times), ) if len(self.request_times) > self.sleep_limit: logger.debug( "Ratelimiter: sleeping request for %f sec", self.sleep_sec, ) ret_defer = run_in_background(self.clock.sleep, self.sleep_sec) self.sleeping_requests.add(request_id) def on_wait_finished(_): logger.debug( "Ratelimit [%s]: Finished sleeping", id(request_id), ) self.sleeping_requests.discard(request_id) queue_defer = queue_request() return queue_defer ret_defer.addBoth(on_wait_finished) else: ret_defer = queue_request() def on_start(r): logger.debug( "Ratelimit [%s]: Processing req", id(request_id), ) self.current_processing.add(request_id) return r def on_err(r): # XXX: why is this necessary? this is called before we start # processing the request so why would the request be in # current_processing? self.current_processing.discard(request_id) return r def on_both(r): # Ensure that we've properly cleaned up. self.sleeping_requests.discard(request_id) self.ready_request_queue.pop(request_id, None) return r ret_defer.addCallbacks(on_start, on_err) ret_defer.addBoth(on_both) return make_deferred_yieldable(ret_defer)
def _process_event_queue_loop(self): try: self._is_processing = True while True: last_token = yield self.store.get_federation_out_pos("events") next_token, events = yield self.store.get_all_new_events_stream( last_token, self._last_poked_id, limit=100, ) logger.debug("Handling %s -> %s", last_token, next_token) if not events and next_token >= self._last_poked_id: break @defer.inlineCallbacks def handle_event(event): # Only send events for this server. send_on_behalf_of = event.internal_metadata.get_send_on_behalf_of( ) is_mine = self.is_mine_id(event.event_id) if not is_mine and send_on_behalf_of is None: return try: # Get the state from before the event. # We need to make sure that this is the state from before # the event and not from after it. # Otherwise if the last member on a server in a room is # banned then it won't receive the event because it won't # be in the room after the ban. destinations = yield self.state.get_current_hosts_in_room( event.room_id, latest_event_ids=[ prev_id for prev_id, _ in event.prev_events ], ) except Exception: logger.exception( "Failed to calculate hosts in room for event: %s", event.event_id, ) return destinations = set(destinations) if send_on_behalf_of is not None: # If we are sending the event on behalf of another server # then it already has the event and there is no reason to # send the event to it. destinations.discard(send_on_behalf_of) logger.debug("Sending %s to %r", event, destinations) self._send_pdu(event, destinations) @defer.inlineCallbacks def handle_room_events(events): for event in events: yield handle_event(event) events_by_room = {} for event in events: events_by_room.setdefault(event.room_id, []).append(event) yield logcontext.make_deferred_yieldable( defer.gatherResults([ logcontext.run_in_background(handle_room_events, evs) for evs in itervalues(events_by_room) ], consumeErrors=True)) yield self.store.update_federation_out_pos( "events", next_token) if events: now = self.clock.time_msec() ts = yield self.store.get_received_ts(events[-1].event_id) synapse.metrics.event_processing_lag.labels( "federation_sender").set(now - ts) synapse.metrics.event_processing_last_ts.labels( "federation_sender").set(ts) events_processed_counter.inc(len(events)) event_processing_loop_room_count.labels( "federation_sender").inc(len(events_by_room)) event_processing_loop_counter.labels("federation_sender").inc() synapse.metrics.event_processing_positions.labels( "federation_sender").set(next_token) finally: self._is_processing = False
def process_v2_response(self, from_server, response_json, requested_ids=[], only_from_server=True): time_now_ms = self.clock.time_msec() response_keys = {} verify_keys = {} for key_id, key_data in response_json["verify_keys"].items(): if is_signing_algorithm_supported(key_id): key_base64 = key_data["key"] key_bytes = decode_base64(key_base64) verify_key = decode_verify_key_bytes(key_id, key_bytes) verify_key.time_added = time_now_ms verify_keys[key_id] = verify_key old_verify_keys = {} for key_id, key_data in response_json["old_verify_keys"].items(): if is_signing_algorithm_supported(key_id): key_base64 = key_data["key"] key_bytes = decode_base64(key_base64) verify_key = decode_verify_key_bytes(key_id, key_bytes) verify_key.expired = key_data["expired_ts"] verify_key.time_added = time_now_ms old_verify_keys[key_id] = verify_key results = {} server_name = response_json["server_name"] if only_from_server: if server_name != from_server: raise KeyLookupError( "Expected a response for server %r not %r" % (from_server, server_name)) for key_id in response_json["signatures"].get(server_name, {}): if key_id not in response_json["verify_keys"]: raise KeyLookupError( "Key response must include verification keys for all" " signatures") if key_id in verify_keys: verify_signed_json(response_json, server_name, verify_keys[key_id]) signed_key_json = sign_json( response_json, self.config.server_name, self.config.signing_key[0], ) signed_key_json_bytes = encode_canonical_json(signed_key_json) ts_valid_until_ms = signed_key_json[u"valid_until_ts"] updated_key_ids = set(requested_ids) updated_key_ids.update(verify_keys) updated_key_ids.update(old_verify_keys) response_keys.update(verify_keys) response_keys.update(old_verify_keys) yield logcontext.make_deferred_yieldable( defer.gatherResults( [ run_in_background( self.store.store_server_keys_json, server_name=server_name, key_id=key_id, from_server=server_name, ts_now_ms=time_now_ms, ts_expires_ms=ts_valid_until_ms, key_json_bytes=signed_key_json_bytes, ) for key_id in updated_key_ids ], consumeErrors=True, ).addErrback(unwrapFirstError)) results[server_name] = response_keys defer.returnValue(results)
def query_devices(self, query_body, timeout): """ Handle a device key query from a client { "device_keys": { "<user_id>": ["<device_id>"] } } -> { "device_keys": { "<user_id>": { "<device_id>": { ... } } } } """ device_keys_query = query_body.get("device_keys", {}) # separate users by domain. # make a map from domain to user_id to device_ids local_query = {} remote_queries = {} for user_id, device_ids in device_keys_query.items(): # we use UserID.from_string to catch invalid user ids if self.is_mine(UserID.from_string(user_id)): local_query[user_id] = device_ids else: remote_queries[user_id] = device_ids # First get local devices. failures = {} results = {} if local_query: local_result = yield self.query_local_devices(local_query) for user_id, keys in local_result.items(): if user_id in local_query: results[user_id] = keys # Now attempt to get any remote devices from our local cache. remote_queries_not_in_cache = {} if remote_queries: query_list = [] for user_id, device_ids in iteritems(remote_queries): if device_ids: query_list.extend( (user_id, device_id) for device_id in device_ids) else: query_list.append((user_id, None)) user_ids_not_in_cache, remote_results = ( yield self.store.get_user_devices_from_cache(query_list)) for user_id, devices in iteritems(remote_results): user_devices = results.setdefault(user_id, {}) for device_id, device in iteritems(devices): keys = device.get("keys", None) device_display_name = device.get("device_display_name", None) if keys: result = dict(keys) unsigned = result.setdefault("unsigned", {}) if device_display_name: unsigned[ "device_display_name"] = device_display_name user_devices[device_id] = result for user_id in user_ids_not_in_cache: domain = get_domain_from_id(user_id) r = remote_queries_not_in_cache.setdefault(domain, {}) r[user_id] = remote_queries[user_id] # Now fetch any devices that we don't have in our cache @defer.inlineCallbacks def do_remote_query(destination): destination_query = remote_queries_not_in_cache[destination] try: remote_result = yield self.federation.query_client_keys( destination, {"device_keys": destination_query}, timeout=timeout) for user_id, keys in remote_result["device_keys"].items(): if user_id in destination_query: results[user_id] = keys except Exception as e: failures[destination] = _exception_to_failure(e) yield make_deferred_yieldable( defer.gatherResults([ run_in_background(do_remote_query, destination) for destination in remote_queries_not_in_cache ], consumeErrors=True)) defer.returnValue({ "device_keys": results, "failures": failures, })
def handle_new_client_event( self, requester, event, context, ratelimit=True, extra_users=[], ): """Processes a new event. This includes checking auth, persisting it, notifying users, sending to remote servers, etc. If called from a worker will hit out to the master process for final processing. Args: requester (Requester) event (FrozenEvent) context (EventContext) ratelimit (bool) extra_users (list(UserID)): Any extra users to notify about event """ try: yield self.auth.check_from_context(event, context) except AuthError as err: logger.warn("Denying new event %r because %s", event, err) raise err # Ensure that we can round trip before trying to persist in db try: dump = frozendict_json_encoder.encode(event.content) json.loads(dump) except Exception: logger.exception("Failed to encode content: %r", event.content) raise yield self.action_generator.handle_push_actions_for_event( event, context) # reraise does not allow inlineCallbacks to preserve the stacktrace, so we # hack around with a try/finally instead. success = False try: # If we're a worker we need to hit out to the master. if self.config.worker_app: yield self.send_event_to_master( event_id=event.event_id, store=self.store, requester=requester, event=event, context=context, ratelimit=ratelimit, extra_users=extra_users, ) success = True return yield self.persist_and_notify_client_event( requester, event, context, ratelimit=ratelimit, extra_users=extra_users, ) success = True finally: if not success: # Ensure that we actually remove the entries in the push actions # staging area, if we calculated them. run_in_background( self.store.remove_push_actions_from_staging, event.event_id, )
def notify_interested_services(self, current_id): """Notifies (pushes) all application services interested in this event. Pushing is done asynchronously, so this method won't block for any prolonged length of time. Args: current_id(int): The current maximum ID. """ services = self.store.get_app_services() if not services or not self.notify_appservices: return self.current_max = max(self.current_max, current_id) if self.is_processing: return with Measure(self.clock, "notify_interested_services"): self.is_processing = True try: limit = 100 while True: upper_bound, events = yield self.store.get_new_events_for_appservice( self.current_max, limit) if not events: break events_by_room = {} for event in events: events_by_room.setdefault(event.room_id, []).append(event) @defer.inlineCallbacks def handle_event(event): # Gather interested services services = yield self._get_services_for_event(event) if len(services) == 0: return # no services need notifying # Do we know this user exists? If not, poke the user # query API for all services which match that user regex. # This needs to block as these user queries need to be # made BEFORE pushing the event. yield self._check_user_exists(event.sender) if event.type == EventTypes.Member: yield self._check_user_exists(event.state_key) if not self.started_scheduler: self.scheduler.start().addErrback(log_failure) self.started_scheduler = True # Fork off pushes to these services for service in services: self.scheduler.submit_event_for_as(service, event) @defer.inlineCallbacks def handle_room_events(events): for event in events: yield handle_event(event) yield make_deferred_yieldable( defer.gatherResults([ run_in_background(handle_room_events, evs) for evs in itervalues(events_by_room) ], consumeErrors=True)) yield self.store.set_appservice_last_pos(upper_bound) now = self.clock.time_msec() ts = yield self.store.get_received_ts(events[-1].event_id) synapse.metrics.event_processing_positions.labels( "appservice_sender").set(upper_bound) events_processed_counter.inc(len(events)) synapse.metrics.event_processing_lag.labels( "appservice_sender").set(now - ts) synapse.metrics.event_processing_last_ts.labels( "appservice_sender").set(ts) finally: self.is_processing = False
def on_rdata(self, stream_name, token, rows): yield super(PusherReplicationHandler, self).on_rdata(stream_name, token, rows) run_in_background(self.poke_pushers, stream_name, token, rows)
def _async_render_GET(self, request): # XXX: if get_user_by_req fails, what should we do in an async render? requester = yield self.auth.get_user_by_req(request) url = request.args.get("url")[0] if "ts" in request.args: ts = int(request.args.get("ts")[0]) else: ts = self.clock.time_msec() # XXX: we could move this into _do_preview if we wanted. url_tuple = urlparse.urlsplit(url) for entry in self.url_preview_url_blacklist: match = True for attrib in entry: pattern = entry[attrib] value = getattr(url_tuple, attrib) logger.debug(("Matching attrib '%s' with value '%s' against" " pattern '%s'") % (attrib, value, pattern)) if value is None: match = False continue if pattern.startswith('^'): if not re.match(pattern, getattr(url_tuple, attrib)): match = False continue else: if not fnmatch.fnmatch(getattr(url_tuple, attrib), pattern): match = False continue if match: logger.warn("URL %s blocked by url_blacklist entry %s", url, entry) raise SynapseError( 403, "URL blocked by url pattern blacklist entry", Codes.UNKNOWN) # the in-memory cache: # * ensures that only one request is active at a time # * takes load off the DB for the thundering herds # * also caches any failures (unlike the DB) so we don't keep # requesting the same endpoint observable = self._cache.get(url) if not observable: download = run_in_background( self._do_preview, url, requester.user, ts, ) observable = ObservableDeferred(download, consumeErrors=True) self._cache[url] = observable else: logger.info("Returning cached response") og = yield make_deferred_yieldable(observable.observe()) respond_with_json_bytes(request, 200, og, send_cors=True)
def _get_server_verify_keys(self, verify_requests): """Tries to find at least one key for each verify request For each verify_request, verify_request.deferred is called back with params (server_name, key_id, VerifyKey) if a key is found, or errbacked with a SynapseError if none of the keys are found. Args: verify_requests (list[VerifyKeyRequest]): list of verify requests """ # These are functions that produce keys given a list of key ids key_fetch_fns = ( self.get_keys_from_store, # First try the local store self.get_keys_from_perspectives, # Then try via perspectives self.get_keys_from_server, # Then try directly ) @defer.inlineCallbacks def do_iterations(): with Measure(self.clock, "get_server_verify_keys"): # dict[str, dict[str, VerifyKey]]: results so far. # map server_name -> key_id -> VerifyKey merged_results = {} # dict[str, set(str)]: keys to fetch for each server missing_keys = {} for verify_request in verify_requests: missing_keys.setdefault(verify_request.server_name, set()).update( verify_request.key_ids) for fn in key_fetch_fns: results = yield fn(missing_keys.items()) merged_results.update(results) # We now need to figure out which verify requests we have keys # for and which we don't missing_keys = {} requests_missing_keys = [] for verify_request in verify_requests: server_name = verify_request.server_name result_keys = merged_results[server_name] if verify_request.deferred.called: # We've already called this deferred, which probably # means that we've already found a key for it. continue for key_id in verify_request.key_ids: if key_id in result_keys: with PreserveLoggingContext(): verify_request.deferred.callback(( server_name, key_id, result_keys[key_id], )) break else: # The else block is only reached if the loop above # doesn't break. missing_keys.setdefault(server_name, set()).update( verify_request.key_ids) requests_missing_keys.append(verify_request) if not missing_keys: break with PreserveLoggingContext(): for verify_request in requests_missing_keys: verify_request.deferred.errback( SynapseError( 401, "No key for %s with id %s" % ( verify_request.server_name, verify_request.key_ids, ), Codes.UNAUTHORIZED, )) def on_err(err): with PreserveLoggingContext(): for verify_request in verify_requests: if not verify_request.deferred.called: verify_request.deferred.errback(err) run_in_background(do_iterations).addErrback(on_err)
def _push_update(self, member, typing): if self.hs.is_mine_id(member.user_id): # Only send updates for changes to our own users. run_in_background(self._push_remote, member, typing) self._push_update_local(member=member, typing=typing)
def get_server_verify_key_v2_indirect(self, server_names_and_key_ids, perspective_name, perspective_keys): # TODO(mark): Set the minimum_valid_until_ts to that needed by # the events being validated or the current time if validating # an incoming request. query_response = yield self.client.post_json( destination=perspective_name, path=b"/_matrix/key/v2/query", data={ u"server_keys": { server_name: { key_id: { u"minimum_valid_until_ts": 0 } for key_id in key_ids } for server_name, key_ids in server_names_and_key_ids } }, long_retries=True, ) keys = {} responses = query_response["server_keys"] for response in responses: if (u"signatures" not in response or perspective_name not in response[u"signatures"]): raise KeyLookupError( "Key response not signed by perspective server" " %r" % (perspective_name, )) verified = False for key_id in response[u"signatures"][perspective_name]: if key_id in perspective_keys: verify_signed_json(response, perspective_name, perspective_keys[key_id]) verified = True if not verified: logging.info( "Response from perspective server %r not signed with a" " known key, signed with: %r, known keys: %r", perspective_name, list(response[u"signatures"][perspective_name]), list(perspective_keys)) raise KeyLookupError( "Response not signed with a known key for perspective" " server %r" % (perspective_name, )) processed_response = yield self.process_v2_response( perspective_name, response, only_from_server=False) for server_name, response_keys in processed_response.items(): keys.setdefault(server_name, {}).update(response_keys) yield logcontext.make_deferred_yieldable( defer.gatherResults( [ run_in_background( self.store_keys, server_name=server_name, from_server=perspective_name, verify_keys=response_keys, ) for server_name, response_keys in keys.items() ], consumeErrors=True).addErrback(unwrapFirstError)) defer.returnValue(keys)
def enqueue(self, service, event): # if this service isn't being sent something self.queued_events.setdefault(service.id, []).append(event) run_in_background(self._send_request, service)
def persist_and_notify_client_event( self, requester, event, context, ratelimit=True, extra_users=[], ): """Called when we have fully built the event, have already calculated the push actions for the event, and checked auth. This should only be run on master. """ assert not self.config.worker_app if ratelimit: yield self.base_handler.ratelimit(requester) yield self.base_handler.maybe_kick_guest_users(event, context) if event.type == EventTypes.CanonicalAlias: # Check the alias is acually valid (at this time at least) room_alias_str = event.content.get("alias", None) if room_alias_str: room_alias = RoomAlias.from_string(room_alias_str) directory_handler = self.hs.get_handlers().directory_handler mapping = yield directory_handler.get_association(room_alias) if mapping["room_id"] != event.room_id: raise SynapseError( 400, "Room alias %s does not point to the room" % (room_alias_str, )) federation_handler = self.hs.get_handlers().federation_handler if event.type == EventTypes.Member: if event.content["membership"] == Membership.INVITE: def is_inviter_member_event(e): return (e.type == EventTypes.Member and e.sender == event.sender) current_state_ids = yield context.get_current_state_ids( self.store) state_to_include_ids = [ e_id for k, e_id in iteritems(current_state_ids) if k[0] in self.hs.config.room_invite_state_types or k == ( EventTypes.Member, event.sender) ] state_to_include = yield self.store.get_events( state_to_include_ids) event.unsigned["invite_room_state"] = [{ "type": e.type, "state_key": e.state_key, "content": e.content, "sender": e.sender, } for e in itervalues(state_to_include)] invitee = UserID.from_string(event.state_key) if not self.hs.is_mine(invitee): # TODO: Can we add signature from remote server in a nicer # way? If we have been invited by a remote server, we need # to get them to sign the event. returned_invite = yield federation_handler.send_invite( invitee.domain, event, ) event.unsigned.pop("room_state", None) # TODO: Make sure the signatures actually are correct. event.signatures.update(returned_invite.signatures) if event.type == EventTypes.Redaction: prev_state_ids = yield context.get_prev_state_ids(self.store) auth_events_ids = yield self.auth.compute_auth_events( event, prev_state_ids, for_verification=True, ) auth_events = yield self.store.get_events(auth_events_ids) auth_events = {(e.type, e.state_key): e for e in auth_events.values()} if self.auth.check_redaction(event, auth_events=auth_events): original_event = yield self.store.get_event( event.redacts, check_redacted=False, get_prev_content=False, allow_rejected=False, allow_none=False) if event.user_id != original_event.user_id: raise AuthError( 403, "You don't have permission to redact events") if event.type == EventTypes.Create: prev_state_ids = yield context.get_prev_state_ids(self.store) if prev_state_ids: raise AuthError( 403, "Changing the room create event is forbidden", ) (event_stream_id, max_stream_id) = yield self.store.persist_event(event, context=context) yield self.pusher_pool.on_new_notifications( event_stream_id, max_stream_id, ) def _notify(): try: self.notifier.on_new_room_event(event, event_stream_id, max_stream_id, extra_users=extra_users) except Exception: logger.exception("Error notifying about new room event") run_in_background(_notify) if event.type == EventTypes.Message: # We don't want to block sending messages on any presence code. This # matters as sometimes presence code can take a while. run_in_background(self._bump_active_time, requester.user)
def on_rdata(self, stream_name, token, rows): yield super(SyncReplicationHandler, self).on_rdata(stream_name, token, rows) run_in_background(self.process_and_notify, stream_name, token, rows)