Bugfix: acive waller-rpc if node changes, debugging (#2066)

* using an updated rpc whenever needed

* better grip why update has been called

* better loading report in wallet_manager

* type-hints

* Add infra for reasonable debugging in vscode

* add doc string for wallet method in rpc

* Update src/cryptoadvance/specter/wallet.py

Co-authored-by: Manolis Mandrapilias <70536101+moneymanolis@users.noreply.github.com>

* Update src/cryptoadvance/specter/wallet.py

Co-authored-by: Manolis Mandrapilias <70536101+moneymanolis@users.noreply.github.com>

* black

* fix circular dependency

Co-authored-by: Manolis Mandrapilias <70536101+moneymanolis@users.noreply.github.com>
Co-authored-by: moneymanolis <moneymanolis@protonmail.com>

.vscode/launch.json

@@ -0,0 +1,29 @@
+{
+    // Use IntelliSense to learn about possible attributes.
+    // Hover to view descriptions of existing attributes.
+    // For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387
+    "version": "0.2.0",
+    "configurations": [
+        {
+            "name": "Python: Flask",
+            "type": "python",
+            "request": "launch",
+            "module": "flask",
+            "env": {
+                "FLASK_APP": "cryptoadvance.specter.server:create_and_init()",
+                "FLASK_ENV": "development",
+                "SPECTER_DATA_FOLDER": "~/.specter_empty",
+                "SPECTER_CONFIG": "DevelopmentConfig",
+                "FLASK_DEBUG": "1",
+                "PATH": "./.env/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
+            },
+            "args": [
+                "run",
+                "--no-debugger",
+                "--no-reload",
+                "--port=25441"
+            ],
+            "jinja": true
+        }
+    ]
+}

src/cryptoadvance/specter/cli/__init__.py

@@ -1,13 +1,13 @@
 import logging
 import os
-from http.client import HTTPConnection
 
 import click
 
-from .cli_noded import bitcoind, elementsd
+from ..server import setup_logging
 from .cli_ext import ext
-from .cli_server import server
 from .cli_gunicorn import gunicorn
+from .cli_noded import bitcoind, elementsd
+from .cli_server import server
 
 logger = logging.getLogger(__name__)
 
@@ -26,39 +26,7 @@ logger = logging.getLogger(__name__)
 )
 @click.pass_context
 def entry_point(config_home, debug=False, tracerpc=False, tracerequests=False):
-    ch = logging.StreamHandler()
-    ch.setLevel(logging.DEBUG)
-    if tracerpc or tracerequests:
-        if tracerpc:
-            debug = True  # otherwise this won't work
-            logging.getLogger("cryptoadvance.specter.rpc").setLevel(logging.DEBUG)
-        if tracerequests:
-            # from here: https://stackoverflow.com/questions/16337511/log-all-requests-from-the-python-requests-module
-            HTTPConnection.debuglevel = 1
-            requests_log = logging.getLogger("requests.packages.urllib3")
-            requests_log.setLevel(logging.DEBUG)
-            requests_log.propagate = True
-    else:
-        logging.getLogger("cryptoadvance.specter.rpc").setLevel(logging.INFO)
-
-    if debug:
-        # No need for timestamps while developing
-        formatter = logging.Formatter("[%(levelname)7s] in %(module)15s: %(message)s")
-        logging.getLogger("cryptoadvance").setLevel(logging.DEBUG)
-        # but not that chatty connectionpool
-        logging.getLogger("urllib3.connectionpool").setLevel(logging.INFO)
-    else:
-        formatter = logging.Formatter(
-            # Too early to format that via the flask-config, so let's copy it from there:
-            os.getenv(
-                "SPECTER_LOGFORMAT",
-                "[%(asctime)s] %(levelname)s in %(module)s: %(message)s",
-            )
-        )
-        logging.getLogger("cryptoadvance").setLevel(logging.INFO)
-    ch.setFormatter(formatter)
-    logging.getLogger().handlers = []
-    logging.getLogger().addHandler(ch)
+    setup_logging(debug, tracerpc, tracerequests)
 
 
 entry_point.add_command(server)

src/cryptoadvance/specter/cli/cli_gunicorn.py

@@ -18,7 +18,8 @@ except ModuleNotFoundError as e:
         pass
     else:
         raise e
-from cryptoadvance.specter.server import create_and_init, create_app, init_app
+from cryptoadvance.specter.server import create_app, init_app
+from cryptoadvance.specter.server import create_and_init
 from OpenSSL import SSL, crypto
 from stem.control import Controller
 

src/cryptoadvance/specter/cli/cli_server.py

@@ -5,15 +5,15 @@ import sys
 import time
 from os import path
 from socket import gethostname
+from urllib.parse import urlparse
 
 import click
 from OpenSSL import SSL, crypto
 from stem.control import Controller
-from urllib.parse import urlparse
 
-from ..server import create_app, init_app
-from ..util.tor import start_hidden_service, stop_hidden_services
+from ..server import create_app, init_app, setup_logging, setup_debug_logging
 from ..specter_error import SpecterError
+from ..util.tor import start_hidden_service, stop_hidden_services
 
 logger = logging.getLogger(__name__)
 
@@ -88,12 +88,15 @@ def server(
     specter_data_folder,
     config,
 ):
-    """Run Specter Desktop as a http(s)-service"""
+    """This code is a function that runs Specter Desktop as a http(s)-service.
+    It sets up logging, creates an app to get Specter instance and its data folder,
+    sets certificates, initializes the app with the given parameters,
+    runs the app with the given parameters,
+    and stops any hidden services when it's done.
+    """
     # logging
     if debug:
-        ca_logger = logging.getLogger("cryptoadvance")
-        ca_logger.setLevel(logging.DEBUG)
-        logger.debug("We're now on level DEBUG on logger cryptoadvance")
+        setup_debug_logging()
 
     # create an app to get Specter instance
     # and it's data folder

src/cryptoadvance/specter/cli/utils.py

@@ -2,6 +2,7 @@ import logging
 import os
 import shutil
 import signal
+from http.client import HTTPConnection
 from pathlib import Path
 
 import click

src/cryptoadvance/specter/devices/bitcoin_core.py

@@ -308,4 +308,4 @@ class BitcoinCoreWatchOnly(BitcoinCore):
         # Change type (also triggers write to file)
         self.set_type(DeviceTypes.BITCOINCORE)
         # After update this device will be available as a BitcoinCore (hot) instance
-        self.manager.update()
+        self.manager.update(comment="via BitcoinCoreWatchOnly")

src/cryptoadvance/specter/gunicorn.py

@@ -1,5 +1,6 @@
 import multiprocessing
-from cryptoadvance.specter.server import init_app, create_app, create_and_init
+
+from cryptoadvance.specter.server import create_and_init, create_app, init_app
 
 from gunicorn.app.wsgiapp import WSGIApplication
 

src/cryptoadvance/specter/managers/wallet_manager.py

@@ -63,12 +63,15 @@ class WalletManager:
         rpc: BitcoinRPC = None,
         chain: str = None,
         use_threading=True,
+        comment="",
     ):
         """Restructures the instance, specifically if chain/rpc changed
         The _update internal method will resync the internal status with Bitcoin Core
         use_threading : for the _update method which is heavily communicating with Bitcoin Core
         """
-        logger.debug("starting update of wallet_manager")
+        logger.debug(
+            f"starting update of wallet_manager (threading: {use_threading} , comment: {comment})"
+        )
         if self.is_loading:
             logger.debug("update in progress, aborting!")
             return
@@ -261,8 +264,10 @@ class WalletManager:
         except RpcError as e:
             logger.error(f"Failed updating wallet manager. RPC error: {e}")
         logger.info("Updating wallet manager done. Result:")
-        logger.info(f"  * failed_load_wallets: {self._failed_load_wallets}")
         logger.info(f"  * loaded_wallets: {len(self.wallets)}")
+        logger.info(f"  * failed_load_wallets: {len(self._failed_load_wallets)}")
+        for wallet in self._failed_load_wallets:
+            logger.info(f"    * {wallet['name']} : {wallet['loading_error']}")
 
         wallets_update_list = {}
         self.is_loading = False

src/cryptoadvance/specter/rpc.py

@@ -324,6 +324,7 @@ class BitcoinRPC:
         self.session = session
 
     def wallet(self, name=""):
+        """Return new instance connected to a specific wallet"""
         return type(self)(
             user=self.user,
             password=self.password,

src/cryptoadvance/specter/server.py

@@ -1,18 +1,13 @@
 import logging
 import os
 import sys
+from distutils.core import setup
+from http.client import HTTPConnection
 from pathlib import Path
-from cryptoadvance.specter.hwi_rpc import HWIBridge
 
-from cryptoadvance.specter.liquid.rpc import LiquidRPC
-from cryptoadvance.specter.managers.service_manager import ServiceManager
-from cryptoadvance.specter.rpc import BitcoinRPC
-from cryptoadvance.specter.services import callbacks
-from cryptoadvance.specter.util.reflection import get_template_static_folder
 from dotenv import load_dotenv
 from flask import Flask, jsonify, redirect, request, session, url_for
 from flask_apscheduler import APScheduler
-from .htmlsafebabel import HTMLSafeBabel
 from flask_login import LoginManager, login_user
 from flask_wtf.csrf import CSRFProtect
 from jinja2 import select_autoescape
@@ -20,6 +15,14 @@ from werkzeug.middleware.dispatcher import DispatcherMiddleware
 from werkzeug.middleware.proxy_fix import ProxyFix
 from werkzeug.wrappers import Response
 
+from cryptoadvance.specter.hwi_rpc import HWIBridge
+from cryptoadvance.specter.liquid.rpc import LiquidRPC
+from cryptoadvance.specter.managers.service_manager import ServiceManager
+from cryptoadvance.specter.rpc import BitcoinRPC
+from cryptoadvance.specter.services import callbacks
+from cryptoadvance.specter.util.reflection import get_template_static_folder
+
+from .htmlsafebabel import HTMLSafeBabel
 from .hwi_server import hwi_server
 from .services.callbacks import after_serverpy_init_app, specter_added_to_flask_app
 from .specter import Specter
@@ -114,7 +117,13 @@ def create_app(config=None):
 
 
 def init_app(app: SpecterFlask, hwibridge=False, specter=None):
-    """see blogpost 19nd Feb 2020"""
+    """This code is used to initialize a Flask application.
+    It sets up the app's URL prefix, runs migrations, initializes login via Flask-Login,
+    sets up a user loader for the login manager, attaches the specter instance to the
+    app, registers blueprints for extensions, and sets up a context processor and
+    language selector for Babel integration. It also initializes a background scheduler
+    and runs an after_serverpy_init_app callback.
+    """
 
     # Configuring a prefix for the app
     if app.config["APP_URL_PREFIX"] != "":
@@ -275,11 +284,61 @@ def init_app(app: SpecterFlask, hwibridge=False, specter=None):
     return app
 
 
-def create_and_init(config="cryptoadvance.specter.config.ProductionConfig"):
+def setup_logging(debug=False, tracerpc=False, tracerequests=False):
+    """This code sets up logging for a Python application. It sets the logging level to DEBUG if the tracerpc
+    or tracerequests flags are set, and INFO otherwise. It also sets up the formatter for the log messages,
+    which can be customized with an environment variable. Finally, it adds a StreamHandler to the root
+    logger and removes any existing handlers.
+    """
+    ch = logging.StreamHandler()
+    ch.setLevel(logging.DEBUG)
+    if tracerpc or tracerequests:
+        if tracerpc:
+            debug = True  # otherwise this won't work
+            logging.getLogger("cryptoadvance.specter.rpc").setLevel(logging.DEBUG)
+        if tracerequests:
+            # from here: https://stackoverflow.com/questions/16337511/log-all-requests-from-the-python-requests-module
+            HTTPConnection.debuglevel = 1
+            requests_log = logging.getLogger("requests.packages.urllib3")
+            requests_log.setLevel(logging.DEBUG)
+            requests_log.propagate = True
+    else:
+        logging.getLogger("cryptoadvance.specter.rpc").setLevel(logging.INFO)
+
+    if debug:
+        # No need for timestamps while developing
+        formatter = logging.Formatter("[%(levelname)7s] in %(module)15s: %(message)s")
+        logging.getLogger("cryptoadvance").setLevel(logging.DEBUG)
+        # but not that chatty connectionpool
+        logging.getLogger("urllib3.connectionpool").setLevel(logging.INFO)
+    else:
+        formatter = logging.Formatter(
+            # Too early to format that via the flask-config, so let's copy it from there:
+            os.getenv(
+                "SPECTER_LOGFORMAT",
+                "[%(asctime)s] %(levelname)s in %(module)s: %(message)s",
+            )
+        )
+        logging.getLogger("cryptoadvance").setLevel(logging.INFO)
+    ch.setFormatter(formatter)
+    logging.getLogger().handlers = []
+    logging.getLogger().addHandler(ch)
+
+
+def setup_debug_logging():
+    """Sets the cryptoadvance.* logger to debug"""
+    ca_logger = logging.getLogger("cryptoadvance")
+    ca_logger.setLevel(logging.DEBUG)
+    logger.debug("We're now on level DEBUG on logger cryptoadvance")
+
+
+def create_and_init(config="cryptoadvance.specter.config.DevelopmentConfig"):
     """This method can be used to fill the FLASK_APP-env variable like
     export FLASK_APP="src/cryptoadvance/specter/server:create_and_init()"
-    See Development.md to use this for debugging
+    See Development.md to use this for debugging. It's currently used in launch.json
     """
+    setup_logging(debug=True)
+    setup_debug_logging()
     app = create_app(config)
     with app.app_context():
         init_app(app)

src/cryptoadvance/specter/server_endpoints/controller.py

@@ -88,7 +88,7 @@ def server_specter_error(se):
         return {"error": str(se)}
     flash(str(se), "error")
     try:
-        app.specter.wallet_manager.update()
+        app.specter.wallet_manager.update(comment="via server_specter_error")
     except SpecterError as se:
         flash(str(se), "error")
     if request.method == "POST":

src/cryptoadvance/specter/server_endpoints/wallets/wallets.py

@@ -35,7 +35,7 @@ wallets_endpoint = Blueprint("wallets_endpoint", __name__)
 def handle_wallet_error(func_name, error):
     flash(_("SpecterError while {}: {}").format(func_name, error), "error")
     app.logger.error(f"SpecterError while {func_name}: {error}")
-    app.specter.wallet_manager.update()
+    app.specter.wallet_manager.update(comment="via handle_wallet_error")
     return redirect(url_for("welcome_endpoint.about"))
 
 
@@ -121,7 +121,9 @@ def failed_wallets():
     if request.method == "POST":
         action = request.form["action"]
         if action == "retry_loading_wallets":
-            app.specter.wallet_manager.update()
+            app.specter.wallet_manager.update(
+                comment="via failed_wallets_retry_loading_wallets"
+            )
         elif action == "delete_failed_wallet":
             try:
                 wallet = json.loads(request.form["wallet_data"])
@@ -130,7 +132,9 @@ def failed_wallets():
                 delete_file(fullpath + ".bkp")
                 delete_file(fullpath.replace(".json", "_addr.csv"))
                 delete_file(fullpath.replace(".json", "_txs.csv"))
-                app.specter.wallet_manager.update()
+                app.specter.wallet_manager.update(
+                    comment="via failed_wallets_delete_failed_wallet"
+                )
             except Exception as e:
                 handle_exception(e)
                 flash(_("Failed to delete wallet: {}").format(str(e)), "error")
@@ -440,7 +444,7 @@ def history(wallet_alias):
     wallet.update_balance()
     wallet.check_utxo()
 
-    return render_template(
+    renderting = render_template(
         "wallet/history/wallet_history.jinja",
         wallet_alias=wallet_alias,
         wallet=wallet,
@@ -449,6 +453,8 @@ def history(wallet_alias):
         rand=rand,
         services=app.specter.service_manager.services,
     )
+    logger.info("-------------------end render_template()")
+    return renderting
 
 
 ###### Wallet receive ######

src/cryptoadvance/specter/specter.py

@@ -231,6 +231,7 @@ class Specter:
             user = self.user_manager.get_user(user)
             user.check()
         else:
+            u: User
             for u in self.user_manager.users:
                 u.check()
 

src/cryptoadvance/specter/user.py

@@ -306,7 +306,10 @@ class User(UserMixin):
             self._wallet_manager = wallet_manager
         else:
             wallet_manager.update(
-                wallets_folder, self.specter.rpc, chain=self.specter.chain
+                wallets_folder,
+                self.specter.rpc,
+                chain=self.specter.chain,
+                comment="via user",
             )
 
     def check_device_manager(self, user=None):

src/cryptoadvance/specter/wallet.py

@@ -130,9 +130,7 @@ class Wallet:
 
         self.device_manager = device_manager
         self.manager = manager
-        self.rpc = self.manager.rpc.wallet(
-            os.path.join(self.manager.rpc_path, self.alias)
-        )
+        self.manager_rpc = manager.rpc
         self._devices = devices
         # check that all of the devices exist
         if None in self.devices:
@@ -176,6 +174,22 @@ class Wallet:
         ):
             self.save_to_file()
 
+    @property
+    def rpc(self):
+        """Cache RPC instance. Reuse if manager's RPC instance hasn't changed. Create new RPC instance otherwise.
+        This RPC instance is also used by objects created by the wallet, such as TxList or TxItem
+        """
+        if hasattr(self, "_rpc"):
+            if (
+                self.manager.rpc is self.manager_rpc
+            ):  # did the manager not change its rpc-instance?
+                return self._rpc
+        self.manager_rpc = self.manager.rpc
+        self._rpc = self.manager_rpc.wallet(
+            os.path.join(self.manager.rpc_path, self.alias)
+        )
+        return self._rpc
+
     @property
     def recv_descriptor(self):
         return add_checksum(str(self.descriptor.branch(0)))