tlogging.py - electrum - Electrum Bitcoin wallet
HTML git clone https://git.parazyd.org/electrum
DIR Log
DIR Files
DIR Refs
DIR Submodules
---
tlogging.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