State logger (#352)

* State logger

Logs the state of an instance, e.g. txbuilder, when an exception is raised. Optionally, the state could be logged every time when the function is called if log level of the parent logger is set to DEBUG.

State logger is added to `TransactionBuilder.build()`, `TransactionBuilder.build_and_sign()`, `ChainContext.submit_tx()`.

* Remove redundant pytest log level

Author: cffls

Makefile

@@ -55,7 +55,7 @@ clean-test: ## remove test and coverage artifacts
 	rm -fr .pytest_cache
 
 test: ## runs tests
-	poetry run pytest -s -vv -n 4
+	poetry run pytest -vv -n 4
 
 test-single: ## runs tests with "single" markers
 	poetry run pytest -s -vv -m single

poetry.lock

@@ -6,6 +6,7 @@
 
 from pycardano.address import Address
 from pycardano.exception import InvalidArgumentException
+from pycardano.logging import log_state
 from pycardano.network import Network
 from pycardano.plutus import ExecutionUnits
 from pycardano.transaction import Transaction, UTxO
@@ -160,6 +161,7 @@ def _utxos(self, address: str) -> List[UTxO]:
         """
         raise NotImplementedError()
 
+    @log_state
     def submit_tx(self, tx: Union[Transaction, bytes, str]):
         """Submit a transaction to the blockchain.
 

pycardano/backend/base.py

@@ -1,14 +1,14 @@
 import logging
 
-__all__ = ["logger"]
+from pprintpp import pformat
+
+__all__ = ["logger", "log_state"]
 
 # create logger
 logger = logging.getLogger("PyCardano")
-logger.setLevel(logging.WARNING)
 
 # create console handler and set level to debug
 ch = logging.StreamHandler()
-ch.setLevel(logging.WARNING)
 
 # create formatter
 formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
@@ -18,3 +18,22 @@
 
 # add ch to logger
 logger.addHandler(ch)
+
+
+def log_state(func):
+    """Decorator to log the state of an object after its function call."""
+
+    def wrapper(obj, *args, **kwargs):
+        try:
+            output = func(obj, *args, **kwargs)
+            logger.debug(
+                f"Class: {obj.__class__}, method: {func}, state:\n {pformat(vars(obj), indent=2)}"
+            )
+            return output
+        except Exception as e:
+            logger.warning(
+                f"Class: {obj.__class__}, method: {func}, state:\n {pformat(vars(obj), indent=2)}"
+            )
+            raise e
+
+    return wrapper

pycardano/logging.py

@@ -29,7 +29,7 @@
 )
 from pycardano.hash import DatumHash, ScriptDataHash, ScriptHash, VerificationKeyHash
 from pycardano.key import ExtendedSigningKey, SigningKey, VerificationKey
-from pycardano.logging import logger
+from pycardano.logging import log_state, logger
 from pycardano.metadata import AuxiliaryData
 from pycardano.nativescript import NativeScript, ScriptAll, ScriptAny, ScriptPubkey
 from pycardano.plutus import (
@@ -988,6 +988,7 @@ def _estimate_fee(self):
 
         return estimated_fee
 
+    @log_state
     def build(
         self,
         change_address: Optional[Address] = None,
@@ -1357,6 +1358,7 @@ def _estimate_execution_units(
 
         return self.context.evaluate_tx(tx)
 
+    @log_state
     def build_and_sign(
         self,
         signing_keys: List[Union[SigningKey, ExtendedSigningKey]],

pycardano/txbuilder.py

@@ -39,7 +39,7 @@ docker = "^6.1.3"
 [tool.poetry.dev-dependencies]
 Sphinx = "^4.3.2"
 sphinx-rtd-theme = "^1.1.1"
-pytest = "^7.4.4"
+pytest = "^8.2.0"
 pytest-cov = "^4.0.0"
 flake8 = "^5.0.4"
 isort = "^5.11.4"
@@ -67,6 +67,7 @@ markers = [
     "single"
 ]
 
+
 [tool.isort]
 profile = "black"
 

pyproject.toml

@@ -1,4 +1,5 @@
 import copy
+import logging
 from dataclasses import replace
 from fractions import Fraction
 from test.pycardano.test_key import SK
@@ -220,6 +221,30 @@ def test_tx_builder_raises_utxo_selection(chain_context):
     assert "{AssetName(b'NewToken'): 1}" in e.value.args[0]
 
 
+def test_tx_builder_state_logger_warning_level(chain_context, caplog):
+    with caplog.at_level(logging.WARNING):
+        test_tx_builder_raises_utxo_selection(chain_context)
+        assert "WARNING" in caplog.text
+
+
+def test_tx_builder_state_logger_error_level(chain_context, caplog):
+    with caplog.at_level(logging.ERROR):
+        test_tx_builder_raises_utxo_selection(chain_context)
+        assert "WARNING" not in caplog.text
+
+
+def test_tx_builder_state_logger_info_level(chain_context, caplog):
+    with caplog.at_level(logging.INFO):
+        test_tx_builder_multi_asset(chain_context)
+        assert "DEBUG" not in caplog.text
+
+
+def test_tx_builder_state_logger_debug_level(chain_context, caplog):
+    with caplog.at_level(logging.DEBUG):
+        test_tx_builder_multi_asset(chain_context)
+        assert "DEBUG" in caplog.text
+
+
 def test_tx_too_big_exception(chain_context):
     tx_builder = TransactionBuilder(chain_context)
     sender = "addr_test1vrm9x2zsux7va6w892g38tvchnzahvcd9tykqf3ygnmwtaqyfg52x"