Add -v option, reduce default logging

- Normal operation confusingly usually printed "unknown args:", this
  removes that unless "--verbose" is given.
- Now, only print kernel arguments + path to which the kernel was
  saved by default.
- To review: General sanity check, I think overall it makes sense and
  is tested.

Author: rkdarst

README.md

@@ -75,6 +75,9 @@ These options directly map to normal Jupyter kernel install options:
 
 These are envkernel-specific options:
 
+* `--verbose`, `-v`: Print more debugging information when installing
+  the kernel.  It is always in verbose mode when actually running the
+  kernel.
 * `--python`: Python interpreter to use when invoking inside the
   environment. (Default `python`.  Unlike other kernels, this defaults
   to a relative path because the point of envkernel is to set up PATH

envkernel.py

@@ -15,7 +15,7 @@
 import tempfile
 
 LOG = logging.getLogger('envkernel')
-LOG.setLevel(logging.DEBUG)
+LOG.setLevel(logging.INFO)
 logging.lastResort.setLevel(logging.DEBUG)
 
 
@@ -127,9 +127,14 @@ def setup(self):
         parser.add_argument('--env', action='append', default=[],
                             help="Environment to add, format NAME=VAL.  Can be given multiple times. "
                                  "These are statically embedded in the kernel.json file")
+        parser.add_argument('--verbose', '-v', action='store_true',
+                                  help="Print more debugging information")
         args, unknown_args = parser.parse_known_args(self.argv)
-        LOG.debug('setup: args: %s', args)
-        LOG.debug('setup: unknown_args: %s', unknown_args)
+        if args.verbose:
+            LOG.setLevel(logging.DEBUG)
+
+        LOG.debug('setup: envkernel setup args: %s', args)
+        LOG.debug('setup: kernel-specific args: %s', unknown_args)
         self.setup_args = args
         self.name = args.name
         self.user = args.user
@@ -243,6 +248,13 @@ def install_kernel(self, kernel, name, user=False, replace=None, prefix=None, lo
             LOG.info("  Note: Kernel not detected with current search path.")
         LOG.info("  Command line: %s", kernel['argv'])
 
+    def run(self):
+        """Hook that gets run before kernel invoked"""
+        # User does not directly see this (except interleaved in
+        # normal jupyter logging output), so we can set it to debug
+        # by default.
+        LOG.setLevel(logging.DEBUG)
+
 
 
 class lmod(envkernel):
@@ -266,6 +278,7 @@ def run(self):
 
         before '--': the modules to load
         after '--': the Python command to run after loading"""
+        super().run()
         argv, rest = split_doubledash(self.argv, 1)
         parser = argparse.ArgumentParser()
         parser.add_argument('--purge', action='store_true', default=False, help="Purge existing modules first")
@@ -330,6 +343,7 @@ def run(self):
 
         before '--': the modules to load
         after '--': the Python command to run after loading"""
+        super().run()
         argv, rest = split_doubledash(self.argv, 1)
         parser = argparse.ArgumentParser()
         #parser.add_argument('--purge', action='store_true', default=False, help="Purge existing modules first")
@@ -399,6 +413,7 @@ def setup(self):
                             replace=self.replace, prefix=self.prefix)
 
     def run(self):
+        super().run()
         argv, rest = split_doubledash(self.argv, 1)
         parser = argparse.ArgumentParser()
         parser.add_argument('image', help='Docker image name')
@@ -534,6 +549,7 @@ def setup(self):
                             replace=self.replace, prefix=self.prefix)
 
     def run(self):
+        super().run()
         argv, rest = split_doubledash(self.argv, 1)
         parser = argparse.ArgumentParser()
         parser.add_argument('image', help='image name')

test_envkernel.py

@@ -1,4 +1,5 @@
 import json
+import logging
 import os
 from os.path import join as pjoin
 import pytest
@@ -141,6 +142,35 @@ def test_help():
         assert mod in stdout, "%s not found in --help output"%mod
     assert p.returncode == 0
 
+def test_logging(d, caplog):
+    """Test that the global -v option works and increases debugging
+
+    Run first without -v and make sure some stuff isn't printed.
+    Then, run with -v and ensure that the argument processing is output.
+    """
+    cmd = "python3 -m envkernel lmod --name=ABC --display-name=AAA MOD1 --prefix=%s"%d
+    print(d)
+    env = os.environ.copy()
+    env['JUPYTER_PATH'] = pjoin(d, 'share/jupyter')
+    # First, test non-verbose (should have minimal output)
+    p = subprocess.Popen(cmd, env=env,
+                         shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+    stdout = p.stdout.read().decode()
+    p.wait()
+    print(stdout)
+    assert 'Namespace' not in stdout
+    assert 'kernel-specific' not in stdout
+    assert 'Command line:' in stdout
+    # Now test verbose (should have some debugging info)
+    p = subprocess.Popen(cmd+' -v', env=env,
+                         shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+    stdout = p.stdout.read().decode()
+    p.wait()
+    #print(stdout)
+    assert 'Namespace' in stdout
+    assert 'kernel-specific' in stdout
+    assert 'Command line:' in stdout
+
 def test_umask(d):
     orig_umask = os.umask(0)
     # Test multiple umasks, and kerneldir + kernel.json