From ae8367c6c7f02b545a74574f746d626fb961dc48 Mon Sep 17 00:00:00 2001
From: Scott Sadler <scott@alphanode.co>
Date: Fri, 24 Feb 2017 13:27:48 +0100
Subject: [PATCH] log election results in election pipeline

---
 bigchaindb/core.py               |  1 -
 bigchaindb/pipelines/election.py | 25 +++++++++++++++++++++----
 bigchaindb/voting.py             |  1 +
 tests/test_voting.py             |  3 ++-
 4 files changed, 24 insertions(+), 6 deletions(-)

diff --git a/bigchaindb/core.py b/bigchaindb/core.py
index 5186b7f2..1f82fd78 100644
--- a/bigchaindb/core.py
+++ b/bigchaindb/core.py
@@ -623,7 +623,6 @@ class Bigchain(object):
                                                          block['id']))
         keyring = self.nodes_except_me + [self.me]
         result = self.consensus.voting.block_election(block, votes, keyring)
-        # TODO: logging
         return result
 
     def block_election_status(self, block):
diff --git a/bigchaindb/pipelines/election.py b/bigchaindb/pipelines/election.py
index 2e5efc3c..8e080183 100644
--- a/bigchaindb/pipelines/election.py
+++ b/bigchaindb/pipelines/election.py
@@ -16,6 +16,7 @@ from bigchaindb import Bigchain
 
 
 logger = logging.getLogger(__name__)
+logger_results = logging.getLogger('pipeline.election.results')
 
 
 class Election:
@@ -32,13 +33,29 @@ class Election:
             next_vote: The next vote.
 
         """
-        next_block = self.bigchain.get_block(
-            next_vote['vote']['voting_for_block'])
+        try:
+            block_id = next_vote['vote']['voting_for_block']
+            node = next_vote['node_pubkey']
+        except IndexError:
+            return
 
-        block_status = self.bigchain.block_election_status(next_block)
-        if block_status == self.bigchain.BLOCK_INVALID:
+        next_block = self.bigchain.get_block(block_id)
+
+        result = self.bigchain.block_election_status(next_block)
+        if result['status'] == self.bigchain.BLOCK_INVALID:
             return Block.from_dict(next_block)
 
+        # Log the result
+        if result['status'] != self.bigchain.BLOCK_UNDECIDED:
+            msg = 'node:%s block:%s status:%s' % \
+                (node, block_id, result['status'])
+            # Extra data can be accessed via the log formatter.
+            # See logging.dictConfig.
+            logger_results.debug(msg, extra={
+                'current_vote': next_vote,
+                'election_result': result,
+            })
+
     def requeue_transactions(self, invalid_block):
         """
         Liquidates transactions from invalid blocks so they can be processed again
diff --git a/bigchaindb/voting.py b/bigchaindb/voting.py
index f8511644..3b36303f 100644
--- a/bigchaindb/voting.py
+++ b/bigchaindb/voting.py
@@ -34,6 +34,7 @@ class Voting:
             cls.partition_eligible_votes(votes, eligible_voters)
         n_voters = len(eligible_voters)
         results = cls.count_votes(eligible_votes)
+        results['block_id'] = block['id']
         results['status'] = cls.decide_votes(n_voters, **results['counts'])
         results['ineligible'] = ineligible_votes
         return results
diff --git a/tests/test_voting.py b/tests/test_voting.py
index ea61fa6a..8fa72ca2 100644
--- a/tests/test_voting.py
+++ b/tests/test_voting.py
@@ -149,7 +149,7 @@ def test_block_election(b):
             return True
 
     keyring = 'abc'
-    block = {'block': {'voters': 'ab'}}
+    block = {'id': 'xyz', 'block': {'voters': 'ab'}}
     votes = [{
         'node_pubkey': c,
         'vote': {'is_block_valid': True, 'previous_block': 'a'}
@@ -157,6 +157,7 @@ def test_block_election(b):
 
     assert TestVoting.block_election(block, votes, keyring) == {
         'status': VALID,
+        'block_id': 'xyz',
         'counts': {'n_agree_prev_block': 2, 'n_valid': 2, 'n_invalid': 0},
         'ineligible': [votes[-1]],
         'cheat': [],