Several fixes and improvements

pisa/block_processor.py

@@ -63,8 +63,6 @@ class BlockProcessor:
 
         return potential_matches
 
-        return potential_matches
-
     @staticmethod
     def get_matches(potential_matches, locator_uuid_map, appointments):
         matches = []

pisa/inspector.py

@@ -72,7 +72,8 @@ class Inspector:
             rcode = errors.APPOINTMENT_WRONG_FIELD_FORMAT
             message = "wrong locator format ({})".format(locator)
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -99,7 +100,8 @@ class Inspector:
             else:
                 message = "start_time is too close to current height"
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -132,7 +134,8 @@ class Inspector:
             else:
                 message = 'end_time is too close to current height'
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -154,7 +157,8 @@ class Inspector:
             message = "dispute delta too small. The dispute delta should be at least {} (current: {})".format(
                 conf.MIN_DISPUTE_DELTA, dispute_delta)
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -176,7 +180,8 @@ class Inspector:
             rcode = errors.APPOINTMENT_WRONG_FIELD_FORMAT
             message = "wrong encrypted_blob format ({})".format(encrypted_blob)
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -197,7 +202,8 @@ class Inspector:
             rcode = errors.APPOINTMENT_CIPHER_NOT_SUPPORTED
             message = "cipher not supported: {}".format(cipher)
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message
 
@@ -218,6 +224,7 @@ class Inspector:
             rcode = errors.APPOINTMENT_HASH_FUNCTION_NOT_SUPPORTED
             message = "hash_function not supported {}".format(hash_function)
 
-        logger.error(message)
+        if message is not None:
+            logger.error(message)
 
         return rcode, message

pisa/logger.py

@@ -0,0 +1,30 @@
+import logging
+import time
+import json
+
+
+class StructuredMessage(object):
+    def __init__(self, message, **kwargs):
+        self.message = message
+        self.time = time.asctime()
+        self.kwargs = kwargs
+
+    def __str__(self):
+        return json.dumps({**self.kwargs, "message": self.message, "time": self.time})
+
+
+class Logger(object):
+    def __init__(self, actor=None):
+        self.actor = actor
+
+    def _add_prefix(self, msg):
+        return msg if self.actor is None else "[{}] {}".format(self.actor, msg)
+
+    def info(self, msg, **kwargs):
+        logging.info(StructuredMessage(self._add_prefix(msg), actor=self.actor, **kwargs))
+
+    def debug(self, msg, **kwargs):
+        logging.debug(StructuredMessage(self._add_prefix(msg), actor=self.actor, **kwargs))
+
+    def error(self, msg, **kwargs):
+        logging.error(StructuredMessage(self._add_prefix(msg), actor=self.actor, **kwargs))

pisa/pisad.py

@@ -23,4 +23,4 @@ if __name__ == '__main__':
             logger.error("bitcoind is running on a different network, check conf.py and bitcoin.conf. Shutting down")
 
     else:
-        logging.error("can't connect to bitcoind. Shutting down")
+        logger.error("can't connect to bitcoind. Shutting down")

pisa/tools.py

@@ -17,14 +17,14 @@ def check_tx_in_chain(tx_id, logger=Logger(), tx_label='transaction'):
         if tx_info.get("confirmations"):
             confirmations = int(tx_info.get("confirmations"))
             tx_in_chain = True
-            logger.error("{} found in the blockchain (txid: {}) ".format(tx_label), txid=tx_id)
+            logger.error("{} found in the blockchain".format(tx_label), txid=tx_id)
 
         else:
-            logger.error("{} found in mempool (txid: {}) ".format(tx_label), txid=tx_id)
+            logger.error("{} found in mempool".format(tx_label), txid=tx_id)
 
     except JSONRPCException as e:
         if e.error.get('code') == RPC_INVALID_ADDRESS_OR_KEY:
-            logger.error("{} not found in mempool nor blockchain (txid: {}) ".format(tx_label), txid=tx_id)
+            logger.error("{} not found in mempool nor blockchain".format(tx_label), txid=tx_id)
 
         else:
             # ToDO: Unhandled errors, check this properly

pisa/utils/zmq_subscriber.py

@@ -3,8 +3,6 @@ import binascii
 from pisa import Logger
 from pisa.conf import FEED_PROTOCOL, FEED_ADDR, FEED_PORT
 
-logger = Logger("ZMQHandler")
-
 
 # ToDo: #7-add-async-back-to-zmq
 class ZMQHandler:
@@ -15,7 +13,8 @@ class ZMQHandler:
         self.zmqSubSocket.setsockopt(zmq.RCVHWM, 0)
         self.zmqSubSocket.setsockopt_string(zmq.SUBSCRIBE, "hashblock")
         self.zmqSubSocket.connect("%s://%s:%s" % (FEED_PROTOCOL, FEED_ADDR, FEED_PORT))
-        self.parent = parent
+        self.logger = Logger("ZMQHandler-{}".format(parent))
+
         self.terminate = False
 
     def handle(self, block_queue):
@@ -31,6 +30,4 @@ class ZMQHandler:
                     block_hash = binascii.hexlify(body).decode('UTF-8')
                     block_queue.put(block_hash)
 
-                    logger.info("new block received via ZMQ",
+                    self.logger.info("new block received via ZMQ", block_hash=block_hash)
-                                parent=self.parent,
-                                block_hash=block_hash)

pisa/watcher.py

@@ -10,7 +10,7 @@ from pisa.conf import MAX_APPOINTMENTS
 from pisa.block_processor import BlockProcessor
 from pisa.utils.zmq_subscriber import ZMQHandler
 
-logging = Logger("Watcher")
+logger = Logger("Watcher")
 
 class Watcher:
     def __init__(self, max_appointments=MAX_APPOINTMENTS):