Merge pull request #630 from EDCD/enhancement/563-proper-logging

Enhancement/563 proper logging

Covers only a few files for now.  But let's get this merged so we can move on.

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,43 @@ 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 a `logging.Logger` for this under the
+ `appname`, so:
+ 
+        import logging
+        from config import appname
+        logger = logging.getLogger(appname)
+        
+        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)
+
+    **DO NOT** use the following, as you might cause a circular import:
+    
+        from EDMarketConnector import logger
+    
+    We have implemented a `logging.Filter` that adds support for the following
+    in `logging.Formatter()` strings:
+    
+    1. `%(qualname)s` which gets the full `<module>.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.
+    
+    *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/).
 
 ---

EDMCLogging.py

@@ -0,0 +1,145 @@
+"""
+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
+import logging
+from typing import Tuple
+
+
+class Logger:
+    """
+    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):
+        """
+        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')  # noqa: E501
+        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 get_logger(self) -> logging.Logger:
+        """
+        :return: The logging.Logger instance.
+        """
+        return self.logger
+
+
+class EDMCContextFilter(logging.Filter):
+    """
+    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:
+
+            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:
+                 <file/module>.<classA>[.classB....].<function>
+
+        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.
+        """
+        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) -> Tuple[str, str]:
+        """
+        Figure out our caller's class name(s) and qualname
+
+        Ref: <https://gist.github.com/techtonik/2151726#gistcomment-2333747>
+
+        :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
+        # of the frames internal to logging.
+        frame = sys._getframe(0)
+        while frame:
+            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
+
+        # 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 frame:
+            if not isinstance(frame.f_locals.get('self'), logging.Logger):
+                break  # We've found the frame we want
+            frame = frame.f_back
+
+        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:
+                    fn = getattr(frame.f_locals['self'], frame.f_code.co_name)
+
+                    if fn and fn.__qualname__:
+                        caller_qualname = fn.__qualname__
+
+                # 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_names = frame_class.__qualname__
+
+        if caller_qualname == '':
+            print('ALERT!  Something went wrong with finding caller qualname for logging!')
+            caller_qualname = '<ERROR in EDMCLogging.caller_class_and_qualname() for "qualname">'
+
+        if caller_class_names == '':
+            print('ALERT!  Something went wrong with finding caller class name(s) for logging!')
+            caller_class_names = '<ERROR in EDMCLogging.caller_class_and_qualname() for "class">'
+
+        return (caller_class_names, caller_qualname)

EDMarketConnector.py

@@ -12,12 +12,10 @@ 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 calendar import timegm
+from time import time, localtime, strftime
 import webbrowser
 
+import EDMCLogging
 from config import appname, applongname, appversion, appversion_nobuild, copyright, config
 
 if getattr(sys, 'frozen', False):
@@ -206,13 +204,13 @@ 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:not self.help_about.showing and self.help_about(self.w))
+            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)
             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
@@ -409,7 +407,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'Frontier CAPI Auth', exc_info=e)
             self.status['text'] = str(e)
         self.cooldown()
 
@@ -522,13 +520,13 @@ class AppWindow(object):
             companion.session.invalidate()
             self.login()
 
-        except Exception as e:			# Including CredentialsError, ServerError
-            if __debug__: print_exc()
+        except Exception as e:  # Including CredentialsError, ServerError
+            logger.debug('"other" exception', exc_info=e)
             self.status['text'] = str(e)
             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))
+        if not self.status['text']:  # no errors
+            self.status['text'] = strftime(_('Last updated at %H:%M:%S'), localtime(querytime))
         if play_sound and play_bad:
             hotkeymgr.play_bad()
 
@@ -538,15 +536,22 @@ 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'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')):
                 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
@@ -607,17 +612,24 @@ 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('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("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
-            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'):
@@ -631,23 +643,24 @@ 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('Monitor: Enable WinSparkle automatic update checks')
 
     # cAPI auth
     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
+                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:
-            if __debug__: print_exc()
+            logger.debug('Frontier CAPI Auth:', exc_info=e)
             self.status['text'] = str(e)
         self.cooldown()
 
@@ -724,7 +737,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):
@@ -798,11 +811,11 @@ 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("<Return>", lambda event:self.apply())
+            button.bind("<Return>", lambda event: self.apply())
             self.protocol("WM_DELETE_WINDOW", self._destroy)
             ############################################################
 
-            print('Current version is {}'.format(appversion))
+            logger.info(f'Current version is {appversion}')
 
         def apply(self):
             self._destroy()
@@ -819,22 +832,35 @@ 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, 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:
-            if __debug__: print_exc()
+            logger.debug('"other" exception', exc_info=e)
             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()
@@ -858,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):
@@ -875,18 +901,17 @@ 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)
 
-# 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]
@@ -910,9 +935,9 @@ if __name__ == "__main__":
 
         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
 
@@ -920,12 +945,15 @@ if __name__ == "__main__":
         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.
                     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)
@@ -935,11 +963,29 @@ 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
-        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())))
+        # 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()
+
+    # 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()
 
     Translations.install(config.get('language') or None)	# Can generate errors so wait til log set up
 

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";

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";

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";

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";

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";

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";

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";

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";

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";

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";

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";

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";

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";

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";

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" = "Лейтенант";

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";

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";

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";

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";

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" = "Лейтенант";

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";

companion.py

@@ -4,9 +4,10 @@ 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
+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
@@ -14,14 +15,15 @@ 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:
     _ = lambda x: x # noqa # to make flake8 stop complaining that the hacked in _ method doesnt exist
 
@@ -196,29 +198,28 @@ 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.exception(f"Frontier CAPI Auth: Can't refresh token for \"{self.cmdr}\"")
 
         else:
-            print('Auth\tNo token for {}'.format(self.cmdr))
+            logger.error(f"Frontier CAPI Auth: No token for \"{self.cmdr}\"")
 
         # New request
-        print('Auth\tNew 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
             )
@@ -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), ('<unknown error>',)
             )
@@ -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.exception(f"Frontier CAPI Auth: Can't get token for \"{self.cmdr}\"")
             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), ('<unknown error>',))
         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,9 +292,9 @@ 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):
+    def base64_url_encode(self, text):
         return base64.urlsafe_b64encode(text).decode().replace('=', '')
 
 
@@ -379,10 +379,8 @@ class Session(object):
             r = self.session.get(self.server + endpoint, timeout=timeout)
 
         except Exception as e:
-            if __debug__:
-                print_exc()
-
-            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
@@ -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.exception('Frontier CAPI Auth: GET ')
             self.dump(r)
             self.close()
 
@@ -410,6 +408,7 @@ class Session(object):
                 self.invalidate()
                 self.retrying = False
                 self.login()
+                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
@@ -418,6 +417,7 @@ class Session(object):
 
             else:
                 self.retrying = False
+                logger.error('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('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", "")}')  # noqa: E501
                 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

plug.py

@@ -7,49 +7,49 @@ import os
 import importlib
 import sys
 import operator
-import threading	# We don't use it, but plugins might
-from traceback import print_exc
-
+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
-from time import time as time
+import myNotebook as nb  # noqa: N813
 
+from config import config, appname
+
+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
@@ -87,28 +87,30 @@ 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:
-            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()
+                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
                     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.exception(f': Failed for Plugin "{name}"')
                 raise
         else:
-            sys.stdout.write('plugin %s disabled\n' % name)
+            logger.info(f'plugin {name} disabled')
 
     def _get_func(self, funcname):
         """
@@ -136,8 +138,8 @@ class Plugin(object):
                 elif not isinstance(appitem, tk.Widget):
                     raise AssertionError
                 return appitem
-            except:
-                print_exc()
+            except Exception as e:
+                logger.exception(f'Failed for Plugin "{self.name}"')
         return None
 
     def get_prefs(self, parent, cmdr, is_beta):
@@ -156,8 +158,8 @@ class Plugin(object):
                 if not isinstance(frame, nb.Frame):
                     raise AssertionError
                 return frame
-            except:
-                print_exc()
+            except Exception as e:
+                logger.exception(f'Failed for Plugin "{self.name}"')
         return None
 
 
@@ -172,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:
-                pass
-    PLUGINS.extend(sorted(internal, key = lambda p: operator.attrgetter('name')(p).lower()))
+            except Exception as 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
     sys.path.append(config.plugin_dir)
@@ -195,9 +197,11 @@ 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.exception(f'Failure loading found Plugin "{name}"')
                 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):
     """
@@ -240,8 +244,8 @@ def notify_stop():
             try:
                 newerror = plugin_stop()
                 error = error or newerror
-            except:
-                print_exc()
+            except Exception as e:
+                logger.exception(f'Plugin "{plugin.name}" failed')
     return error
 
 
@@ -257,8 +261,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.exception(f'Plugin "{plugin.name}" failed')
 
 
 def notify_prefs_changed(cmdr, is_beta):
@@ -275,8 +279,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.exception(f'Plugin "{plugin.name}" failed')
 
 
 def notify_journal_entry(cmdr, is_beta, system, station, entry, state):
@@ -298,8 +302,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.exception(f'Plugin "{plugin.name}" failed')
     return error
 
 
@@ -319,8 +323,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.exception(f'Plugin "{plugin.name}" failed')
     return error
 
 
@@ -338,8 +342,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.exception(f'Plugin "{plugin.name}" failed')
     return error
 
 

plugins/eddn.py

@@ -8,7 +8,7 @@ from platform import system
 import re
 import requests
 import sys
-import uuid
+import logging
 
 import tkinter as tk
 from ttkHyperlinkLabel import HyperlinkLabel
@@ -19,14 +19,12 @@ from prefs import prefsVersion
 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 config import appname, applongname, appversion, config
 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
@@ -62,15 +60,15 @@ class EDDN(object):
             try:
                 # Try to open existing file
                 self.replayfile = open(filename, 'r+', buffering=1)
-            except:
+            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)
-        except:
-            if __debug__: print_exc()
+                    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('Failed opening "replay.jsonl"', exc_info=e)
             if self.replayfile:
                 self.replayfile.close()
             self.replayfile = None
@@ -104,16 +102,13 @@ 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':\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']
 
@@ -128,12 +123,11 @@ 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()
-            self.replaylog.pop(0)	# Discard and continue
+            logger.debug(f'\n{self.replaylog[0]}\n', exc_info=e)
+            # Discard and continue
+            self.replaylog.pop(0)
         else:
             # Rewrite old schema name
             if msg['$schemaRef'].startswith('http://schemas.elite-markets.net/eddn/'):
@@ -144,21 +138,22 @@ class EDDN(object):
                 if not len(self.replaylog) % self.REPLAYFLUSH:
                     self.flush()
             except requests.exceptions.RequestException as e:
-                if __debug__: print_exc()
+                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:
-                if __debug__: print_exc()
+                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'])),
@@ -443,10 +438,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('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('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,12 +461,13 @@ 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):
     if data['commander'].get('docked') and config.getint('output') & config.OUT_MKT_EDDN:
         try:
@@ -492,9 +488,9 @@ def cmdr_data(data, is_beta):
                 status.update_idletasks()
 
         except requests.RequestException as e:
-            if __debug__: print_exc()
+            logger.debug('Failed exporting data', exc_info=e)
             return _("Error: Can't connect to EDDN")
 
         except Exception as e:
-            if __debug__: print_exc()
+            logger.debug('Failed exporting data', exc_info=e)
             return str(e)

plugins/edsm.py

@@ -14,20 +14,21 @@
 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
 
 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
 
-if __debug__:
-    from traceback import print_exc
+logger = logging.getLogger(appname)
 
 EDSM_POLL = 0.1
 _TIMEOUT = 20
@@ -357,23 +358,28 @@ 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:
-                        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']):
                             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('<<EDSMStatus>>', when="tail")	# calls update_status in main thread
+                                # calls update_status in main thread
+                                this.system_link.event_generate('<<EDSMStatus>>', when="tail")
                             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'
+                                               f'{json.dumps(e, separators = (",", ": "))}')
                         pending = []
 
                 break
-            except:
-                if __debug__: print_exc()
+            except Exception as e:
+                logger.debug('Sending API events', exc_info=e)
                 retrying += 1
         else:
             plug.show_error(_("Error: Can't connect to EDSM"))

plugins/inara.py

@@ -10,6 +10,7 @@ import time
 from operator import itemgetter
 from queue import Queue
 from threading import Thread
+import logging
 
 import tkinter as tk
 from ttkHyperlinkLabel import HyperlinkLabel
@@ -17,9 +18,7 @@ import myNotebook as nb
 
 from config import appname, applongname, appversion, config
 import plug
-
-if __debug__:
-    from traceback import print_exc
+logger = logging.getLogger(appname)
 
 
 _TIMEOUT = 20
@@ -457,7 +456,7 @@ def journal_entry(cmdr, is_beta, system, station, entry, state):
                 call()
 
         except Exception as e:
-            if __debug__: print_exc()
+            logger.debug('Adding events', exc_info=e)
             return str(e)
 
         #
@@ -896,28 +895,36 @@ 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
-                    print('Inara\t%s %s' % (reply['header']['eventStatus'], reply['header'].get('eventStatusText', '')))
-                    print(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']):
                         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']:
+                                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('<<InaraLocation>>', when="tail")	# calls update_location in main thread
+                            # calls update_location in main thread
+                            this.system_link.event_generate('<<InaraLocation>>', when="tail")
                         elif data_event['eventName'] in ['addCommanderShip', 'setCommanderShip']:
                             this.lastship = reply_event.get('eventData', {})
-                            this.system_link.event_generate('<<InaraShip>>', when="tail")	# calls update_ship in main thread
+                            # calls update_ship in main thread
+                            this.system_link.event_generate('<<InaraShip>>', when="tail")
 
                 break
-            except:
-                if __debug__: print_exc()
+            except Exception as e:
+                logger.debug('Sending events', exc_info=e)
                 retrying += 1
         else:
             if callback: