Merge pull request #719 from EDCD/enhancement/trace-logging

Implement a TRACE level of logging

.mypy.ini

@@ -0,0 +1,4 @@
+[mypy]
+follow_imports = skip
+ignore_missing_imports = True
+scripts_are_modules = True

.pre-commit-config.yaml

@@ -0,0 +1,67 @@
+# See https://pre-commit.com for more information
+# See https://pre-commit.com/hooks.html for more hooks
+repos:
+-   repo: https://github.com/pre-commit/pre-commit-hooks
+    rev: v2.4.0
+    hooks:
+      - id: check-merge-conflict 
+      - id: debug-statements 
+      - id: end-of-file-fixer 
+      - id: mixed-line-ending
+
+        #-   repo: https://github.com/pre-commit/mirrors-autopep8
+        #    rev: ''
+        #    hooks:
+        #      - id: autopep8
+
+# flake8 --show-source <file>
+-   repo: https://gitlab.com/pycqa/flake8
+    rev: ''
+    hooks:
+      - id: flake8
+
+-   repo: https://github.com/pre-commit/pygrep-hooks
+    rev: ''
+    hooks:
+      - id: python-no-eval 
+      - id: python-no-log-warn 
+# This is a pain where a comment begins with the word 'type' otherwise
+#      - id: python-use-type-annotations 
+
+# mypy - static type checking
+# mypy --follow-imports skip <file>
+-   repo: https://github.com/pre-commit/mirrors-mypy
+    rev: ''
+    hooks:
+      - id: mypy
+        args: [ "--follow-imports", "skip", "--ignore-missing-imports", "--scripts-are-modules" ]
+
+### # pydocstyle.exe <file>
+### -   repo: https://github.com/FalconSocial/pre-commit-mirrors-pep257
+###     rev: ''
+###     hooks:
+###       - id: pep257  # docstring conventions
+###       # Alternate https://github.com/PyCQA/pydocstyle
+
+# -   repo: https://github.com/digitalpulp/pre-commit-php
+#     rev: ''
+#     hooks:
+#       -id: php-unit 
+
+# safety.exe check -r requirements.txt
+-   repo: https://github.com/Lucas-C/pre-commit-hooks-safety
+    rev: ''
+    hooks:
+      - id: python-safety-dependencies-check 
+        entry: safety
+        args: [check, --bare, -r]
+        language: system
+
+default_language_version:
+    python: python3.7
+
+default_stages: [ commit, push ]
+
+#files: '([^\.].+/)*.py'
+
+exclude: cp37-setup-new.py

EDMC.py

@@ -1,19 +1,24 @@
 #!/usr/bin/env python3
-#
+"""Command-line interface. Requires prior setup through the GUI."""
-# Command-line interface. Requires prior setup through the GUI.
-#
 
 
 import argparse
 import json
 import locale
-import logging
 import os
 import re
 import sys
 from os.path import getmtime, join
 from time import sleep, time
-from typing import Any, Optional
+from typing import TYPE_CHECKING, Any, Optional
+
+# See EDMCLogging.py docs.
+# isort: off
+from EDMCLogging import edmclogger, logger, logging
+if TYPE_CHECKING:
+    from logging import trace, TRACE  # type: ignore # noqa: F401
+# isort: on
+edmclogger.set_channels_loglevel(logging.INFO)
 
 # workaround for https://github.com/EDCD/EDMarketConnector/issues/568
 os.environ["EDMC_NO_UI"] = "1"
@@ -21,7 +26,6 @@ os.environ["EDMC_NO_UI"] = "1"
 import collate
 import commodity
 import companion
-import EDMCLogging
 import edshipyard
 import l10n
 import loadout
@@ -40,11 +44,9 @@ sys.path.append(config.internal_plugin_dir)
 import eddn  # noqa: E402
 # isort: on
 
-logger = EDMCLogging.Logger(appcmdname).get_logger()
-logger.setLevel(logging.INFO)
-
 
 def log_locale(prefix: str) -> None:
+    """Log the current state of locale settings."""
     logger.debug(f'''Locale: {prefix}
 Locale LC_COLLATE: {locale.getlocale(locale.LC_COLLATE)}
 Locale LC_CTYPE: {locale.getlocale(locale.LC_CTYPE)}
@@ -62,12 +64,30 @@ EXIT_SUCCESS, EXIT_SERVER, EXIT_CREDENTIALS, EXIT_VERIFICATION, EXIT_LAGGING, EX
 JOURNAL_RE = re.compile(r'^Journal(Beta)?\.[0-9]{12}\.[0-9]{2}\.log$')
 
 
-# quick and dirty version comparison assuming "strict" numeric only version numbers
 def versioncmp(versionstring):
+    """Quick and dirty version comparison assuming "strict" numeric only version numbers."""
     return list(map(int, versionstring.split('.')))
 
 
 def deep_get(target: dict, *args: str, default=None) -> Any:
+    """
+    Walk into a dict and return the specified deep value.
+
+    Example usage:
+
+        >>> thing = {'a': {'b': {'c': 'foo'} } }
+        >>> deep_get(thing, ('a', 'b', 'c'), None)
+        'foo'
+        >>> deep_get(thing, ('a', 'b'), None)
+        {'c': 'foo'}
+        >>> deep_get(thing, ('a', 'd'), None)
+        None
+
+    :param target: The dict to walk into for the desired value.
+    :param args: The list of keys to walk down through.
+    :param default: What to return if the target has no value.
+    :return: The value at the target deep key.
+    """
     if not hasattr(target, 'get'):
         raise ValueError(f"Cannot call get on {target} ({type(target)})")
 
@@ -83,6 +103,7 @@ def deep_get(target: dict, *args: str, default=None) -> Any:
 
 
 def main():
+    """Run the main code of the program."""
     try:
         # arg parsing
         parser = argparse.ArgumentParser(
@@ -93,7 +114,16 @@ def main():
         )
 
         parser.add_argument('-v', '--version', help='print program version and exit', action='store_const', const=True)
-        parser.add_argument('--loglevel', metavar='loglevel', help='Set the logging loglevel to one of: CRITICAL, ERROR, WARNING, INFO, DEBUG')  # noqa: E501
+        group_loglevel = parser.add_mutually_exclusive_group()
+        group_loglevel.add_argument('--loglevel',
+                                    metavar='loglevel',
+                                    help='Set the logging loglevel to one of: '
+                                         'CRITICAL, ERROR, WARNING, INFO, DEBUG, TRACE',
+                                    )
+        group_loglevel.add_argument('--trace',
+                                    help='Set the Debug logging loglevel to TRACE',
+                                    action='store_true',
+                                    )
         parser.add_argument('-a', metavar='FILE', help='write ship loadout to FILE in Companion API json format')
         parser.add_argument('-e', metavar='FILE', help='write ship loadout to FILE in E:D Shipyard plain text format')
         parser.add_argument('-l', metavar='FILE', help='write ship locations to FILE in CSV format')
@@ -117,11 +147,14 @@ def main():
 
             return
 
-        if args.loglevel:
+        if args.trace:
-            if args.loglevel not in ('CRITICAL', 'ERROR', 'WARNING', 'INFO', 'DEBUG'):
+            edmclogger.set_channels_loglevel(logging.TRACE)
-                print('loglevel must be one of: CRITICAL, ERROR, WARNING, INFO, DEBUG', file=sys.stderr)
+
+        elif args.loglevel:
+            if args.loglevel not in ('CRITICAL', 'ERROR', 'WARNING', 'INFO', 'DEBUG', 'TRACE'):
+                print('loglevel must be one of: CRITICAL, ERROR, WARNING, INFO, DEBUG, TRACE', file=sys.stderr)
                 sys.exit(EXIT_ARGS)
-            logger.setLevel(args.loglevel)
+            edmclogger.set_channels_loglevel(args.loglevel)
 
         logger.debug(f'Startup v{appversion} : Running on Python v{sys.version}')
         logger.debug(f'''Platform: {sys.platform}
@@ -250,10 +283,9 @@ sys.path: {sys.path}'''
             stats.export_status(data, args.t)
 
         if data['commander'].get('docked'):
-            print('{},{}'.format(
+            print(f'{deep_get(data, "lastSystem", "name", default="Unknown")},'
-                deep_get(data, 'lastSystem', 'name', default='Unknown'),
+                  f'{deep_get(data, "lastStarport", "name", default="Unknown")}'
-                deep_get(data, 'lastStarport', 'name', default='Unknown')
+                  )
-            ))
 
         else:
             print(deep_get(data, 'lastSystem', 'name', default='Unknown'))

EDMCLogging.py

@@ -5,6 +5,34 @@ 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.
+
+If type checking, e.g. mypy, objects to `logging.trace(...)` then include this
+stanza:
+
+    # See EDMCLogging.py docs.
+    # isort: off
+    if TYPE_CHECKING:
+        from logging import trace, TRACE  # type: ignore # noqa: F401
+    # isort: on
+
+This is needed because we add the TRACE level and the trace() function
+ourselves at runtime.
+
+To utilise logging in core code, or internal plugins, include this:
+
+    from EDMCLogging import get_main_logger
+
+    logger = get_main_logger()
+
+To utilise logging in a 'found' (third-party) plugin, include this:
+
+    import os
+    import logging
+
+    plugin_name = os.path.basename(os.path.dirname(__file__))
+    # plugin_name here *must* be the name of the folder the plugin resides in
+    # See, plug.py:load_plugins()
+    logger = logging.getLogger(f'{appname}.{plugin_name}')
 """
 
 import inspect
@@ -44,6 +72,17 @@ from config import appcmdname, appname, config
 
 _default_loglevel = logging.DEBUG
 
+# Define a TRACE level
+LEVEL_TRACE = 5
+logging.addLevelName(LEVEL_TRACE, "TRACE")
+logging.TRACE = LEVEL_TRACE  # type: ignore
+logging.Logger.trace = lambda self, message, *args, **kwargs: self._log(  # type: ignore
+    logging.TRACE,  # type: ignore
+    message,
+    args,
+    **kwargs
+)
+
 
 class Logger:
     """
@@ -66,9 +105,9 @@ class Logger:
         """
         self.logger = logging.getLogger(logger_name)
         # Configure the logging.Logger
-        # This needs to always be DEBUG in order to let DEBUG level messages
+        # This needs to always be TRACE in order to let TRACE level messages
         # through to check the *handler* levels.
-        self.logger.setLevel(logging.DEBUG)
+        self.logger.setLevel(logging.TRACE)  # type: ignore
 
         # Set up filter for adding class name
         self.logger_filter = EDMCContextFilter()
@@ -102,8 +141,8 @@ class Logger:
             encoding='utf-8',
             delay=False
         )
-        # Yes, we always want these rotated files to be at DEBUG level
+        # Yes, we always want these rotated files to be at TRACE level
-        self.logger_channel_rotating.setLevel(logging.DEBUG)
+        self.logger_channel_rotating.setLevel(logging.TRACE)  # type: ignore
         self.logger_channel_rotating.setFormatter(self.logger_formatter)
         self.logger.addHandler(self.logger_channel_rotating)
 
@@ -118,10 +157,33 @@ class Logger:
     def get_streamhandler(self) -> logging.Handler:
         """
         Obtain the self.logger_channel StreamHandler instance.
+
         :return: logging.StreamHandler
         """
         return self.logger_channel
 
+    def set_channels_loglevel(self, level: int) -> None:
+        """
+        Set the specified log level on the channels.
+
+        :param level: A valid `logging` level.
+        :return: None
+        """
+        self.logger_channel.setLevel(level)
+        self.logger_channel_rotating.setLevel(level)
+
+    def set_console_loglevel(self, level: int) -> None:
+        """
+        Set the specified log level on the console channel.
+
+        :param level: A valid `logging` level.
+        :return: None
+        """
+        if self.logger_channel.level != logging.TRACE:  # type: ignore
+            self.logger_channel.setLevel(level)
+        else:
+            logger.trace("Not changing log level because it's TRACE")  # type: ignore
+
 
 def get_plugin_logger(plugin_name: str, loglevel: int = _default_loglevel) -> logging.Logger:
     """
@@ -131,16 +193,21 @@ def get_plugin_logger(plugin_name: str, loglevel: int = _default_loglevel) -> lo
     coming from, but we don't need to set up *everything* for them.
 
     The name will be '{config.appname}.{plugin.name}', e.g.
-    'EDMarketConnector.miggytest'.  This means that any logging sent through
+    'EDMarketConnector.plugintest', or using appcmdname for EDMC CLI tool.
-    there *also* goes to the channels defined in the 'EDMarketConnector'
+      Note that `plugin_name` must be the same as the name of the folder the
-    logger, so we can let that take care of the formatting.
+    plugin resides in.
+      This means that any logging sent through there *also* goes to the channels
+    defined in the 'EDMarketConnector' (or 'EDMC') logger, so we can let that
+    take care of the formatting.
 
     If we add our own channel then the output gets duplicated (assuming same
     logLevel set).
 
     However we do need to attach our filter to this still.  That's not at
     the channel level.
-    :param name: Name of this Logger.
+
+    :param plugin_name: Name of this Logger.  **Must** be the name of the
+        folder the plugin resides in.
     :param loglevel: Optional logLevel for this Logger.
     :return: logging.Logger instance, all set up.
     """
@@ -335,7 +402,6 @@ class EDMCContextFilter(logging.Filter):
 
 def get_main_logger() -> logging.Logger:
     """Return the correct logger for how the program is being run."""
-
     if not os.getenv("EDMC_NO_UI"):
         # GUI app being run
         return logging.getLogger(appname)
@@ -348,5 +414,11 @@ def get_main_logger() -> logging.Logger:
 loglevel = config.get('loglevel')
 if not loglevel:
     loglevel = logging.INFO
-edmclogger = Logger(appname, loglevel=loglevel)
+
+if not os.getenv('EDMC_NO_UI'):
+    base_logger_name = appname
+else:
+    base_logger_name = appcmdname
+
+edmclogger = Logger(base_logger_name, loglevel=loglevel)
 logger = edmclogger.get_logger()

EDMarketConnector - TRACE.bat

@@ -0,0 +1 @@
+EDMarketConnector.exe --trace

EDMarketConnector.py

@@ -1,20 +1,29 @@
 #!/usr/bin/env python3
 # -*- coding: utf-8 -*-
 
-from builtins import str
+import argparse
-from builtins import object
+import html
-import sys
-from sys import platform
 import json
 import locale
+import re
+import sys
+import webbrowser
+from builtins import object, str
 from os import chdir, environ
 from os.path import dirname, isdir, join
-import re
+from sys import platform
-import html
+from time import localtime, strftime, time
-from time import time, localtime, strftime
+from typing import TYPE_CHECKING
-import webbrowser
 
-from config import appname, applongname, appversion, appversion_nobuild, copyright, config
+from EDMCLogging import edmclogger, logger, logging
+
+# See EDMCLogging.py docs.
+# isort: off
+if TYPE_CHECKING:
+    from logging import trace, TRACE  # type: ignore # noqa: F401
+# isort: on
+
+from config import applongname, appname, appversion, appversion_nobuild, config, copyright
 
 # TODO: Test: Make *sure* this redirect is working, else py2exe is going to cause an exit popup
 if __name__ == "__main__":
@@ -36,10 +45,11 @@ if getattr(sys, 'frozen', False):
         environ['TK_LIBRARY'] = join(dirname(sys.path[0]), 'lib', 'tk')
 
 import tkinter as tk
-from tkinter import ttk
 import tkinter.filedialog
 import tkinter.font
 import tkinter.messagebox
+from tkinter import ttk
+
 from ttkHyperlinkLabel import HyperlinkLabel
 
 if __debug__:
@@ -49,18 +59,18 @@ if __debug__:
 
         signal.signal(signal.SIGTERM, lambda sig, frame: pdb.Pdb().set_trace(frame))
 
-import companion
 import commodity
-from commodity import COMMODITY_CSV
+import companion
-import td
-import stats
-import prefs
 import plug
+import prefs
+import stats
+import td
+from commodity import COMMODITY_CSV
+from dashboard import dashboard
 from hotkey import hotkeymgr
 from l10n import Translations
 from monitor import monitor
 from protocol import protocolhandler
-from dashboard import dashboard
 from theme import theme
 
 SERVER_RETRY = 5  # retry pause for Companion servers [s]
@@ -613,17 +623,17 @@ class AppWindow(object):
         def crewroletext(role):
             # Return translated crew role. Needs to be dynamic to allow for changing language.
             return {
-                None        : '',
+                None:         '',
-                'Idle'      : '',
+                'Idle':       '',
                 'FighterCon': _('Fighter'),  # Multicrew role
-                'FireCon'   : _('Gunner'),  # Multicrew role
+                'FireCon':    _('Gunner'),  # Multicrew role
-                'FlightCon' : _('Helm'),  # Multicrew role
+                'FlightCon':  _('Helm'),  # Multicrew role
             }.get(role, role)
 
         while True:
             entry = monitor.get_entry()
             if not entry:
-                logger.debug('No entry from monitor.get_entry()')
+                logger.trace('No entry from monitor.get_entry()')
                 return
 
             # Update main window
@@ -640,8 +650,8 @@ class AppWindow(object):
                 self.ship_label['text'] = _('Ship') + ':'  # Main window
                 self.ship.configure(
                     text=monitor.state['ShipName']
-                         or companion.ship_map.get(monitor.state['ShipType'], monitor.state['ShipType'])
+                    or companion.ship_map.get(monitor.state['ShipType'], monitor.state['ShipType'])
-                         or '',
+                    or '',
                     url=self.shipyard_url)
             else:
                 self.cmdr['text'] = ''
@@ -675,7 +685,7 @@ class AppWindow(object):
                 self.login()
 
             if not entry['event'] or not monitor.mode:
-                logger.debug('Startup or in CQC, returning')
+                logger.trace('Startup or in CQC, returning')
                 return  # Startup or in CQC
 
             if entry['event'] in ['StartUp', 'LoadGame'] and monitor.started:
@@ -934,7 +944,8 @@ class AppWindow(object):
     def onexit(self, event=None):
         # 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('+')))
+            x, y = self.w.geometry().split('+')[1:3]  # e.g. '212x170+2881+1267'
+            config.set('geometry', f'+{x}+{y}')
         self.w.withdraw()  # Following items can take a few seconds, so hide the main window while they happen
         protocolhandler.close()
         hotkeymgr.unregister()
@@ -986,13 +997,13 @@ 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 HWND, LPWSTR, LPCWSTR, INT, BOOL, LPARAM
+        from ctypes.wintypes import BOOL, HWND, INT, LPARAM, LPCWSTR, LPWSTR
 
         EnumWindows = ctypes.windll.user32.EnumWindows  # noqa: N806
         GetClassName = ctypes.windll.user32.GetClassNameW  # noqa: N806
-        GetClassName.argtypes = [HWND, LPWSTR, ctypes.c_int]  # noqa: N806
+        GetClassName.argtypes = [HWND, LPWSTR, ctypes.c_int]
         GetWindowText = ctypes.windll.user32.GetWindowTextW  # noqa: N806
-        GetWindowText.argtypes = [HWND, LPWSTR, ctypes.c_int]  # noqa: N806
+        GetWindowText.argtypes = [HWND, LPWSTR, ctypes.c_int]
         GetWindowTextLength = ctypes.windll.user32.GetWindowTextLengthW  # noqa: N806
         GetProcessHandleFromHwnd = ctypes.windll.oleacc.GetProcessHandleFromHwnd  # noqa: N806
 
@@ -1059,7 +1070,27 @@ Locale LC_TIME: {locale.getlocale(locale.LC_TIME)}'''
 if __name__ == "__main__":
     enforce_single_instance()
 
-    from EDMCLogging import logger
+    # Command-line arguments
+    parser = argparse.ArgumentParser(
+        prog=appname,
+        description="Utilises Elite Dangerous Journal files and the Frontier "
+                    "Companion API (CAPI) service to gather data about a "
+                    "player's state and actions to upload to third-party sites "
+                    "such as EDSM, Inara.cz and EDDB."
+    )
+
+    parser.add_argument('--trace',
+                        help='Set the Debug logging loglevel to TRACE',
+                        action='store_true',
+                        )
+
+    args = parser.parse_args()
+
+    if args.trace:
+        logger.setLevel(logging.TRACE)
+        edmclogger.set_channels_loglevel(logging.TRACE)
+    else:
+        edmclogger.set_channels_loglevel(logging.DEBUG)
 
     logger.info(f'Startup v{appversion} : Running on Python v{sys.version}')
     logger.debug(f'''Platform: {sys.platform}
@@ -1114,7 +1145,7 @@ sys.path: {sys.path}'''
         ui_scale = 100
         config.set('ui_scale', ui_scale)
     theme.default_ui_scale = root.tk.call('tk', 'scaling')
-    logger.debug(f'Default tk scaling = {theme.default_ui_scale}')
+    logger.trace(f'Default tk scaling = {theme.default_ui_scale}')
     theme.startup_ui_scale = ui_scale
     root.tk.call('tk', 'scaling', theme.default_ui_scale * float(ui_scale) / 100.0)
     app = AppWindow(root)

companion.py

@@ -274,7 +274,7 @@ class Auth(object):
         s = random.SystemRandom().getrandbits(8 * 32)
         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/
-        logger.debug(f'Trying auth from scratch for Commander "{self.cmdr}"')
+        logger.info(f'Trying auth from scratch for Commander "{self.cmdr}"')
         challenge = self.base64_url_encode(hashlib.sha256(self.verifier).digest())
         webbrowser.open(
             f'{SERVER_AUTH}{URL_AUTH}?response_type=code&audience=frontier&scope=capi&client_id={CLIENT_ID}&code_challenge={challenge}&code_challenge_method=S256&state={self.state}&redirect_uri={protocolhandler.redirect}'  # noqa: E501 # I cant make this any shorter
@@ -399,7 +399,7 @@ class Session(object):
                 raise CredentialsError('Missing credentials')  # Shouldn't happen
 
             elif self.state == Session.STATE_OK:
-                logger.debug('already logged in')
+                logger.debug('already logged in (state == STATE_OK)')
                 return True  # already logged in
 
         else:
@@ -409,7 +409,6 @@ class Session(object):
                 return True  # already logged in
 
             else:
-                # changed account or retrying login during auth
                 logger.debug('changed account or retrying login during auth')
                 self.close()
                 self.credentials = credentials
@@ -461,7 +460,7 @@ class Session(object):
 
     def query(self, endpoint: str) -> CAPIData:
         """Perform a query against the specified CAPI endpoint."""
-        logger.debug(f'Performing query for endpoint "{endpoint}"')
+        logger.trace(f'Performing query for endpoint "{endpoint}"')
         if self.state == Session.STATE_INIT:
             if self.login():
                 return self.query(endpoint)
@@ -471,7 +470,7 @@ class Session(object):
             raise CredentialsError('cannot make a query when unauthorized')
 
         try:
-            logger.debug('Trying...')
+            logger.trace('Trying...')
             r = self.session.get(self.server + endpoint, timeout=timeout)
 
         except Exception as e:
@@ -479,7 +478,7 @@ class Session(object):
             raise ServerError(f'unable to get endpoint {endpoint}') from e
 
         if r.url.startswith(SERVER_AUTH):
-            logger.debug('Redirected back to Auth Server')
+            logger.info('Redirected back to Auth Server')
             # Redirected back to Auth server - force full re-authentication
             self.dump(r)
             self.invalidate()
@@ -521,7 +520,7 @@ class Session(object):
 
         self.retrying = False
         if 'timestamp' not in data:
-            logger.debug('timestamp not in data, adding from response headers')
+            logger.trace('timestamp not in data, adding from response headers')
             data['timestamp'] = time.strftime('%Y-%m-%dT%H:%M:%SZ', parsedate(r.headers['Date']))  # type: ignore
 
         return data

monitor.py

@@ -243,7 +243,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
             for line in loghandle:
                 try:
                     if b'"event":"Location"' in line:
-                        logger.debug('"Location" event in the past at startup')
+                        logger.trace('"Location" event in the past at startup')
 
                     self.parse_entry(line)  # Some events are of interest even in the past
 
@@ -327,7 +327,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
                 loghandle.seek(log_pos, SEEK_SET)  # reset EOF flag # TODO: log_pos reported as possibly unbound
                 for line in loghandle:
                     if b'"event":"Location"' in line:
-                        logger.debug('Found "Location" event, appending to event_queue')
+                        logger.trace('Found "Location" event, appending to event_queue')
 
                     self.event_queue.append(line)
 
@@ -340,7 +340,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
 
             # Check whether we're still supposed to be running
             if threading.current_thread() != self.thread:
-                logger.inof("We're not meant to be running, exiting...")
+                logger.info("We're not meant to be running, exiting...")
                 return  # Terminate
 
             if self.game_was_running:
@@ -538,7 +538,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
                     self.planet = entry.get('Body') if entry.get('BodyType') == 'Planet' else None
 
                     if event_type == 'Location':
-                        logger.debug('"Location" event')
+                        logger.trace('"Location" event')
 
                 elif event_type == 'FSDJump':
                     self.planet = None
@@ -827,7 +827,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
             entry = self.parse_entry(self.event_queue.pop(0))
 
             if entry['event'] == 'Location':
-                logger.debug('"Location" event')
+                logger.trace('"Location" event')
 
             if not self.live and entry['event'] not in (None, 'Fileheader'):
                 # Game not running locally, but Journal has been updated
@@ -856,7 +856,7 @@ class EDLogs(FileSystemEventHandler):  # type: ignore # See below
                     ])
 
                 if entry['event'] == 'Location':
-                    logger.debug('Appending "Location" event to event_queue')
+                    logger.trace('Appending "Location" event to event_queue')
 
                 self.event_queue.append(json.dumps(entry, separators=(', ', ':')))
 

plug.py

@@ -304,7 +304,7 @@ def notify_journal_entry(cmdr, is_beta, system, station, entry, state):
     :returns: Error message from the first plugin that returns one (if any)
     """
     if entry['event'] in ('Location'):
-        logger.debug('Notifying plugins of "Location" event')
+        logger.trace('Notifying plugins of "Location" event')
 
     error = None
     for plugin in PLUGINS:

plugins/edsm.py

@@ -333,7 +333,7 @@ def journal_entry(
 ) -> None:
     """Journal Entry hook."""
     if entry['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked'):
-        logger.debug(f'''{entry["event"]}
+        logger.trace(f'''{entry["event"]}
 Commander: {cmdr}
 System: {system}
 Station: {station}
@@ -431,7 +431,7 @@ entry: {entry!r}'''
             this.queue.put((cmdr, materials))
 
         if entry['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked'):
-            logger.debug(f'''{entry["event"]}
+            logger.trace(f'''{entry["event"]}
 Queueing: {entry!r}'''
                          )
         this.queue.put((cmdr, entry))
@@ -530,12 +530,12 @@ def worker() -> None:
 
                 if should_send(pending):
                     if any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
-                        logger.debug("pending has at least one of "
+                        logger.trace("pending has at least one of "
                                      "('CarrierJump', 'FSDJump', 'Location', 'Docked')"
                                      " and it passed should_send()")
                         for p in pending:
                             if p['event'] in ('Location'):
-                                logger.debug('"Location" event in pending passed should_send(), '
+                                logger.trace('"Location" event in pending passed should_send(), '
                                              f'timestamp: {p["timestamp"]}')
 
                     creds = credentials(cmdr)  # TODO: possibly unbound
@@ -554,13 +554,13 @@ def worker() -> None:
                     if any(p for p in pending if p['event'] in ('CarrierJump', 'FSDJump', 'Location', 'Docked')):
                         data_elided = data.copy()
                         data_elided['apiKey'] = '<elided>'
-                        logger.debug("pending has at least one of "
+                        logger.trace("pending has at least one of "
                                      "('CarrierJump', 'FSDJump', 'Location', 'Docked')"
                                      " Attempting API cal...")
 
                         for p in pending:
                             if p['event'] in ('Location'):
-                                logger.debug('Attempting API call for "Location" event with timestamp: '
+                                logger.trace('Attempting API call for "Location" event with timestamp: '
                                              f'{p["timestamp"]}')
 
                     r = this.session.post('https://www.edsm.net/api-journal-v1', data=data, timeout=_TIMEOUT)

prefs.py

@@ -14,7 +14,7 @@ from typing import TYPE_CHECKING, Any, Callable, Optional, Type, Union
 
 import myNotebook as nb  # noqa: N813
 import plug
-from config import applongname, appname, appversion, config
+from config import applongname, appversion, config
 from EDMCLogging import edmclogger, get_main_logger
 from hotkey import hotkeymgr
 from l10n import Translations
@@ -1060,7 +1060,7 @@ class PreferencesDialog(tk.Toplevel):
         config.set('system_provider', self.system_provider.get())
         config.set('station_provider', self.station_provider.get())
         config.set('loglevel', self.select_loglevel.get())
-        edmclogger.get_streamhandler().setLevel(self.select_loglevel.get())
+        edmclogger.set_console_loglevel(self.select_loglevel.get())
 
         lang_codes = {v: k for k, v in self.languages.items()}  # Codes by name
         config.set('language', lang_codes.get(self.lang.get()) or '')  # or '' used here due to Default being None above