From e1752506c5111bc6e94dc9396734eaa65224d44d Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 14:51:26 +0100 Subject: [PATCH 01/35] Move "only run once" code into def enforce_single_instance() --- EDMarketConnector.py | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 8867dfbf..c48ed103 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -880,13 +880,12 @@ class AppWindow(object): self.theme_menubar.grid_remove() self.blank_menubar.grid(row=0, columnspan=2, sticky=tk.NSEW) -# Run the app -if __name__ == "__main__": +def enforce_single_instance() -> None: # Ensure only one copy of the app is running under this user account. OSX does this automatically. Linux TODO. if platform == 'win32': import ctypes - from ctypes.wintypes import * + from ctypes.wintypes import HWND, LPWSTR, LPCWSTR, INT, BOOL, LPARAM EnumWindows = ctypes.windll.user32.EnumWindows GetClassName = ctypes.windll.user32.GetClassNameW GetClassName.argtypes = [HWND, LPWSTR, ctypes.c_int] @@ -935,6 +934,10 @@ if __name__ == "__main__": EnumWindows(enumwindowsproc, 0) +# Run the app +if __name__ == "__main__": + + enforce_single_instance() if getattr(sys, 'frozen', False): # By default py2exe tries to write log to dirname(sys.executable) which fails when installed import tempfile From cd4216d19c197bf5d282b2ab190ef227ece685c1 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 15:00:21 +0100 Subject: [PATCH 02/35] logger setup and initialisation * Initial printing of version is now a logger.info(...) --- EDMarketConnector.py | 19 ++++++++++++++++++- 1 file changed, 18 insertions(+), 1 deletion(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index c48ed103..ee7b1271 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -942,7 +942,24 @@ if __name__ == "__main__": # By default py2exe tries to write log to dirname(sys.executable) which fails when installed import tempfile sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), '%s.log' % appname), 'wt', 1) # unbuffered not allowed for text in python3, so use line buffering - print('%s %s %s' % (applongname, appversion, strftime('%Y-%m-%dT%H:%M:%S', localtime()))) + + ########################################################################### + # Set up a logging instance + import logging + + logger_default_loglevel = logging.INFO + logger = logging.getLogger(appname) + logger.setLevel(logger_default_loglevel) + logger_ch = logging.StreamHandler() + logger_ch.setLevel(logger_default_loglevel) + logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(funcName)s: %(message)s') + logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' + logger_formatter.default_msec_format = '%s.%03d' + logger_ch.setFormatter(logger_formatter) + logger.addHandler(logger_ch) + ########################################################################### + + logger.info(f'{applongname} {appversion}') Translations.install(config.get('language') or None) # Can generate errors so wait til log set up From c971106c0e7c9cd84a0e669467f3199954522bbe Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 16:51:16 +0100 Subject: [PATCH 03/35] Convert print()s to logging & refactor help_about -> HelpAbout --- EDMarketConnector.py | 32 +++++++++++++++++++------------- 1 file changed, 19 insertions(+), 13 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index ee7b1271..465ca1f8 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -207,7 +207,7 @@ class AppWindow(object): self.help_menu.add_command(command=self.help_privacy) self.help_menu.add_command(command=self.help_releases) self.help_menu.add_command(command=lambda:self.updater.checkForUpdates()) - self.help_menu.add_command(command=lambda:not self.help_about.showing and self.help_about(self.w)) + self.help_menu.add_command(command=lambda: not self.HelpAbout.showing and self.HelpAbout(self.w)) self.menubar.add_cascade(menu=self.help_menu) if platform == 'win32': @@ -409,7 +409,7 @@ class AppWindow(object): except (companion.CredentialsError, companion.ServerError, companion.ServerLagging) as e: self.status['text'] = str(e) except Exception as e: - if __debug__: print_exc() + logger.debug(f'{__class__}', exc_info=e) self.status['text'] = str(e) self.cooldown() @@ -523,7 +523,7 @@ class AppWindow(object): self.login() except Exception as e: # Including CredentialsError, ServerError - if __debug__: print_exc() + logger.debug(f'{__class__}', exc_info=e) self.status['text'] = str(e) play_bad = True @@ -538,8 +538,14 @@ class AppWindow(object): # Try again to get shipyard data and send to EDDN. Don't report errors if can't get or send the data. try: data = companion.session.station() - if __debug__: - print('Retry for shipyard - ' + (data['commander'].get('docked') and (data.get('lastStarport', {}).get('ships') and 'Success' or 'Failure') or 'Undocked!')) + if data['commander'].get('docked'): + if data.get('lastStarport', {}).get('ships'): + report = 'Success' + else: + report ='Failure' + else: + report = 'Undocked!' + logger.debug(f'{__class__}: Retry for shipyard - {report}') if not data['commander'].get('docked'): pass # might have undocked while we were waiting for retry in which case station data is unreliable elif (data.get('lastSystem', {}).get('name') == monitor.system and @@ -607,10 +613,10 @@ class AppWindow(object): # Disable WinSparkle automatic update checks, IFF configured to do so when in-game if config.getint('disable_autoappupdatecheckingame') and 1: self.updater.setAutomaticUpdatesCheck(False) - print('Monitor: Disable WinSparkle automatic update checks') + logger.info(f'{__class__}: Monitor: Disable WinSparkle automatic update checks') # Can start dashboard monitoring if not dashboard.start(self.w, monitor.started): - print("Can't start Status monitoring") + logger.info(f"{__class__}: Can't start Status monitoring") # Export loadout if entry['event'] == 'Loadout' and not monitor.state['Captain'] and config.getint('output') & config.OUT_SHIP: @@ -631,7 +637,7 @@ class AppWindow(object): # Enable WinSparkle automatic update checks # NB: Do this blindly, in case option got changed whilst in-game self.updater.setAutomaticUpdatesCheck(True) - print('Monitor: Enable WinSparkle automatic update checks') + logger.info(f'{__class__}: Monitor: Enable WinSparkle automatic update checks') # cAPI auth def auth(self, event=None): @@ -647,7 +653,7 @@ class AppWindow(object): except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: - if __debug__: print_exc() + logger.debug(f'{__class__}', exc_info=e) self.status['text'] = str(e) self.cooldown() @@ -724,7 +730,7 @@ class AppWindow(object): def help_releases(self, event=None): webbrowser.open('https://github.com/EDCD/EDMarketConnector/releases') - class help_about(tk.Toplevel): + class HelpAbout(tk.Toplevel): showing = False def __init__(self, parent): @@ -802,7 +808,7 @@ class AppWindow(object): self.protocol("WM_DELETE_WINDOW", self._destroy) ############################################################ - print('Current version is {}'.format(appversion)) + logger.info(f'{__class__}: Current version is {appversion}') def apply(self): self._destroy() @@ -830,7 +836,7 @@ class AppWindow(object): except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: - if __debug__: print_exc() + logger.debug(f'{__class__}', exc_info=e) self.status['text'] = str(e) def onexit(self, event=None): @@ -952,7 +958,7 @@ if __name__ == "__main__": logger.setLevel(logger_default_loglevel) logger_ch = logging.StreamHandler() logger_ch.setLevel(logger_default_loglevel) - logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(funcName)s: %(message)s') + logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s:%(lineno)d:%(funcName)s: %(message)s') logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' logger_formatter.default_msec_format = '%s.%03d' logger_ch.setFormatter(logger_formatter) From fa1443b49cb82df92ed173ee06d7461250889510 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 17:24:16 +0100 Subject: [PATCH 04/35] Contributing.md: Document use of logging. Also fixes some camelCase to be proper snake_case in an example. --- Contributing.md | 26 +++++++++++++++++++++++--- 1 file changed, 23 insertions(+), 3 deletions(-) diff --git a/Contributing.md b/Contributing.md index ff683dff..c82a4cee 100644 --- a/Contributing.md +++ b/Contributing.md @@ -184,14 +184,14 @@ Coding Conventions Yes: ```python -if somethingTrue: - Things_we_then_do() +if something_true: + one_thing_we_do() ``` No: ```python -if somethingTrue: One_thing_we_do() +if something_true: one_thing_we_do() ``` Yes, some existing code still flouts this rule. @@ -224,6 +224,26 @@ No: * Going forwards please do place [type hints](https://docs.python.org/3/library/typing.html) on the declarations of your functions, both their arguments and return types. +* Use `logging` not `print()`, and definitely not `sys.stdout.write()`! + `EDMarketConnector.py` sets up `logger` for this, so: + + from EDMarketConnector import logger + + logger.info(f'Some message with a {variable}') + + try: + something + except Exception as e: # Try to be more specific + logger.error(f'Error in ... with ...', exc_info=e) + + Also if the code is within a class definition at all then please use: + + logger.info(f'{__class__}: ...) + + so that the class name is included in the output. No `logger.Formatter` + does not support this (probably because there's no way to get at the + information for a calling function). + * In general, please follow [PEP8](https://www.python.org/dev/peps/pep-0008/). --- From fe0ff2498edb8b226164f3fab6fe31498b6b6fae Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 17:25:21 +0100 Subject: [PATCH 05/35] Moves logger definition so it's import'able --- EDMarketConnector.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 465ca1f8..aa5bb0bb 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -17,6 +17,7 @@ from time import gmtime, time, localtime, strftime, strptime import _strptime # Workaround for http://bugs.python.org/issue7980 from calendar import timegm import webbrowser +import logging from config import appname, applongname, appversion, appversion_nobuild, copyright, config @@ -940,6 +941,8 @@ def enforce_single_instance() -> None: EnumWindows(enumwindowsproc, 0) +# Has to be here to be defined for other modules importing +logger = logging.getLogger(appname) # Run the app if __name__ == "__main__": @@ -951,10 +954,7 @@ if __name__ == "__main__": ########################################################################### # Set up a logging instance - import logging - logger_default_loglevel = logging.INFO - logger = logging.getLogger(appname) logger.setLevel(logger_default_loglevel) logger_ch = logging.StreamHandler() logger_ch.setLevel(logger_default_loglevel) From 23b167fe66525e3896b6d45f57f571e441b5295a Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 17:31:48 +0100 Subject: [PATCH 06/35] Change startup version back to a print() This is so early it doesn't need to be a spammy log message. --- EDMarketConnector.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index aa5bb0bb..bc7762b9 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -965,7 +965,8 @@ if __name__ == "__main__": logger.addHandler(logger_ch) ########################################################################### - logger.info(f'{applongname} {appversion}') + # Plain, not via `logger` + print(f'{applongname} {appversion}') Translations.install(config.get('language') or None) # Can generate errors so wait til log set up From 2e12513c6cf043ad8634c14fd08d07330ec46490 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 17:44:49 +0100 Subject: [PATCH 07/35] Changes plug.py to proper logging. This relies on the logger.Formatter setup to fill in function name rather than calling out exactly why we're logging. It should be obvious, i.e. if you're in plug.py:notify_journal_entry then the named plugin threw an un-caught exception trying to call its method for this. --- plug.py | 52 +++++++++++++++++++++++++++------------------------- 1 file changed, 27 insertions(+), 25 deletions(-) diff --git a/plug.py b/plug.py index 56eaa884..2efc1ecb 100644 --- a/plug.py +++ b/plug.py @@ -14,6 +14,7 @@ import tkinter as tk import myNotebook as nb from config import config +from EDMarketConnector import logger from time import time as time @@ -92,7 +93,7 @@ class Plugin(object): self.module = None # None for disabled plugins. if loadfile: - sys.stdout.write('loading plugin {} from "{}"\n'.format(name.replace('.', '_'), loadfile)) + logger.info(f'loading plugin "{name.replace(".", "_")}" from "{loadfile}"') try: module = importlib.machinery.SourceFileLoader('plugin_{}'.format(name.encode(encoding='ascii', errors='replace').decode('utf-8').replace('.', '_')), loadfile).load_module() if getattr(module, 'plugin_start3', None): @@ -100,15 +101,15 @@ class Plugin(object): self.name = newname and str(newname) or name self.module = module elif getattr(module, 'plugin_start', None): - sys.stdout.write('plugin %s needs migrating\n' % name) + logger.warning(f'plugin {name} needs migrating\n') PLUGINS_not_py3.append(self) else: - sys.stdout.write('plugin %s has no plugin_start3() function\n' % name) - except: - print_exc() + logger.error(f'plugin {name} has no plugin_start3() function') + except Exception as e: + logger.error(f'{__class__}: Failed for Plugin "{name}"', exc_info=e) raise else: - sys.stdout.write('plugin %s disabled\n' % name) + logger.info(f'{__class__}: plugin {name} disabled') def _get_func(self, funcname): """ @@ -136,8 +137,8 @@ class Plugin(object): elif not isinstance(appitem, tk.Widget): raise AssertionError return appitem - except: - print_exc() + except Exception as e: + logger.error(f'{__class__}: Failed for Plugin "{self.name}"', exc_info=e) return None def get_prefs(self, parent, cmdr, is_beta): @@ -156,8 +157,8 @@ class Plugin(object): if not isinstance(frame, nb.Frame): raise AssertionError return frame - except: - print_exc() + except Exception as e: + logger.error(f'{__class__}: Failed for Plugin "{self.name}"', exc_info=e) return None @@ -174,8 +175,8 @@ def load_plugins(master): plugin = Plugin(name[:-3], os.path.join(config.internal_plugin_dir, name)) plugin.folder = None # Suppress listing in Plugins prefs tab internal.append(plugin) - except: - pass + except Exception as e: + logger.error(f'Failure loading internal Plugin "{name}"', exc_info=e) PLUGINS.extend(sorted(internal, key = lambda p: operator.attrgetter('name')(p).lower())) # Add plugin folder to load path so packages can be loaded from plugin folder @@ -195,7 +196,8 @@ def load_plugins(master): # Add plugin's folder to load path in case plugin has internal package dependencies sys.path.append(os.path.join(config.plugin_dir, name)) found.append(Plugin(name, os.path.join(config.plugin_dir, name, 'load.py'))) - except: + except Exception as e: + logger.error(f'Failure loading found Plugin "{name}"', exc_info=e) pass PLUGINS.extend(sorted(found, key = lambda p: operator.attrgetter('name')(p).lower())) @@ -240,8 +242,8 @@ def notify_stop(): try: newerror = plugin_stop() error = error or newerror - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) return error @@ -257,8 +259,8 @@ def notify_prefs_cmdr_changed(cmdr, is_beta): if prefs_cmdr_changed: try: prefs_cmdr_changed(cmdr, is_beta) - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) def notify_prefs_changed(cmdr, is_beta): @@ -275,8 +277,8 @@ def notify_prefs_changed(cmdr, is_beta): if prefs_changed: try: prefs_changed(cmdr, is_beta) - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) def notify_journal_entry(cmdr, is_beta, system, station, entry, state): @@ -298,8 +300,8 @@ def notify_journal_entry(cmdr, is_beta, system, station, entry, state): # Pass a copy of the journal entry in case the callee modifies it newerror = journal_entry(cmdr, is_beta, system, station, dict(entry), dict(state)) error = error or newerror - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) return error @@ -319,8 +321,8 @@ def notify_dashboard_entry(cmdr, is_beta, entry): # Pass a copy of the status entry in case the callee modifies it newerror = status(cmdr, is_beta, dict(entry)) error = error or newerror - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) return error @@ -338,8 +340,8 @@ def notify_newdata(data, is_beta): try: newerror = cmdr_data(data, is_beta) error = error or newerror - except: - print_exc() + except Exception as e: + logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) return error From debc7f97d3916feec4e941e71b55b5e58e7a0250 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 20:42:06 +0100 Subject: [PATCH 08/35] Use a logging.Filter to implement %(class)s in formatting. --- EDMarketConnector.py | 80 ++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 78 insertions(+), 2 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index bc7762b9..6d0ff021 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -18,6 +18,8 @@ import _strptime # Workaround for http://bugs.python.org/issue7980 from calendar import timegm import webbrowser import logging +import traceback +from typing import Any, Optional from config import appname, applongname, appversion, appversion_nobuild, copyright, config @@ -941,8 +943,68 @@ def enforce_single_instance() -> None: EnumWindows(enumwindowsproc, 0) +########################################################################### +# Logging + # Has to be here to be defined for other modules importing logger = logging.getLogger(appname) + +class EDMCContextFilter(logging.Filter): + """ + logging.Filter sub-class to place the calling __class__ in the record. + """ + def filter(self, record: logging.LogRecord) -> bool: + """ + + :param record: + :return: bool - True for this record to be logged. + """ + record.__dict__['class'] = self.caller_class() + return True + + def caller_class(self, skip=5) -> str: + """ + Figure out our caller class. + + Ref: + + :param skip: How many stack frames above to look. + :return: str: The class name. + """ + import inspect + + def stack_(frame): + framelist = [] + while frame: + framelist.append(frame) + frame = frame.f_back + return framelist + + stack = stack_(sys._getframe(1)) + start = 0 + skip + if len(stack) < start + 1: + return '' + + class_name = [] + frame = stack[start] + module = inspect.getmodule(frame) + # `modname` can be None when frame is executed directly in console + # TODO(techtonik): consider using __main__ + #if module: + # class_name.append(module.__name__) + # detect classname + if 'self' in frame.f_locals: + # I don't know any way to detect call from the object method + # XXX: there seems to be no way to detect static method call - it will + # be just a function call + class_name.insert(0, frame.f_locals['self'].__class__.__qualname__) + codename = frame.f_code.co_name + #if codename != '': # top level usually + # class_name.append(codename) # function or a method + + return ".".join(class_name) +########################################################################### + # Run the app if __name__ == "__main__": @@ -954,19 +1016,33 @@ if __name__ == "__main__": ########################################################################### # Set up a logging instance - logger_default_loglevel = logging.INFO + logger_default_loglevel = logging.DEBUG logger.setLevel(logger_default_loglevel) + + # Set up filter for adding class name + logger_f = EDMCContextFilter() + logger.addFilter(logger_f) + logger_ch = logging.StreamHandler() logger_ch.setLevel(logger_default_loglevel) - logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s:%(lineno)d:%(funcName)s: %(message)s') + + logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s<.%(class)s>.%(funcName)s:%(lineno)d: %(message)s') logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' logger_formatter.default_msec_format = '%s.%03d' + logger_ch.setFormatter(logger_formatter) logger.addHandler(logger_ch) ########################################################################### # Plain, not via `logger` print(f'{applongname} {appversion}') + logger.info('Logging test from __main__') + class A(object): + class B(object): + def __init__(self): + logger.info('Test from A.B.__init__') + + ab = A.B() Translations.install(config.get('language') or None) # Can generate errors so wait til log set up From 6b9d4a11cbcc78a3059e3393022749138578436b Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:02:16 +0100 Subject: [PATCH 09/35] Use a logging.Filter to implement %(qualname)s in formatting. This gets the function that called the logging, and if it's in a class it looks up the function via getattr(, ) and then uses __qualname__ to quickly get the fully qualified name. --- EDMarketConnector.py | 48 ++++++++++++++++++++++++++++++++++---------- 1 file changed, 37 insertions(+), 11 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 6d0ff021..bec122df 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -960,6 +960,7 @@ class EDMCContextFilter(logging.Filter): :return: bool - True for this record to be logged. """ record.__dict__['class'] = self.caller_class() + record.__dict__['qualname'] = self.caller_qualname() return True def caller_class(self, skip=5) -> str: @@ -987,22 +988,47 @@ class EDMCContextFilter(logging.Filter): class_name = [] frame = stack[start] - module = inspect.getmodule(frame) - # `modname` can be None when frame is executed directly in console - # TODO(techtonik): consider using __main__ - #if module: - # class_name.append(module.__name__) - # detect classname if 'self' in frame.f_locals: # I don't know any way to detect call from the object method # XXX: there seems to be no way to detect static method call - it will # be just a function call - class_name.insert(0, frame.f_locals['self'].__class__.__qualname__) - codename = frame.f_code.co_name - #if codename != '': # top level usually - # class_name.append(codename) # function or a method + class_name.append(frame.f_locals['self'].__class__.__qualname__) return ".".join(class_name) + + def caller_qualname(self, skip=5) -> str: + """ + Figure out our caller's qualname + + Ref: + + :param skip: How many stack frames above to look. + :return: str: The caller's qualname + """ + import inspect + + def stack_(frame): + framelist = [] + while frame: + framelist.append(frame) + frame = frame.f_back + return framelist + + stack = stack_(sys._getframe(1)) + start = 0 + skip + if len(stack) < start + 1: + return '' + + class_name = [] + frame = stack[start] + if 'self' in frame.f_locals: + # I don't know any way to detect call from the object method + # XXX: there seems to be no way to detect static method call - it will + # be just a function call + class_name.append(getattr(frame.f_locals['self'], frame.f_code.co_name).__qualname__) + + return ".".join(class_name) + ########################################################################### # Run the app @@ -1026,7 +1052,7 @@ if __name__ == "__main__": logger_ch = logging.StreamHandler() logger_ch.setLevel(logger_default_loglevel) - logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s<.%(class)s>.%(funcName)s:%(lineno)d: %(message)s') + logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(qualname)s:%(lineno)d: %(message)s') logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' logger_formatter.default_msec_format = '%s.%03d' From 5af87a5b982bd4a41ca297a8c7c3ed3910fed92a Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:04:22 +0100 Subject: [PATCH 10/35] Clean up EDMarketConnector.py after that qualname testing --- EDMarketConnector.py | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index bec122df..458ebb41 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -1041,7 +1041,7 @@ if __name__ == "__main__": sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), '%s.log' % appname), 'wt', 1) # unbuffered not allowed for text in python3, so use line buffering ########################################################################### - # Set up a logging instance + # Configure the logging.Logger logger_default_loglevel = logging.DEBUG logger.setLevel(logger_default_loglevel) @@ -1062,13 +1062,6 @@ if __name__ == "__main__": # Plain, not via `logger` print(f'{applongname} {appversion}') - logger.info('Logging test from __main__') - class A(object): - class B(object): - def __init__(self): - logger.info('Test from A.B.__init__') - - ab = A.B() Translations.install(config.get('language') or None) # Can generate errors so wait til log set up From 818bd89fd7e195417cb437a05cc6e0a5b3c42333 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:05:48 +0100 Subject: [PATCH 11/35] Remove un-necessary {__class__} from logging messages --- plug.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/plug.py b/plug.py index 2efc1ecb..01694520 100644 --- a/plug.py +++ b/plug.py @@ -106,10 +106,10 @@ class Plugin(object): else: logger.error(f'plugin {name} has no plugin_start3() function') except Exception as e: - logger.error(f'{__class__}: Failed for Plugin "{name}"', exc_info=e) + logger.error(f': Failed for Plugin "{name}"', exc_info=e) raise else: - logger.info(f'{__class__}: plugin {name} disabled') + logger.info(f'plugin {name} disabled') def _get_func(self, funcname): """ @@ -138,7 +138,7 @@ class Plugin(object): raise AssertionError return appitem except Exception as e: - logger.error(f'{__class__}: Failed for Plugin "{self.name}"', exc_info=e) + logger.error(f'Failed for Plugin "{self.name}"', exc_info=e) return None def get_prefs(self, parent, cmdr, is_beta): @@ -158,7 +158,7 @@ class Plugin(object): raise AssertionError return frame except Exception as e: - logger.error(f'{__class__}: Failed for Plugin "{self.name}"', exc_info=e) + logger.error(f'Failed for Plugin "{self.name}"', exc_info=e) return None From 6aa409388ea9f7afbd1e049963489e3bf5771a46 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:08:53 +0100 Subject: [PATCH 12/35] plugins/eddn: Converted to proper logging --- plugins/eddn.py | 45 ++++++++++++++++++++++----------------------- 1 file changed, 22 insertions(+), 23 deletions(-) diff --git a/plugins/eddn.py b/plugins/eddn.py index 15d7941c..5853cb13 100644 --- a/plugins/eddn.py +++ b/plugins/eddn.py @@ -15,13 +15,11 @@ from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb from prefs import prefsVersion +from EDMarketConnector import logger if sys.platform != 'win32': from fcntl import lockf, LOCK_EX, LOCK_NB -if __debug__: - from traceback import print_exc - from config import applongname, appversion, config from companion import category_map @@ -62,15 +60,15 @@ class EDDN(object): try: # Try to open existing file self.replayfile = open(filename, 'r+', buffering=1) - except: + except Exception as e: if exists(filename): raise # Couldn't open existing file else: self.replayfile = open(filename, 'w+', buffering=1) # Create file if sys.platform != 'win32': # open for writing is automatically exclusive on Windows lockf(self.replayfile, LOCK_EX|LOCK_NB) - except: - if __debug__: print_exc() + except Exception as e: + logger.debug(f'Failed opening "replay.jsonl"', exc_info=e) if self.replayfile: self.replayfile.close() self.replayfile = None @@ -104,11 +102,14 @@ class EDDN(object): ]) r = self.session.post(self.UPLOAD, data=json.dumps(msg), timeout=self.TIMEOUT) - if __debug__ and r.status_code != requests.codes.ok: - print('Status\t%s' % r.status_code) - print('URL\t%s' % r.url) - print('Headers\t%s' % r.headers) - print('Content:\n%s' % r.text) + if r.status_code != requests.codes.ok: + logger.debug(f''': +Status\t{r.status_code} +URL\t{r.url} +Headers\t{r.headers}' +Content:\n{r.text} +''' + ) r.raise_for_status() def sendreplay(self): @@ -128,11 +129,9 @@ class EDDN(object): self.parent.update_idletasks() try: cmdr, msg = json.loads(self.replaylog[0], object_pairs_hook=OrderedDict) - except: + except json.JSONDecodeError as e: # Couldn't decode - shouldn't happen! - if __debug__: - print(self.replaylog[0]) - print_exc() + logger.debug(f'\n{self.replaylog[0]}\n', exc_info=e) self.replaylog.pop(0) # Discard and continue else: # Rewrite old schema name @@ -144,11 +143,11 @@ class EDDN(object): if not len(self.replaylog) % self.REPLAYFLUSH: self.flush() except requests.exceptions.RequestException as e: - if __debug__: print_exc() + logger.debug(f'Failed sending', exc_info=e) status['text'] = _("Error: Can't connect to EDDN") return # stop sending except Exception as e: - if __debug__: print_exc() + logger.debug(f'Failed sending', exc_info=e) status['text'] = str(e) return # stop sending @@ -443,10 +442,10 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): try: this.eddn.export_journal_entry(cmdr, is_beta, filter_localised(entry)) except requests.exceptions.RequestException as e: - if __debug__: print_exc() + logger.debug(f'Failed in export_journal_entry', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: - if __debug__: print_exc() + logger.debug(f'Failed in export_journal_entry', exc_info=e) return str(e) elif (config.getint('output') & config.OUT_MKT_EDDN and not state['Captain'] and @@ -466,10 +465,10 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): this.eddn.export_journal_shipyard(cmdr, is_beta, entry) except requests.exceptions.RequestException as e: - if __debug__: print_exc() + logger.debug(f'Failed exporting {entry["event"]}', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: - if __debug__: print_exc() + logger.debug(f'Failed exporting {entry["event"]}', exc_info=e) return str(e) def cmdr_data(data, is_beta): @@ -492,9 +491,9 @@ def cmdr_data(data, is_beta): status.update_idletasks() except requests.RequestException as e: - if __debug__: print_exc() + logger.debug(f'Failed exporting data', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: - if __debug__: print_exc() + logger.debug(f'Failed exporting data', exc_info=e) return str(e) From 7951463fba064876c407df2fb7b1714bfc0ae363 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:17:59 +0100 Subject: [PATCH 13/35] plugins/edsm: Converted to proper logging --- plugins/edsm.py | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/plugins/edsm.py b/plugins/edsm.py index 34b64b80..ff29e099 100644 --- a/plugins/edsm.py +++ b/plugins/edsm.py @@ -23,11 +23,10 @@ import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb +from EDMarketConnector import logger from config import appname, applongname, appversion, config import plug -if __debug__: - from traceback import print_exc EDSM_POLL = 0.1 _TIMEOUT = 20 @@ -359,7 +358,7 @@ def worker(): (msgnum, msg) = reply['msgnum'], reply['msg'] # 1xx = OK, 2xx = fatal error, 3&4xx not generated at top-level, 5xx = error but events saved for later processing if msgnum // 100 == 2: - print('EDSM\t%s %s\t%s' % (msgnum, msg, json.dumps(pending, separators = (',', ': ')))) + logger.warning(f'EDSM\t{msgnum} {msg}\t{json.dumps(pending, separators = (",", ": "))}') plug.show_error(_('Error: EDSM {MSG}').format(MSG=msg)) else: for e, r in zip(pending, reply['events']): @@ -368,12 +367,12 @@ def worker(): this.lastlookup = r this.system_link.event_generate('<>', when="tail") # calls update_status in main thread elif r['msgnum'] // 100 != 1: - print('EDSM\t%s %s\t%s' % (r['msgnum'], r['msg'], json.dumps(e, separators = (',', ': ')))) + logger.warning(f'EDSM\t{r["msgnum"]} {r["msg"]}\t{json.dumps(e, separators = (",", ": "))}') pending = [] break - except: - if __debug__: print_exc() + except Exception as e: + logger.debug(f'Sending API events', exc_info=e) retrying += 1 else: plug.show_error(_("Error: Can't connect to EDSM")) From 89cadbc0eb9f7a92304eeb2e091f9681490a7d49 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:32:21 +0100 Subject: [PATCH 14/35] Add paranoia checks to class and qualname finders --- EDMarketConnector.py | 27 ++++++++++++++------------- 1 file changed, 14 insertions(+), 13 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 458ebb41..f280a9af 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -986,15 +986,15 @@ class EDMCContextFilter(logging.Filter): if len(stack) < start + 1: return '' - class_name = [] + class_name = '' frame = stack[start] if 'self' in frame.f_locals: - # I don't know any way to detect call from the object method - # XXX: there seems to be no way to detect static method call - it will - # be just a function call - class_name.append(frame.f_locals['self'].__class__.__qualname__) + # Paranoia checks + frame_class = frame.f_locals['self'].__class__ + if frame_class and frame_class.__qualname__: + class_name = frame_class.__qualname__ - return ".".join(class_name) + return class_name def caller_qualname(self, skip=5) -> str: """ @@ -1019,15 +1019,16 @@ class EDMCContextFilter(logging.Filter): if len(stack) < start + 1: return '' - class_name = [] + qualname = '' frame = stack[start] - if 'self' in frame.f_locals: - # I don't know any way to detect call from the object method - # XXX: there seems to be no way to detect static method call - it will - # be just a function call - class_name.append(getattr(frame.f_locals['self'], frame.f_code.co_name).__qualname__) + if frame.f_locals and 'self' in frame.f_locals: + # Paranoia checks + if frame.f_code and frame.f_code.co_name: + fn = getattr(frame.f_locals['self'], frame.f_code.co_name) + if fn and fn.__qualname__: + qualname = n.__qualname__ - return ".".join(class_name) + return qualname ########################################################################### From 4d7f81cec1ea80f8b9cd8679a1622950e1177e66 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:34:50 +0100 Subject: [PATCH 15/35] Add emergency print()s if we can't find class/qualname --- EDMarketConnector.py | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index f280a9af..e8f25a67 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -991,9 +991,13 @@ class EDMCContextFilter(logging.Filter): if 'self' in frame.f_locals: # Paranoia checks frame_class = frame.f_locals['self'].__class__ + if frame_class and frame_class.__qualname__: class_name = frame_class.__qualname__ + if class_name = '': + print('ALERT! Something went wrong with finding class name for logging!') + return class_name def caller_qualname(self, skip=5) -> str: @@ -1023,11 +1027,16 @@ class EDMCContextFilter(logging.Filter): frame = stack[start] if frame.f_locals and 'self' in frame.f_locals: # Paranoia checks + if frame.f_code and frame.f_code.co_name: fn = getattr(frame.f_locals['self'], frame.f_code.co_name) + if fn and fn.__qualname__: qualname = n.__qualname__ + if qualname == '': + print('ALERT! Something went wrong with finding caller qualname for logging!') + return qualname ########################################################################### From 7d060aa325e1543e70f95c3e216ea39e0e0e351f Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 21:39:18 +0100 Subject: [PATCH 16/35] plugins/inara: Convert to proper logging --- plugins/inara.py | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-) diff --git a/plugins/inara.py b/plugins/inara.py index dcfd5c70..0288076c 100644 --- a/plugins/inara.py +++ b/plugins/inara.py @@ -15,12 +15,10 @@ import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb +from EDMarketConnector import logger from config import appname, applongname, appversion, config import plug -if __debug__: - from traceback import print_exc - _TIMEOUT = 20 FAKE = ['CQC', 'Training', 'Destination'] # Fake systems that shouldn't be sent to Inara @@ -457,7 +455,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): call() except Exception as e: - if __debug__: print_exc() + logger.debug(f'Adding events', exc_info=e) return str(e) # @@ -898,14 +896,15 @@ def worker(): callback(reply) elif status // 100 != 2: # 2xx == OK (maybe with warnings) # Log fatal errors - print('Inara\t%s %s' % (reply['header']['eventStatus'], reply['header'].get('eventStatusText', ''))) - print(json.dumps(data, indent=2, separators = (',', ': '))) + log.warning(f'Inara\t{status} {reply["header"].get("eventStatusText", "")}') + log.debug(f'JSON data:\n{json.dumps(data, indent=2, separators = (",", ": "))}') plug.show_error(_('Error: Inara {MSG}').format(MSG = reply['header'].get('eventStatusText', status))) else: # Log individual errors and warnings for data_event, reply_event in zip(data['events'], reply['events']): if reply_event['eventStatus'] != 200: - print('Inara\t%s %s\t%s' % (reply_event['eventStatus'], reply_event.get('eventStatusText', ''), json.dumps(data_event))) + logger.warning(f'Inara\t{status} {reply_event.get("eventStatusText", "")}') + logger.debug(f'JSON data:\n{json.dumps(data_event)}') if reply_event['eventStatus'] // 100 != 2: plug.show_error(_('Error: Inara {MSG}').format(MSG = '%s, %s' % (data_event['eventName'], reply_event.get('eventStatusText', reply_event['eventStatus'])))) if data_event['eventName'] in ['addCommanderTravelCarrierJump', 'addCommanderTravelDock', 'addCommanderTravelFSDJump', 'setCommanderTravelLocation']: @@ -916,8 +915,8 @@ def worker(): this.system_link.event_generate('<>', when="tail") # calls update_ship in main thread break - except: - if __debug__: print_exc() + except Exceptionas e: + logger.debug(f'Sending events', exc_info=e) retrying += 1 else: if callback: From 8e1f3b8a90fd167c52213de1b1e1727093bff365 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 22:01:29 +0100 Subject: [PATCH 17/35] plugins/inara: Fix typo on except: --- plugins/inara.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/plugins/inara.py b/plugins/inara.py index 0288076c..1fcf5911 100644 --- a/plugins/inara.py +++ b/plugins/inara.py @@ -915,7 +915,7 @@ def worker(): this.system_link.event_generate('<>', when="tail") # calls update_ship in main thread break - except Exceptionas e: + except Exception as e: logger.debug(f'Sending events', exc_info=e) retrying += 1 else: From 2176187be712d00787eadaa9e2f18428602bc8ef Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 22:02:19 +0100 Subject: [PATCH 18/35] Fix typos in class/qualname finders --- EDMarketConnector.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index e8f25a67..1fdc1a9f 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -995,7 +995,7 @@ class EDMCContextFilter(logging.Filter): if frame_class and frame_class.__qualname__: class_name = frame_class.__qualname__ - if class_name = '': + if class_name == '': print('ALERT! Something went wrong with finding class name for logging!') return class_name @@ -1032,7 +1032,7 @@ class EDMCContextFilter(logging.Filter): fn = getattr(frame.f_locals['self'], frame.f_code.co_name) if fn and fn.__qualname__: - qualname = n.__qualname__ + qualname = fn.__qualname__ if qualname == '': print('ALERT! Something went wrong with finding caller qualname for logging!') From bae2f25e19fbe5fb837956f7f7e951ae0caab6d7 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 22:17:33 +0100 Subject: [PATCH 19/35] companion.py: Convert to proper logging --- companion.py | 69 +++++++++++++++++++++------------------------------- 1 file changed, 28 insertions(+), 41 deletions(-) diff --git a/companion.py b/companion.py index 57911342..62d07282 100644 --- a/companion.py +++ b/companion.py @@ -14,12 +14,14 @@ import os from os.path import join import random import time -from traceback import print_exc import urllib.parse import webbrowser from config import appname, appversion, config from protocol import protocolhandler +import logging +logger = logging.getLogger(appname) + from typing import TYPE_CHECKING if TYPE_CHECKING: @@ -196,18 +198,17 @@ class Auth(object): return data.get('access_token') else: - print('Auth\tCan\'t refresh token for {}'.format(self.cmdr)) + logger.error(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"") self.dump(r) - except Exception: - print('Auth\tCan\'t refresh token for {}'.format(self.cmdr)) - print_exc() + except Exception as e: + logger.error(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"", exc_info=e) else: - print('Auth\tNo token for {}'.format(self.cmdr)) + logger.error(f"Frontier CAPI Auth: No token for \"{self.cmdr}\"", exc_info=e) # New request - print('Auth\tNew authorization request') + logger.info(f'Frontier CAPI Auth: New authorization request') v = random.SystemRandom().getrandbits(8 * 32) self.verifier = self.base64URLEncode(v.to_bytes(32, byteorder='big')).encode('utf-8') s = random.SystemRandom().getrandbits(8 * 32) @@ -228,16 +229,16 @@ class Auth(object): # Handle OAuth authorization code callback. # Returns access token if successful, otherwise raises CredentialsError if '?' not in payload: - print('Auth\tMalformed response {!r}'.format(payload)) + logger.error(f'Frontier CAPI Auth: Malformed response\n{payload}\n') raise CredentialsError('malformed payload') # Not well formed data = urllib.parse.parse_qs(payload[(payload.index('?') + 1):]) if not self.state or not data.get('state') or data['state'][0] != self.state: - print('Auth\tUnexpected response {!r}'.format(payload)) + logger.error(f'Frontier CAPI Auth: Unexpected response\n{payload}\n') raise CredentialsError('Unexpected response from authorization {!r}'.format(payload)) # Unexpected reply if not data.get('code'): - print('Auth\tNegative response {!r}'.format(payload)) + logger.error(f'Frontier CAPI Auth: Negative response\n{payload}\n') error = next( (data[k] for k in ('error_description', 'error', 'message') if k in data), ('',) ) @@ -256,7 +257,7 @@ class Auth(object): r = self.session.post(SERVER_AUTH + URL_TOKEN, data=data, timeout=auth_timeout) data = r.json() if r.status_code == requests.codes.ok: - print('Auth\tNew token for {}'.format(self.cmdr)) + logger.info(f'Frontier CAPI Auth: New token for \"{self.cmdr}\"') cmdrs = config.get('cmdrs') idx = cmdrs.index(self.cmdr) tokens = config.get('fdev_apikeys') or [] @@ -268,21 +269,20 @@ class Auth(object): return data.get('access_token') except Exception as e: - print('Auth\tCan\'t get token for {}'.format(self.cmdr)) - print_exc() + logger.error(f"Frontier CAPI Auth: Can't get token for \"{self.cmdr}\"", exc_info=e) if r: self.dump(r) raise CredentialsError('unable to get token') from e - print('Auth\tCan\'t get token for {}'.format(self.cmdr)) + logger.error(f"Frontier CAPI Auth: Can't get token for \"{self.cmdr}\"") self.dump(r) error = next((data[k] for k in ('error_description', 'error', 'message') if k in data), ('',)) raise CredentialsError('Error: {!r}'.format(error)[0]) @staticmethod def invalidate(cmdr): - print('Auth\tInvalidated token for {}'.format(cmdr)) + logger.info(f'Frontier CAPI Auth: Invalidated token for "{cmdr}"') cmdrs = config.get('cmdrs') idx = cmdrs.index(cmdr) tokens = config.get('fdev_apikeys') or [] @@ -292,7 +292,7 @@ class Auth(object): config.save() # Save settings now for use by command-line app def dump(self, r): - print('Auth\t' + r.url, r.status_code, r.reason if r.reason else 'None', r.text) + logger.debug(f'Frontier CAPI Auth: {r.url} {r.status_code} {r.reason if r.reason else "None"} {r.text}') def base64URLEncode(self, text): return base64.urlsafe_b64encode(text).decode().replace('=', '') @@ -379,9 +379,7 @@ class Session(object): r = self.session.get(self.server + endpoint, timeout=timeout) except Exception as e: - if __debug__: - print_exc() - + logger.debug(f'Attempting GET', exc_info=e) raise ServerError('unable to get endpoint {}'.format(endpoint)) from e if r.url.startswith(SERVER_AUTH): @@ -402,7 +400,7 @@ class Session(object): data = r.json() # May also fail here if token expired since response is empty except (requests.HTTPError, ValueError) as e: - print_exc() + logger.error(f'Frontier CAPI Auth: GET ', exc_info=e) self.dump(r) self.close() @@ -410,6 +408,7 @@ class Session(object): self.invalidate() self.retrying = False self.login() + logger.error(f'Frontier CAPI Auth: query failed after refresh') raise CredentialsError('query failed after refresh') from e elif self.login(): # Maybe our token expired. Re-authorize in any case @@ -418,6 +417,7 @@ class Session(object): else: self.retrying = False + logger.error(f'Frontier CAPI Auth: HTTP error or invalid JSON') raise CredentialsError('HTTP error or invalid JSON') from e self.retrying = False @@ -461,9 +461,8 @@ class Session(object): try: self.session.close() - except Exception: - if __debug__: - print_exc() + except Exception as e: + logger.debug(f'Frontier CAPI Auth: closing', exc_info=e) self.session = None @@ -473,7 +472,7 @@ class Session(object): Auth.invalidate(self.credentials['cmdr']) def dump(self, r): - print('cAPI\t' + r.url, r.status_code, r.reason and r.reason or 'None', r.text) + logger.error(f'Frontier CAPI Auth: {r.url} {r.status_code} {r.reason and r.reason or "None"} {r.text}') # Returns a shallow copy of the received data suitable for export to older tools # English commodity names and anomalies fixed up @@ -497,15 +496,7 @@ def fixup(data): # But also see https://github.com/Marginal/EDMarketConnector/issues/32 for thing in ('buyPrice', 'sellPrice', 'demand', 'demandBracket', 'stock', 'stockBracket'): if not isinstance(commodity.get(thing), numbers.Number): - if __debug__: - print( - 'Invalid {!r}:{!r} ({}) for {!r}'.format( - thing, - commodity.get(thing), - type(commodity.get(thing)), - commodity.get('name', '') - ) - ) + logger.debug(f'Invalid {thing}:{commodity.get(thing)} ({type(commodity.get(thing))}) for {commodity.get("name", "")}') break else: @@ -520,20 +511,16 @@ def fixup(data): pass elif not commodity.get('categoryname'): - if __debug__: - print('Missing "categoryname" for {!r}'.format(commodity.get('name', ''))) + logger.debug(f'Missing "categoryname" for {commodity.get("name", "")}') elif not commodity.get('name'): - if __debug__: - print('Missing "name" for a commodity in {!r}'.format(commodity.get('categoryname', ''))) + logger.debug(f'Missing "name" for a commodity in {commodity.get("categoryname", "")}') elif not commodity['demandBracket'] in range(4): - if __debug__: - print('Invalid "demandBracket":{!r} for {!r}'.format(commodity['demandBracket'], commodity['name'])) + logger.debug(f'Invalid "demandBracket":{commodity["demandBracket"]} for {commodity["name"]}') elif not commodity['stockBracket'] in range(4): - if __debug__: - print('Invalid "stockBracket":{!r} for {!r}'.format(commodity['stockBracket'], commodity['name'])) + logger.debug(f'Invalid "stockBracket":{commodity["stockBracket"]} for {commodity["name"]}') else: # Rewrite text fields From 2e58d106bd9f7281a82caf0447b8915130bca6e6 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 22:23:40 +0100 Subject: [PATCH 20/35] logging.getLogger(appname) instead of import from EDMarketConnector Using: from EDMarketConnector import logger causes issues if EDMarketConnector is already importing 'this' file. So just get a logger using logger.getLogger(appname) instead. `from config import appname` if needs be. --- plug.py | 8 ++++---- plugins/eddn.py | 5 +++-- plugins/edsm.py | 3 ++- plugins/inara.py | 3 ++- 4 files changed, 11 insertions(+), 8 deletions(-) diff --git a/plug.py b/plug.py index 01694520..50d9af07 100644 --- a/plug.py +++ b/plug.py @@ -8,15 +8,15 @@ import importlib import sys import operator import threading # We don't use it, but plugins might -from traceback import print_exc - +import logging import tkinter as tk + import myNotebook as nb -from config import config -from EDMarketConnector import logger +from config import config, appname from time import time as time +logger = logging.getLogger(appname) # Dashboard Flags constants FlagsDocked = 1<<0 # on a landing pad diff --git a/plugins/eddn.py b/plugins/eddn.py index 5853cb13..e2e2b141 100644 --- a/plugins/eddn.py +++ b/plugins/eddn.py @@ -9,20 +9,21 @@ import re import requests import sys import uuid +import logging import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb from prefs import prefsVersion -from EDMarketConnector import logger if sys.platform != 'win32': from fcntl import lockf, LOCK_EX, LOCK_NB -from config import applongname, appversion, config +from config import appname, applongname, appversion, config from companion import category_map +logger = logging.getLogger(appname) this = sys.modules[__name__] # For holding module globals diff --git a/plugins/edsm.py b/plugins/edsm.py index ff29e099..eb0ab84f 100644 --- a/plugins/edsm.py +++ b/plugins/edsm.py @@ -18,15 +18,16 @@ import time import urllib.request, urllib.error, urllib.parse from queue import Queue from threading import Thread +import logging import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb -from EDMarketConnector import logger from config import appname, applongname, appversion, config import plug +logger = logging.getLogger(appname) EDSM_POLL = 0.1 _TIMEOUT = 20 diff --git a/plugins/inara.py b/plugins/inara.py index 1fcf5911..abf221f4 100644 --- a/plugins/inara.py +++ b/plugins/inara.py @@ -10,14 +10,15 @@ import time from operator import itemgetter from queue import Queue from threading import Thread +import logging import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel import myNotebook as nb -from EDMarketConnector import logger from config import appname, applongname, appversion, config import plug +logger = logging.getLogger(appname) _TIMEOUT = 20 From a82824c0e936d90fd8e91880de977c7c5464542b Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 24 Jul 2020 22:41:30 +0100 Subject: [PATCH 21/35] Contributing.md: Update logging docs for auto qualname and proper import --- Contributing.md | 31 +++++++++++++++++++++++-------- 1 file changed, 23 insertions(+), 8 deletions(-) diff --git a/Contributing.md b/Contributing.md index c82a4cee..ef2ab460 100644 --- a/Contributing.md +++ b/Contributing.md @@ -225,9 +225,12 @@ No: types. * Use `logging` not `print()`, and definitely not `sys.stdout.write()`! - `EDMarketConnector.py` sets up `logger` for this, so: + `EDMarketConnector.py` sets up a `logging.Logger` for this under the + `appname`, so: - from EDMarketConnector import logger + import logging + from config import appname + logger = logging.getLogger(appname) logger.info(f'Some message with a {variable}') @@ -235,14 +238,26 @@ No: something except Exception as e: # Try to be more specific logger.error(f'Error in ... with ...', exc_info=e) - - Also if the code is within a class definition at all then please use: + + **DO NOT** use the following, as you might cause a circular import: - logger.info(f'{__class__}: ...) + from EDMarketConnector import logger - so that the class name is included in the output. No `logger.Formatter` - does not support this (probably because there's no way to get at the - information for a calling function). + We have implemented a `logging.Filter` that adds support for the following + in `logging.Formatter()` strings: + + 1. `%(qualname)s` which gets the full `ClassA(.ClassB...).func` of the + calling function. + 1. `%(class)s` which gets just the immediately encloding class name + of the calling function. + + So don't worry about adding anything about the class or function you're + logging from, it's taken care of. + + *Do use a pertinent message, even when using `exc_info=...` to log an + exception*. e.g. Logging will know you were in your `get_foo()` function + but you should still tell it what actually (failed to have) happened + in there. * In general, please follow [PEP8](https://www.python.org/dev/peps/pep-0008/). From c196a38e09da396bb94c5c281148671339072b47 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 06:53:40 +0100 Subject: [PATCH 22/35] Add logging TODOs. logger creation & frame detection * Nothing should "from EDMarketConnector import logger" any more, so we can move this back inside __main__ section * We shouldn't rely on a magic number of frames to skip. Detect the proper frame automatically. --- EDMarketConnector.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 1fdc1a9f..6685ddd0 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -947,6 +947,7 @@ def enforce_single_instance() -> None: # Logging # Has to be here to be defined for other modules importing +# TODO: now nothing should import this, can it move back into __main__ block ? logger = logging.getLogger(appname) class EDMCContextFilter(logging.Filter): @@ -982,6 +983,11 @@ class EDMCContextFilter(logging.Filter): return framelist stack = stack_(sys._getframe(1)) + # TODO: Make this less fragile by not depending on a magic number of + # stack frames to skip. Should be able to find the last + # logger frame, where one of the critical, debug etc functions + # was called and then use the next frame before that. + # ALSO UPDATE caller_qualname() !!! start = 0 + skip if len(stack) < start + 1: return '' From 596527bda29266f0d015c457c8bc225f7ed7688e Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 14:46:10 +0100 Subject: [PATCH 23/35] Move logging setup to EDMCLogging.py with a class * Also now providers single caller_class_and_qualname() method to get both strings, returned as a Tuple[str, str]. Either could be empty if something went wrong. * Rather than a fragile 'skip' this now: 1. Looks for the first up-stack frame with self of logging.Logger 1. Then looks for the next up-stack frame with self NOT of logging.Logger. This should be the call site we want. --- EDMCLogging.py | 124 ++++++++++++++++++++++++++++++++++++++++ EDMarketConnector.py | 131 +++---------------------------------------- 2 files changed, 133 insertions(+), 122 deletions(-) create mode 100644 EDMCLogging.py diff --git a/EDMCLogging.py b/EDMCLogging.py new file mode 100644 index 00000000..24edac32 --- /dev/null +++ b/EDMCLogging.py @@ -0,0 +1,124 @@ +""" +TODO: blurb +""" + +import sys +import logging +from typing import Tuple + +class logger(object): + """ + TODO: desc + Wrapper class for all logging configuration and code. + """ + def __init__(self, logger_name: str, loglevel: int=logging.DEBUG): + """ + Set up a `logging.Logger` with our preferred configuration. + This includes using an EDMCContextFilter to add 'class' and 'qualname' + expansions for logging.Formatter(). + """ + self.logger = logging.getLogger(logger_name) + # Configure the logging.Logger + self.logger.setLevel(loglevel) + + # Set up filter for adding class name + self.logger_filter = EDMCContextFilter() + self.logger.addFilter(self.logger_filter) + + self.logger_channel = logging.StreamHandler() + self.logger_channel.setLevel(loglevel) + + self.logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(qualname)s:%(lineno)d: %(class)s: %(message)s') + self.logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' + self.logger_formatter.default_msec_format = '%s.%03d' + + self.logger_channel.setFormatter(self.logger_formatter) + self.logger.addHandler(self.logger_channel) + + def getLogger(self) -> logging.Logger: + return self.logger + + +class EDMCContextFilter(logging.Filter): + """ + TODO: Update this + logging.Filter sub-class to place the calling __class__ in the record. + """ + def filter(self, record: logging.LogRecord) -> bool: + """ + + :param record: + :return: bool - True for this record to be logged. + """ + # TODO: Only set these if they're not already, in case upstream + # adds them. + # TODO: Try setattr(record, 'class', ... + (class_name, qualname) = self.caller_class_and_qualname() + record.__dict__['class'] = class_name + record.__dict__['qualname'] = qualname + return True + + def caller_class_and_qualname(self, skip=4) -> Tuple[str, str]: + """ + Figure out our caller's qualname + + Ref: + + :param skip: How many stack frames above to look. + :return: str: The caller's qualname + """ + import inspect + + # TODO: Fold this into caller_class() + def stack_(frame): + framelist = [] + while frame: + framelist.append(frame) + frame = frame.f_back + return framelist + + stack = stack_(sys._getframe(0)) + # Go up through stack frames until we find the first with a + # type(f_locals.self) of logging.Logger. This should be the start + # of the frames internal to logging. + f = 0 + while stack[f]: + if type(stack[f].f_locals.get('self')) == logging.Logger: + f += 1 # Want to start on the next frame below + break + f += 1 + + # Now continue up through frames until we find the next one where + # that is *not* true, as it should be the call site of the logger + # call + while stack[f]: + if type(stack[f].f_locals.get('self')) != logging.Logger: + break # We've found the frame we want + f += 1 + + caller_qualname = caller_class_name = '' + if stack[f]: + frame = stack[f] + if frame.f_locals and 'self' in frame.f_locals: + + # Find __qualname__ of the caller + # Paranoia checks + if frame.f_code and frame.f_code.co_name: + fn = getattr(frame.f_locals['self'], frame.f_code.co_name) + + if fn and fn.__qualname__: + caller_qualname = fn.__qualname__ + + # Find immediate containing class name of caller, if any + frame_class = frame.f_locals['self'].__class__ + # Paranoia checks + if frame_class and frame_class.__qualname__: + caller_class_name = frame_class.__qualname__ + + if caller_qualname == '': + print('ALERT! Something went wrong with finding caller qualname for logging!') + + if caller_class_name == '': + print('ALERT! Something went wrong with finding caller class name for logging!') + + return (caller_class_name, caller_qualname) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 6685ddd0..4d0e6099 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -21,6 +21,7 @@ import logging import traceback from typing import Any, Optional +import EDMCLogging from config import appname, applongname, appversion, appversion_nobuild, copyright, config if getattr(sys, 'frozen', False): @@ -943,109 +944,6 @@ def enforce_single_instance() -> None: EnumWindows(enumwindowsproc, 0) -########################################################################### -# Logging - -# Has to be here to be defined for other modules importing -# TODO: now nothing should import this, can it move back into __main__ block ? -logger = logging.getLogger(appname) - -class EDMCContextFilter(logging.Filter): - """ - logging.Filter sub-class to place the calling __class__ in the record. - """ - def filter(self, record: logging.LogRecord) -> bool: - """ - - :param record: - :return: bool - True for this record to be logged. - """ - record.__dict__['class'] = self.caller_class() - record.__dict__['qualname'] = self.caller_qualname() - return True - - def caller_class(self, skip=5) -> str: - """ - Figure out our caller class. - - Ref: - - :param skip: How many stack frames above to look. - :return: str: The class name. - """ - import inspect - - def stack_(frame): - framelist = [] - while frame: - framelist.append(frame) - frame = frame.f_back - return framelist - - stack = stack_(sys._getframe(1)) - # TODO: Make this less fragile by not depending on a magic number of - # stack frames to skip. Should be able to find the last - # logger frame, where one of the critical, debug etc functions - # was called and then use the next frame before that. - # ALSO UPDATE caller_qualname() !!! - start = 0 + skip - if len(stack) < start + 1: - return '' - - class_name = '' - frame = stack[start] - if 'self' in frame.f_locals: - # Paranoia checks - frame_class = frame.f_locals['self'].__class__ - - if frame_class and frame_class.__qualname__: - class_name = frame_class.__qualname__ - - if class_name == '': - print('ALERT! Something went wrong with finding class name for logging!') - - return class_name - - def caller_qualname(self, skip=5) -> str: - """ - Figure out our caller's qualname - - Ref: - - :param skip: How many stack frames above to look. - :return: str: The caller's qualname - """ - import inspect - - def stack_(frame): - framelist = [] - while frame: - framelist.append(frame) - frame = frame.f_back - return framelist - - stack = stack_(sys._getframe(1)) - start = 0 + skip - if len(stack) < start + 1: - return '' - - qualname = '' - frame = stack[start] - if frame.f_locals and 'self' in frame.f_locals: - # Paranoia checks - - if frame.f_code and frame.f_code.co_name: - fn = getattr(frame.f_locals['self'], frame.f_code.co_name) - - if fn and fn.__qualname__: - qualname = fn.__qualname__ - - if qualname == '': - print('ALERT! Something went wrong with finding caller qualname for logging!') - - return qualname - -########################################################################### # Run the app if __name__ == "__main__": @@ -1056,29 +954,18 @@ if __name__ == "__main__": import tempfile sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), '%s.log' % appname), 'wt', 1) # unbuffered not allowed for text in python3, so use line buffering - ########################################################################### - # Configure the logging.Logger - logger_default_loglevel = logging.DEBUG - logger.setLevel(logger_default_loglevel) - - # Set up filter for adding class name - logger_f = EDMCContextFilter() - logger.addFilter(logger_f) - - logger_ch = logging.StreamHandler() - logger_ch.setLevel(logger_default_loglevel) - - logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(qualname)s:%(lineno)d: %(message)s') - logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' - logger_formatter.default_msec_format = '%s.%03d' - - logger_ch.setFormatter(logger_formatter) - logger.addHandler(logger_ch) - ########################################################################### + logger = EDMCLogging.logger(appname).getLogger() # Plain, not via `logger` print(f'{applongname} {appversion}') + class A(object): + class B(object): + def __init__(self): + logger.debug('A call from A.B.__init__') + + abinit = A.B() + Translations.install(config.get('language') or None) # Can generate errors so wait til log set up root = tk.Tk(className=appname.lower()) From 5a779a33790d24ab2ee9bb5dd7624d98d91578bc Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 15:22:22 +0100 Subject: [PATCH 24/35] Cleanups and docstrings * Added/fleshed out docstrings on file, classes and functions. * No need to use a function for the stack frame getting. * Check if LogRecord has class or qualname before setting, allowing upstream to implement them. * Use setattr()/getattr() rather than __dict__ fiddling. * Force an error string into class/qualname if we have issues finding them, rather than failing silently to ''. --- EDMCLogging.py | 76 +++++++++++++++++++++++++++++++++----------------- 1 file changed, 50 insertions(+), 26 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 24edac32..f522864e 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -1,5 +1,8 @@ """ -TODO: blurb +This module provides for a common logging-powered log facility. +Mostly it implements a logging.Filter() in order to get two extra +members on the logging.LogRecord instance for use in logging.Formatter() +strings. """ import sys @@ -8,8 +11,14 @@ from typing import Tuple class logger(object): """ - TODO: desc Wrapper class for all logging configuration and code. + + Class instantiation requires the 'logger name' and optional loglevel. + It is intended that this 'logger name' be re-used in all files/modules + that need to log. + + Users of this class should then call getLogger() to get the + logging.Logger instance. """ def __init__(self, logger_name: str, loglevel: int=logging.DEBUG): """ @@ -36,48 +45,61 @@ class logger(object): self.logger.addHandler(self.logger_channel) def getLogger(self) -> logging.Logger: + """ + :return: The logging.Logger instance. + """ return self.logger class EDMCContextFilter(logging.Filter): """ - TODO: Update this - logging.Filter sub-class to place the calling __class__ in the record. + logging.Filter sub-class to place extra attributes of the calling site + into the record. """ def filter(self, record: logging.LogRecord) -> bool: """ + Attempt to set the following in the LogRecord: - :param record: - :return: bool - True for this record to be logged. + 1. class = class name of the call site, if applicable + 2. qualname = __qualname__ of the call site. This simplifies + logging.Formatter() as you can use just this no matter if there is + a class involved or not, so you get a nice clean: + .[.classB....]. + + :param record: The LogRecord we're "filtering" + :return: bool - Always true in order for this record to be logged. """ - # TODO: Only set these if they're not already, in case upstream - # adds them. - # TODO: Try setattr(record, 'class', ... - (class_name, qualname) = self.caller_class_and_qualname() - record.__dict__['class'] = class_name - record.__dict__['qualname'] = qualname + class_name = qualname = '' + # Don't even call in if both already set. + if not getattr(record, 'class', None) or not getattr(record, 'qualname', None): + (class_name, qualname) = self.caller_class_and_qualname() + + # Only set if not already provided by logging itself + if getattr(record, 'class', None) is None: + setattr(record, 'class', class_name) + + # Only set if not already provided by logging itself + if getattr(record, 'qualname', None) is None: + setattr(record, 'qualname', qualname) + return True - def caller_class_and_qualname(self, skip=4) -> Tuple[str, str]: + def caller_class_and_qualname(self) -> Tuple[str, str]: """ - Figure out our caller's qualname + Figure out our caller's class name and qualname Ref: - :param skip: How many stack frames above to look. - :return: str: The caller's qualname + :return: Tuple[str, str]: The caller's class name and qualname """ - import inspect + # TODO: we might as well just walk this below. + # Build the stack of frames from here upwards + stack = [] + frame = sys._getframe(0) + while frame: + stack.append(frame) + frame = frame.f_back - # TODO: Fold this into caller_class() - def stack_(frame): - framelist = [] - while frame: - framelist.append(frame) - frame = frame.f_back - return framelist - - stack = stack_(sys._getframe(0)) # Go up through stack frames until we find the first with a # type(f_locals.self) of logging.Logger. This should be the start # of the frames internal to logging. @@ -117,8 +139,10 @@ class EDMCContextFilter(logging.Filter): if caller_qualname == '': print('ALERT! Something went wrong with finding caller qualname for logging!') + caller_qualname = '' if caller_class_name == '': print('ALERT! Something went wrong with finding caller class name for logging!') + caller_class_name = '' return (caller_class_name, caller_qualname) From 2eba647f17753a4e6a3b00a04af4195da658ad60 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 15:30:34 +0100 Subject: [PATCH 25/35] Simply walk up the stack finding the frame we want. Also leave that 'A.B' test around as a hint for a unittest. Obviously that instantiation will need commenting out for a release. --- EDMCLogging.py | 27 +++++++++------------------ 1 file changed, 9 insertions(+), 18 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index f522864e..0c7c629d 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -92,35 +92,26 @@ class EDMCContextFilter(logging.Filter): :return: Tuple[str, str]: The caller's class name and qualname """ - # TODO: we might as well just walk this below. - # Build the stack of frames from here upwards - stack = [] - frame = sys._getframe(0) - while frame: - stack.append(frame) - frame = frame.f_back - # Go up through stack frames until we find the first with a # type(f_locals.self) of logging.Logger. This should be the start # of the frames internal to logging. - f = 0 - while stack[f]: - if type(stack[f].f_locals.get('self')) == logging.Logger: - f += 1 # Want to start on the next frame below + frame = sys._getframe(0) + while frame: + if type(frame.f_locals.get('self')) == logging.Logger: + frame = frame.f_back # Want to start on the next frame below break - f += 1 + frame = frame.f_back # Now continue up through frames until we find the next one where # that is *not* true, as it should be the call site of the logger # call - while stack[f]: - if type(stack[f].f_locals.get('self')) != logging.Logger: + while frame: + if type(frame.f_locals.get('self')) != logging.Logger: break # We've found the frame we want - f += 1 + frame = frame.f_back caller_qualname = caller_class_name = '' - if stack[f]: - frame = stack[f] + if frame: if frame.f_locals and 'self' in frame.f_locals: # Find __qualname__ of the caller From 66e2c354c77c4afec22d06f02fd51f3984bb50f6 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 16:14:57 +0100 Subject: [PATCH 26/35] Documentation update and getLogger() -> get_logger() * Technically %(class)s can be e.g. A.B not just 'B' so say "name(s)". * To not confuse EDMCLogging.getLogger() with logging.getLogger() it's been renamed to get_logger(). * Note how we signal errors with finding class and/or qualname. * Call out EDMCLogging.py in Contributing.md. --- Contributing.md | 8 +++++--- EDMCLogging.py | 31 ++++++++++++++++++------------- EDMarketConnector.py | 2 +- 3 files changed, 24 insertions(+), 17 deletions(-) diff --git a/Contributing.md b/Contributing.md index ef2ab460..dfbd1b1e 100644 --- a/Contributing.md +++ b/Contributing.md @@ -246,11 +246,13 @@ No: We have implemented a `logging.Filter` that adds support for the following in `logging.Formatter()` strings: - 1. `%(qualname)s` which gets the full `ClassA(.ClassB...).func` of the - calling function. - 1. `%(class)s` which gets just the immediately encloding class name + 1. `%(qualname)s` which gets the full `.ClassA(.ClassB...).func` of the calling function. + 1. `%(class)s` which gets just the enclosing class name(s) of the calling + function. + If you want to see how we did this, check `EDMCLogging.py`. + So don't worry about adding anything about the class or function you're logging from, it's taken care of. diff --git a/EDMCLogging.py b/EDMCLogging.py index 0c7c629d..504467d6 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -44,7 +44,7 @@ class logger(object): self.logger_channel.setFormatter(self.logger_formatter) self.logger.addHandler(self.logger_channel) - def getLogger(self) -> logging.Logger: + def get_logger(self) -> logging.Logger: """ :return: The logging.Logger instance. """ @@ -60,12 +60,18 @@ class EDMCContextFilter(logging.Filter): """ Attempt to set the following in the LogRecord: - 1. class = class name of the call site, if applicable + 1. class = class name(s) of the call site, if applicable 2. qualname = __qualname__ of the call site. This simplifies logging.Formatter() as you can use just this no matter if there is a class involved or not, so you get a nice clean: .[.classB....]. + If we fail to be able to properly set either then: + + 1. Use print() to alert, to be SURE a message is seen. + 2. But also return strings noting the error, so there'll be + something in the log output if it happens. + :param record: The LogRecord we're "filtering" :return: bool - Always true in order for this record to be logged. """ @@ -86,11 +92,11 @@ class EDMCContextFilter(logging.Filter): def caller_class_and_qualname(self) -> Tuple[str, str]: """ - Figure out our caller's class name and qualname + Figure out our caller's class name(s) and qualname Ref: - :return: Tuple[str, str]: The caller's class name and qualname + :return: Tuple[str, str]: The caller's class name(s) and qualname """ # Go up through stack frames until we find the first with a # type(f_locals.self) of logging.Logger. This should be the start @@ -110,10 +116,9 @@ class EDMCContextFilter(logging.Filter): break # We've found the frame we want frame = frame.f_back - caller_qualname = caller_class_name = '' + caller_qualname = caller_class_names = '' if frame: if frame.f_locals and 'self' in frame.f_locals: - # Find __qualname__ of the caller # Paranoia checks if frame.f_code and frame.f_code.co_name: @@ -122,18 +127,18 @@ class EDMCContextFilter(logging.Filter): if fn and fn.__qualname__: caller_qualname = fn.__qualname__ - # Find immediate containing class name of caller, if any + # Find containing class name(s) of caller, if any frame_class = frame.f_locals['self'].__class__ # Paranoia checks if frame_class and frame_class.__qualname__: - caller_class_name = frame_class.__qualname__ + caller_class_names = frame_class.__qualname__ if caller_qualname == '': print('ALERT! Something went wrong with finding caller qualname for logging!') - caller_qualname = '' + caller_qualname = '' - if caller_class_name == '': - print('ALERT! Something went wrong with finding caller class name for logging!') - caller_class_name = '' + if caller_class_names == '': + print('ALERT! Something went wrong with finding caller class name(s) for logging!') + caller_class_names = '' - return (caller_class_name, caller_qualname) + return (caller_class_names, caller_qualname) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 4d0e6099..485814a0 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -954,7 +954,7 @@ if __name__ == "__main__": import tempfile sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), '%s.log' % appname), 'wt', 1) # unbuffered not allowed for text in python3, so use line buffering - logger = EDMCLogging.logger(appname).getLogger() + logger = EDMCLogging.logger(appname).get_logger() # Plain, not via `logger` print(f'{applongname} {appversion}') From 307910739a807ead6e364fa76ce5e7f5e6153a93 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sat, 25 Jul 2020 19:55:09 +0100 Subject: [PATCH 27/35] Remove now un-necessary imports for logging/traceback --- EDMarketConnector.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 485814a0..72c2b84e 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -17,9 +17,6 @@ from time import gmtime, time, localtime, strftime, strptime import _strptime # Workaround for http://bugs.python.org/issue7980 from calendar import timegm import webbrowser -import logging -import traceback -from typing import Any, Optional import EDMCLogging from config import appname, applongname, appversion, appversion_nobuild, copyright, config From 3653a1342fc6bb4d7526083e3ffbac0bdfb4f94e Mon Sep 17 00:00:00 2001 From: Athanasius Date: Sun, 26 Jul 2020 11:51:58 +0100 Subject: [PATCH 28/35] No need to subclass object. --- EDMCLogging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 504467d6..21fc39b2 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -9,7 +9,7 @@ import sys import logging from typing import Tuple -class logger(object): +class logger(): """ Wrapper class for all logging configuration and code. From f9a23cc831aa45afb170edd3b3168f814eb758c6 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 09:37:10 +0100 Subject: [PATCH 29/35] Clean up flake8 output for this branch --- EDMCLogging.py | 6 ++-- EDMarketConnector.py | 38 ++++++++++++-------- companion.py | 28 +++++++-------- plug.py | 83 ++++++++++++++++++++++---------------------- plugins/eddn.py | 41 ++++++++++------------ plugins/edsm.py | 15 +++++--- plugins/inara.py | 19 +++++----- 7 files changed, 122 insertions(+), 108 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 21fc39b2..aa0a14fe 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -9,7 +9,7 @@ import sys import logging from typing import Tuple -class logger(): +class Logger: """ Wrapper class for all logging configuration and code. @@ -20,7 +20,7 @@ class logger(): Users of this class should then call getLogger() to get the logging.Logger instance. """ - def __init__(self, logger_name: str, loglevel: int=logging.DEBUG): + def __init__(self, logger_name: str, loglevel: int = logging.DEBUG): """ Set up a `logging.Logger` with our preferred configuration. This includes using an EDMCContextFilter to add 'class' and 'qualname' @@ -37,7 +37,7 @@ class logger(): self.logger_channel = logging.StreamHandler() self.logger_channel.setLevel(loglevel) - self.logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(qualname)s:%(lineno)d: %(class)s: %(message)s') + self.logger_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(module)s.%(qualname)s:%(lineno)d: %(class)s: %(message)s') # noqa: E501 self.logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' self.logger_formatter.default_msec_format = '%s.%03d' diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 72c2b84e..7ef9a9d7 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -15,7 +15,6 @@ import html import requests from time import gmtime, time, localtime, strftime, strptime import _strptime # Workaround for http://bugs.python.org/issue7980 -from calendar import timegm import webbrowser import EDMCLogging @@ -207,7 +206,7 @@ class AppWindow(object): self.help_menu.add_command(command=self.help_general) self.help_menu.add_command(command=self.help_privacy) self.help_menu.add_command(command=self.help_releases) - self.help_menu.add_command(command=lambda:self.updater.checkForUpdates()) + self.help_menu.add_command(command=lambda: self.updater.checkForUpdates()) self.help_menu.add_command(command=lambda: not self.HelpAbout.showing and self.HelpAbout(self.w)) self.menubar.add_cascade(menu=self.help_menu) @@ -528,7 +527,7 @@ class AppWindow(object): self.status['text'] = str(e) play_bad = True - if not self.status['text']: # no errors + if not self.status['text']: # no errors self.status['text'] = strftime(_('Last updated at {HH}:{MM}:{SS}').format(HH='%H', MM='%M', SS='%S'), localtime(querytime)) if play_sound and play_bad: hotkeymgr.play_bad() @@ -543,12 +542,13 @@ class AppWindow(object): if data.get('lastStarport', {}).get('ships'): report = 'Success' else: - report ='Failure' + report = 'Failure' else: report = 'Undocked!' logger.debug(f'{__class__}: Retry for shipyard - {report}') if not data['commander'].get('docked'): - pass # might have undocked while we were waiting for retry in which case station data is unreliable + # might have un-docked while we were waiting for retry in which case station data is unreliable + pass elif (data.get('lastSystem', {}).get('name') == monitor.system and data.get('lastStarport', {}).get('name') == monitor.station and data.get('lastStarport', {}).get('ships', {}).get('shipyard_list')): @@ -620,7 +620,9 @@ class AppWindow(object): logger.info(f"{__class__}: Can't start Status monitoring") # Export loadout - if entry['event'] == 'Loadout' and not monitor.state['Captain'] and config.getint('output') & config.OUT_SHIP: + if entry['event'] == 'Loadout'\ + and not monitor.state['Captain']\ + and config.getint('output') & config.OUT_SHIP: monitor.export_ship() # Plugins @@ -649,8 +651,8 @@ class AppWindow(object): self.view_menu.entryconfigure(0, state=tk.NORMAL) # Status self.file_menu.entryconfigure(0, state=tk.NORMAL) # Save Raw Data else: - self.file_menu.entryconfigure(0, state=tk.NORMAL) # Status - self.file_menu.entryconfigure(1, state=tk.NORMAL) # Save Raw Data + self.file_menu.entryconfigure(0, state=tk.NORMAL) # Status + self.file_menu.entryconfigure(1, state=tk.NORMAL) # Save Raw Data except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: @@ -805,7 +807,7 @@ class AppWindow(object): row += 1 button = ttk.Button(frame, text=_('OK'), command=self.apply) button.grid(row=row, column=2, sticky=tk.E) - button.bind("", lambda event:self.apply()) + button.bind("", lambda event: self.apply()) self.protocol("WM_DELETE_WINDOW", self._destroy) ############################################################ @@ -833,7 +835,11 @@ class AppWindow(object): initialfile = '%s%s.%s.json' % (data.get('lastSystem', {}).get('name', 'Unknown'), data['commander'].get('docked') and '.'+data.get('lastStarport', {}).get('name', 'Unknown') or '', strftime('%Y-%m-%dT%H.%M.%S', localtime()))) if f: with open(f, 'wb') as h: - h.write(json.dumps(data, ensure_ascii=False, indent=2, sort_keys=True, separators=(',', ': ')).encode('utf-8')) + h.write(json.dumps(data, + ensure_ascii=False, + indent=2, + sort_keys=True, + separators=(',', ': ')).encode('utf-8')) except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: @@ -841,7 +847,8 @@ class AppWindow(object): self.status['text'] = str(e) def onexit(self, event=None): - if platform!='darwin' or self.w.winfo_rooty()>0: # http://core.tcl.tk/tk/tktview/c84f660833546b1b84e7 + # http://core.tcl.tk/tk/tktview/c84f660833546b1b84e7 + if platform != 'darwin' or self.w.winfo_rooty() > 0: config.set('geometry', '+{1}+{2}'.format(*self.w.geometry().split('+'))) self.w.withdraw() # Following items can take a few seconds, so hide the main window while they happen protocolhandler.close() @@ -882,7 +889,7 @@ class AppWindow(object): self.theme_menubar.grid(row=0, columnspan=2, sticky=tk.NSEW) def onleave(self, event=None): - if config.getint('theme') > 1 and event.widget==self.w: + if config.getint('theme') > 1 and event.widget == self.w: self.w.attributes("-transparentcolor", 'grey4') self.theme_menubar.grid_remove() self.blank_menubar.grid(row=0, columnspan=2, sticky=tk.NSEW) @@ -931,7 +938,7 @@ def enforce_single_instance() -> None: if len(sys.argv) > 1 and sys.argv[1].startswith(protocolhandler.redirect): # Browser invoked us directly with auth response. Forward the response to the other app instance. CoInitializeEx(0, COINIT_APARTMENTTHREADED | COINIT_DISABLE_OLE1DDE) - ShowWindow(hWnd, SW_RESTORE) # Wait for it to be responsive to avoid ShellExecute recursing + ShowWindow(hWnd, SW_RESTORE) # Wait for it to be responsive to avoid ShellExecute recursing ShellExecute(0, None, sys.argv[1], None, None, SW_RESTORE) else: ShowWindowAsync(hWnd, SW_RESTORE) @@ -949,9 +956,10 @@ if __name__ == "__main__": if getattr(sys, 'frozen', False): # By default py2exe tries to write log to dirname(sys.executable) which fails when installed import tempfile - sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), '%s.log' % appname), 'wt', 1) # unbuffered not allowed for text in python3, so use line buffering + # unbuffered not allowed for text in python3, so use line buffering + sys.stdout = sys.stderr = open(join(tempfile.gettempdir(), f'{appname}.log'), 'wt', 1) - logger = EDMCLogging.logger(appname).get_logger() + logger = EDMCLogging.Logger(appname).get_logger() # Plain, not via `logger` print(f'{applongname} {appversion}') diff --git a/companion.py b/companion.py index 62d07282..d1ef0481 100644 --- a/companion.py +++ b/companion.py @@ -4,6 +4,7 @@ from builtins import object import base64 import csv import requests +from typing import TYPE_CHECKING # TODO: see https://github.com/EDCD/EDMarketConnector/issues/569 from http.cookiejar import LWPCookieJar # No longer needed but retained in case plugins use it @@ -23,7 +24,6 @@ import logging logger = logging.getLogger(appname) -from typing import TYPE_CHECKING if TYPE_CHECKING: _ = lambda x: x # noqa # to make flake8 stop complaining that the hacked in _ method doesnt exist @@ -205,21 +205,21 @@ class Auth(object): logger.error(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"", exc_info=e) else: - logger.error(f"Frontier CAPI Auth: No token for \"{self.cmdr}\"", exc_info=e) + logger.error(f"Frontier CAPI Auth: No token for \"{self.cmdr}\"") # New request - logger.info(f'Frontier CAPI Auth: New authorization request') + logger.info('Frontier CAPI Auth: New authorization request') v = random.SystemRandom().getrandbits(8 * 32) - self.verifier = self.base64URLEncode(v.to_bytes(32, byteorder='big')).encode('utf-8') + self.verifier = self.base64_url_encode(v.to_bytes(32, byteorder='big')).encode('utf-8') s = random.SystemRandom().getrandbits(8 * 32) - self.state = self.base64URLEncode(s.to_bytes(32, byteorder='big')) + self.state = self.base64_url_encode(s.to_bytes(32, byteorder='big')) # Won't work under IE: https://blogs.msdn.microsoft.com/ieinternals/2011/07/13/understanding-protocols/ webbrowser.open( '{server_auth}{url_auth}?response_type=code&audience=frontier&scope=capi&client_id={client_id}&code_challenge={challenge}&code_challenge_method=S256&state={state}&redirect_uri={redirect}'.format( # noqa: E501 # I cant make this any shorter server_auth=SERVER_AUTH, url_auth=URL_AUTH, client_id=CLIENT_ID, - challenge=self.base64URLEncode(hashlib.sha256(self.verifier).digest()), + challenge=self.base64_url_encode(hashlib.sha256(self.verifier).digest()), state=self.state, redirect=protocolhandler.redirect ) @@ -294,7 +294,7 @@ class Auth(object): def dump(self, r): logger.debug(f'Frontier CAPI Auth: {r.url} {r.status_code} {r.reason if r.reason else "None"} {r.text}') - def base64URLEncode(self, text): + def base64_url_encode(self, text): return base64.urlsafe_b64encode(text).decode().replace('=', '') @@ -379,8 +379,8 @@ class Session(object): r = self.session.get(self.server + endpoint, timeout=timeout) except Exception as e: - logger.debug(f'Attempting GET', exc_info=e) - raise ServerError('unable to get endpoint {}'.format(endpoint)) from e + logger.debug('Attempting GET', exc_info=e) + raise ServerError(f'unable to get endpoint {endpoint}') from e if r.url.startswith(SERVER_AUTH): # Redirected back to Auth server - force full re-authentication @@ -400,7 +400,7 @@ class Session(object): data = r.json() # May also fail here if token expired since response is empty except (requests.HTTPError, ValueError) as e: - logger.error(f'Frontier CAPI Auth: GET ', exc_info=e) + logger.error('Frontier CAPI Auth: GET ', exc_info=e) self.dump(r) self.close() @@ -408,7 +408,7 @@ class Session(object): self.invalidate() self.retrying = False self.login() - logger.error(f'Frontier CAPI Auth: query failed after refresh') + logger.error('Frontier CAPI Auth: query failed after refresh') raise CredentialsError('query failed after refresh') from e elif self.login(): # Maybe our token expired. Re-authorize in any case @@ -417,7 +417,7 @@ class Session(object): else: self.retrying = False - logger.error(f'Frontier CAPI Auth: HTTP error or invalid JSON') + logger.error('Frontier CAPI Auth: HTTP error or invalid JSON') raise CredentialsError('HTTP error or invalid JSON') from e self.retrying = False @@ -462,7 +462,7 @@ class Session(object): self.session.close() except Exception as e: - logger.debug(f'Frontier CAPI Auth: closing', exc_info=e) + logger.debug('Frontier CAPI Auth: closing', exc_info=e) self.session = None @@ -496,7 +496,7 @@ def fixup(data): # But also see https://github.com/Marginal/EDMarketConnector/issues/32 for thing in ('buyPrice', 'sellPrice', 'demand', 'demandBracket', 'stock', 'stockBracket'): if not isinstance(commodity.get(thing), numbers.Number): - logger.debug(f'Invalid {thing}:{commodity.get(thing)} ({type(commodity.get(thing))}) for {commodity.get("name", "")}') + logger.debug(f'Invalid {thing}:{commodity.get(thing)} ({type(commodity.get(thing))}) for {commodity.get("name", "")}') # noqa: E501 break else: diff --git a/plug.py b/plug.py index 50d9af07..a443de21 100644 --- a/plug.py +++ b/plug.py @@ -7,50 +7,49 @@ import os import importlib import sys import operator -import threading # We don't use it, but plugins might +import threading # noqa: F401 - We don't use it, but plugins might import logging import tkinter as tk import myNotebook as nb from config import config, appname -from time import time as time logger = logging.getLogger(appname) # Dashboard Flags constants -FlagsDocked = 1<<0 # on a landing pad -FlagsLanded = 1<<1 # on planet surface -FlagsLandingGearDown = 1<<2 -FlagsShieldsUp = 1<<3 -FlagsSupercruise = 1<<4 -FlagsFlightAssistOff = 1<<5 -FlagsHardpointsDeployed = 1<<6 -FlagsInWing = 1<<7 -FlagsLightsOn = 1<<8 -FlagsCargoScoopDeployed = 1<<9 -FlagsSilentRunning = 1<<10 -FlagsScoopingFuel = 1<<11 -FlagsSrvHandbrake = 1<<12 -FlagsSrvTurret = 1<<13 # using turret view -FlagsSrvUnderShip = 1<<14 # turret retracted -FlagsSrvDriveAssist = 1<<15 -FlagsFsdMassLocked = 1<<16 -FlagsFsdCharging = 1<<17 -FlagsFsdCooldown = 1<<18 -FlagsLowFuel = 1<<19 # <25% -FlagsOverHeating = 1<<20 # > 100% -FlagsHasLatLong = 1<<21 -FlagsIsInDanger = 1<<22 -FlagsBeingInterdicted = 1<<23 -FlagsInMainShip = 1<<24 -FlagsInFighter = 1<<25 -FlagsInSRV = 1<<26 -FlagsAnalysisMode = 1<<27 # Hud in Analysis mode -FlagsNightVision = 1<<28 -FlagsAverageAltitude = 1<<29 # Altitude from Average radius -FlagsFsdJump = 1<<30 -FlagsSrvHighBeam = 1<<31 +FlagsDocked = 1 << 0 # on a landing pad +FlagsLanded = 1 << 1 # on planet surface +FlagsLandingGearDown = 1 << 2 +FlagsShieldsUp = 1 << 3 +FlagsSupercruise = 1 << 4 +FlagsFlightAssistOff = 1 << 5 +FlagsHardpointsDeployed = 1 << 6 +FlagsInWing = 1 << 7 +FlagsLightsOn = 1 << 8 +FlagsCargoScoopDeployed = 1 << 9 +FlagsSilentRunning = 1 << 10 +FlagsScoopingFuel = 1 << 11 +FlagsSrvHandbrake = 1 << 12 +FlagsSrvTurret = 1 << 13 # using turret view +FlagsSrvUnderShip = 1 << 14 # turret retracted +FlagsSrvDriveAssist = 1 << 15 +FlagsFsdMassLocked = 1 << 16 +FlagsFsdCharging = 1 << 17 +FlagsFsdCooldown = 1 << 18 +FlagsLowFuel = 1 << 19 # <25% +FlagsOverHeating = 1 << 20 # > 100% +FlagsHasLatLong = 1 << 21 +FlagsIsInDanger = 1 << 22 +FlagsBeingInterdicted = 1 << 23 +FlagsInMainShip = 1 << 24 +FlagsInFighter = 1 << 25 +FlagsInSRV = 1 << 26 +FlagsAnalysisMode = 1 << 27 # Hud in Analysis mode +FlagsNightVision = 1 << 28 +FlagsAverageAltitude = 1 << 29 # Altitude from Average radius +FlagsFsdJump = 1 << 30 +FlagsSrvHighBeam = 1 << 31 # Dashboard GuiFocus constants GuiFocusNoFocus = 0 @@ -88,14 +87,16 @@ class Plugin(object): :raises Exception: Typically ImportError or OSError """ - self.name = name # Display name. - self.folder = name # basename of plugin folder. None for internal plugins. - self.module = None # None for disabled plugins. + self.name = name # Display name. + self.folder = name # basename of plugin folder. None for internal plugins. + self.module = None # None for disabled plugins. if loadfile: logger.info(f'loading plugin "{name.replace(".", "_")}" from "{loadfile}"') try: - module = importlib.machinery.SourceFileLoader('plugin_{}'.format(name.encode(encoding='ascii', errors='replace').decode('utf-8').replace('.', '_')), loadfile).load_module() + module = importlib.machinery.SourceFileLoader('plugin_{}'.format( + name.encode(encoding='ascii', errors='replace').decode('utf-8').replace('.', '_')), + loadfile).load_module() if getattr(module, 'plugin_start3', None): newname = module.plugin_start3(os.path.dirname(loadfile)) self.name = newname and str(newname) or name @@ -173,11 +174,11 @@ def load_plugins(master): if name.endswith('.py') and not name[0] in ['.', '_']: try: plugin = Plugin(name[:-3], os.path.join(config.internal_plugin_dir, name)) - plugin.folder = None # Suppress listing in Plugins prefs tab + plugin.folder = None # Suppress listing in Plugins prefs tab internal.append(plugin) except Exception as e: logger.error(f'Failure loading internal Plugin "{name}"', exc_info=e) - PLUGINS.extend(sorted(internal, key = lambda p: operator.attrgetter('name')(p).lower())) + PLUGINS.extend(sorted(internal, key=lambda p: operator.attrgetter('name')(p).lower())) # Add plugin folder to load path so packages can be loaded from plugin folder sys.path.append(config.plugin_dir) @@ -199,7 +200,7 @@ def load_plugins(master): except Exception as e: logger.error(f'Failure loading found Plugin "{name}"', exc_info=e) pass - PLUGINS.extend(sorted(found, key = lambda p: operator.attrgetter('name')(p).lower())) + PLUGINS.extend(sorted(found, key=lambda p: operator.attrgetter('name')(p).lower())) def provides(fn_name): """ diff --git a/plugins/eddn.py b/plugins/eddn.py index e2e2b141..1e979d48 100644 --- a/plugins/eddn.py +++ b/plugins/eddn.py @@ -8,7 +8,6 @@ from platform import system import re import requests import sys -import uuid import logging import tkinter as tk @@ -25,7 +24,7 @@ from companion import category_map logger = logging.getLogger(appname) -this = sys.modules[__name__] # For holding module globals +this = sys.modules[__name__] # For holding module globals # Track location to add to Journal events this.systemaddress = None @@ -61,15 +60,15 @@ class EDDN(object): try: # Try to open existing file self.replayfile = open(filename, 'r+', buffering=1) - except Exception as e: + except Exception: if exists(filename): - raise # Couldn't open existing file + raise # Couldn't open existing file else: - self.replayfile = open(filename, 'w+', buffering=1) # Create file - if sys.platform != 'win32': # open for writing is automatically exclusive on Windows - lockf(self.replayfile, LOCK_EX|LOCK_NB) + self.replayfile = open(filename, 'w+', buffering=1) # Create file + if sys.platform != 'win32': # open for writing is automatically exclusive on Windows + lockf(self.replayfile, LOCK_EX | LOCK_NB) except Exception as e: - logger.debug(f'Failed opening "replay.jsonl"', exc_info=e) + logger.debug('Failed opening "replay.jsonl"', exc_info=e) if self.replayfile: self.replayfile.close() self.replayfile = None @@ -104,18 +103,12 @@ class EDDN(object): r = self.session.post(self.UPLOAD, data=json.dumps(msg), timeout=self.TIMEOUT) if r.status_code != requests.codes.ok: - logger.debug(f''': -Status\t{r.status_code} -URL\t{r.url} -Headers\t{r.headers}' -Content:\n{r.text} -''' - ) + logger.debug(f':\nStatus\t{r.status_code}URL\t{r.url}Headers\t{r.headers}Content:\n{r.text}') r.raise_for_status() def sendreplay(self): if not self.replayfile: - return # Probably closing app + return # Probably closing app status = self.parent.children['status'] @@ -148,17 +141,18 @@ Content:\n{r.text} status['text'] = _("Error: Can't connect to EDDN") return # stop sending except Exception as e: - logger.debug(f'Failed sending', exc_info=e) + logger.debug('Failed sending', exc_info=e) status['text'] = str(e) - return # stop sending + return # stop sending self.parent.after(self.REPLAYPERIOD, self.sendreplay) def export_commodities(self, data, is_beta): commodities = [] for commodity in data['lastStarport'].get('commodities') or []: - if (category_map.get(commodity['categoryname'], True) and # Check marketable - not commodity.get('legality')): # check not prohibited + # Check 'marketable' and 'not prohibited' + if (category_map.get(commodity['categoryname'], True) + and not commodity.get('legality')): commodities.append(OrderedDict([ ('name', commodity['name'].lower()), ('meanPrice', int(commodity['meanPrice'])), @@ -446,7 +440,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): logger.debug(f'Failed in export_journal_entry', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: - logger.debug(f'Failed in export_journal_entry', exc_info=e) + logger.debug('Failed in export_journal_entry', exc_info=e) return str(e) elif (config.getint('output') & config.OUT_MKT_EDDN and not state['Captain'] and @@ -472,6 +466,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): logger.debug(f'Failed exporting {entry["event"]}', exc_info=e) return str(e) + def cmdr_data(data, is_beta): if data['commander'].get('docked') and config.getint('output') & config.OUT_MKT_EDDN: try: @@ -492,9 +487,9 @@ def cmdr_data(data, is_beta): status.update_idletasks() except requests.RequestException as e: - logger.debug(f'Failed exporting data', exc_info=e) + logger.debug('Failed exporting data', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: - logger.debug(f'Failed exporting data', exc_info=e) + logger.debug('Failed exporting data', exc_info=e) return str(e) diff --git a/plugins/edsm.py b/plugins/edsm.py index eb0ab84f..3e59404d 100644 --- a/plugins/edsm.py +++ b/plugins/edsm.py @@ -15,7 +15,9 @@ import json import requests import sys import time -import urllib.request, urllib.error, urllib.parse +import urllib.request +import urllib.error +import urllib.parse from queue import Queue from threading import Thread import logging @@ -357,7 +359,10 @@ def worker(): r.raise_for_status() reply = r.json() (msgnum, msg) = reply['msgnum'], reply['msg'] - # 1xx = OK, 2xx = fatal error, 3&4xx not generated at top-level, 5xx = error but events saved for later processing + # 1xx = OK + # 2xx = fatal error + # 3&4xx not generated at top-level + # 5xx = error but events saved for later processing if msgnum // 100 == 2: logger.warning(f'EDSM\t{msgnum} {msg}\t{json.dumps(pending, separators = (",", ": "))}') plug.show_error(_('Error: EDSM {MSG}').format(MSG=msg)) @@ -366,9 +371,11 @@ def worker(): if not closing and e['event'] in ['StartUp', 'Location', 'FSDJump', 'CarrierJump']: # Update main window's system status this.lastlookup = r - this.system_link.event_generate('<>', when="tail") # calls update_status in main thread + # calls update_status in main thread + this.system_link.event_generate('<>', when="tail") elif r['msgnum'] // 100 != 1: - logger.warning(f'EDSM\t{r["msgnum"]} {r["msg"]}\t{json.dumps(e, separators = (",", ": "))}') + logger.warning(f'EDSM\t{r["msgnum"]} {r["msg"]}\t' + f'{json.dumps(e, separators = (",", ": "))}') pending = [] break diff --git a/plugins/inara.py b/plugins/inara.py index abf221f4..a0f33191 100644 --- a/plugins/inara.py +++ b/plugins/inara.py @@ -456,7 +456,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): call() except Exception as e: - logger.debug(f'Adding events', exc_info=e) + logger.debug('Adding events', exc_info=e) return str(e) # @@ -895,11 +895,11 @@ def worker(): status = reply['header']['eventStatus'] if callback: callback(reply) - elif status // 100 != 2: # 2xx == OK (maybe with warnings) + elif status // 100 != 2: # 2xx == OK (maybe with warnings) # Log fatal errors - log.warning(f'Inara\t{status} {reply["header"].get("eventStatusText", "")}') - log.debug(f'JSON data:\n{json.dumps(data, indent=2, separators = (",", ": "))}') - plug.show_error(_('Error: Inara {MSG}').format(MSG = reply['header'].get('eventStatusText', status))) + logger.warning(f'Inara\t{status} {reply["header"].get("eventStatusText", "")}') + logger.debug(f'JSON data:\n{json.dumps(data, indent=2, separators = (",", ": "))}') + plug.show_error(_('Error: Inara {MSG}').format(MSG=reply['header'].get('eventStatusText', status))) else: # Log individual errors and warnings for data_event, reply_event in zip(data['events'], reply['events']): @@ -907,17 +907,20 @@ def worker(): logger.warning(f'Inara\t{status} {reply_event.get("eventStatusText", "")}') logger.debug(f'JSON data:\n{json.dumps(data_event)}') if reply_event['eventStatus'] // 100 != 2: - plug.show_error(_('Error: Inara {MSG}').format(MSG = '%s, %s' % (data_event['eventName'], reply_event.get('eventStatusText', reply_event['eventStatus'])))) + plug.show_error(_('Error: Inara {MSG}').format( + MSG=f'{data_event["eventName"]},' + f'{reply_event.get("eventStatusText", reply_event["eventStatus"])}')) if data_event['eventName'] in ['addCommanderTravelCarrierJump', 'addCommanderTravelDock', 'addCommanderTravelFSDJump', 'setCommanderTravelLocation']: this.lastlocation = reply_event.get('eventData', {}) this.system_link.event_generate('<>', when="tail") # calls update_location in main thread elif data_event['eventName'] in ['addCommanderShip', 'setCommanderShip']: this.lastship = reply_event.get('eventData', {}) - this.system_link.event_generate('<>', when="tail") # calls update_ship in main thread + # calls update_ship in main thread + this.system_link.event_generate('<>', when="tail") break except Exception as e: - logger.debug(f'Sending events', exc_info=e) + logger.debug('Sending events', exc_info=e) retrying += 1 else: if callback: From cbba1ce28ae046ebed3493559a7e45df0349aee7 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 09:44:12 +0100 Subject: [PATCH 30/35] Change time string in translations. It makes the code far too complicated to sub {HH} -> %H and the like. --- L10n/cs.strings | 2 +- L10n/de.strings | 2 +- L10n/en.template | 4 ++-- L10n/es.strings | 2 +- L10n/fi.strings | 2 +- L10n/fr.strings | 2 +- L10n/hu.strings | 2 +- L10n/it.strings | 2 +- L10n/ja.strings | 2 +- L10n/lv.strings | 2 +- L10n/nl.strings | 2 +- L10n/pl.strings | 2 +- L10n/pt-BR.strings | 2 +- L10n/pt-PT.strings | 2 +- L10n/ru.strings | 2 +- L10n/sl.strings | 2 +- L10n/sr-Latn-BA.strings | 2 +- L10n/sr-Latn.strings | 2 +- L10n/sv-SE.strings | 2 +- L10n/uk.strings | 2 +- L10n/zh-Hans.strings | 2 +- 21 files changed, 22 insertions(+), 22 deletions(-) diff --git a/L10n/cs.strings b/L10n/cs.strings index 48c58606..08a59767 100644 --- a/L10n/cs.strings +++ b/L10n/cs.strings @@ -236,7 +236,7 @@ "Language" = "Jazyk"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Poslední aktualizace {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Poslední aktualizace %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/de.strings b/L10n/de.strings index 9e50095f..301916f5 100644 --- a/L10n/de.strings +++ b/L10n/de.strings @@ -236,7 +236,7 @@ "Language" = "Sprache"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Zuletzt aktualisiert um {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Zuletzt aktualisiert um %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Kapitänleutnant"; diff --git a/L10n/en.template b/L10n/en.template index 132df0d5..97e0d8b9 100644 --- a/L10n/en.template +++ b/L10n/en.template @@ -235,8 +235,8 @@ /* Appearance setting prompt. [prefs.py] */ "Language" = "Language"; -/* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Last updated at {HH}:{MM}:{SS}"; +/* [EDMarketConnector.py] - Leave '%H:%M:%S' as-is */ +"Last updated at %H:%M:%S" = "Last updated at %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/es.strings b/L10n/es.strings index 5d4d819a..e1675de9 100644 --- a/L10n/es.strings +++ b/L10n/es.strings @@ -236,7 +236,7 @@ "Language" = "Idioma"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Última actualización: {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Última actualización: %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Teniente de navío"; diff --git a/L10n/fi.strings b/L10n/fi.strings index 7c00b1b1..dd7cbaeb 100644 --- a/L10n/fi.strings +++ b/L10n/fi.strings @@ -236,7 +236,7 @@ "Language" = "Kieli"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Päivitetty viimeksi {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Päivitetty viimeksi %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/fr.strings b/L10n/fr.strings index 97550996..081d83cd 100644 --- a/L10n/fr.strings +++ b/L10n/fr.strings @@ -236,7 +236,7 @@ "Language" = "Langue"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Dernière mise à jour à {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Dernière mise à jour à %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/hu.strings b/L10n/hu.strings index daa68919..71da38f1 100644 --- a/L10n/hu.strings +++ b/L10n/hu.strings @@ -233,7 +233,7 @@ "Language" = "Nyelv"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Utoljára frissítve {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Utoljára frissítve %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Hadnagy"; diff --git a/L10n/it.strings b/L10n/it.strings index 8ec9f094..aa21a2ba 100644 --- a/L10n/it.strings +++ b/L10n/it.strings @@ -236,7 +236,7 @@ "Language" = "Lingua"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Ultimo aggiornamento alle {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Ultimo aggiornamento alle %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/ja.strings b/L10n/ja.strings index 1810a0a7..f38bc39b 100644 --- a/L10n/ja.strings +++ b/L10n/ja.strings @@ -236,7 +236,7 @@ "Language" = "言語"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "最終更新時間 {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "最終更新時間 %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/lv.strings b/L10n/lv.strings index 3113fbbb..b60a470b 100644 --- a/L10n/lv.strings +++ b/L10n/lv.strings @@ -218,7 +218,7 @@ "Language" = "Valoda"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Pēdējo reizi atjaunināts {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Pēdējo reizi atjaunināts %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Leitnants"; diff --git a/L10n/nl.strings b/L10n/nl.strings index a3ee89e7..14a1baa1 100644 --- a/L10n/nl.strings +++ b/L10n/nl.strings @@ -236,7 +236,7 @@ "Language" = "Taal"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Voor het laatst bijgewerkt om {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Voor het laatst bijgewerkt om %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/pl.strings b/L10n/pl.strings index e2d26f8e..4fd57b59 100644 --- a/L10n/pl.strings +++ b/L10n/pl.strings @@ -236,7 +236,7 @@ "Language" = "Język"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Ostatnia aktualizacja {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Ostatnia aktualizacja %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/pt-BR.strings b/L10n/pt-BR.strings index bb0c339f..1700da85 100644 --- a/L10n/pt-BR.strings +++ b/L10n/pt-BR.strings @@ -236,7 +236,7 @@ "Language" = "Idioma"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Última atualização {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Última atualização %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Tenente"; diff --git a/L10n/pt-PT.strings b/L10n/pt-PT.strings index 249b6e29..50a86c34 100644 --- a/L10n/pt-PT.strings +++ b/L10n/pt-PT.strings @@ -236,7 +236,7 @@ "Language" = "Linguagem"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Última actualização: {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Última actualização: %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Tenente"; diff --git a/L10n/ru.strings b/L10n/ru.strings index e7f012b8..55ffd08f 100644 --- a/L10n/ru.strings +++ b/L10n/ru.strings @@ -236,7 +236,7 @@ "Language" = "Язык"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Последнее обновление в {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Последнее обновление в %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Лейтенант"; diff --git a/L10n/sl.strings b/L10n/sl.strings index fe2f7435..e01dd1fa 100644 --- a/L10n/sl.strings +++ b/L10n/sl.strings @@ -185,7 +185,7 @@ "Language" = "Jezik"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Zadnja osvežitev podatkov {HH}:{MM}:{SS} "; +"Last updated at %H:%M:%S" = "Zadnja osvežitev podatkov %H:%M:%S "; /* Federation rank. [stats.py] */ "Lieutenant" = "LIeutenant"; diff --git a/L10n/sr-Latn-BA.strings b/L10n/sr-Latn-BA.strings index 3a1dbdc2..cf72a459 100644 --- a/L10n/sr-Latn-BA.strings +++ b/L10n/sr-Latn-BA.strings @@ -236,7 +236,7 @@ "Language" = "Jezik"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Posljednji put osvježeno {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Posljednji put osvježeno %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/sr-Latn.strings b/L10n/sr-Latn.strings index 1245451b..ddeb2648 100644 --- a/L10n/sr-Latn.strings +++ b/L10n/sr-Latn.strings @@ -236,7 +236,7 @@ "Language" = "Jezik"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Poslednji put osveženo {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Poslednji put osveženo %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/sv-SE.strings b/L10n/sv-SE.strings index d707eedd..ee630ea0 100644 --- a/L10n/sv-SE.strings +++ b/L10n/sv-SE.strings @@ -236,7 +236,7 @@ "Language" = "Språk"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Senaste uppdatering: {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Senaste uppdatering: %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; diff --git a/L10n/uk.strings b/L10n/uk.strings index 09b80c27..756e8484 100644 --- a/L10n/uk.strings +++ b/L10n/uk.strings @@ -236,7 +236,7 @@ "Language" = "Мова"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "Останнє оновлення було {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "Останнє оновлення було %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Лейтенант"; diff --git a/L10n/zh-Hans.strings b/L10n/zh-Hans.strings index 2ddbeee6..a304460c 100644 --- a/L10n/zh-Hans.strings +++ b/L10n/zh-Hans.strings @@ -233,7 +233,7 @@ "Language" = "语言"; /* [EDMarketConnector.py] */ -"Last updated at {HH}:{MM}:{SS}" = "最后更新于 {HH}:{MM}:{SS}"; +"Last updated at %H:%M:%S" = "最后更新于 %H:%M:%S"; /* Federation rank. [stats.py] */ "Lieutenant" = "Lieutenant"; From d7c23724171a5ac3dd798e4f724afab0cb857d8b Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 10:14:16 +0100 Subject: [PATCH 31/35] Flake8 cleanup round #2 --- EDMCLogging.py | 1 + EDMarketConnector.py | 59 +++++++++++++++++++++++++++----------------- companion.py | 2 +- plug.py | 3 ++- plugins/eddn.py | 9 ++++--- plugins/edsm.py | 5 ++-- plugins/inara.py | 8 ++++-- 7 files changed, 54 insertions(+), 33 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index aa0a14fe..69e8389b 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -9,6 +9,7 @@ import sys import logging from typing import Tuple + class Logger: """ Wrapper class for all logging configuration and code. diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 7ef9a9d7..1ea0967e 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -12,9 +12,7 @@ from os import chdir, environ from os.path import dirname, expanduser, isdir, join import re import html -import requests -from time import gmtime, time, localtime, strftime, strptime -import _strptime # Workaround for http://bugs.python.org/issue7980 +from time import time, localtime, strftime import webbrowser import EDMCLogging @@ -212,7 +210,7 @@ class AppWindow(object): self.menubar.add_cascade(menu=self.help_menu) if platform == 'win32': # Must be added after at least one "real" menu entry - self.always_ontop = tk.BooleanVar(value = config.getint('always_ontop')) + self.always_ontop = tk.BooleanVar(value=config.getint('always_ontop')) self.system_menu = tk.Menu(self.menubar, name='system', tearoff=tk.FALSE) self.system_menu.add_separator() self.system_menu.add_checkbutton(label=_('Always on top'), variable = self.always_ontop, command=self.ontop_changed) # Appearance setting @@ -528,7 +526,7 @@ class AppWindow(object): play_bad = True if not self.status['text']: # no errors - self.status['text'] = strftime(_('Last updated at {HH}:{MM}:{SS}').format(HH='%H', MM='%M', SS='%S'), localtime(querytime)) + self.status['text'] = strftime(_('Last updated at %H:%M:%S'), localtime(querytime)) if play_sound and play_bad: hotkeymgr.play_bad() @@ -553,7 +551,7 @@ class AppWindow(object): data.get('lastStarport', {}).get('name') == monitor.station and data.get('lastStarport', {}).get('ships', {}).get('shipyard_list')): self.eddn.export_shipyard(data, monitor.is_beta) - elif tries > 1: # bogus data - retry + elif tries > 1: # bogus data - retry self.w.after(int(SERVER_RETRY * 1000), lambda:self.retry_for_shipyard(tries-1)) except: pass @@ -626,7 +624,12 @@ class AppWindow(object): monitor.export_ship() # Plugins - err = plug.notify_journal_entry(monitor.cmdr, monitor.is_beta, monitor.system, monitor.station, entry, monitor.state) + err = plug.notify_journal_entry(monitor.cmdr, + monitor.is_beta, + monitor.system, + monitor.station, + entry, + monitor.state) if err: self.status['text'] = err if not config.getint('hotkey_mute'): @@ -646,10 +649,11 @@ class AppWindow(object): def auth(self, event=None): try: companion.session.auth_callback() - self.status['text'] = _('Authentication successful') # Successfully authenticated with the Frontier website + # Successfully authenticated with the Frontier website + self.status['text'] = _('Authentication successful') if platform == 'darwin': - self.view_menu.entryconfigure(0, state=tk.NORMAL) # Status - self.file_menu.entryconfigure(0, state=tk.NORMAL) # Save Raw Data + self.view_menu.entryconfigure(0, state=tk.NORMAL) # Status + self.file_menu.entryconfigure(0, state=tk.NORMAL) # Save Raw Data else: self.file_menu.entryconfigure(0, state=tk.NORMAL) # Status self.file_menu.entryconfigure(1, state=tk.NORMAL) # Save Raw Data @@ -828,11 +832,19 @@ class AppWindow(object): try: data = companion.session.station() self.status['text'] = '' - f = tkinter.filedialog.asksaveasfilename(parent = self.w, - defaultextension = platform=='darwin' and '.json' or '', - filetypes = [('JSON', '.json'), ('All Files', '*')], - initialdir = config.get('outdir'), - initialfile = '%s%s.%s.json' % (data.get('lastSystem', {}).get('name', 'Unknown'), data['commander'].get('docked') and '.'+data.get('lastStarport', {}).get('name', 'Unknown') or '', strftime('%Y-%m-%dT%H.%M.%S', localtime()))) + default_extension: str = '' + if platform == 'darwin': + default_extension = '.json' + last_system: str = data.get("lastSystem", {}).get("name", "Unknown") + last_starport: str = '' + if data['commander'].get('docked'): + last_starport = '.'+data.get('lastStarport', {}).get('name', 'Unknown') + timestamp: str = strftime('%Y-%m-%dT%H.%M.%S', localtime()) + f = tkinter.filedialog.asksaveasfilename(parent=self.w, + defaultextension=default_extension, + filetypes=[('JSON', '.json'), ('All Files', '*')], + initialdir=config.get('outdir'), + initialfile=f'{last_system}{last_starport}.{timestamp}') if f: with open(f, 'wb') as h: h.write(json.dumps(data, @@ -872,10 +884,10 @@ class AppWindow(object): self.drag_offset = None def oniconify(self, event=None): - self.w.overrideredirect(0) # Can't iconize while overrideredirect + self.w.overrideredirect(0) # Can't iconize while overrideredirect self.w.iconify() - self.w.update_idletasks() # Size and windows styles get recalculated here - self.w.wait_visibility() # Need main window to be re-created before returning + self.w.update_idletasks() # Size and windows styles get recalculated here + self.w.wait_visibility() # Need main window to be re-created before returning theme.active = None # So theme will be re-applied on map def onmap(self, event=None): @@ -923,9 +935,9 @@ def enforce_single_instance() -> None: def WindowTitle(h): if h: - l = GetWindowTextLength(h) + 1 - buf = ctypes.create_unicode_buffer(l) - if GetWindowText(h, buf, l): + text_length = GetWindowTextLength(h) + 1 + buf = ctypes.create_unicode_buffer(text_length) + if GetWindowText(h, buf, text_length): return buf.value return None @@ -933,7 +945,10 @@ def enforce_single_instance() -> None: def enumwindowsproc(hWnd, lParam): # class name limited to 256 - https://msdn.microsoft.com/en-us/library/windows/desktop/ms633576 cls = ctypes.create_unicode_buffer(257) - if GetClassName(hWnd, cls, 257) and cls.value == 'TkTopLevel' and WindowTitle(hWnd) == applongname and GetProcessHandleFromHwnd(hWnd): + if GetClassName(hWnd, cls, 257)\ + and cls.value == 'TkTopLevel'\ + and WindowTitle(hWnd) == applongname\ + and GetProcessHandleFromHwnd(hWnd): # If GetProcessHandleFromHwnd succeeds then the app is already running as this user if len(sys.argv) > 1 and sys.argv[1].startswith(protocolhandler.redirect): # Browser invoked us directly with auth response. Forward the response to the other app instance. diff --git a/companion.py b/companion.py index d1ef0481..10c6ecaf 100644 --- a/companion.py +++ b/companion.py @@ -7,7 +7,7 @@ import requests from typing import TYPE_CHECKING # TODO: see https://github.com/EDCD/EDMarketConnector/issues/569 -from http.cookiejar import LWPCookieJar # No longer needed but retained in case plugins use it +from http.cookiejar import LWPCookieJar # noqa: F401 - No longer needed but retained in case plugins use it from email.utils import parsedate import hashlib import numbers diff --git a/plug.py b/plug.py index a443de21..13f187d4 100644 --- a/plug.py +++ b/plug.py @@ -11,7 +11,7 @@ import threading # noqa: F401 - We don't use it, but plugins might import logging import tkinter as tk -import myNotebook as nb +import myNotebook as nb # noqa: N813 from config import config, appname @@ -202,6 +202,7 @@ def load_plugins(master): pass PLUGINS.extend(sorted(found, key=lambda p: operator.attrgetter('name')(p).lower())) + def provides(fn_name): """ Find plugins that provide a function diff --git a/plugins/eddn.py b/plugins/eddn.py index 1e979d48..b65ac034 100644 --- a/plugins/eddn.py +++ b/plugins/eddn.py @@ -126,7 +126,8 @@ class EDDN(object): except json.JSONDecodeError as e: # Couldn't decode - shouldn't happen! logger.debug(f'\n{self.replaylog[0]}\n', exc_info=e) - self.replaylog.pop(0) # Discard and continue + # Discard and continue + self.replaylog.pop(0) else: # Rewrite old schema name if msg['$schemaRef'].startswith('http://schemas.elite-markets.net/eddn/'): @@ -137,9 +138,9 @@ class EDDN(object): if not len(self.replaylog) % self.REPLAYFLUSH: self.flush() except requests.exceptions.RequestException as e: - logger.debug(f'Failed sending', exc_info=e) + logger.debug('Failed sending', exc_info=e) status['text'] = _("Error: Can't connect to EDDN") - return # stop sending + return # stop sending except Exception as e: logger.debug('Failed sending', exc_info=e) status['text'] = str(e) @@ -437,7 +438,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state): try: this.eddn.export_journal_entry(cmdr, is_beta, filter_localised(entry)) except requests.exceptions.RequestException as e: - logger.debug(f'Failed in export_journal_entry', exc_info=e) + logger.debug('Failed in export_journal_entry', exc_info=e) return _("Error: Can't connect to EDDN") except Exception as e: logger.debug('Failed in export_journal_entry', exc_info=e) diff --git a/plugins/edsm.py b/plugins/edsm.py index 3e59404d..790f9289 100644 --- a/plugins/edsm.py +++ b/plugins/edsm.py @@ -14,7 +14,6 @@ import json import requests import sys -import time import urllib.request import urllib.error import urllib.parse @@ -24,7 +23,7 @@ import logging import tkinter as tk from ttkHyperlinkLabel import HyperlinkLabel -import myNotebook as nb +import myNotebook as nb # noqa: N813 from config import appname, applongname, appversion, config import plug @@ -380,7 +379,7 @@ def worker(): break except Exception as e: - logger.debug(f'Sending API events', exc_info=e) + logger.debug('Sending API events', exc_info=e) retrying += 1 else: plug.show_error(_("Error: Can't connect to EDSM")) diff --git a/plugins/inara.py b/plugins/inara.py index a0f33191..bfff9e5d 100644 --- a/plugins/inara.py +++ b/plugins/inara.py @@ -910,9 +910,13 @@ def worker(): plug.show_error(_('Error: Inara {MSG}').format( MSG=f'{data_event["eventName"]},' f'{reply_event.get("eventStatusText", reply_event["eventStatus"])}')) - if data_event['eventName'] in ['addCommanderTravelCarrierJump', 'addCommanderTravelDock', 'addCommanderTravelFSDJump', 'setCommanderTravelLocation']: + if data_event['eventName'] in ('addCommanderTravelCarrierJump', + 'addCommanderTravelDock', + 'addCommanderTravelFSDJump', + 'setCommanderTravelLocation'): this.lastlocation = reply_event.get('eventData', {}) - this.system_link.event_generate('<>', when="tail") # calls update_location in main thread + # calls update_location in main thread + this.system_link.event_generate('<>', when="tail") elif data_event['eventName'] in ['addCommanderShip', 'setCommanderShip']: this.lastship = reply_event.get('eventData', {}) # calls update_ship in main thread From 6c9139e395b48f30155810dd3ede31a0e497e12a Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 10:35:08 +0100 Subject: [PATCH 32/35] TODO: unittest hint about testing logging And comment out the use of it here. --- EDMarketConnector.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 1ea0967e..d6e9e579 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -979,12 +979,13 @@ if __name__ == "__main__": # Plain, not via `logger` print(f'{applongname} {appversion}') + # TODO: unittest in place of this class A(object): class B(object): def __init__(self): logger.debug('A call from A.B.__init__') - abinit = A.B() + #abinit = A.B() Translations.install(config.get('language') or None) # Can generate errors so wait til log set up From 6429cae9328193f02174625031c9dd8dd4c7b707 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 10:37:36 +0100 Subject: [PATCH 33/35] Use isinstance() for type checking --- EDMCLogging.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 69e8389b..acae327d 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -104,7 +104,7 @@ class EDMCContextFilter(logging.Filter): # of the frames internal to logging. frame = sys._getframe(0) while frame: - if type(frame.f_locals.get('self')) == logging.Logger: + if isinstance(frame.f_locals.get('self'), logging.Logger): frame = frame.f_back # Want to start on the next frame below break frame = frame.f_back @@ -113,7 +113,7 @@ class EDMCContextFilter(logging.Filter): # that is *not* true, as it should be the call site of the logger # call while frame: - if type(frame.f_locals.get('self')) != logging.Logger: + if not isinstance(frame.f_locals.get('self'), logging.Logger): break # We've found the frame we want frame = frame.f_back From 19e750edddb4815496681e6a0bc722d220d15db1 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 10:47:57 +0100 Subject: [PATCH 34/35] Use logger.exception() not log.error(.., exc_info=..) --- EDMarketConnector.py | 2 +- companion.py | 6 +++--- plug.py | 22 +++++++++++----------- 3 files changed, 15 insertions(+), 15 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index d6e9e579..2c11c0ef 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -407,7 +407,7 @@ class AppWindow(object): except (companion.CredentialsError, companion.ServerError, companion.ServerLagging) as e: self.status['text'] = str(e) except Exception as e: - logger.debug(f'{__class__}', exc_info=e) + logger.debug(f'Frontier CAPI Auth', exc_info=e) self.status['text'] = str(e) self.cooldown() diff --git a/companion.py b/companion.py index 10c6ecaf..3bb23fa1 100644 --- a/companion.py +++ b/companion.py @@ -202,7 +202,7 @@ class Auth(object): self.dump(r) except Exception as e: - logger.error(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"", exc_info=e) + logger.exception(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"") else: logger.error(f"Frontier CAPI Auth: No token for \"{self.cmdr}\"") @@ -269,7 +269,7 @@ class Auth(object): return data.get('access_token') except Exception as e: - logger.error(f"Frontier CAPI Auth: Can't get token for \"{self.cmdr}\"", exc_info=e) + logger.exception(f"Frontier CAPI Auth: Can't get token for \"{self.cmdr}\"") if r: self.dump(r) @@ -400,7 +400,7 @@ class Session(object): data = r.json() # May also fail here if token expired since response is empty except (requests.HTTPError, ValueError) as e: - logger.error('Frontier CAPI Auth: GET ', exc_info=e) + logger.exception('Frontier CAPI Auth: GET ') self.dump(r) self.close() diff --git a/plug.py b/plug.py index 13f187d4..f836d7cd 100644 --- a/plug.py +++ b/plug.py @@ -107,7 +107,7 @@ class Plugin(object): else: logger.error(f'plugin {name} has no plugin_start3() function') except Exception as e: - logger.error(f': Failed for Plugin "{name}"', exc_info=e) + logger.exception(f': Failed for Plugin "{name}"') raise else: logger.info(f'plugin {name} disabled') @@ -139,7 +139,7 @@ class Plugin(object): raise AssertionError return appitem except Exception as e: - logger.error(f'Failed for Plugin "{self.name}"', exc_info=e) + logger.exception(f'Failed for Plugin "{self.name}"') return None def get_prefs(self, parent, cmdr, is_beta): @@ -159,7 +159,7 @@ class Plugin(object): raise AssertionError return frame except Exception as e: - logger.error(f'Failed for Plugin "{self.name}"', exc_info=e) + logger.exception(f'Failed for Plugin "{self.name}"') return None @@ -177,7 +177,7 @@ def load_plugins(master): plugin.folder = None # Suppress listing in Plugins prefs tab internal.append(plugin) except Exception as e: - logger.error(f'Failure loading internal Plugin "{name}"', exc_info=e) + logger.exception(f'Failure loading internal Plugin "{name}"') PLUGINS.extend(sorted(internal, key=lambda p: operator.attrgetter('name')(p).lower())) # Add plugin folder to load path so packages can be loaded from plugin folder @@ -198,7 +198,7 @@ def load_plugins(master): sys.path.append(os.path.join(config.plugin_dir, name)) found.append(Plugin(name, os.path.join(config.plugin_dir, name, 'load.py'))) except Exception as e: - logger.error(f'Failure loading found Plugin "{name}"', exc_info=e) + logger.exception(f'Failure loading found Plugin "{name}"') pass PLUGINS.extend(sorted(found, key=lambda p: operator.attrgetter('name')(p).lower())) @@ -245,7 +245,7 @@ def notify_stop(): newerror = plugin_stop() error = error or newerror except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') return error @@ -262,7 +262,7 @@ def notify_prefs_cmdr_changed(cmdr, is_beta): try: prefs_cmdr_changed(cmdr, is_beta) except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') def notify_prefs_changed(cmdr, is_beta): @@ -280,7 +280,7 @@ def notify_prefs_changed(cmdr, is_beta): try: prefs_changed(cmdr, is_beta) except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') def notify_journal_entry(cmdr, is_beta, system, station, entry, state): @@ -303,7 +303,7 @@ def notify_journal_entry(cmdr, is_beta, system, station, entry, state): newerror = journal_entry(cmdr, is_beta, system, station, dict(entry), dict(state)) error = error or newerror except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') return error @@ -324,7 +324,7 @@ def notify_dashboard_entry(cmdr, is_beta, entry): newerror = status(cmdr, is_beta, dict(entry)) error = error or newerror except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') return error @@ -343,7 +343,7 @@ def notify_newdata(data, is_beta): newerror = cmdr_data(data, is_beta) error = error or newerror except Exception as e: - logger.error(f'Plugin "{plugin.name}" failed', exc_info=e) + logger.exception(f'Plugin "{plugin.name}" failed') return error From 63f3859af443a61b4208c3c267e3892bc98e2b18 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Mon, 27 Jul 2020 10:56:57 +0100 Subject: [PATCH 35/35] Remove extraneous __class__ in logging strings --- EDMarketConnector.py | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 2c11c0ef..bbf2dfa0 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -520,8 +520,8 @@ class AppWindow(object): companion.session.invalidate() self.login() - except Exception as e: # Including CredentialsError, ServerError - logger.debug(f'{__class__}', exc_info=e) + except Exception as e: # Including CredentialsError, ServerError + logger.debug('"other" exception', exc_info=e) self.status['text'] = str(e) play_bad = True @@ -543,7 +543,7 @@ class AppWindow(object): report = 'Failure' else: report = 'Undocked!' - logger.debug(f'{__class__}: Retry for shipyard - {report}') + logger.debug(f'Retry for shipyard - {report}') if not data['commander'].get('docked'): # might have un-docked while we were waiting for retry in which case station data is unreliable pass @@ -612,10 +612,10 @@ class AppWindow(object): # Disable WinSparkle automatic update checks, IFF configured to do so when in-game if config.getint('disable_autoappupdatecheckingame') and 1: self.updater.setAutomaticUpdatesCheck(False) - logger.info(f'{__class__}: Monitor: Disable WinSparkle automatic update checks') + logger.info('Monitor: Disable WinSparkle automatic update checks') # Can start dashboard monitoring if not dashboard.start(self.w, monitor.started): - logger.info(f"{__class__}: Can't start Status monitoring") + logger.info("Can't start Status monitoring") # Export loadout if entry['event'] == 'Loadout'\ @@ -643,7 +643,7 @@ class AppWindow(object): # Enable WinSparkle automatic update checks # NB: Do this blindly, in case option got changed whilst in-game self.updater.setAutomaticUpdatesCheck(True) - logger.info(f'{__class__}: Monitor: Enable WinSparkle automatic update checks') + logger.info('Monitor: Enable WinSparkle automatic update checks') # cAPI auth def auth(self, event=None): @@ -660,7 +660,7 @@ class AppWindow(object): except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: - logger.debug(f'{__class__}', exc_info=e) + logger.debug('Frontier CAPI Auth:', exc_info=e) self.status['text'] = str(e) self.cooldown() @@ -815,7 +815,7 @@ class AppWindow(object): self.protocol("WM_DELETE_WINDOW", self._destroy) ############################################################ - logger.info(f'{__class__}: Current version is {appversion}') + logger.info(f'Current version is {appversion}') def apply(self): self._destroy() @@ -855,7 +855,7 @@ class AppWindow(object): except companion.ServerError as e: self.status['text'] = str(e) except Exception as e: - logger.debug(f'{__class__}', exc_info=e) + logger.debug('"other" exception', exc_info=e) self.status['text'] = str(e) def onexit(self, event=None):