From f749ce2f974351b065068ca945540aea62fe0bba Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Mon, 25 Jun 2018 14:05:39 +0100 Subject: [PATCH 1/7] Add test for attack/issue #59 --- test/byzantine.py | 396 +++++++++++++++++++++++++++++++++++ test/test_binaryagreement.py | 88 +++++++- 2 files changed, 476 insertions(+), 8 deletions(-) create mode 100644 test/byzantine.py diff --git a/test/byzantine.py b/test/byzantine.py new file mode 100644 index 00000000..4fcde31d --- /dev/null +++ b/test/byzantine.py @@ -0,0 +1,396 @@ +import logging +from collections import defaultdict +from distutils.util import strtobool +from os import environ + +import gevent +from gevent.event import AsyncResult, Event +from gevent.queue import Queue + +from honeybadgerbft.exceptions import RedundantMessageError + + +logger = logging.getLogger(__name__) +CONF_PHASE = strtobool(environ.get('CONF_PHASE', '1')) + +a0, a1, bob, x = 0, 1, 2, 3 + +def byz_ba_issue_59(sid, pid, N, f, coin, input, decide, broadcast, receive): + """Modified binary consensus from [MMR14], so that it exhibits a + byzantine behavior as per issue #59 + (see https://github.com/amiller/HoneyBadgerBFT/issues/59). + + :param sid: session identifier + :param pid: my id number + :param N: the number of parties + :param f: the number of byzantine parties + :param coin: a ``common coin(r)`` is called to block until receiving a bit + :param input: ``input()`` is called to receive an input + :param decide: ``decide(0)`` or ``output(1)`` is eventually called + :param broadcast: broadcast channel + :param receive: receive channel + :return: blocks until + """ + # Messages received are routed to either a shared coin, the broadcast, or AUX + est_values = defaultdict(lambda: [set(), set()]) + aux_values = defaultdict(lambda: [set(), set()]) + conf_values = defaultdict(lambda: {(0,): set(), (1,): set(), (0, 1): set()}) + est_sent = defaultdict(lambda: [False, False]) + conf_sent = defaultdict(lambda: {(0,): False, (1,): False, (0, 1): False}) + bin_values = defaultdict(set) + + # This event is triggered whenever bin_values or aux_values changes + bv_signal = Event() + + def _recv(): + while True: # not finished[pid]: + (sender, msg) = receive() + logger.debug(f'receive {msg} from node {sender}', + extra={'nodeid': pid, 'epoch': msg[1]}) + assert sender in range(N) + if msg[0] == 'EST': + # BV_Broadcast message + _, r, v = msg + assert v in (0, 1) + if sender in est_values[r][v]: + print('Redundant EST received', msg) + raise RedundantMessageError( + 'Redundant EST received {}'.format(msg)) + + est_values[r][v].add(sender) + # Relay after reaching first threshold + if len(est_values[r][v]) >= f + 1 and not est_sent[r][v]: + est_sent[r][v] = True + for receiver in range(N): + logger.debug( + f"broadcast {('EST', r, v)} to node {receiver}", + extra={'nodeid': pid, 'epoch': r}) + if receiver != 2: + broadcast(('EST', r, v), receiver=receiver) + + # Output after reaching second threshold + if len(est_values[r][v]) >= 2 * f + 1: + logger.debug( + f'add v = {v} to bin_value[{r}] = {bin_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + bin_values[r].add(v) + logger.debug(f'bin_values[{r}] is now: {bin_values[r]}', + extra={'nodeid': pid, 'epoch': r}) + bv_signal.set() + + elif msg[0] == 'AUX': + # Aux message + _, r, v = msg + assert v in (0, 1) + if sender in aux_values[r][v]: + print('Redundant AUX received', msg) + raise RedundantMessageError( + 'Redundant AUX received {}'.format(msg)) + + aux_values[r][v].add(sender) + logger.debug( + f'add v = {v} to aux_value[{r}] = {aux_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + + bv_signal.set() + + elif msg[0] == 'CONF' and CONF_PHASE: + # CONF message + _, r, v = msg + assert v in ((0,), (1,), (0, 1)) + if sender in conf_values[r][v]: + # FIXME: raise or continue? For now will raise just + # because it appeared first, but maybe the protocol simply + # needs to continue. + print(f'Redundant CONF received {msg} by {sender}') + raise RedundantMessageError( + f'Redundant CONF received {msg} by {sender}') + + conf_values[r][v].add(sender) + logger.debug( + f'add v = {v} to conf_value[{r}] = {conf_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + + bv_signal.set() + + # Run the receive loop in the background + _thread_recv = gevent.spawn(_recv) + + # Block waiting for the input + vi = input() + assert vi in (0, 1) + est = vi + r = 0 + already_decided = None + while True: # Unbounded number of rounds + logger.debug(f'starting round {r} with est set to {est}', + extra={'nodeid': pid, 'epoch': r}) + not_est = int(not bool(est)) + if not est_sent[r][est]: + est_sent[r][est] = True + est_sent[r][not_est] = True + logger.debug( + f"broadcast {('EST', r, int(not bool(est)))} to node {0}", + extra={'nodeid': pid, 'epoch': r}, + ) + broadcast(('EST', r, int(not bool(est))), receiver=0) + logger.debug( + f"broadcast {('EST', r, est)} to node {1}", + extra={'nodeid': pid, 'epoch': r}, + ) + broadcast(('EST', r, est), receiver=1) + + while len(bin_values[r]) == 0: + # Block until a value is output + bv_signal.clear() + bv_signal.wait() + + w = next(iter(bin_values[r])) # take an element + logger.debug(f"broadcast {('AUX', r, w)}", + extra={'nodeid': pid, 'epoch': r}) + for receiver in range(N): + if receiver != 2: + broadcast(('AUX', r, w), receiver=receiver) + + # After this all messages within A are delivered and x sends both + # BVAL(0) and BVAL(1) to every node in A. Thus every node in A + # broadcasts both BVAL(0) and BVAL(1) and sets bin_values={0,1}. + logger.debug( + 'x sends both BVAL(0) and BVAL(1) to every node in A.', + extra={'nodeid': pid, 'epoch': r}, + ) + broadcast(('EST', r, est), receiver=0) + broadcast(('EST', r, int(not bool(est))), receiver=1) + + # XXX CONF phase + if CONF_PHASE and not conf_sent[r][(0, 1)]: + conf_sent[r][(0, 1)] = True + logger.debug(f"broadcast {('CONF', r, (0, 1))}", + extra={'nodeid': pid, 'epoch': r}) + broadcast(('CONF', r, (0, 1))) + + logger.debug( + f'Block until receiving the common coin value', + extra={'nodeid': pid, 'epoch': r}, + ) + # Block until receiving the common coin value + s = coin(r) + logger.debug(f's = coin(r) | s = {s}, r = {r}', + extra={'nodeid': pid, 'epoch': r}) + not_s = int(not bool(s)) + + logger.debug(f"broadcast {('EST', r, not_s)} to node 2", + extra={'nodeid': pid, 'epoch': r}) + broadcast(('EST', r, not_s), receiver=2) + logger.debug(f"broadcast {('AUX', r, not_s)} to node 2", + extra={'nodeid': pid, 'epoch': r}) + broadcast(('AUX', r, not_s), receiver=2) + logger.debug(f'exiting round {r}, setting est = s ({s})', + extra={'nodeid': pid, 'epoch': r}) + est = s + r += 1 + + +class SendCondition(Event): + + epoch = 0 + priority = None + value = None + + +class NetworkScheduler: + COIN_PHASE_BEGIN = 18 + LAST = 24 + NO_DELAY = None + + def __init__(self, *, receivers): + self.queues = [Queue() for _ in range(4)] + self.receivers = receivers + self.events = defaultdict(SendCondition) + self.coins = defaultdict(AsyncResult) + self.initial_values = defaultdict(AsyncResult) + self.initial_values[0].set(0) + + def consume_queue(self, queue): + for m in queue: + gevent.spawn(self.schedule, m) + + def schedule(self, message): + # TODO once get_events() is implemented + # event, next_event = self.get_events(message) + sender, receiver, (tag, epoch, bin_value) = message + priority = self.get_priority(message) + + if priority == self.COIN_PHASE_BEGIN: + coin = int(not bool(bin_value)) + self.coins[epoch].set(coin) + self.initial_values[epoch + 1].set(coin) + + if priority == self.LAST: + next_event_priority = 0 + next_event_epoch = epoch + 1 + elif priority is not self.NO_DELAY: + next_event_priority = priority + 1 + next_event_epoch = epoch + + try: + next_event = self.events[next_event_epoch, next_event_priority] + except NameError: + next_event = None + else: + next_event.priority = next_event_priority + next_event.epoch = next_event_epoch + + event = self.events[epoch, priority] + event.epoch = epoch + event.priority = priority + event.value = bin_value + + logger.debug(f'Schedule message {message} with priority {priority}.', + extra={'nodeid': message[0], 'epoch': message[2][1]}) + gevent.spawn(self.send, message, event=event, next_event=next_event) + + def send(self, message, *, event, next_event): + sender, receiver, (tag, epoch, value) = message + logger.info( + f'Wait for condition {event} with priority {event.priority} for' + f'epoch {event.epoch} and value {event.value}', + extra={'nodeid': sender, 'epoch': epoch}, + ) + event.wait() + logger.info(f'Send message {message} --- PRIORITY: {event.priority}', + extra={'nodeid': sender, 'epoch': epoch}) + self.receivers[receiver].put((sender, (tag, epoch, value))) + if next_event: + logger.info( + f'Set (ready) condition {next_event} with priority' + f'{next_event.priority} for epoch {next_event.epoch}' + f'and value {event.value}', + extra={'nodeid': sender, 'epoch': epoch}, + ) + next_event.set() + + # Move to next round. + if next_event.priority == self.LAST: + self.events[next_event.epoch + 1, self.NO_DELAY].set() + + def get_priority(self, message): + message_map = self.get_message_map(message) + _, receiver, (tag, epoch, _) = message + try: + priority = message_map[message] + except KeyError: + if tag == 'CONF' or receiver == x: + priority = self.NO_DELAY + else: + priority = self.LAST + return priority + + def get_events(self, message): + raise NotImplementedError + + def get_message_map(self, message): + sender, receiver, (tag, epoch, _) = message + if self.is_a_coin_dependent_message( + sender=sender, receiver=receiver, tag=tag): + message_map = self.coin_dependent_message_map(epoch) + else: + message_map = self.coin_independent_message_map(epoch) + return message_map + + def coin_independent_message_map(self, epoch): + r = epoch + v = self.initial_values[r].get() + not_v = int(not bool(v)) + msg_map = { + (x, a0, ('EST', r, not_v)): 0, + (x, a1, ('EST', r, v)): 1, + (bob, a0, ('EST', r, not_v)): 2, + (bob, a1, ('EST', r, not_v)): 3, + (a0, a0, ('EST', r, v)): 4, + (a0, a0, ('EST', r, not_v)): 5, + # ... + (a1, a1, ('EST', r, v)): 6, + (a0, a1, ('EST', r, v)): 7, + # ... + (a1, a0, ('EST', r, v)): 8, + (a0, a1, ('EST', r, not_v)): 9, + (a0, a0, ('AUX', r, not_v)): 10, + (a0, a1, ('AUX', r, not_v)): 11, + (a1, a0, ('AUX', r, v)): 12, + (a1, a1, ('AUX', r, v)): 13, + # ... + (x, a0, ('EST', r, v)): 14, + (x, a1, ('EST', r, not_v)): 15, + (x, a0, ('AUX', r, not_v)): 16, + (x, a1, ('AUX', r, not_v)): 17, + # not_coin phase - one of these two messages is sent to B, such + # that the value is the boolean NOT of the coin value + (x, bob, ('EST', r, 0)): 18, + (x, bob, ('EST', r, 1)): 18, + } + return msg_map + + def coin_dependent_message_map(self, epoch): + """Messages for which the scheduling depends on the value of + the coin. + """ + coin = self.coins[epoch].get() + not_coin = int(not bool(coin)) + return { + (a0, bob, ('EST', epoch, not_coin)): 19, + (a1, bob, ('EST', epoch, not_coin)): 20, + (a0, bob, ('AUX', epoch, not_coin)): 21, + (a1, bob, ('AUX', epoch, not_coin)): 21, + (bob, bob, ('AUX', epoch, not_coin)): 22, + (x, bob, ('AUX', epoch, not_coin)): 23, + } + + def is_a_coin_dependent_message(self, *, sender, receiver, tag): + """Checks if the message depends on the value of the coin for + its scheduling. + """ + return receiver == bob and (tag == 'AUX' or + sender in (a0, a1) and tag == 'EST') + + def start(self): + for queue in self.queues: + gevent.spawn(self.consume_queue, queue) + self.events[0, 0].set() + self.events[0, self.NO_DELAY].set() + + +def broadcast_router(N): + """Router controlled by an adversary such that incoming messages are + redirected to the queues of an adversarial network scheduler. + + :return: (receives, sends) + """ + queues = [Queue() for _ in range(N)] + ns = NetworkScheduler(receivers=queues) + ns.start() + + def makeBroadcast(i): + def _send(j, o): + ns.queues[i].put((i, j, o)) + + def _bc(o, receiver=None): + if receiver is not None: + _send(receiver, o) + else: + for j in range(N): + _send(j, o) + + return _bc + + def makeRecv(j): + def _recv(): + (i,o) = queues[j].get() + return (i,o) + return _recv + + return ([makeBroadcast(i) for i in range(N)], + [makeRecv(j) for j in range(N)]) diff --git a/test/test_binaryagreement.py b/test/test_binaryagreement.py index 539cf1be..26f47197 100644 --- a/test/test_binaryagreement.py +++ b/test/test_binaryagreement.py @@ -1,6 +1,8 @@ +import logging import unittest import gevent import random + from gevent.event import Event from gevent.queue import Queue from honeybadgerbft.core.commoncoin import shared_coin @@ -10,6 +12,7 @@ from pytest import mark, raises +logger = logging.getLogger(__name__) def simple_broadcast_router(N, maxdelay=0.005, seed=None): """Builds a set of connected channels, with random delay @@ -88,6 +91,11 @@ def _recv(): [makeRecv(j) for j in range(N)]) +def release_held_messages(q, receivers): + for m in q: + receivers[m['receiver']].put((m['sender'], m['msg'])) + + def dummy_coin(sid, N, f): counter = defaultdict(int) events = defaultdict(Event) @@ -143,7 +151,7 @@ def test_binaryagreement_dummy(): _test_binaryagreement_dummy() -@mark.parametrize('msg_type', ('EST', 'AUX')) +@mark.parametrize('msg_type', ('EST', 'AUX', 'CONF')) @mark.parametrize('byznode', (1, 2, 3)) def test_binaryagreement_dummy_with_redundant_messages(byznode, msg_type): N = 4 @@ -267,13 +275,6 @@ def test_binaryagreement(): for i in range(5): _test_binaryagreement(seed=i) -@mark.xfail( - raises=NotImplementedError, - reason='Place holder for https://github.com/amiller/HoneyBadgerBFT/issues/59') -def test_issue59_attack(): - raise NotImplementedError("Placeholder test failure for Issue #59") - - @mark.parametrize('values,s,already_decided,expected_est,' 'expected_already_decided,expected_output', ( ({0}, 0, None, 0, 0, 0), @@ -340,3 +341,74 @@ def test_set_next_round_estimate_raises(values, s, already_decided): already_decided=already_decided, decide=None, ) + + +def test_issue59_attack(caplog): + from .byzantine import byz_ba_issue_59, broadcast_router + N = 4 + f = 1 + seed = None + sid = 'sidA' + rnd = random.Random(seed) + sends, recvs = broadcast_router(N) + threads = [] + inputs = [] + outputs = [] + + coins_seed = rnd.random() + coins = _make_coins(sid+'COIN', N, f, coins_seed) + + for i in range(4): + inputs.append(Queue()) + outputs.append(Queue()) + + t = gevent.spawn(byz_ba_issue_59, sid, 3, N, f, coins[3], + inputs[3].get, outputs[3].put_nowait, sends[3], recvs[3]) + threads.append(t) + + for i in (2, 0, 1): + t = gevent.spawn(binaryagreement, sid, i, N, f, coins[i], + inputs[i].get, outputs[i].put_nowait, sends[i], recvs[i]) + threads.append(t) + + inputs[0].put(0) # A_0 + inputs[1].put(0) # A_1 + inputs[2].put(1) # B + inputs[3].put(0) # F (x) + + try: + outs = [outputs[i].get() for i in range(N)] + except gevent.hub.LoopExit: + ba_node_2_log_records = [ + record for record in caplog.records + if record.nodeid == 2 and record.module == 'binaryagreement' + ] + round_0_records = [ + record for record in ba_node_2_log_records if record.epoch == 0 + ] + round_1_records = [ + record for record in ba_node_2_log_records if record.epoch == 1 + ] + conf_phase_record = [ + record for record in round_0_records + if record.message == 'Completed CONF phase with values = {0, 1}' + ] + assert len(conf_phase_record) == 1 + coin_value_record = [ + record for record in round_0_records + if record.message.startswith('Received coin with value = ') + ] + assert len(coin_value_record) == 1 + coin_value = coin_value_record[0].message.split('=')[1] + round_1_begin_log = [ + record for record in round_1_records + if record.message.startswith('Starting with est = ') + ] + assert len(round_1_begin_log) == 1 + est_value_round_1 = round_1_begin_log[0].message.split('=')[1] + assert est_value_round_1 == coin_value + + try: + gevent.joinall(threads) + except gevent.hub.LoopExit: + pass From 60c1180305b68ddb181ecdbfcfeb11acd1d2c22f Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Mon, 25 Jun 2018 14:11:16 +0100 Subject: [PATCH 2/7] Add custom colored logging --- setup.py | 1 + test/conftest.py | 47 +++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 48 insertions(+) create mode 100644 test/conftest.py diff --git a/setup.py b/setup.py index d2742d91..1f1201e6 100644 --- a/setup.py +++ b/setup.py @@ -34,6 +34,7 @@ tests_require = [ 'coverage', 'flake8', + 'logutils', 'pytest', 'pytest-cov', 'pytest-mock', diff --git a/test/conftest.py b/test/conftest.py new file mode 100644 index 00000000..8faf1a28 --- /dev/null +++ b/test/conftest.py @@ -0,0 +1,47 @@ +import logging + +from logutils.colorize import ColorizingStreamHandler + +from pytest import fixture + + +class BadgerColoredLogs(ColorizingStreamHandler): + + nodeid_map = { + 0: (None, 'green', False), + 1: (None, 'cyan', False), + 2: (None, 'blue', False), + 3: (None, 'magenta', False), + } + + def colorize(self, message, record): + """ + Colorize a message for a logging event. + + This implementation uses the ``level_map`` class attribute to + map the LogRecord's level to a colour/intensity setting, which is + then applied to the whole message. + + :param message: The message to colorize. + :param record: The ``LogRecord`` for the message. + """ + if record.nodeid in self.nodeid_map: + bg, fg, bold = self.nodeid_map[record.nodeid] + params = [] + if bg in self.color_map: + params.append(str(self.color_map[bg] + 40)) + if fg in self.color_map: + params.append(str(self.color_map[fg] + 30)) + if bold: + params.append('1') + if params: + message = ''.join((self.csi, ';'.join(params), + 'm', message, self.reset)) + return message + + +logging.basicConfig( + format='node %(nodeid)s|round %(epoch)s> %(module)s:%(funcName)s (%(lineno)d) %(message)s', + level=logging.DEBUG, + handlers=[BadgerColoredLogs()], +) From b5077f38b4ea366652ae378145fdf5f7393b2582 Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Mon, 25 Jun 2018 14:21:58 +0100 Subject: [PATCH 3/7] Add a bit of logging for debugging purposes --- honeybadgerbft/core/binaryagreement.py | 59 ++++++++++++++++++++++++-- honeybadgerbft/core/commoncoin.py | 16 +++++++ 2 files changed, 72 insertions(+), 3 deletions(-) diff --git a/honeybadgerbft/core/binaryagreement.py b/honeybadgerbft/core/binaryagreement.py index eb4e1ea3..142a0d0d 100644 --- a/honeybadgerbft/core/binaryagreement.py +++ b/honeybadgerbft/core/binaryagreement.py @@ -1,10 +1,15 @@ import gevent from gevent.event import Event + from collections import defaultdict +import logging from honeybadgerbft.exceptions import RedundantMessageError, AbandonedNodeError +logger = logging.getLogger(__name__) + + def binaryagreement(sid, pid, N, f, coin, input, decide, broadcast, receive): """Binary consensus from [MMR14]. It takes an input ``vi`` and will finally write the decided value into ``decide`` channel. @@ -32,6 +37,8 @@ def binaryagreement(sid, pid, N, f, coin, input, decide, broadcast, receive): def _recv(): while True: # not finished[pid]: (sender, msg) = receive() + logger.debug(f'receive {msg} from node {sender}', + extra={'nodeid': pid, 'epoch': msg[1]}) assert sender in range(N) if msg[0] == 'EST': # BV_Broadcast message @@ -41,7 +48,11 @@ def _recv(): # FIXME: raise or continue? For now will raise just # because it appeared first, but maybe the protocol simply # needs to continue. - print('Redundant EST received', msg) + print(f'Redundant EST received by {sender}', msg) + logger.warn( + f'Redundant EST message received by {sender}: {msg}', + extra={'nodeid': pid, 'epoch': msg[1]} + ) raise RedundantMessageError( 'Redundant EST received {}'.format(msg)) # continue @@ -51,10 +62,18 @@ def _recv(): if len(est_values[r][v]) >= f + 1 and not est_sent[r][v]: est_sent[r][v] = True broadcast(('EST', r, v)) + logger.debug(f"broadcast {('EST', r, v)}", + extra={'nodeid': pid, 'epoch': r}) # Output after reaching second threshold if len(est_values[r][v]) >= 2 * f + 1: + logger.debug( + f'add v = {v} to bin_value[{r}] = {bin_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) bin_values[r].add(v) + logger.debug(f'bin_values[{r}] is now: {bin_values[r]}', + extra={'nodeid': pid, 'epoch': r}) bv_signal.set() elif msg[0] == 'AUX': @@ -68,9 +87,17 @@ def _recv(): print('Redundant AUX received', msg) raise RedundantMessageError( 'Redundant AUX received {}'.format(msg)) - # continue + logger.debug( + f'add sender = {sender} to aux_value[{r}][{v}] = {aux_values[r][v]}', + extra={'nodeid': pid, 'epoch': r}, + ) aux_values[r][v].add(sender) + logger.debug( + f'aux_value[{r}][{v}] is now: {aux_values[r][v]}', + extra={'nodeid': pid, 'epoch': r}, + ) + bv_signal.set() # Translate mmr14 broadcast into coin.broadcast @@ -88,6 +115,9 @@ def _recv(): r = 0 already_decided = None while True: # Unbounded number of rounds + logger.debug(f'Starting with est = {est}', + extra={'nodeid': pid, 'epoch': r}) + if not est_sent[r][est]: est_sent[r][est] = True broadcast(('EST', r, est)) @@ -98,10 +128,19 @@ def _recv(): bv_signal.wait() w = next(iter(bin_values[r])) # take an element + logger.debug(f"broadcast {('AUX', r, w)}", + extra={'nodeid': pid, 'epoch': r}) broadcast(('AUX', r, w)) values = None + logger.debug( + f'block until at least N-f ({N-f}) AUX values are received', + extra={'nodeid': pid, 'epoch': r}) while True: + logger.debug(f'bin_values[{r}]: {bin_values[r]}', + extra={'nodeid': pid, 'epoch': r}) + logger.debug(f'aux_values[{r}]: {aux_values[r]}', + extra={'nodeid': pid, 'epoch': r}) # Block until at least N-f AUX values are received if 1 in bin_values[r] and len(aux_values[r][1]) >= N - f: values = set((1,)) @@ -118,8 +157,16 @@ def _recv(): bv_signal.clear() bv_signal.wait() + logger.debug(f'Completed AUX phase with values = {values}', + extra={'nodeid': pid, 'epoch': r}) + logger.debug( + f'Block until receiving the common coin value', + extra={'nodeid': pid, 'epoch': r}, + ) # Block until receiving the common coin value s = coin(r) + logger.debug(f'Received coin with value = {s}', + extra={'nodeid': pid, 'epoch': r}) try: est, already_decided = set_new_estimate( @@ -127,20 +174,26 @@ def _recv(): s=s, already_decided=already_decided, decide=decide, + nodeid=pid, + epoch=r, ) except AbandonedNodeError: # print('[sid:%s] [pid:%d] QUITTING in round %d' % (sid,pid,r))) + logger.debug(f'QUIT!', + extra={'nodeid': pid, 'epoch': r}) _thread_recv.kill() return r += 1 -def set_new_estimate(*, values, s, already_decided, decide): +def set_new_estimate(*, values, s, already_decided, decide, nodeid, epoch): if len(values) == 1: v = next(iter(values)) if v == s: if already_decided is None: + logger.debug(f'DECIDE on value {v}', + extra={'nodeid': pid, 'epoch': epoch}) already_decided = v decide(v) elif already_decided == v: diff --git a/honeybadgerbft/core/commoncoin.py b/honeybadgerbft/core/commoncoin.py index bad6f57e..fe3e7c86 100644 --- a/honeybadgerbft/core/commoncoin.py +++ b/honeybadgerbft/core/commoncoin.py @@ -1,9 +1,13 @@ +import logging + from honeybadgerbft.crypto.threshsig.boldyreva import serialize from collections import defaultdict from gevent import Greenlet from gevent.queue import Queue import hashlib +logger = logging.getLogger(__name__) + class CommonCoinFailureException(Exception): """Raised for common coin failures.""" @@ -34,8 +38,12 @@ def shared_coin(sid, pid, N, f, PK, SK, broadcast, receive): def _recv(): while True: # main receive loop + logger.debug(f'entering loop', + extra={'nodeid': pid, 'epoch': '?'}) # New shares for some round r, from sender i (i, (_, r, sig)) = receive() + logger.debug(f'received i, _, r, sig: {i, _, r, sig}', + extra={'nodeid': pid, 'epoch': r}) assert i in range(N) assert r >= 0 if i in received[r]: @@ -56,6 +64,10 @@ def _recv(): # After reaching the threshold, compute the output and # make it available locally + logger.debug( + f'if len(received[r]) == f + 1: {len(received[r]) == f + 1}', + extra={'nodeid': pid, 'epoch': r}, + ) if len(received[r]) == f + 1: # Verify and get the combined signature @@ -65,6 +77,8 @@ def _recv(): # Compute the bit from the least bit of the hash bit = hash(serialize(sig))[0] % 2 + logger.debug(f'put bit {bit} in output queue', + extra={'nodeid': pid, 'epoch': r}) outputQueue[r].put_nowait(bit) # greenletPacker(Greenlet(_recv), 'shared_coin', (pid, N, f, broadcast, receive)).start() @@ -79,6 +93,8 @@ def getCoin(round): """ # I have to do mapping to 1..l h = PK.hash_message(str((sid, round))) + logger.debug(f"broadcast {('COIN', round, SK.sign(h))}", + extra={'nodeid': pid, 'epoch': round}) broadcast(('COIN', round, SK.sign(h))) return outputQueue[round].get() From 2597672df5df387818396105e471fa6128dd008e Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Tue, 3 Jul 2018 11:17:52 +0100 Subject: [PATCH 4/7] Add CONF message phase to BA Addresses #59 --- honeybadgerbft/core/binaryagreement.py | 65 ++++++++++++++++++++++++-- 1 file changed, 60 insertions(+), 5 deletions(-) diff --git a/honeybadgerbft/core/binaryagreement.py b/honeybadgerbft/core/binaryagreement.py index 142a0d0d..f38370ea 100644 --- a/honeybadgerbft/core/binaryagreement.py +++ b/honeybadgerbft/core/binaryagreement.py @@ -2,12 +2,15 @@ from gevent.event import Event from collections import defaultdict +from distutils.util import strtobool +from os import environ import logging from honeybadgerbft.exceptions import RedundantMessageError, AbandonedNodeError logger = logging.getLogger(__name__) +CONF_PHASE = strtobool(environ.get('CONF_PHASE', '1')) def binaryagreement(sid, pid, N, f, coin, input, decide, broadcast, receive): @@ -28,7 +31,9 @@ def binaryagreement(sid, pid, N, f, coin, input, decide, broadcast, receive): # Messages received are routed to either a shared coin, the broadcast, or AUX est_values = defaultdict(lambda: [set(), set()]) aux_values = defaultdict(lambda: [set(), set()]) + conf_values = defaultdict(lambda: {(0,): set(), (1,): set(), (0, 1): set()}) est_sent = defaultdict(lambda: [False, False]) + conf_sent = defaultdict(lambda: {(0,): False, (1,): False, (0, 1): False}) bin_values = defaultdict(set) # This event is triggered whenever bin_values or aux_values changes @@ -100,6 +105,27 @@ def _recv(): bv_signal.set() + elif msg[0] == 'CONF' and CONF_PHASE: + _, r, v = msg + assert v in ((0,), (1,), (0, 1)) + if sender in conf_values[r][v]: + logger.warn(f'Redundant CONF received {msg} by {sender}', + extra={'nodeid': pid, 'epoch': r}) + # FIXME: Raise for now to simplify things & be consistent + # with how other TAGs are handled. Will replace the raise + # with a continue statement as part of + # https://github.com/initc3/HoneyBadgerBFT-Python/issues/10 + raise RedundantMessageError( + 'Redundant CONF received {}'.format(msg)) + + conf_values[r][v].add(sender) + logger.debug( + f'add v = {v} to conf_value[{r}] = {conf_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + + bv_signal.set() + # Translate mmr14 broadcast into coin.broadcast # _coin_broadcast = lambda (r, sig): broadcast(('COIN', r, sig)) # _coin_recv = Queue() @@ -159,6 +185,39 @@ def _recv(): logger.debug(f'Completed AUX phase with values = {values}', extra={'nodeid': pid, 'epoch': r}) + + # XXX CONF phase + logger.debug( + f'block until at least N-f ({N-f}) CONF values are received', + extra={'nodeid': pid, 'epoch': r}) + if CONF_PHASE and not conf_sent[r][tuple(values)]: + conf_sent[r][tuple(values)] = True + logger.debug(f"broadcast {('CONF', r, tuple(values))}", + extra={'nodeid': pid, 'epoch': r}) + broadcast(('CONF', r, tuple(bin_values[r]))) + while True: + logger.debug( + f'looping ... conf_values[r] is: {conf_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + if 1 in bin_values[r] and len(conf_values[r][(1,)]) >= N - f: + values = set((1,)) + break + if 0 in bin_values[r] and len(conf_values[r][(0,)]) >= N - f: + values = set((0,)) + break + if (sum(len(senders) for conf_value, senders in + conf_values[r].items() if senders and + set(conf_value).issubset(bin_values[r])) >= N - f): + values = set((0, 1)) + break + + bv_signal.clear() + bv_signal.wait() + + logger.debug(f'Completed CONF phase with values = {values}', + extra={'nodeid': pid, 'epoch': r}) + logger.debug( f'Block until receiving the common coin value', extra={'nodeid': pid, 'epoch': r}, @@ -174,8 +233,6 @@ def _recv(): s=s, already_decided=already_decided, decide=decide, - nodeid=pid, - epoch=r, ) except AbandonedNodeError: # print('[sid:%s] [pid:%d] QUITTING in round %d' % (sid,pid,r))) @@ -187,13 +244,11 @@ def _recv(): r += 1 -def set_new_estimate(*, values, s, already_decided, decide, nodeid, epoch): +def set_new_estimate(*, values, s, already_decided, decide): if len(values) == 1: v = next(iter(values)) if v == s: if already_decided is None: - logger.debug(f'DECIDE on value {v}', - extra={'nodeid': pid, 'epoch': epoch}) already_decided = v decide(v) elif already_decided == v: From b2b297a48c082ef82edaa1859b701145c2f21b41 Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Thu, 12 Jul 2018 20:18:53 +0100 Subject: [PATCH 5/7] Change some debug logging to info --- honeybadgerbft/core/binaryagreement.py | 8 ++++---- test/byzantine.py | 6 +++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/honeybadgerbft/core/binaryagreement.py b/honeybadgerbft/core/binaryagreement.py index f38370ea..c160f956 100644 --- a/honeybadgerbft/core/binaryagreement.py +++ b/honeybadgerbft/core/binaryagreement.py @@ -141,8 +141,8 @@ def _recv(): r = 0 already_decided = None while True: # Unbounded number of rounds - logger.debug(f'Starting with est = {est}', - extra={'nodeid': pid, 'epoch': r}) + logger.info(f'Starting with est = {est}', + extra={'nodeid': pid, 'epoch': r}) if not est_sent[r][est]: est_sent[r][est] = True @@ -224,8 +224,8 @@ def _recv(): ) # Block until receiving the common coin value s = coin(r) - logger.debug(f'Received coin with value = {s}', - extra={'nodeid': pid, 'epoch': r}) + logger.info(f'Received coin with value = {s}', + extra={'nodeid': pid, 'epoch': r}) try: est, already_decided = set_new_estimate( diff --git a/test/byzantine.py b/test/byzantine.py index 4fcde31d..eaa9a095 100644 --- a/test/byzantine.py +++ b/test/byzantine.py @@ -126,7 +126,7 @@ def _recv(): r = 0 already_decided = None while True: # Unbounded number of rounds - logger.debug(f'starting round {r} with est set to {est}', + logger.info(f'starting round {r} with est set to {est}', extra={'nodeid': pid, 'epoch': r}) not_est = int(not bool(est)) if not est_sent[r][est]: @@ -172,7 +172,7 @@ def _recv(): extra={'nodeid': pid, 'epoch': r}) broadcast(('CONF', r, (0, 1))) - logger.debug( + logger.info( f'Block until receiving the common coin value', extra={'nodeid': pid, 'epoch': r}, ) @@ -188,7 +188,7 @@ def _recv(): logger.debug(f"broadcast {('AUX', r, not_s)} to node 2", extra={'nodeid': pid, 'epoch': r}) broadcast(('AUX', r, not_s), receiver=2) - logger.debug(f'exiting round {r}, setting est = s ({s})', + logger.info(f'exiting round {r}, setting est = s ({s})', extra={'nodeid': pid, 'epoch': r}) est = s r += 1 From 09fec408e1165ca177ff921570d38d29c416835d Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Tue, 21 Aug 2018 17:00:25 +0100 Subject: [PATCH 6/7] Refactor to remove temporary CONF_PHASE switch --- honeybadgerbft/core/binaryagreement.py | 115 ++++++++++++++----------- test/byzantine.py | 21 ++--- test/conftest.py | 12 ++- 3 files changed, 87 insertions(+), 61 deletions(-) diff --git a/honeybadgerbft/core/binaryagreement.py b/honeybadgerbft/core/binaryagreement.py index c160f956..5925a603 100644 --- a/honeybadgerbft/core/binaryagreement.py +++ b/honeybadgerbft/core/binaryagreement.py @@ -2,15 +2,58 @@ from gevent.event import Event from collections import defaultdict -from distutils.util import strtobool -from os import environ import logging from honeybadgerbft.exceptions import RedundantMessageError, AbandonedNodeError logger = logging.getLogger(__name__) -CONF_PHASE = strtobool(environ.get('CONF_PHASE', '1')) + + +def handle_conf_messages(*, sender, message, conf_values, pid, bv_signal): + _, r, v = message + assert v in ((0,), (1,), (0, 1)) + if sender in conf_values[r][v]: + logger.warn(f'Redundant CONF received {message} by {sender}', + extra={'nodeid': pid, 'epoch': r}) + # FIXME: Raise for now to simplify things & be consistent + # with how other TAGs are handled. Will replace the raise + # with a continue statement as part of + # https://github.com/initc3/HoneyBadgerBFT-Python/issues/10 + raise RedundantMessageError( + 'Redundant CONF received {}'.format(message)) + + conf_values[r][v].add(sender) + logger.debug( + f'add v = {v} to conf_value[{r}] = {conf_values[r]}', + extra={'nodeid': pid, 'epoch': r}, + ) + + bv_signal.set() + + +def wait_for_conf_values(*, pid, N, f, epoch, conf_sent, bin_values, + values, conf_values, bv_signal, broadcast): + conf_sent[epoch][tuple(values)] = True + logger.debug(f"broadcast {('CONF', epoch, tuple(values))}", + extra={'nodeid': pid, 'epoch': epoch}) + broadcast(('CONF', epoch, tuple(bin_values[epoch]))) + while True: + logger.debug( + f'looping ... conf_values[epoch] is: {conf_values[epoch]}', + extra={'nodeid': pid, 'epoch': epoch}, + ) + if 1 in bin_values[epoch] and len(conf_values[epoch][(1,)]) >= N - f: + return set((1,)) + if 0 in bin_values[epoch] and len(conf_values[epoch][(0,)]) >= N - f: + return set((0,)) + if (sum(len(senders) for conf_value, senders in + conf_values[epoch].items() if senders and + set(conf_value).issubset(bin_values[epoch])) >= N - f): + return set((0, 1)) + + bv_signal.clear() + bv_signal.wait() def binaryagreement(sid, pid, N, f, coin, input, decide, broadcast, receive): @@ -105,27 +148,15 @@ def _recv(): bv_signal.set() - elif msg[0] == 'CONF' and CONF_PHASE: - _, r, v = msg - assert v in ((0,), (1,), (0, 1)) - if sender in conf_values[r][v]: - logger.warn(f'Redundant CONF received {msg} by {sender}', - extra={'nodeid': pid, 'epoch': r}) - # FIXME: Raise for now to simplify things & be consistent - # with how other TAGs are handled. Will replace the raise - # with a continue statement as part of - # https://github.com/initc3/HoneyBadgerBFT-Python/issues/10 - raise RedundantMessageError( - 'Redundant CONF received {}'.format(msg)) - - conf_values[r][v].add(sender) - logger.debug( - f'add v = {v} to conf_value[{r}] = {conf_values[r]}', - extra={'nodeid': pid, 'epoch': r}, + elif msg[0] == 'CONF': + handle_conf_messages( + sender=sender, + message=msg, + conf_values=conf_values, + pid=pid, + bv_signal=bv_signal, ) - bv_signal.set() - # Translate mmr14 broadcast into coin.broadcast # _coin_broadcast = lambda (r, sig): broadcast(('COIN', r, sig)) # _coin_recv = Queue() @@ -186,35 +217,23 @@ def _recv(): logger.debug(f'Completed AUX phase with values = {values}', extra={'nodeid': pid, 'epoch': r}) - # XXX CONF phase + # CONF phase logger.debug( f'block until at least N-f ({N-f}) CONF values are received', extra={'nodeid': pid, 'epoch': r}) - if CONF_PHASE and not conf_sent[r][tuple(values)]: - conf_sent[r][tuple(values)] = True - logger.debug(f"broadcast {('CONF', r, tuple(values))}", - extra={'nodeid': pid, 'epoch': r}) - broadcast(('CONF', r, tuple(bin_values[r]))) - while True: - logger.debug( - f'looping ... conf_values[r] is: {conf_values[r]}', - extra={'nodeid': pid, 'epoch': r}, - ) - if 1 in bin_values[r] and len(conf_values[r][(1,)]) >= N - f: - values = set((1,)) - break - if 0 in bin_values[r] and len(conf_values[r][(0,)]) >= N - f: - values = set((0,)) - break - if (sum(len(senders) for conf_value, senders in - conf_values[r].items() if senders and - set(conf_value).issubset(bin_values[r])) >= N - f): - values = set((0, 1)) - break - - bv_signal.clear() - bv_signal.wait() - + if not conf_sent[r][tuple(values)]: + values = wait_for_conf_values( + pid=pid, + N=N, + f=f, + epoch=r, + conf_sent=conf_sent, + bin_values=bin_values, + values=values, + conf_values=conf_values, + bv_signal=bv_signal, + broadcast=broadcast, + ) logger.debug(f'Completed CONF phase with values = {values}', extra={'nodeid': pid, 'epoch': r}) diff --git a/test/byzantine.py b/test/byzantine.py index eaa9a095..d8ba74c0 100644 --- a/test/byzantine.py +++ b/test/byzantine.py @@ -1,7 +1,5 @@ import logging from collections import defaultdict -from distutils.util import strtobool -from os import environ import gevent from gevent.event import AsyncResult, Event @@ -11,10 +9,10 @@ logger = logging.getLogger(__name__) -CONF_PHASE = strtobool(environ.get('CONF_PHASE', '1')) a0, a1, bob, x = 0, 1, 2, 3 + def byz_ba_issue_59(sid, pid, N, f, coin, input, decide, broadcast, receive): """Modified binary consensus from [MMR14], so that it exhibits a byzantine behavior as per issue #59 @@ -46,7 +44,7 @@ def _recv(): while True: # not finished[pid]: (sender, msg) = receive() logger.debug(f'receive {msg} from node {sender}', - extra={'nodeid': pid, 'epoch': msg[1]}) + extra={'nodeid': pid, 'epoch': msg[1]}) assert sender in range(N) if msg[0] == 'EST': # BV_Broadcast message @@ -96,7 +94,7 @@ def _recv(): bv_signal.set() - elif msg[0] == 'CONF' and CONF_PHASE: + elif msg[0] == 'CONF': # CONF message _, r, v = msg assert v in ((0,), (1,), (0, 1)) @@ -117,17 +115,16 @@ def _recv(): bv_signal.set() # Run the receive loop in the background - _thread_recv = gevent.spawn(_recv) + gevent.spawn(_recv) # Block waiting for the input vi = input() assert vi in (0, 1) est = vi r = 0 - already_decided = None while True: # Unbounded number of rounds logger.info(f'starting round {r} with est set to {est}', - extra={'nodeid': pid, 'epoch': r}) + extra={'nodeid': pid, 'epoch': r}) not_est = int(not bool(est)) if not est_sent[r][est]: est_sent[r][est] = True @@ -166,7 +163,7 @@ def _recv(): broadcast(('EST', r, int(not bool(est))), receiver=1) # XXX CONF phase - if CONF_PHASE and not conf_sent[r][(0, 1)]: + if not conf_sent[r][(0, 1)]: conf_sent[r][(0, 1)] = True logger.debug(f"broadcast {('CONF', r, (0, 1))}", extra={'nodeid': pid, 'epoch': r}) @@ -189,7 +186,7 @@ def _recv(): extra={'nodeid': pid, 'epoch': r}) broadcast(('AUX', r, not_s), receiver=2) logger.info(f'exiting round {r}, setting est = s ({s})', - extra={'nodeid': pid, 'epoch': r}) + extra={'nodeid': pid, 'epoch': r}) est = s r += 1 @@ -388,8 +385,8 @@ def _bc(o, receiver=None): def makeRecv(j): def _recv(): - (i,o) = queues[j].get() - return (i,o) + i, o = queues[j].get() + return i, o return _recv return ([makeBroadcast(i) for i in range(N)], diff --git a/test/conftest.py b/test/conftest.py index 8faf1a28..4b725e0e 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -2,7 +2,17 @@ from logutils.colorize import ColorizingStreamHandler -from pytest import fixture +import pytest + + +def pytest_collection_modifyitems(config, items): + if config.getoption('-m') == 'demo': + # do not skip demo tests + return + skip_demo = pytest.mark.skip(reason='need "-m demo" option to run') + for item in items: + if 'demo' in item.keywords: + item.add_marker(skip_demo) class BadgerColoredLogs(ColorizingStreamHandler): From 6842b7b4d030b0dadf969cdc65a2d4d68c7eb218 Mon Sep 17 00:00:00 2001 From: Sylvain Bellemare Date: Tue, 21 Aug 2018 17:01:15 +0100 Subject: [PATCH 7/7] Add demo of attack on BA liveness issue: amiller/HoneyBadgerBFT#59 --- test/demo_attack_issue59.py | 57 +++++++++++++++++++++++++++++++++++++ 1 file changed, 57 insertions(+) create mode 100644 test/demo_attack_issue59.py diff --git a/test/demo_attack_issue59.py b/test/demo_attack_issue59.py new file mode 100644 index 00000000..6cf38a98 --- /dev/null +++ b/test/demo_attack_issue59.py @@ -0,0 +1,57 @@ +import random + +import gevent +from gevent.queue import Queue +from pytest import mark + + +@mark.demo +def test_issue59_attack_demo(mocker, monkeypatch): + from .byzantine import byz_ba_issue_59, broadcast_router + from .test_binaryagreement import _make_coins + from honeybadgerbft.core import binaryagreement + + def mocked_conf_message_receiver(**kwargs): + pass + + def mocked_conf_phase_handler(**kwargs): + return kwargs['values'] + + monkeypatch.setattr( + binaryagreement, 'handle_conf_messages', mocked_conf_message_receiver) + monkeypatch.setattr( + binaryagreement, 'wait_for_conf_values', mocked_conf_phase_handler) + + N = 4 + f = 1 + seed = None + sid = 'sidA' + rnd = random.Random(seed) + sends, recvs = broadcast_router(N) + threads = [] + inputs = [] + outputs = [] + + coins_seed = rnd.random() + coins = _make_coins(sid+'COIN', N, f, coins_seed) + + for i in range(4): + inputs.append(Queue()) + outputs.append(Queue()) + + byz_thread = gevent.spawn(byz_ba_issue_59, sid, 3, N, f, coins[3], + inputs[3].get, outputs[3].put_nowait, sends[3], recvs[3]) + threads.append(byz_thread) + + for i in (2, 0, 1): + t = gevent.spawn(binaryagreement.binaryagreement, sid, i, N, f, coins[i], + inputs[i].get, outputs[i].put_nowait, sends[i], recvs[i]) + threads.append(t) + + inputs[0].put(0) # A_0 + inputs[1].put(0) # A_1 + inputs[2].put(1) # B + inputs[3].put(0) # F (x) + + for i in range(N): + outputs[i].get()