Fix verbose output and debug logging

Resolves: bz782339

2 files changed, 33 insertions, 29 deletions

diff --git a/sos/plugintools.py b/sos/plugintools.py
index a6fb330e..4fdbd768 100644
--- a/sos/plugintools.py
+++ b/sos/plugintools.py
@@ -67,8 +67,8 @@ class PluginBase:
 
         self.must_exit = False
 
-        self.soslog = logging.getLogger('sos')
-        self.proflog = logging.getLogger('sosprofile')
+        self.soslog = self.cInfo['soslog']
+        self.proflog = self.cInfo['proflog']
 
         # get the option list into a dictionary
         for opt in self.optionList:
@@ -105,7 +105,7 @@ class PluginBase:
                     except KeyboardInterrupt:
                       raise KeyboardInterrupt
                     except Exception, e:
-                        # self.soslog.debug("problem at path %s (%s)" % (abspath,e))
+                        self.soslog.info("could not apply regex substitution at path %s (%s)" % (abspath,e))
                         break
         return False
 
@@ -137,7 +137,7 @@ class PluginBase:
             return ''
 
         if not os.path.exists(srcpath):
-            # self.soslog.debug("file or directory %s does not exist" % srcpath)
+            self.soslog.info("file or directory %s does not exist" % srcpath)
             return
 
         if os.path.islink(srcpath):
@@ -162,19 +162,19 @@ class PluginBase:
 
             # make sure the link doesn't already exists
             if os.path.exists(dstslname):
-                # self.soslog.debug("skipping symlink creation: already exists (%s)" % dstslname)
+                self.soslog.info("skipping symlink creation: already exists (%s)" % dstslname)
                 return
 
             # make sure the dst dir exists
             if not (os.path.exists(os.path.dirname(dstslname)) and os.path.isdir(os.path.dirname(dstslname))):
                 os.makedirs(os.path.dirname(dstslname))
 
-            # self.soslog.debug("creating symlink %s -> %s" % (dstslname, rpth))
+            self.soslog.debug("creating symlink %s -> %s" % (dstslname, rpth))
 
             try:
                 os.symlink(rpth, dstslname)
             except OSError:
-                # self.soslog.debug("skipping symlink creation: already exists (%s)" % dstslname)
+                self.soslog.info("skipping symlink creation: already exists (%s)" % dstslname)
                 return
             if os.path.isabs(link):
                 self.doCopyFileOrDir(link)
@@ -195,17 +195,17 @@ class PluginBase:
 
         # if we get here, it's definitely a regular file (not a symlink or dir)
 
-        # self.soslog.debug("copying file %s" % srcpath)
+        self.soslog.debug("copying file %s" % srcpath)
         try:
             tdstpath, abspath = self.__copyFile(srcpath)
-        except EnvironmentError:
-            # self.soslog.debug("error copying file %s (already exists)" % (srcpath))
+        except PluginException:
+            self.soslog.debug("error copying file %s (already exists)" % (srcpath))
             return
         except IOError:
-            # self.soslog.debug("error copying file %s (IOError)" % (srcpath))
+            self.soslog.info("error copying file %s (IOError)" % (srcpath))
             return 
         except:
-            # self.soslog.debug("error copying file %s (SOMETHING HAPPENED)" % (srcpath))
+            self.soslog.exception("error copying file %s" % (srcpath))
             return 
 
         self.copiedFiles.append({'srcpath':srcpath, 'dstpath':tdstpath, 'symlink':"no"}) # save in our list
@@ -285,7 +285,7 @@ class PluginBase:
         """Add a file specification (with limits)
         """
         if not ( fname and len(fname) ):
-            # self.soslog.warning("invalid file path")
+            self.soslog.warning("invalid file path")
             return False
         files = glob.glob(fname)
         files.sort()
@@ -309,7 +309,7 @@ class PluginBase:
         copied into the sosreport by this module
         """
         if not ( copyspec and len(copyspec) ):
-            # self.soslog.warning("invalid file path")
+            self.soslog.warning("invalid file path")
             return False
         # Glob case handling is such that a valid non-glob is a reduced glob
         for filespec in glob.glob(copyspec):
@@ -399,7 +399,7 @@ class PluginBase:
             outfn_strip = outfn[len(self.cInfo['cmddir'])+1:]
 
         else:
-            # self.soslog.debug("could not run command: %s" % exe)
+            self.soslog.info("could not run command: %s" % exe)
             outfn = None
             outfn_strip = None
 
@@ -463,11 +463,11 @@ class PluginBase:
 
         for progs in izip(self.collectProgs):
             prog, suggest_filename, root_symlink, timeout = progs[0]
-            # self.soslog.debug("collecting output of '%s'" % prog)
+            self.soslog.debug("collecting output of '%s'" % prog)
             try:
                 self.collectOutputNow(prog, suggest_filename, root_symlink, timeout)
             except Exception, e:
-                self.soslog.debug("error collection output of '%s', traceback follows:" % prog)
+                self.soslog.info("error collection output of '%s', traceback follows:" % prog)
 
     def exit_please(self):
         """ This function tells the plugin that it should exit ASAP"""
diff --git a/sos/sosreport.py b/sos/sosreport.py
index ccacdff4..e1a2a633 100755
--- a/sos/sosreport.py
+++ b/sos/sosreport.py
@@ -361,17 +361,16 @@ def sosreport(opts):
     soslog = logging.getLogger('sos')
     soslog.setLevel(logging.DEBUG)
 
-    logging.VERBOSE  = logging.INFO - 1
-    logging.VERBOSE2 = logging.INFO - 2
-    logging.VERBOSE3 = logging.INFO - 3
-    logging.addLevelName(logging.VERBOSE, "verbose")
-    logging.addLevelName(logging.VERBOSE2,"verbose2")
-    logging.addLevelName(logging.VERBOSE3,"verbose3")
-
     if GlobalVars.__cmdLineOpts__.profiler:
         proflog = logging.getLogger('sosprofile')
         proflog.setLevel(logging.DEBUG)
-        
+    else:
+        proflog = None
+
+    # limit verbosity to DEBUG
+    if GlobalVars.__cmdLineOpts__.verbosity > 3:
+        GlobalVars.__cmdLineOpts__.verbosity = 3 
+
     # if stdin is not a tty, disable colors and don't ask questions
     if not sys.stdin.isatty():
         GlobalVars.__cmdLineOpts__.nocolors = True
@@ -380,7 +379,11 @@ def sosreport(opts):
     # log to a file
     flog = logging.FileHandler(logdir + "/sos.log")
     flog.setFormatter(logging.Formatter('%(asctime)s %(levelname)s: %(message)s'))
-    flog.setLevel(logging.VERBOSE3)
+    if GlobalVars.__cmdLineOpts__.verbosity > 0:
+        # standard log levels have a step of 10
+        flog.setLevel(logging.INFO - (GlobalVars.__cmdLineOpts__.verbosity * 10))
+    else:
+        flog.setLevel(logging.INFO)
     soslog.addHandler(flog)
 
     if GlobalVars.__cmdLineOpts__.profiler:
@@ -393,9 +396,10 @@ def sosreport(opts):
     # define a Handler which writes INFO messages or higher to the sys.stderr
     console = logging.StreamHandler(sys.stderr)
     if GlobalVars.__cmdLineOpts__.verbosity > 0:
-        console.setLevel(20 - GlobalVars.__cmdLineOpts__.verbosity)
+        # standard log levels have a step of 10
+        console.setLevel(logging.WARNING - (GlobalVars.__cmdLineOpts__.verbosity * 10))
     else:
-        console.setLevel(logging.INFO)
+        console.setLevel(logging.WARNING)
     console.setFormatter(logging.Formatter('%(message)s'))
     soslog.addHandler(console)
 
@@ -403,7 +407,7 @@ def sosreport(opts):
 
     # set up dict so everyone can share the following
     commons = {'dstroot': GlobalVars.dstroot, 'cmddir': cmddir, 'logdir': logdir, 'rptdir': rptdir,
-               'soslog': soslog, 'policy': GlobalVars.policy, 'verbosity' : GlobalVars.__cmdLineOpts__.verbosity,
+               'soslog': soslog, 'proflog': proflog, 'policy': GlobalVars.policy, 'verbosity' : GlobalVars.__cmdLineOpts__.verbosity,
                'xmlreport' : xmlrep, 'cmdlineopts':GlobalVars.__cmdLineOpts__, 'config':config }
 
     # Make policy aware of the commons