logging.py (9662B)
1 # Copyright (C) 2019 The Electrum developers 2 # Distributed under the MIT software license, see the accompanying 3 # file LICENCE or http://www.opensource.org/licenses/mit-license.php 4 5 import logging 6 import datetime 7 import sys 8 import pathlib 9 import os 10 import platform 11 from typing import Optional 12 import copy 13 import subprocess 14 15 16 class LogFormatterForFiles(logging.Formatter): 17 18 def formatTime(self, record, datefmt=None): 19 # timestamps follow ISO 8601 UTC 20 date = datetime.datetime.fromtimestamp(record.created).astimezone(datetime.timezone.utc) 21 if not datefmt: 22 datefmt = "%Y%m%dT%H%M%S.%fZ" 23 return date.strftime(datefmt) 24 25 def format(self, record): 26 record = _shorten_name_of_logrecord(record) 27 return super().format(record) 28 29 30 file_formatter = LogFormatterForFiles(fmt="%(asctime)22s | %(levelname)8s | %(name)s | %(message)s") 31 32 33 class LogFormatterForConsole(logging.Formatter): 34 35 def format(self, record): 36 record = _shorten_name_of_logrecord(record) 37 text = super().format(record) 38 shortcut = getattr(record, 'custom_shortcut', None) 39 if shortcut: 40 text = text[:1] + f"/{shortcut}" + text[1:] 41 return text 42 43 44 # try to make console log lines short... no timestamp, short levelname, no "electrum." 45 console_formatter = LogFormatterForConsole(fmt="%(levelname).1s | %(name)s | %(message)s") 46 47 48 def _shorten_name_of_logrecord(record: logging.LogRecord) -> logging.LogRecord: 49 record = copy.copy(record) # avoid mutating arg 50 # strip the main module name from the logger name 51 if record.name.startswith("electrum."): 52 record.name = record.name[9:] 53 # manual map to shorten common module names 54 record.name = record.name.replace("interface.Interface", "interface", 1) 55 record.name = record.name.replace("network.Network", "network", 1) 56 record.name = record.name.replace("synchronizer.Synchronizer", "synchronizer", 1) 57 record.name = record.name.replace("verifier.SPV", "verifier", 1) 58 record.name = record.name.replace("gui.qt.main_window.ElectrumWindow", "gui.qt.main_window", 1) 59 return record 60 61 62 # enable logs universally (including for other libraries) 63 root_logger = logging.getLogger() 64 root_logger.setLevel(logging.WARNING) 65 66 # log to stderr; by default only WARNING and higher 67 console_stderr_handler = logging.StreamHandler(sys.stderr) 68 console_stderr_handler.setFormatter(console_formatter) 69 console_stderr_handler.setLevel(logging.WARNING) 70 root_logger.addHandler(console_stderr_handler) 71 72 # creates a logger specifically for electrum library 73 electrum_logger = logging.getLogger("electrum") 74 electrum_logger.setLevel(logging.DEBUG) 75 76 77 def _delete_old_logs(path, keep=10): 78 files = sorted(list(pathlib.Path(path).glob("electrum_log_*.log")), reverse=True) 79 for f in files[keep:]: 80 os.remove(str(f)) 81 82 83 _logfile_path = None 84 def _configure_file_logging(log_directory: pathlib.Path): 85 global _logfile_path 86 assert _logfile_path is None, 'file logging already initialized' 87 log_directory.mkdir(exist_ok=True) 88 89 _delete_old_logs(log_directory) 90 91 timestamp = datetime.datetime.utcnow().strftime("%Y%m%dT%H%M%SZ") 92 PID = os.getpid() 93 _logfile_path = log_directory / f"electrum_log_{timestamp}_{PID}.log" 94 95 file_handler = logging.FileHandler(_logfile_path, encoding='utf-8') 96 file_handler.setFormatter(file_formatter) 97 file_handler.setLevel(logging.DEBUG) 98 root_logger.addHandler(file_handler) 99 100 101 def _configure_verbosity(*, verbosity, verbosity_shortcuts): 102 if not verbosity and not verbosity_shortcuts: 103 return 104 console_stderr_handler.setLevel(logging.DEBUG) 105 _process_verbosity_log_levels(verbosity) 106 _process_verbosity_filter_shortcuts(verbosity_shortcuts) 107 108 109 def _process_verbosity_log_levels(verbosity): 110 if verbosity == '*' or not isinstance(verbosity, str): 111 return 112 # example verbosity: 113 # debug,network=error,interface=error // effectively blacklists network and interface 114 # warning,network=debug,interface=debug // effectively whitelists network and interface 115 filters = verbosity.split(',') 116 for filt in filters: 117 if not filt: continue 118 items = filt.split('=') 119 if len(items) == 1: 120 level = items[0] 121 electrum_logger.setLevel(level.upper()) 122 elif len(items) == 2: 123 logger_name, level = items 124 logger = get_logger(logger_name) 125 logger.setLevel(level.upper()) 126 else: 127 raise Exception(f"invalid log filter: {filt}") 128 129 130 def _process_verbosity_filter_shortcuts(verbosity_shortcuts): 131 if not isinstance(verbosity_shortcuts, str): 132 return 133 if len(verbosity_shortcuts) < 1: 134 return 135 # depending on first character being '^', either blacklist or whitelist 136 is_blacklist = verbosity_shortcuts[0] == '^' 137 if is_blacklist: 138 filters = verbosity_shortcuts[1:] 139 else: # whitelist 140 filters = verbosity_shortcuts[0:] 141 filt = ShortcutFilteringFilter(is_blacklist=is_blacklist, filters=filters) 142 # apply filter directly (and only!) on stderr handler 143 # note that applying on one of the root loggers directly would not work, 144 # see https://docs.python.org/3/howto/logging.html#logging-flow 145 console_stderr_handler.addFilter(filt) 146 147 148 class ShortcutInjectingFilter(logging.Filter): 149 150 def __init__(self, *, shortcut: Optional[str]): 151 super().__init__() 152 self.__shortcut = shortcut 153 154 def filter(self, record): 155 record.custom_shortcut = self.__shortcut 156 return True 157 158 159 class ShortcutFilteringFilter(logging.Filter): 160 161 def __init__(self, *, is_blacklist: bool, filters: str): 162 super().__init__() 163 self.__is_blacklist = is_blacklist 164 self.__filters = filters 165 166 def filter(self, record): 167 # all errors are let through 168 if record.levelno >= logging.ERROR: 169 return True 170 # the logging module itself is let through 171 if record.name == __name__: 172 return True 173 # do filtering 174 shortcut = getattr(record, 'custom_shortcut', None) 175 if self.__is_blacklist: 176 if shortcut is None: 177 return True 178 if shortcut in self.__filters: 179 return False 180 return True 181 else: # whitelist 182 if shortcut is None: 183 return False 184 if shortcut in self.__filters: 185 return True 186 return False 187 188 189 # --- External API 190 191 def get_logger(name: str) -> logging.Logger: 192 if name.startswith("electrum."): 193 name = name[9:] 194 return electrum_logger.getChild(name) 195 196 197 _logger = get_logger(__name__) 198 _logger.setLevel(logging.INFO) 199 200 201 class Logger: 202 203 # Single character short "name" for this class. 204 # Can be used for filtering log lines. Does not need to be unique. 205 LOGGING_SHORTCUT = None # type: Optional[str] 206 207 def __init__(self): 208 self.logger = self.__get_logger_for_obj() 209 210 def __get_logger_for_obj(self) -> logging.Logger: 211 cls = self.__class__ 212 if cls.__module__: 213 name = f"{cls.__module__}.{cls.__name__}" 214 else: 215 name = cls.__name__ 216 try: 217 diag_name = self.diagnostic_name() 218 except Exception as e: 219 raise Exception("diagnostic name not yet available?") from e 220 if diag_name: 221 name += f".[{diag_name}]" 222 logger = get_logger(name) 223 if self.LOGGING_SHORTCUT: 224 logger.addFilter(ShortcutInjectingFilter(shortcut=self.LOGGING_SHORTCUT)) 225 return logger 226 227 def diagnostic_name(self): 228 return '' 229 230 231 def configure_logging(config): 232 verbosity = config.get('verbosity') 233 verbosity_shortcuts = config.get('verbosity_shortcuts') 234 _configure_verbosity(verbosity=verbosity, verbosity_shortcuts=verbosity_shortcuts) 235 236 log_to_file = config.get('log_to_file', False) 237 is_android = 'ANDROID_DATA' in os.environ 238 if is_android: 239 from jnius import autoclass 240 build_config = autoclass("org.electrum.electrum.BuildConfig") 241 log_to_file |= bool(build_config.DEBUG) 242 if log_to_file: 243 log_directory = pathlib.Path(config.path) / "logs" 244 _configure_file_logging(log_directory) 245 246 # if using kivy, avoid kivy's own logs to get printed twice 247 logging.getLogger('kivy').propagate = False 248 249 from . import ELECTRUM_VERSION 250 from .constants import GIT_REPO_URL 251 _logger.info(f"Electrum version: {ELECTRUM_VERSION} - https://electrum.org - {GIT_REPO_URL}") 252 _logger.info(f"Python version: {sys.version}. On platform: {describe_os_version()}") 253 _logger.info(f"Logging to file: {str(_logfile_path)}") 254 _logger.info(f"Log filters: verbosity {repr(verbosity)}, verbosity_shortcuts {repr(verbosity_shortcuts)}") 255 256 257 def get_logfile_path() -> Optional[pathlib.Path]: 258 return _logfile_path 259 260 261 def describe_os_version() -> str: 262 if 'ANDROID_DATA' in os.environ: 263 from kivy import utils 264 if utils.platform != "android": 265 return utils.platform 266 import jnius 267 bv = jnius.autoclass('android.os.Build$VERSION') 268 b = jnius.autoclass('android.os.Build') 269 return "Android {} on {} {} ({})".format(bv.RELEASE, b.BRAND, b.DEVICE, b.DISPLAY) 270 else: 271 return platform.platform() 272 273 274 def get_git_version() -> Optional[str]: 275 dir = os.path.dirname(os.path.realpath(__file__)) 276 try: 277 version = subprocess.check_output( 278 ['git', 'describe', '--always', '--dirty'], cwd=dir) 279 version = str(version, "utf8").strip() 280 except Exception: 281 version = None 282 return version