logging: logs before & after all transactions

raiden/network/proxies/discovery.py

@@ -1,3 +1,4 @@
+import structlog
 from eth_utils import is_binary_address, to_checksum_address, to_normalized_address
 from web3.exceptions import BadFunctionCallOutput
 
@@ -12,10 +13,12 @@
 from raiden.network.rpc.smartcontract_proxy import ContractProxy
 from raiden.network.rpc.transactions import check_transaction_threw
 from raiden.settings import EXPECTED_CONTRACTS_VERSION
-from raiden.utils import compare_versions, pex
+from raiden.utils import compare_versions, pex, privatekey_to_address
 from raiden_contracts.constants import CONTRACT_ENDPOINT_REGISTRY
 from raiden_contracts.contract_manager import CONTRACT_MANAGER
 
+log = structlog.get_logger(__name__)  # pylint: disable=invalid-name
+
 
 class Discovery:
     """On chain smart contract raiden node discovery: allows registering
@@ -50,6 +53,7 @@ def __init__(
             raise AddressWrongContract('')
 
         self.address = discovery_address
+        self.node_address = privatekey_to_address(jsonrpc_client.privkey)
         self.client = jsonrpc_client
         self.not_found_address = NULL_ADDRESS
         self.proxy = proxy
@@ -58,6 +62,13 @@ def register_endpoint(self, node_address, endpoint):
         if node_address != self.client.sender:
             raise ValueError("node_address doesnt match this node's address")
 
+        log_details = {
+            'node': pex(self.node_address),
+            'node_address': pex(node_address),
+            'endpoint': endpoint,
+        }
+        log.debug('registerEndpoint called', **log_details)
+
         transaction_hash = self.proxy.transact(
             'registerEndpoint',
             endpoint,
@@ -67,8 +78,11 @@ def register_endpoint(self, node_address, endpoint):
 
         receipt_or_none = check_transaction_threw(self.client, transaction_hash)
         if receipt_or_none:
+            log.critical('registerEndpoint failed', **log_details)
             raise TransactionThrew('Register Endpoint', receipt_or_none)
 
+        log.debug('registerEndpoint successful', **log_details)
+
     def endpoint_by_address(self, node_address_bin):
         node_address_hex = to_checksum_address(node_address_bin)
         endpoint = self.proxy.contract.functions.findEndpointByAddress(

raiden/network/proxies/secret_registry.py

@@ -56,67 +56,58 @@ def register_secret(self, secret: typing.Secret):
         self.register_secret_batch([secret])
 
     def register_secret_batch(self, secrets: List[typing.Secret]):
-        secret_batch = list()
+        secrets_to_register = list()
+        secrethashes_to_register = list()
+        secrethashes_not_sent = list()
         secret_registry_transaction = AsyncResult()
 
         for secret in secrets:
             secrethash = sha3(secret)
-            if not self.check_registered(secrethash):
-                if secret not in self.open_secret_transactions:
-                    secret_batch.append(secret)
-                    self.open_secret_transactions[secret] = secret_registry_transaction
+
+            is_register_needed = (
+                not self.check_registered(secrethash) and
+                secret not in self.open_secret_transactions
+            )
+            if is_register_needed:
+                secrets_to_register.append(secret)
+                secrethashes_to_register.append(secrethash)
+                self.open_secret_transactions[secret] = secret_registry_transaction
             else:
-                log.info(
-                    f'secret {encode_hex(secrethash)} already registered.',
-                    node=pex(self.node_address),
-                    contract=pex(self.address),
-                    secrethash=encode_hex(secrethash),
-                )
-
-        if not secret_batch:
-            return
-
-        log.info(
-            'registerSecretBatch called',
-            node=pex(self.node_address),
-            contract=pex(self.address),
-        )
+                secrethashes_not_sent.append(secrethash)
+
+        log_details = {
+            'node': pex(self.node_address),
+            'contract': pex(self.address),
+            'secrets': secrethashes_to_register,
+            'secrets_not_sent': secrethashes_not_sent,
+        }
+
+        if not secrets_to_register:
+            log.debug('registerSecretBatch skipped', **log_details)
+
+        log.debug('registerSecretBatch called', **log_details)
 
         try:
-            transaction_hash = self._register_secret_batch(secret_batch)
+            transaction_hash = self._register_secret_batch(secrets_to_register)
         except Exception as e:
+            log.critical('registerSecretBatch failed', **log_details)
             secret_registry_transaction.set_exception(e)
             raise
         else:
+            log.info('registerSecretBatch successful', **log_details)
             secret_registry_transaction.set(transaction_hash)
         finally:
-            for secret in secret_batch:
+            for secret in secrets_to_register:
                 self.open_secret_transactions.pop(secret, None)
 
     def _register_secret_batch(self, secrets):
-        transaction_hash = self.proxy.transact(
-            'registerSecretBatch',
-            secrets,
-        )
-
+        transaction_hash = self.proxy.transact('registerSecretBatch', secrets)
         self.client.poll(transaction_hash)
         receipt_or_none = check_transaction_threw(self.client, transaction_hash)
 
         if receipt_or_none:
-            log.critical(
-                'registerSecretBatch failed',
-                node=pex(self.node_address),
-                contract=pex(self.address),
-                secrets=secrets,
-            )
             raise TransactionThrew('registerSecretBatch', receipt_or_none)
 
-        log.info(
-            'registerSecretBatch successful',
-            node=pex(self.node_address),
-            contract=pex(self.address),
-            secrets=secrets,
-        )
         return transaction_hash
 
     def get_register_block_for_secrethash(self, secrethash: typing.Keccak256) -> int:

raiden/network/proxies/token.py

@@ -1,12 +1,16 @@
+import structlog
 from eth_utils import is_binary_address, to_checksum_address, to_normalized_address
 
 from raiden.exceptions import TransactionThrew
 from raiden.network.rpc.client import check_address_has_code
 from raiden.network.rpc.smartcontract_proxy import ContractProxy
 from raiden.network.rpc.transactions import check_transaction_threw
+from raiden.utils import pex, privatekey_to_address
 from raiden_contracts.constants import CONTRACT_HUMAN_STANDARD_TOKEN
 from raiden_contracts.contract_manager import CONTRACT_MANAGER
 
+log = structlog.get_logger(__name__)  # pylint: disable=invalid-name
+
 
 class Token:
     def __init__(
@@ -27,6 +31,7 @@ def __init__(
 
         self.address = token_address
         self.client = jsonrpc_client
+        self.node_address = privatekey_to_address(jsonrpc_client.privkey)
         self.proxy = proxy
 
     def allowance(self, owner, spender):
@@ -35,14 +40,26 @@ def allowance(self, owner, spender):
             to_checksum_address(spender),
         ).call()
 
-    def approve(self, contract_address, allowance):
-        """ Aprove `contract_address` to transfer up to `deposit` amount of token. """
-        # TODO: check that `contract_address` is a netting channel and that
-        # `self.address` is one of the participants (maybe add this logic into
-        # `NettingChannel` and keep this straight forward)
+    def approve(self, allowed_address, allowance):
+        """ Aprove `allowed_address` to transfer up to `deposit` amount of token.
+
+        Note:
+
+            For channel deposit please use the channel proxy, since it does
+            additional validations.
+        """
+
+        log_details = {
+            'node': pex(self.node_address),
+            'contract': pex(self.address),
+            'allowed_address': pex(allowed_address),
+            'allowance': allowance,
+        }
+        log.debug('approve called', **log_details)
+
         transaction_hash = self.proxy.transact(
             'approve',
-            to_checksum_address(contract_address),
+            to_checksum_address(allowed_address),
             allowance,
         )
 
@@ -61,7 +78,6 @@ def approve(self, contract_address, allowance):
                     "contract is not a valid ERC20 token or you don't have funds "
                     "to use for openning a channel. "
                 )
-                raise TransactionThrew(msg, receipt_or_none)
 
             # The approve call failed, check the user has enough balance
             # (assuming the token smart contract may check for the maximum
@@ -73,18 +89,22 @@ def approve(self, contract_address, allowance):
                     'approve failed. Please make sure the corresponding smart '
                     'contract is a valid ERC20 token.'
                 ).format(user_balance)
-                raise TransactionThrew(msg, receipt_or_none)
 
             # If the user has enough balance, warn the user the smart contract
             # may not have the approve function.
             else:
                 msg = (
-                    'Approve failed. \n'
-                    'Your account balance is {}, the request allowance is {}. '
-                    'The smart contract may be rejecting your request for the '
-                    'lack of balance.'
-                ).format(user_balance, allowance)
-                raise TransactionThrew(msg, receipt_or_none)
+                    f'Approve failed. \n'
+                    f'Your account balance is {user_balance}, '
+                    f'the request allowance is {allowance}. '
+                    f'The smart contract may be rejecting your request for the '
+                    f'lack of balance.'
+                )
+
+            log.critical(f'approve failed, {msg}', **log_details)
+            raise TransactionThrew(msg, receipt_or_none)
+
+        log.info('approve successful', **log_details)
 
     def balance_of(self, address):
         """ Return the balance of `address`. """
@@ -93,6 +113,14 @@ def balance_of(self, address):
         ).call()
 
     def transfer(self, to_address, amount):
+        log_details = {
+            'node': pex(self.node_address),
+            'contract': pex(self.address),
+            'to_address': pex(to_address),
+            'amount': amount,
+        }
+        log.debug('transfer called', **log_details)
+
         transaction_hash = self.proxy.transact(
             'transfer',
             to_checksum_address(to_address),
@@ -102,6 +130,8 @@ def transfer(self, to_address, amount):
         self.client.poll(transaction_hash)
         receipt_or_none = check_transaction_threw(self.client, transaction_hash)
         if receipt_or_none:
+            log.critical('transfer failed', **log_details)
             raise TransactionThrew('Transfer', receipt_or_none)
 
-        # TODO: check Transfer event
+        # TODO: check Transfer event (issue: #2598)
+        log.info('transfer successful', **log_details)