rewrite the plugin loader

uses click to init the logging system

lazily loads commands, so if the user calls a specific command
only that command must be loaded.

python/lsst/daf/butler/cli/butler.py

@@ -22,68 +22,96 @@
 import click
 import logging
 import os
-import sys
 
-from lsst.daf.butler.cli.opt.verbose import verbose_option
 import lsst.log
 from lsst.utils import doImport
 
 
-def _getPluginList():
-    pluginModules = os.environ.get("DAF_BUTLER_PLUGINS")
-    if pluginModules is None:
-        return []
-    return pluginModules.split(":")
-
-
-def _importPlugins(pluginList, group):
-    for pluginName in pluginList:
-        try:
-            plugin = doImport(pluginName)
-        except (TypeError, ModuleNotFoundError, ImportError) as err:
-            logging.warning("Could not import plugin from %s, skipping.", pluginName)
-            logging.debug("Plugin import exception: %s", err)
-            continue
-        for command in plugin.__all__:
-            fullCommand = pluginName + "." + command
-            logging.debug("Loading CLI command: %s", fullCommand)
+def _initLogging(logLevel):
+    log = lsst.log.Log.getLogger("lsst.daf.butler")
+    if "critical" == logLevel:
+        logging.basicConfig(level=logging.CRITICAL)
+        log.setLevel(lsst.log.Log.FATAL)
+        return
+    elif "error" == logLevel:
+        logging.basicConfig(level=logging.ERROR)
+        log.setLevel(lsst.log.Log.FATAL)
+        return
+    elif "warning" == logLevel or "warn" == logLevel:
+        logging.basicConfig(level=logging.WARNING)
+        log.setLevel(lsst.log.Log.WARN)
+        return
+    elif "info" == logLevel:
+        logging.basicConfig(level=logging.INFO)
+        log.setLevel(lsst.log.Log.INFO)
+        return
+    elif "debug" == logLevel:
+        logging.basicConfig(level=logging.DEBUG)
+        log.setLevel(lsst.log.Log.DEBUG)
+        return
+    elif "trace" == logLevel:
+        logging.basicConfig(level=logging.DEBUG)
+        log.setLevel(lsst.log.Log.TRACE)
+        return
+    # This should not happen; log levels should be restricted to the choices
+    # in the --log-level option, and each of those choices should be handled
+    # here.
+    raise RuntimeError(f"Unhandled logging level:{logLevel}")
+
+
+class LoaderCLI(click.MultiCommand):
+
+    @staticmethod
+    def _getPluginList():
+        pluginModules = os.environ.get("DAF_BUTLER_PLUGINS")
+        if pluginModules is None:
+            return []
+        return pluginModules.split(":")
+
+    def list_commands(self, ctx):
+        commands = []
+        for pluginName in self._getPluginList():
             try:
-                cmd = doImport(fullCommand)
+                plugin = doImport(pluginName)
             except (TypeError, ModuleNotFoundError, ImportError) as err:
-                logging.warning("Could not import command from %s, skipping.", fullCommand)
-                logging.debug("Command import exception: %s", err)
+                logging.warning("Could not import plugin from %s, skipping.", pluginName)
+                logging.debug("Plugin import exception: %s", err)
                 continue
-            try:
-                group.add_command(cmd)
-            except Exception as err:
-                logging.warning("Failed while adding command %s from %s, skipping.", command, pluginName)
-                logging.debug("Exception during add_command: %s", err)
-
-
-def _addCommands(group):
-    pluginList = _getPluginList()
-    _importPlugins(pluginList, group)
-
-
-@click.group()
-# this group doesn't use the verbose command but does allow (ignore) it,
-# because the -v flag is used for logging while building the group.
-@verbose_option
-def cli(verbose):
-    pass
+            for command in plugin.__all__:
+                commands.append(command)
+        commands.sort()
+        return commands
 
-
-lgr = logging.getLogger("lsst.daf.butler")
-log = lsst.log.Log.getLogger("lsst.daf.butler")
-
-
-def getCli():
-    _addCommands(cli)
-    return cli
+    def get_command(self, context, name):
+        for pluginName in self._getPluginList():
+            try:
+                plugin = doImport(pluginName)
+            except (TypeError, ModuleNotFoundError, ImportError) as err:
+                logging.warning("Could not import plugin from %s, skipping.", pluginName)
+                logging.debug("Plugin import exception: %s", err)
+                continue
+            for command in plugin.__all__:
+                if command == name:
+                    fullCommand = pluginName + "." + command
+                    try:
+                        cmd = doImport(fullCommand)
+                    except (TypeError, ModuleNotFoundError, ImportError) as err:
+                        logging.debug("Command import exception: %s", err)
+                        context.fail("Could not import command {fullCommand}")
+                    return cmd
+
+
+@click.command(cls=LoaderCLI)
+@click.option("--log-level",
+              # These log level choices are the union of the log levels in the
+              # python logging pacakge and in the lsst log package.
+              type=click.Choice(["critical", "error", "warning", "warn", "info", "debug", "trace"]),
+              help="""The log level. Most log levels are common to both lsst.log and python.logging. The
+                    'trace' level will set lsst.daf.butler logging to 'trace' and python logging to 'debug'.
+                    """)
+def cli(log_level="warning"):
+    _initLogging(log_level)
 
 
 def main():
-    verbose = len(sys.argv) > 1 and "-v" == sys.argv[1]
-    logging.basicConfig(level=logging.DEBUG if verbose else logging.INFO)
-    log.setLevel(lsst.log.Log.DEBUG if verbose else lsst.log.Log.INFO)
-    return getCli()()
+    return cli()