diff --git a/pyproject.toml b/pyproject.toml index 002bfe2cd..ee1855442 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -58,6 +58,7 @@ branch = true [tool.pytest.ini_options] testpaths = ["tests"] +addopts = "-p no:logging" [tool.setuptools] include-package-data = true diff --git a/src/main.py b/src/main.py old mode 100644 new mode 100755 index 740faf30a..c6888267c --- a/src/main.py +++ b/src/main.py @@ -1,4 +1,53 @@ +#!/usr/bin/env python + +import argparse +import logging +import sys + from seedsigner.controller import Controller -# Get the one and only Controller instance and start our main loop -Controller.get_instance().start() +logger = logging.getLogger(__name__) + +DEFAULT_MODULE_LOG_LEVELS = { + "PIL": logging.WARNING, + # "seedsigner.gui.toast": logging.DEBUG, # example of more specific submodule logging config +} + + +def main(sys_argv=None): + parser = argparse.ArgumentParser() + parser.add_argument( + "-l", + "--loglevel", + choices=list((logging._nameToLevel.keys())), + default="INFO", + type=str, + help=( + "Set the log level (default: %(default)s), WARNING: changing the log level " + "to something more verbose than %(default)s may result in unwanted data " + "being written to stderr" + ), + ) + + args = parser.parse_args(sys_argv) + + root_logger = logging.getLogger() + root_logger.setLevel(logging.getLevelName(args.loglevel)) + console_handler = logging.StreamHandler(sys.stderr) + console_handler.setFormatter( + logging.Formatter("%(asctime)s %(levelname)8s [%(name)s %(funcName)s (%(lineno)d)]: %(message)s") + ) + root_logger.addHandler(console_handler) + + # Set log levels for specific modules + for module, level in DEFAULT_MODULE_LOG_LEVELS.items(): + logging.getLogger(module).setLevel(level) + + logger.info(f"Starting SeedSigner with: {args.__dict__}") + + # Get the one and only Controller instance and start our main loop + Controller.get_instance().start() + + +if __name__ == "__main__": + main(sys.argv[1:]) diff --git a/src/seedsigner/controller.py b/src/seedsigner/controller.py index 37d80e479..6243955ff 100644 --- a/src/seedsigner/controller.py +++ b/src/seedsigner/controller.py @@ -264,7 +264,7 @@ def start(self, initial_destination: Destination = None) -> None: Example: class MyView(View) def run(self, some_arg, other_arg): - print(other_arg) + logger.info(other_arg) class OtherView(View): def run(self): @@ -305,11 +305,11 @@ def run(self): self.psbt_parser = None self.psbt_seed = None - print(f"back_stack: {self.back_stack}") + logger.info(f"\nback_stack: {self.back_stack}") try: # Instantiate the View class and run it - print(f"Executing {next_destination}") + logger.info(f"Executing {next_destination}") next_destination = next_destination.run() except StopFlowBasedTest: @@ -337,7 +337,7 @@ def run(self): # Remove the current View from history; it's forwarding us straight # to the next View so it should be as if this View never happened. current_view = self.back_stack.pop() - print(f"Skipping current view: {current_view}") + logger.info(f"Skipping current view: {current_view}") # Hang on to this reference... clear_history = next_destination.clear_history @@ -355,12 +355,10 @@ def run(self): # Do not push a "new" destination if it is the same as the current one on # the top of the stack. if len(self.back_stack) == 0 or self.back_stack[-1] != next_destination: - print(f"Appending next destination: {next_destination}") + logger.info(f"Appending next destination: {next_destination}") self.back_stack.append(next_destination) else: - print(f"NOT appending {next_destination}") - - print("-" * 30) + logger.info(f"NOT appending {next_destination}") finally: from seedsigner.gui.renderer import Renderer @@ -371,7 +369,7 @@ def run(self): self.toast_notification_thread.stop() # Clear the screen when exiting - print("Clearing screen, exiting") + logger.info("Clearing screen, exiting") Renderer.get_instance().display_blank_screen() @@ -385,10 +383,10 @@ def start_screensaver(self): # block until the screensaver is done, at which point the toast can re-acquire # the Renderer.lock and resume where it left off. if self.toast_notification_thread and self.toast_notification_thread.is_alive(): - print(f"Controller: settings toggle_render_lock for {self.toast_notification_thread.__class__.__name__}") + logger.info(f"Controller: settings toggle_render_lock for {self.toast_notification_thread.__class__.__name__}") self.toast_notification_thread.toggle_renderer_lock() - print("Controller: Starting screensaver") + logger.info("Controller: Starting screensaver") if not self.screensaver: # Do a lazy/late import and instantiation to reduce Controller initial startup time from seedsigner.views.screensaver import ScreensaverScreen @@ -397,7 +395,7 @@ def start_screensaver(self): # Start the screensaver, but it will block until it can acquire the Renderer.lock. self.screensaver.start() - print("Controller: Screensaver started") + logger.info("Controller: Screensaver started") def reset_screensaver_timeout(self): @@ -416,16 +414,16 @@ def activate_toast(self, toast_manager_thread: BaseToastOverlayManagerThread): """ if self.is_screensaver_running: # New toast notifications break out of the Screensaver - print("Controller: stopping screensaver") + logger.info("Controller: stopping screensaver") self.screensaver.stop() if self.toast_notification_thread and self.toast_notification_thread.is_alive(): # Can only run one toast at a time - print(f"Controller: stopping {self.toast_notification_thread.__class__.__name__}") + logger.info(f"Controller: stopping {self.toast_notification_thread.__class__.__name__}") self.toast_notification_thread.stop() self.toast_notification_thread = toast_manager_thread - print(f"Controller: starting {self.toast_notification_thread.__class__.__name__}") + logger.info(f"Controller: starting {self.toast_notification_thread.__class__.__name__}") self.toast_notification_thread.start() diff --git a/src/seedsigner/gui/components.py b/src/seedsigner/gui/components.py index 2046f4e17..0706f2139 100644 --- a/src/seedsigner/gui/components.py +++ b/src/seedsigner/gui/components.py @@ -1,3 +1,4 @@ +import logging import math import os import pathlib @@ -13,6 +14,8 @@ from seedsigner.models.settings_definition import SettingsConstants from seedsigner.models.singleton import Singleton +logger = logging.getLogger(__name__) + # TODO: Remove all pixel hard coding class GUIConstants: @@ -1439,7 +1442,7 @@ def reflow_text_into_pages(text: str, lines = [] for line_dict in reflowed_lines_dicts: lines.append(line_dict["text"]) - print(f"""{line_dict["text_width"]:3}: {line_dict["text"]}""") + logging.info(f"""{line_dict["text_width"]:3}: {line_dict["text"]}""") font = Fonts.get_font(font_name=font_name, size=font_size) # Measure the font's height above baseline and how for below it certain characters diff --git a/src/seedsigner/gui/screens/seed_screens.py b/src/seedsigner/gui/screens/seed_screens.py index 89e42daa2..4db7012d3 100644 --- a/src/seedsigner/gui/screens/seed_screens.py +++ b/src/seedsigner/gui/screens/seed_screens.py @@ -1,4 +1,5 @@ import math +import logging import time from dataclasses import dataclass @@ -16,6 +17,7 @@ from seedsigner.gui.keyboard import Keyboard, TextEntryDisplay from seedsigner.hardware.buttons import HardwareButtons, HardwareButtonsConstants +logger = logging.getLogger(__name__) @dataclass @@ -1411,9 +1413,9 @@ def __post_init__(self): def _run_callback(self): # Exit the screen on success via a non-None value - print(f"verified_index: {self.verified_index.cur_count}") + logger.info(f"verified_index: {self.verified_index.cur_count}") if self.verified_index.cur_count is not None: - print("Screen callback returning success!") + logger.info("Screen callback returning success!") self.threads[-1].stop() while self.threads[-1].is_alive(): time.sleep(0.01) diff --git a/src/seedsigner/gui/toast.py b/src/seedsigner/gui/toast.py index 7a07f30bc..d21ff02c9 100644 --- a/src/seedsigner/gui/toast.py +++ b/src/seedsigner/gui/toast.py @@ -1,8 +1,10 @@ +import logging import time from dataclasses import dataclass from seedsigner.gui.components import BaseComponent, GUIConstants, Icon, SeedSignerIconConstants, TextArea from seedsigner.models.threads import BaseThread +logger = logging.getLogger(__name__) @dataclass @@ -119,33 +121,33 @@ def toggle_renderer_lock(self): def run(self): - print(f"{self.__class__.__name__}: started") + logger.info(f"{self.__class__.__name__}: started") start = time.time() while time.time() - start < self.activation_delay: if self.hw_inputs.has_any_input(): # User has pressed a button, cancel the toast - print(f"{self.__class__.__name__}: Canceling toast due to user input") + logger.info(f"{self.__class__.__name__}: Canceling toast due to user input") return time.sleep(0.1) try: # Hold onto the Renderer lock so we're guaranteed to restore the original # screen before any other listener can get a screen write in. - print(f"{self.__class__.__name__}: Acquiring lock") + logger.info(f"{self.__class__.__name__}: Acquiring lock") self.renderer.lock.acquire() - print(f"{self.__class__.__name__}: Lock acquired") + logger.info(f"{self.__class__.__name__}: Lock acquired") has_rendered = False previous_screen_state = None while self.keep_running and self.should_keep_running(): if self.hw_inputs.has_any_input(): # User has pressed a button, hide the toast - print(f"{self.__class__.__name__}: Exiting due to user input") + logger.info(f"{self.__class__.__name__}: Exiting due to user input") break if self._toggle_renderer_lock: # Controller has notified us that another process needs the lock - print(f"{self.__class__.__name__}: Releasing lock") + logger.info(f"{self.__class__.__name__}: Releasing lock") self._toggle_renderer_lock = False self.renderer.lock.release() @@ -155,29 +157,29 @@ def run(self): time.sleep(0.1) # Block while waiting to reaquire the lock - print(f"{self.__class__.__name__}: Blocking to re-acquire lock") + logger.info(f"{self.__class__.__name__}: Blocking to re-acquire lock") self.renderer.lock.acquire() - print(f"{self.__class__.__name__}: Lock re-acquired") + logger.info(f"{self.__class__.__name__}: Lock re-acquired") if not has_rendered: previous_screen_state = self.renderer.canvas.copy() - print(f"{self.__class__.__name__}: Showing toast") + logger.info(f"{self.__class__.__name__}: Showing toast") self.toast.render() has_rendered = True if time.time() - start > self.activation_delay + self.duration and has_rendered: - print(f"{self.__class__.__name__}: Hiding toast") + logger.info(f"{self.__class__.__name__}: Hiding toast") break # Free up cpu resources for main thread time.sleep(0.1) finally: - print(f"{self.__class__.__name__}: exiting") + logger.info(f"{self.__class__.__name__}: exiting") if has_rendered and self.renderer.lock.locked(): # As far as we know, we currently hold the Renderer.lock self.renderer.show_image(previous_screen_state) - print(f"{self.__class__.__name__}: restored previous screen state") + logger.info(f"{self.__class__.__name__}: restored previous screen state") # We're done, release the lock self.renderer.lock.release() @@ -223,7 +225,7 @@ def __init__(self, action: str, *args, **kwargs): def instantiate_toast(self) -> ToastOverlay: - print("instantiating toast!") + logger.info("instantiating toast!") return ToastOverlay( icon_name=SeedSignerIconConstants.MICROSD, label_text=self.message, diff --git a/src/seedsigner/hardware/buttons.py b/src/seedsigner/hardware/buttons.py index 8d42105d0..6fecc10fa 100644 --- a/src/seedsigner/hardware/buttons.py +++ b/src/seedsigner/hardware/buttons.py @@ -1,12 +1,16 @@ +import logging from typing import List import RPi.GPIO as GPIO import time from seedsigner.models.singleton import Singleton +logger = logging.getLogger(__name__) + + class HardwareButtons(Singleton): if GPIO.RPI_INFO['P1_REVISION'] == 3: #This indicates that we have revision 3 GPIO - print("Detected 40pin GPIO (Rasbperry Pi 2 and above)") + logger.info("Detected 40pin GPIO (Rasbperry Pi 2 and above)") KEY_UP_PIN = 31 KEY_DOWN_PIN = 35 KEY_LEFT_PIN = 29 @@ -18,7 +22,7 @@ class HardwareButtons(Singleton): KEY3_PIN = 36 else: - print("Assuming 26 Pin GPIO (Raspberry P1 1)") + logger.info("Assuming 26 Pin GPIO (Raspberry P1 1)") KEY_UP_PIN = 5 KEY_DOWN_PIN = 11 KEY_LEFT_PIN = 3 diff --git a/src/seedsigner/hardware/microsd.py b/src/seedsigner/hardware/microsd.py index 26065c03e..da545b7f8 100644 --- a/src/seedsigner/hardware/microsd.py +++ b/src/seedsigner/hardware/microsd.py @@ -1,3 +1,4 @@ +import logging import os import time @@ -5,6 +6,7 @@ from seedsigner.models.threads import BaseThread from seedsigner.models.settings import Settings +logger = logging.getLogger(__name__) class MicroSD(Singleton, BaseThread): @@ -63,7 +65,7 @@ def run(self): while self.keep_running: with open(self.FIFO_PATH) as fifo: action = fifo.read() - print(f"fifo message: {action}") + logger.info(f"fifo message: {action}") Settings.handle_microsd_state_change(action=action) Controller.get_instance().activate_toast(SDCardStateChangeToastManagerThread(action=action)) diff --git a/src/seedsigner/hardware/pivideostream.py b/src/seedsigner/hardware/pivideostream.py index cb3031b33..06a1ebb7d 100644 --- a/src/seedsigner/hardware/pivideostream.py +++ b/src/seedsigner/hardware/pivideostream.py @@ -1,9 +1,12 @@ # import the necessary packages +import logging from picamera.array import PiRGBArray from picamera import PiCamera from threading import Thread import time +logger = logging.getLogger(__name__) + # Modified from: https://github.com/jrosebr1/imutils class PiVideoStream: @@ -41,7 +44,7 @@ def update(self): # if the thread indicator variable is set, stop the thread # and resource camera resources if self.should_stop: - print("PiVideoStream: closing everything") + logger.info("PiVideoStream: closing everything") self.stream.close() self.rawCapture.close() self.camera.close() diff --git a/src/seedsigner/models/decode_qr.py b/src/seedsigner/models/decode_qr.py index 78ded320d..55991668a 100644 --- a/src/seedsigner/models/decode_qr.py +++ b/src/seedsigner/models/decode_qr.py @@ -912,7 +912,7 @@ def add(self, segment, qr_type=QRType.SIGN_MESSAGE): # TODO: support formats other than ascii? if fmt != "ascii": - print(f"Sign message: Unsupported format: {fmt}") + logger.info(f"Sign message: Unsupported format: {fmt}") return DecodeQRStatus.INVALID self.complete = True @@ -1083,7 +1083,7 @@ def add(self, segment, qr_type=QRType.WALLET__GENERIC): self.complete = True return DecodeQRStatus.COMPLETE except Exception as e: - print(repr(e)) + logger.info(repr(e), exc_info=True) return DecodeQRStatus.INVALID diff --git a/src/seedsigner/models/psbt_parser.py b/src/seedsigner/models/psbt_parser.py index 8faba3fe0..60d14fdef 100644 --- a/src/seedsigner/models/psbt_parser.py +++ b/src/seedsigner/models/psbt_parser.py @@ -1,3 +1,4 @@ +import logging from binascii import hexlify from embit import psbt, script, ec, bip32 from embit.descriptor import Descriptor @@ -9,6 +10,7 @@ from seedsigner.models.seed import Seed from seedsigner.models.settings import SettingsConstants +logger = logging.getLogger(__name__) class OPCODES: OP_RETURN = 106 @@ -68,11 +70,11 @@ def _set_root(self): def parse(self): if self.psbt is None: - print(f"self.psbt is None!!") + logger.info(f"self.psbt is None!!") return False if not self.seed: - print("self.seed is None!") + logger.info("self.seed is None!") return False self._set_root() diff --git a/src/seedsigner/models/seed.py b/src/seedsigner/models/seed.py index 6164ff84c..4ab7405b9 100644 --- a/src/seedsigner/models/seed.py +++ b/src/seedsigner/models/seed.py @@ -1,3 +1,4 @@ +import logging import unicodedata import hashlib import hmac @@ -9,6 +10,8 @@ from seedsigner.models.settings import SettingsConstants +logger = logging.getLogger(__name__) + class InvalidSeedException(Exception): pass @@ -46,7 +49,7 @@ def _generate_seed(self) -> bool: try: self.seed_bytes = bip39.mnemonic_to_seed(self.mnemonic_str, password=self._passphrase, wordlist=self.wordlist) except Exception as e: - print(repr(e)) + logger.info(repr(e), exc_info=True) raise InvalidSeedException(repr(e)) diff --git a/src/seedsigner/models/settings.py b/src/seedsigner/models/settings.py index f0b1c97f0..ae5b4ffe7 100644 --- a/src/seedsigner/models/settings.py +++ b/src/seedsigner/models/settings.py @@ -1,3 +1,4 @@ +import logging import json import os import platform @@ -7,6 +8,8 @@ from seedsigner.models.settings_definition import SettingsConstants, SettingsDefinition from seedsigner.models.singleton import Singleton +logger = logging.getLogger(__name__) + class InvalidSettingsQRData(Exception): pass @@ -77,7 +80,7 @@ def parse_settingsqr(cls, data: str) -> tuple[str, dict]: # Replace abbreviated name with full attr_name settings_entry = SettingsDefinition.get_settings_entry_by_abbreviated_name(abbreviated_name) if not settings_entry: - print(f"Ignoring unrecognized attribute: {abbreviated_name}") + logger.info(f"Ignoring unrecognized attribute: {abbreviated_name}") continue # Validate value(s) against SettingsDefinition's valid options @@ -162,9 +165,9 @@ def set_value(self, attr_name: str, value: any): if attr_name == SettingsConstants.SETTING__PERSISTENT_SETTINGS and value == SettingsConstants.OPTION__DISABLED: try: os.remove(self.SETTINGS_FILENAME) - print(f"Removed {self.SETTINGS_FILENAME}") + logger.info(f"Removed {self.SETTINGS_FILENAME}") except: - print(f"{self.SETTINGS_FILENAME} not found to be removed") + logger.info(f"{self.SETTINGS_FILENAME} not found to be removed") self._data[attr_name] = value self.save() diff --git a/src/seedsigner/views/scan_views.py b/src/seedsigner/views/scan_views.py index 7bac9a459..1b923efa0 100644 --- a/src/seedsigner/views/scan_views.py +++ b/src/seedsigner/views/scan_views.py @@ -1,3 +1,4 @@ +import logging import re from embit.descriptor import Descriptor @@ -9,6 +10,7 @@ from seedsigner.views.settings_views import SettingsIngestSettingsQRView from seedsigner.views.view import BackStackView, ErrorView, MainMenuView, NotYetImplementedView, OptionDisabledView, View, Destination +logger = logging.getLogger(__name__) class ScanView(View): @@ -111,14 +113,14 @@ def run(self): p = re.compile(r'(\[[0-9,a-f,A-F]+?\/[0-9,\/,h,\']+?\][a-z,A-Z,0-9]*?)([\,,\)])') descriptor_str = p.sub(r'\1/{0,1}/*\2', descriptor_str) except Exception as e: - print(repr(e)) + logger.info(repr(e), exc_info=True) descriptor_str = orig_descriptor_str descriptor = Descriptor.from_string(descriptor_str) if not descriptor.is_basic_multisig: # TODO: Handle single-sig descriptors? - print(f"Received single sig descriptor: {descriptor}") + logger.info(f"Received single sig descriptor: {descriptor}") return Destination(NotYetImplementedView) self.controller.multisig_wallet_descriptor = descriptor diff --git a/src/seedsigner/views/screensaver.py b/src/seedsigner/views/screensaver.py index 960df6c8d..84476da47 100644 --- a/src/seedsigner/views/screensaver.py +++ b/src/seedsigner/views/screensaver.py @@ -1,3 +1,4 @@ +import logging import os import random import time @@ -9,6 +10,7 @@ from seedsigner.models.settings import Settings from seedsigner.models.settings_definition import SettingsConstants +logger = logging.getLogger(__name__) # TODO: This early code is now outdated vis-a-vis Screen vs View distinctions @@ -178,7 +180,7 @@ def start(self): except KeyboardInterrupt as e: # Exit triggered; close gracefully - print("Shutting down Screensaver") + logger.info("Shutting down Screensaver") # Have to let the interrupt bubble up to exit the main app raise e diff --git a/src/seedsigner/views/seed_views.py b/src/seedsigner/views/seed_views.py index 215af14f5..4df524e0c 100644 --- a/src/seedsigner/views/seed_views.py +++ b/src/seedsigner/views/seed_views.py @@ -1,3 +1,4 @@ +import logging import embit import random import time @@ -25,7 +26,7 @@ from seedsigner.models.threads import BaseThread, ThreadsafeCounter from seedsigner.views.view import NotYetImplementedView, OptionDisabledView, View, Destination, BackStackView, MainMenuView - +logger = logging.getLogger(__name__) class SeedsMenuView(View): @@ -1818,7 +1819,7 @@ def __init__(self, address: str, seed: Seed, descriptor: Descriptor, script_type def run(self): while self.keep_running: if self.threadsafe_counter.cur_count % 10 == 0: - print(f"Incremented to {self.threadsafe_counter.cur_count}") + logger.info(f"Incremented to {self.threadsafe_counter.cur_count}") i = self.threadsafe_counter.cur_count diff --git a/src/seedsigner/views/tools_views.py b/src/seedsigner/views/tools_views.py index ad2940bea..92081075a 100644 --- a/src/seedsigner/views/tools_views.py +++ b/src/seedsigner/views/tools_views.py @@ -1,5 +1,6 @@ from dataclasses import dataclass import hashlib +import logging import os import time @@ -21,6 +22,7 @@ from .view import View, Destination, BackStackView +logger = logging.getLogger(__name__) class ToolsMenuView(View): @@ -143,7 +145,7 @@ def run(self): serial_hash = hashlib.sha256(serial_num) hash_bytes = serial_hash.digest() except Exception as e: - print(repr(e)) + logger.info(repr(e), exc_info=True) hash_bytes = b'0' # Build in modest entropy via millis since power on diff --git a/tests/test_main.py b/tests/test_main.py new file mode 100644 index 000000000..f4e48fc82 --- /dev/null +++ b/tests/test_main.py @@ -0,0 +1,40 @@ +import logging +import sys +from unittest.mock import patch, call + +import pytest + +sys.path.insert(0,'src') +from main import main + + +@patch("main.Controller") +def test_main__argparse__default(patched_controller): + main([]) + assert logging.root.level == logging.INFO + assert logging.getLogger().getEffectiveLevel() == logging.INFO + patched_controller.assert_has_calls( + [call.get_instance(), call.get_instance().start()] + ) + + +@patch("main.Controller") +def test_main__argparse__enable_debug_logging(patched_controller): + main(["--loglevel", "DEBUG"]) + assert logging.root.level == logging.DEBUG + assert logging.getLogger().getEffectiveLevel() == logging.DEBUG + patched_controller.assert_has_calls( + [call.get_instance(), call.get_instance().start()] + ) + + +def test_main__argparse__invalid_arg(): + with pytest.raises(SystemExit): + main(["--invalid"]) + + +@patch("main.Controller") +def test_main__logging__writes_to_stderr(patched_controller, capsys): + main([]) + _, err = capsys.readouterr() + assert "Starting SeedSigner" in err and "INFO" in err