From 898ff9fbb2548bb4aa55aa446ba911e20a451ac5 Mon Sep 17 00:00:00 2001
From: Athanasius <github@miggy.org>
Date: Thu, 30 Jul 2020 15:33:55 +0100
Subject: [PATCH] Logging: Make correct loggers for 'found' plugins

* Log messages propagate up Parent.Child chains, so we don't need a
 channel on the plugin logger.
* But it still needs the filter to define qualname and class for
 formatting.
---
 EDMCLogging.py | 31 ++++++++++++++++++++++++++++++-
 plug.py        | 16 ++++++++++++----
 2 files changed, 42 insertions(+), 5 deletions(-)

diff --git a/EDMCLogging.py b/EDMCLogging.py
index 15a29286..7ad069a1 100644
--- a/EDMCLogging.py
+++ b/EDMCLogging.py
@@ -35,6 +35,8 @@ from typing import Tuple
 #
 #      14. Call from *package*
 
+_default_loglevel = logging.DEBUG
+
 
 class Logger:
     """
@@ -47,7 +49,7 @@ class Logger:
     Users of this class should then call getLogger() to get the
     logging.Logger instance.
     """
-    def __init__(self, logger_name: str, loglevel: int = logging.DEBUG):
+    def __init__(self, logger_name: str, loglevel: int = _default_loglevel):
         """
         Set up a `logging.Logger` with our preferred configuration.
         This includes using an EDMCContextFilter to add 'class' and 'qualname'
@@ -78,6 +80,33 @@ class Logger:
         return self.logger
 
 
+def get_plugin_logger(name: str, loglevel: int = _default_loglevel) -> logging.Logger:
+    """
+    'Found' plugins need their own logger to call out where the logging is
+    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
+    there *also* goes to the channels defined in the 'EDMarketConnector'
+    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 loglevel: Optional logLevel for this Logger.
+    :return: logging.Logger instance, all set up.
+    """
+    plugin_logger = logging.getLogger(name)
+    plugin_logger.setLevel(loglevel)
+
+    plugin_logger.addFilter(EDMCContextFilter())
+
+    return plugin_logger
+
+
 class EDMCContextFilter(logging.Filter):
     """
     logging.Filter sub-class to place extra attributes of the calling site
diff --git a/plug.py b/plug.py
index f836d7cd..0a0a3f8a 100644
--- a/plug.py
+++ b/plug.py
@@ -8,12 +8,14 @@ import importlib
 import sys
 import operator
 import threading  # noqa: F401 - We don't use it, but plugins might
+from typing import Optional
 import logging
 import tkinter as tk
 
 import myNotebook as nb  # noqa: N813
 
 from config import config, appname
+import EDMCLogging
 
 logger = logging.getLogger(appname)
 
@@ -79,7 +81,7 @@ last_error = {
 
 class Plugin(object):
 
-    def __init__(self, name, loadfile):
+    def __init__(self, name: str, loadfile: str, plugin_logger: Optional[logging.Logger]):
         """
         Load a single plugin
         :param name: module name
@@ -90,6 +92,7 @@ class Plugin(object):
         self.name = name  # Display name.
         self.folder = name  # basename of plugin folder. None for internal plugins.
         self.module = None  # None for disabled plugins.
+        self.logger = plugin_logger
 
         if loadfile:
             logger.info(f'loading plugin "{name.replace(".", "_")}" from "{loadfile}"')
@@ -173,7 +176,7 @@ def load_plugins(master):
     for name in sorted(os.listdir(config.internal_plugin_dir)):
         if name.endswith('.py') and not name[0] in ['.', '_']:
             try:
-                plugin = Plugin(name[:-3], os.path.join(config.internal_plugin_dir, name))
+                plugin = Plugin(name[:-3], os.path.join(config.internal_plugin_dir, name), logger)
                 plugin.folder = None  # Suppress listing in Plugins prefs tab
                 internal.append(plugin)
             except Exception as e:
@@ -191,12 +194,17 @@ def load_plugins(master):
             pass
         elif name.endswith('.disabled'):
             name, discard = name.rsplit('.', 1)
-            found.append(Plugin(name, None))
+            found.append(Plugin(name, None, logger))
         else:
             try:
                 # 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')))
+
+                # Create a logger for this 'found' plugin.  Must be before the
+                # load.py is loaded.
+                plugin_logger = EDMCLogging.get_plugin_logger(f'{appname}.{name}')
+
+                found.append(Plugin(name, os.path.join(config.plugin_dir, name, 'load.py'), plugin_logger))
             except Exception as e:
                 logger.exception(f'Failure loading found Plugin "{name}"')
                 pass