Skip to content
Snippets Groups Projects
Commit 1ad490df authored by inso's avatar inso
Browse files

Enhance logging

parent 25b1a7ae
No related branches found
No related tags found
No related merge requests found
...@@ -17,6 +17,15 @@ from sakia.errors import InvalidNodeCurrency ...@@ -17,6 +17,15 @@ from sakia.errors import InvalidNodeCurrency
from ..entities.node import Node from ..entities.node import Node
class NodeConnectorLoggerAdapter(logging.LoggerAdapter):
"""
This example adapter expects the passed in dict-like object to have a
'connid' key, whose value in brackets is prepended to the log message.
"""
def process(self, msg, kwargs):
return '[%s] %s' % (self.extra['pubkey'][:5], msg), kwargs
class NodeConnector(QObject): class NodeConnector(QObject):
""" """
A node is a peer send from the client point of view. A node is a peer send from the client point of view.
...@@ -38,7 +47,8 @@ class NodeConnector(QObject): ...@@ -38,7 +47,8 @@ class NodeConnector(QObject):
'peer': False} 'peer': False}
self._user_parameters = user_parameters self._user_parameters = user_parameters
self.session = session self.session = session
self._logger = logging.getLogger('sakia') self._raw_logger = logging.getLogger('sakia')
self._logger = NodeConnectorLoggerAdapter(self._raw_logger, {'pubkey': self.node.pubkey})
def __del__(self): def __del__(self):
for ws in self._ws_tasks.values(): for ws in self._ws_tasks.values():
...@@ -69,7 +79,7 @@ class NodeConnector(QObject): ...@@ -69,7 +79,7 @@ class NodeConnector(QObject):
if currency and peer.currency != currency: if currency and peer.currency != currency:
raise InvalidNodeCurrency(currency, peer.currency) raise InvalidNodeCurrency(currency, peer.currency)
node = Node(peer.currency, peer.pubkey, peer.endpoints, peer.blockUID) node = Node(peer.currency, peer.pubkey, peer.endpoints, peer.blockUID, last_state_change=time.time())
logging.getLogger('sakia').debug("Node from address : {:}".format(str(node))) logging.getLogger('sakia').debug("Node from address : {:}".format(str(node)))
return cls(node, user_parameters, session=session) return cls(node, user_parameters, session=session)
...@@ -87,7 +97,7 @@ class NodeConnector(QObject): ...@@ -87,7 +97,7 @@ class NodeConnector(QObject):
if currency and peer.currency != currency: if currency and peer.currency != currency:
raise InvalidNodeCurrency(currency, peer.currency) raise InvalidNodeCurrency(currency, peer.currency)
node = Node(peer.currency, peer.pubkey, peer.endpoints, peer.blockUID) node = Node(peer.currency, peer.pubkey, peer.endpoints, peer.blockUID, last_state_change=time.time())
logging.getLogger('sakia').debug("Node from peer : {:}".format(str(node))) logging.getLogger('sakia').debug("Node from peer : {:}".format(str(node)))
return cls(node, user_parameters, session=None) return cls(node, user_parameters, session=None)
...@@ -98,11 +108,10 @@ class NodeConnector(QObject): ...@@ -98,11 +108,10 @@ class NodeConnector(QObject):
data = await request(conn_handler, **req_args) data = await request(conn_handler, **req_args)
return data return data
except (ClientError, gaierror, TimeoutError, ConnectionRefusedError, ValueError) as e: except (ClientError, gaierror, TimeoutError, ConnectionRefusedError, ValueError) as e:
self._logger.debug("{0} : {1}".format(str(e), self.node.pubkey[:5])) self._logger.debug("{0}".format(str(e)))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
except jsonschema.ValidationError as e: except jsonschema.ValidationError as e:
self._logger.debug(str(e)) self._logger.debug(str(e))
self._logger.debug("Validation error : {0}".format(self.node.pubkey[:5]))
self.change_state_and_emit(Node.CORRUPTED) self.change_state_and_emit(Node.CORRUPTED)
async def init_session(self): async def init_session(self):
...@@ -151,11 +160,10 @@ class NodeConnector(QObject): ...@@ -151,11 +160,10 @@ class NodeConnector(QObject):
ws_connection = bma.ws.block(conn_handler) ws_connection = bma.ws.block(conn_handler)
async with ws_connection as ws: async with ws_connection as ws:
self._connected['block'] = True self._connected['block'] = True
self._logger.debug("Connected successfully to block ws : {0}" self._logger.debug("Connected successfully to block ws")
.format(self.node.pubkey[:5]))
async for msg in ws: async for msg in ws:
if msg.tp == aiohttp.WSMsgType.TEXT: if msg.tp == aiohttp.WSMsgType.TEXT:
self._logger.debug("Received a block : {0}".format(self.node.pubkey[:5])) self._logger.debug("Received a block")
block_data = bma.parse_text(msg.data, bma.ws.WS_BLOCk_SCHEMA) block_data = bma.parse_text(msg.data, bma.ws.WS_BLOCk_SCHEMA)
await self.refresh_block(block_data) await self.refresh_block(block_data)
elif msg.tp == aiohttp.WSMsgType.CLOSED: elif msg.tp == aiohttp.WSMsgType.CLOSED:
...@@ -163,15 +171,14 @@ class NodeConnector(QObject): ...@@ -163,15 +171,14 @@ class NodeConnector(QObject):
elif msg.tp == aiohttp.WSMsgType.ERROR: elif msg.tp == aiohttp.WSMsgType.ERROR:
break break
except (aiohttp.WSServerHandshakeError, ValueError) as e: except (aiohttp.WSServerHandshakeError, ValueError) as e:
self._logger.debug("Websocket block {0} : {1} - {2}" self._logger.debug("Websocket block {0} : {1}".format(type(e).__name__, str(e)))
.format(type(e).__name__, str(e), self.node.pubkey[:5]))
await self.request_current_block() await self.request_current_block()
except (ClientError, gaierror, TimeoutError) as e: except (ClientError, gaierror, TimeoutError) as e:
self._logger.debug("{0} : {1}".format(str(e), self.node.pubkey[:5])) self._logger.debug("{0} : {1}".format(str(e), self.node.pubkey[:5]))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
except jsonschema.ValidationError as e: except jsonschema.ValidationError as e:
self._logger.debug(str(e)) self._logger.debug(str(e))
self._logger.debug("Validation error : {0}".format(self.node.pubkey[:5])) self._logger.debug("Validation error")
self.change_state_and_emit(Node.CORRUPTED) self.change_state_and_emit(Node.CORRUPTED)
finally: finally:
self._connected['block'] = False self._connected['block'] = False
...@@ -196,9 +203,9 @@ class NodeConnector(QObject): ...@@ -196,9 +203,9 @@ class NodeConnector(QObject):
self.change_state_and_emit(Node.ONLINE) self.change_state_and_emit(Node.ONLINE)
else: else:
self.change_state_and_emit(Node.CORRUPTED) self.change_state_and_emit(Node.CORRUPTED)
self._logger.debug("Error in block reply of {0} : {1}}".format(self.node.pubkey[:5], str(e))) self._logger.debug("Error in block reply : {0}".format(str(e)))
else: else:
self._logger.debug("Could not connect to any BMA endpoint : {0}".format(self.node.pubkey[:5])) self._logger.debug("Could not connect to any BMA endpoint")
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
async def refresh_block(self, block_data): async def refresh_block(self, block_data):
...@@ -237,7 +244,7 @@ class NodeConnector(QObject): ...@@ -237,7 +244,7 @@ class NodeConnector(QObject):
block_data['number'])) block_data['number']))
self.changed.emit() self.changed.emit()
else: else:
self._logger.debug("Could not connect to any BMA endpoint : {0}".format(self.node.pubkey[:5])) self._logger.debug("Could not connect to any BMA endpoint")
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
else: else:
self.change_state_and_emit(Node.ONLINE) self.change_state_and_emit(Node.ONLINE)
...@@ -259,10 +266,10 @@ class NodeConnector(QObject): ...@@ -259,10 +266,10 @@ class NodeConnector(QObject):
self.identity_changed.emit() self.identity_changed.emit()
return # Break endpoints loop return # Break endpoints loop
except errors.DuniterError as e: except errors.DuniterError as e:
self._logger.debug("Error in summary of {0} : {1}".format(self.node.pubkey[:5], str(e))) self._logger.debug("Error in summary : {:}".format(str(e)))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
else: else:
self._logger.debug("Could not connect to any BMA endpoint : {0}".format(self.node.pubkey[:5])) self._logger.debug("Could not connect to any BMA endpoint")
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
async def connect_peers(self): async def connect_peers(self):
...@@ -278,10 +285,10 @@ class NodeConnector(QObject): ...@@ -278,10 +285,10 @@ class NodeConnector(QObject):
ws_connection = bma.ws.peer(conn_handler) ws_connection = bma.ws.peer(conn_handler)
async with ws_connection as ws: async with ws_connection as ws:
self._connected['peer'] = True self._connected['peer'] = True
self._logger.debug("Connected successfully to peer ws : {0}".format(self.node.pubkey[:5])) self._logger.debug("Connected successfully to peer ws")
async for msg in ws: async for msg in ws:
if msg.tp == aiohttp.WSMsgType.TEXT: if msg.tp == aiohttp.WSMsgType.TEXT:
self._logger.debug("Received a peer : {0}".format(self.node.pubkey[:5])) self._logger.debug("Received a peer")
peer_data = bma.parse_text(msg.data, bma.ws.WS_PEER_SCHEMA) peer_data = bma.parse_text(msg.data, bma.ws.WS_PEER_SCHEMA)
self.refresh_peer_data(peer_data) self.refresh_peer_data(peer_data)
elif msg.tp == aiohttp.WSMsgType.CLOSED: elif msg.tp == aiohttp.WSMsgType.CLOSED:
...@@ -289,15 +296,14 @@ class NodeConnector(QObject): ...@@ -289,15 +296,14 @@ class NodeConnector(QObject):
elif msg.tp == aiohttp.WSMsgType.ERROR: elif msg.tp == aiohttp.WSMsgType.ERROR:
break break
except (aiohttp.WSServerHandshakeError, ValueError) as e: except (aiohttp.WSServerHandshakeError, ValueError) as e:
self._logger.debug("Websocket peer {0} : {1} - {2}" self._logger.debug("Websocket peer {0} : {1}"
.format(type(e).__name__, str(e), self.node.pubkey[:5])) .format(type(e).__name__, str(e)))
await self.request_peers() await self.request_peers()
except (ClientError, gaierror, TimeoutError) as e: except (ClientError, gaierror, TimeoutError) as e:
self._logger.debug("{0} : {1}".format(str(e), self.node.pubkey[:5])) self._logger.debug("{0}".format(str(e)))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
except jsonschema.ValidationError as e: except jsonschema.ValidationError as e:
self._logger.debug(str(e)) self._logger.debug(str(e))
self._logger.debug("Validation error : {0}".format(self.node.pubkey[:5]))
self.change_state_and_emit(Node.CORRUPTED) self.change_state_and_emit(Node.CORRUPTED)
finally: finally:
self._connected['peer'] = False self._connected['peer'] = False
...@@ -328,9 +334,8 @@ class NodeConnector(QObject): ...@@ -328,9 +334,8 @@ class NodeConnector(QObject):
break break
self.refresh_peer_data(leaf_data['leaf']['value']) self.refresh_peer_data(leaf_data['leaf']['value'])
except (AttributeError, ValueError, errors.DuniterError) as e: except (AttributeError, ValueError, errors.DuniterError) as e:
self._logger.debug("{pubkey} : Incorrect peer data in {leaf}" self._logger.debug("Incorrect peer data in {leaf}"
.format(pubkey=self.node.pubkey[:5], .format(leaf=leaf_hash))
leaf=leaf_hash))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
else: else:
self.node.merkle_peers_root = peers_data['root'] self.node.merkle_peers_root = peers_data['root']
...@@ -340,7 +345,7 @@ class NodeConnector(QObject): ...@@ -340,7 +345,7 @@ class NodeConnector(QObject):
self._logger.debug("Error in peers reply : {0}".format(str(e))) self._logger.debug("Error in peers reply : {0}".format(str(e)))
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
else: else:
self._logger.debug("Could not connect to any BMA endpoint : {0}".format(self.node.pubkey[:5])) self._logger.debug("Could not connect to any BMA endpoint")
self.change_state_and_emit(Node.OFFLINE) self.change_state_and_emit(Node.OFFLINE)
def refresh_peer_data(self, peer_data): def refresh_peer_data(self, peer_data):
...@@ -356,9 +361,6 @@ class NodeConnector(QObject): ...@@ -356,9 +361,6 @@ class NodeConnector(QObject):
self._logger.debug("Incorrect leaf reply") self._logger.debug("Incorrect leaf reply")
def change_state_and_emit(self, new_state): def change_state_and_emit(self, new_state):
if self.node.state in (Node.CORRUPTED, Node.OFFLINE):
self.error.emit()
if self.node.state != new_state: if self.node.state != new_state:
self.node.last_state_change = time.time() self.node.last_state_change = time.time()
self.node.state = new_state self.node.state = new_state
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment