2015-03-05 09:30:33 -07:00
|
|
|
# -*- coding: utf-8 -*-
|
2016-01-06 21:26:29 -07:00
|
|
|
# Copyright 2015, 2016 OpenMarket Ltd
|
2015-03-05 09:30:33 -07:00
|
|
|
#
|
|
|
|
# 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.
|
|
|
|
"""
|
|
|
|
This module controls the reliability for application service transactions.
|
|
|
|
|
|
|
|
The nominal flow through this module looks like:
|
2015-03-16 07:15:40 -06:00
|
|
|
__________
|
|
|
|
1---ASa[e]-->| Service |--> Queue ASa[f]
|
|
|
|
2----ASb[e]->| Queuer |
|
|
|
|
3--ASa[f]--->|__________|-----------+ ASa[e], ASb[e]
|
|
|
|
V
|
2015-03-05 09:30:33 -07:00
|
|
|
-````````- +------------+
|
|
|
|
|````````|<--StoreTxn-|Transaction |
|
2015-03-05 10:35:07 -07:00
|
|
|
|Database| | Controller |---> SEND TO AS
|
2015-03-05 09:30:33 -07:00
|
|
|
`--------` +------------+
|
|
|
|
What happens on SEND TO AS depends on the state of the Application Service:
|
|
|
|
- If the AS is marked as DOWN, do nothing.
|
|
|
|
- If the AS is marked as UP, send the transaction.
|
|
|
|
* SUCCESS : Increment where the AS is up to txn-wise and nuke the txn
|
|
|
|
contents from the db.
|
|
|
|
* FAILURE : Marked AS as DOWN and start Recoverer.
|
|
|
|
|
|
|
|
Recoverer attempts to recover ASes who have died. The flow for this looks like:
|
|
|
|
,--------------------- backoff++ --------------.
|
|
|
|
V |
|
|
|
|
START ---> Wait exp ------> Get oldest txn ID from ----> FAILURE
|
|
|
|
backoff DB and try to send it
|
2015-03-06 03:25:50 -07:00
|
|
|
^ |___________
|
|
|
|
Mark AS as | V
|
|
|
|
UP & quit +---------- YES SUCCESS
|
|
|
|
| | |
|
|
|
|
NO <--- Have more txns? <------ Mark txn success & nuke <-+
|
2015-03-05 09:30:33 -07:00
|
|
|
from db; incr AS pos.
|
2015-03-05 10:45:52 -07:00
|
|
|
Reset backoff.
|
2015-03-05 10:35:07 -07:00
|
|
|
|
|
|
|
This is all tied together by the AppServiceScheduler which DIs the required
|
|
|
|
components.
|
2015-03-05 09:30:33 -07:00
|
|
|
"""
|
|
|
|
|
2015-03-06 08:12:24 -07:00
|
|
|
from synapse.appservice import ApplicationServiceState
|
2015-03-06 04:50:27 -07:00
|
|
|
from twisted.internet import defer
|
2015-03-06 08:12:24 -07:00
|
|
|
import logging
|
|
|
|
|
|
|
|
logger = logging.getLogger(__name__)
|
2015-03-06 04:50:27 -07:00
|
|
|
|
2015-03-05 09:30:33 -07:00
|
|
|
|
2016-05-31 06:53:48 -06:00
|
|
|
class ApplicationServiceScheduler(object):
|
2015-03-05 10:35:07 -07:00
|
|
|
""" Public facing API for this module. Does the required DI to tie the
|
|
|
|
components together. This also serves as the "event_pool", which in this
|
|
|
|
case is a simple array.
|
|
|
|
"""
|
|
|
|
|
2016-05-31 06:53:48 -06:00
|
|
|
def __init__(self, hs):
|
|
|
|
self.clock = hs.get_clock()
|
|
|
|
self.store = hs.get_datastore()
|
|
|
|
self.as_api = hs.get_application_service_api()
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 03:25:50 -07:00
|
|
|
def create_recoverer(service, callback):
|
2016-05-31 06:53:48 -06:00
|
|
|
return _Recoverer(self.clock, self.store, self.as_api, service, callback)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 03:25:50 -07:00
|
|
|
self.txn_ctrl = _TransactionController(
|
2016-05-31 06:53:48 -06:00
|
|
|
self.clock, self.store, self.as_api, create_recoverer
|
2015-03-06 03:25:50 -07:00
|
|
|
)
|
2015-03-16 07:15:40 -06:00
|
|
|
self.queuer = _ServiceQueuer(self.txn_ctrl)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 07:53:35 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-05 10:35:07 -07:00
|
|
|
def start(self):
|
2015-03-10 04:04:20 -06:00
|
|
|
logger.info("Starting appservice scheduler")
|
2015-03-06 03:25:50 -07:00
|
|
|
# check for any DOWN ASes and start recoverers for them.
|
2015-03-06 07:53:35 -07:00
|
|
|
recoverers = yield _Recoverer.start(
|
2015-03-06 03:25:50 -07:00
|
|
|
self.clock, self.store, self.as_api, self.txn_ctrl.on_recovered
|
|
|
|
)
|
2015-03-06 07:53:35 -07:00
|
|
|
self.txn_ctrl.add_recoverers(recoverers)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 03:25:50 -07:00
|
|
|
def submit_event_for_as(self, service, event):
|
2015-03-16 07:15:40 -06:00
|
|
|
self.queuer.enqueue(service, event)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
|
|
|
|
2015-03-16 07:15:40 -06:00
|
|
|
class _ServiceQueuer(object):
|
|
|
|
"""Queues events for the same application service together, sending
|
|
|
|
transactions as soon as possible. Once a transaction is sent successfully,
|
|
|
|
this schedules any other events in the queue to run.
|
2015-03-06 03:25:50 -07:00
|
|
|
"""
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-16 07:15:40 -06:00
|
|
|
def __init__(self, txn_ctrl):
|
2015-03-16 08:03:16 -06:00
|
|
|
self.queued_events = {} # dict of {service_id: [events]}
|
|
|
|
self.pending_requests = {} # dict of {service_id: Deferred}
|
2015-03-16 07:15:40 -06:00
|
|
|
self.txn_ctrl = txn_ctrl
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-16 04:16:59 -06:00
|
|
|
def enqueue(self, service, event):
|
2015-03-16 08:03:16 -06:00
|
|
|
# if this service isn't being sent something
|
|
|
|
if not self.pending_requests.get(service.id):
|
|
|
|
self._send_request(service, [event])
|
|
|
|
else:
|
|
|
|
# add to queue for this service
|
|
|
|
if service.id not in self.queued_events:
|
|
|
|
self.queued_events[service.id] = []
|
|
|
|
self.queued_events[service.id].append(event)
|
|
|
|
|
|
|
|
def _send_request(self, service, events):
|
|
|
|
# send request and add callbacks
|
|
|
|
d = self.txn_ctrl.send(service, events)
|
2015-03-26 04:11:52 -06:00
|
|
|
d.addBoth(self._on_request_finish)
|
2015-03-16 08:03:16 -06:00
|
|
|
d.addErrback(self._on_request_fail)
|
|
|
|
self.pending_requests[service.id] = d
|
|
|
|
|
|
|
|
def _on_request_finish(self, service):
|
|
|
|
self.pending_requests[service.id] = None
|
|
|
|
# if there are queued events, then send them.
|
|
|
|
if (service.id in self.queued_events
|
|
|
|
and len(self.queued_events[service.id]) > 0):
|
|
|
|
self._send_request(service, self.queued_events[service.id])
|
|
|
|
self.queued_events[service.id] = []
|
|
|
|
|
|
|
|
def _on_request_fail(self, err):
|
|
|
|
logger.error("AS request failed: %s", err)
|
2015-03-06 03:25:50 -07:00
|
|
|
|
2015-03-05 10:35:07 -07:00
|
|
|
|
|
|
|
class _TransactionController(object):
|
|
|
|
|
2015-03-16 07:15:40 -06:00
|
|
|
def __init__(self, clock, store, as_api, recoverer_fn):
|
2015-03-06 03:25:50 -07:00
|
|
|
self.clock = clock
|
2015-03-05 10:35:07 -07:00
|
|
|
self.store = store
|
|
|
|
self.as_api = as_api
|
|
|
|
self.recoverer_fn = recoverer_fn
|
2015-03-06 07:53:35 -07:00
|
|
|
# keep track of how many recoverers there are
|
|
|
|
self.recoverers = []
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 09:09:05 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-16 07:15:40 -06:00
|
|
|
def send(self, service, events):
|
2015-03-16 04:38:02 -06:00
|
|
|
try:
|
2015-03-16 07:15:40 -06:00
|
|
|
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:
|
|
|
|
txn.complete(self.store)
|
|
|
|
else:
|
|
|
|
self._start_recoverer(service)
|
2015-03-16 04:38:02 -06:00
|
|
|
except Exception as e:
|
|
|
|
logger.exception(e)
|
2015-03-26 04:11:52 -06:00
|
|
|
self._start_recoverer(service)
|
2015-03-16 08:03:16 -06:00
|
|
|
# request has finished
|
|
|
|
defer.returnValue(service)
|
2015-03-06 03:25:50 -07:00
|
|
|
|
2015-03-06 08:12:24 -07:00
|
|
|
@defer.inlineCallbacks
|
|
|
|
def on_recovered(self, recoverer):
|
2015-03-06 08:17:50 -07:00
|
|
|
self.recoverers.remove(recoverer)
|
2015-03-10 04:04:20 -06:00
|
|
|
logger.info("Successfully recovered application service AS ID %s",
|
|
|
|
recoverer.service.id)
|
|
|
|
logger.info("Remaining active recoverers: %s", len(self.recoverers))
|
|
|
|
yield self.store.set_appservice_state(
|
2015-03-06 08:12:24 -07:00
|
|
|
recoverer.service,
|
|
|
|
ApplicationServiceState.UP
|
|
|
|
)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 07:53:35 -07:00
|
|
|
def add_recoverers(self, recoverers):
|
|
|
|
for r in recoverers:
|
|
|
|
self.recoverers.append(r)
|
2015-03-06 08:17:50 -07:00
|
|
|
if len(recoverers) > 0:
|
2015-03-10 04:04:20 -06:00
|
|
|
logger.info("New active recoverers: %s", len(self.recoverers))
|
2015-03-06 07:53:35 -07:00
|
|
|
|
2015-03-06 08:12:24 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-05 10:35:07 -07:00
|
|
|
def _start_recoverer(self, service):
|
2015-03-10 04:04:20 -06:00
|
|
|
yield self.store.set_appservice_state(
|
2015-03-06 08:12:24 -07:00
|
|
|
service,
|
|
|
|
ApplicationServiceState.DOWN
|
|
|
|
)
|
2015-03-10 04:04:20 -06:00
|
|
|
logger.info(
|
|
|
|
"Application service falling behind. Starting recoverer. AS ID %s",
|
|
|
|
service.id
|
|
|
|
)
|
|
|
|
recoverer = self.recoverer_fn(service, self.on_recovered)
|
|
|
|
self.add_recoverers([recoverer])
|
|
|
|
recoverer.recover()
|
2015-03-05 10:35:07 -07:00
|
|
|
|
2015-03-06 09:09:05 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-06 03:25:50 -07:00
|
|
|
def _is_service_up(self, service):
|
2015-03-06 09:09:05 -07:00
|
|
|
state = yield self.store.get_appservice_state(service)
|
2015-03-09 11:45:41 -06:00
|
|
|
defer.returnValue(state == ApplicationServiceState.UP or state is None)
|
2015-03-05 10:35:07 -07:00
|
|
|
|
|
|
|
|
|
|
|
class _Recoverer(object):
|
2015-03-05 09:30:33 -07:00
|
|
|
|
2015-03-06 03:25:50 -07:00
|
|
|
@staticmethod
|
2015-03-06 07:53:35 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-06 03:25:50 -07:00
|
|
|
def start(clock, store, as_api, callback):
|
2015-03-06 08:12:24 -07:00
|
|
|
services = yield store.get_appservices_by_state(
|
|
|
|
ApplicationServiceState.DOWN
|
|
|
|
)
|
2015-03-06 07:53:35 -07:00
|
|
|
recoverers = [
|
|
|
|
_Recoverer(clock, store, as_api, s, callback) for s in services
|
|
|
|
]
|
|
|
|
for r in recoverers:
|
2015-03-10 04:04:20 -06:00
|
|
|
logger.info("Starting recoverer for AS ID %s which was marked as "
|
|
|
|
"DOWN", r.service.id)
|
2015-03-06 07:53:35 -07:00
|
|
|
r.recover()
|
|
|
|
defer.returnValue(recoverers)
|
2015-03-06 03:25:50 -07:00
|
|
|
|
|
|
|
def __init__(self, clock, store, as_api, service, callback):
|
|
|
|
self.clock = clock
|
2015-03-05 10:35:07 -07:00
|
|
|
self.store = store
|
|
|
|
self.as_api = as_api
|
|
|
|
self.service = service
|
2015-03-06 03:25:50 -07:00
|
|
|
self.callback = callback
|
2015-03-05 10:35:07 -07:00
|
|
|
self.backoff_counter = 1
|
2015-03-05 09:30:33 -07:00
|
|
|
|
2015-03-05 10:35:07 -07:00
|
|
|
def recover(self):
|
2015-03-09 11:01:19 -06:00
|
|
|
self.clock.call_later((2 ** self.backoff_counter), self.retry)
|
2015-03-06 03:25:50 -07:00
|
|
|
|
2015-03-16 04:38:02 -06:00
|
|
|
def _backoff(self):
|
2015-10-21 03:10:55 -06:00
|
|
|
# cap the backoff to be around 8.5min => (2^9) = 512 secs
|
|
|
|
if self.backoff_counter < 9:
|
2015-03-16 04:38:02 -06:00
|
|
|
self.backoff_counter += 1
|
|
|
|
self.recover()
|
|
|
|
|
2015-03-06 04:50:27 -07:00
|
|
|
@defer.inlineCallbacks
|
2015-03-06 03:25:50 -07:00
|
|
|
def retry(self):
|
2015-03-16 04:38:02 -06:00
|
|
|
try:
|
|
|
|
txn = yield self.store.get_oldest_unsent_txn(self.service)
|
|
|
|
if txn:
|
|
|
|
logger.info("Retrying transaction %s for AS ID %s",
|
|
|
|
txn.id, txn.service.id)
|
|
|
|
sent = yield txn.send(self.as_api)
|
|
|
|
if sent:
|
|
|
|
yield txn.complete(self.store)
|
|
|
|
# reset the backoff counter and retry immediately
|
|
|
|
self.backoff_counter = 1
|
|
|
|
yield self.retry()
|
|
|
|
else:
|
|
|
|
self._backoff()
|
2015-03-05 10:35:07 -07:00
|
|
|
else:
|
2015-03-16 04:38:02 -06:00
|
|
|
self._set_service_recovered()
|
|
|
|
except Exception as e:
|
|
|
|
logger.exception(e)
|
|
|
|
self._backoff()
|
2015-03-05 09:30:33 -07:00
|
|
|
|
2015-03-06 03:25:50 -07:00
|
|
|
def _set_service_recovered(self):
|
2015-03-06 08:12:24 -07:00
|
|
|
self.callback(self)
|