Sanitize the origin/level/importance system

Use reporting when possible (some messages automatically use Logger to avoid duplication)
Improve the Output thread to use the new level/importance system

7 files changed, 136 insertions, 58 deletions

diff --git a/firstaidkit b/firstaidkit
index c0012f1..2c23c51 100755
--- a/firstaidkit
+++ b/firstaidkit
@@ -16,7 +16,7 @@
 # along with this program; if not, write to the Free Software
 # Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
 
-import sys, getopt, os
+import sys, getopt, os, pprint, logging
 from threading import Thread
 from pyfirstaidkit import Tasker
 from pyfirstaidkit import Config
@@ -28,18 +28,56 @@ class Flags:
     main_help = False
 
 class Output(Thread):
-    def __init__(self, queue, *args, **kwargs):
+    def __init__(self, queue, importance = logging.INFO, *args, **kwargs):
+        Thread.__init__(self, *args, **kwargs)
         self._running = True
         self._queue = queue
-        Thread.__init__(self, *args, **kwargs)
+        self._importance = importance
 
     def run(self):
+        levelstack = []
+
         while self._running:
             message = self._queue.get()
-            if message["semantics"]==reporting.END:
+
+            if message["action"]==reporting.END:
                 self._running = False
                 continue
-            print message
+            elif message["action"]==reporting.QUESTION:
+                print "FIXME: Questions not implemented yet"
+            elif message["action"]==reporting.START:
+                if self._importance<=message["importance"]:
+                    print "START: %s (%s)" % (message["origin"].name, message["message"])
+                levelstack.append(message["origin"].name)
+            elif message["action"]==reporting.STOP:
+                if self._importance<=message["importance"]:
+                    print "STOP: %s (%s)" % (message["origin"].name, message["message"])
+                if levelstack[-1]!=message["origin"].name:
+                    print "WARNING: START/STOP ordering mismatch in stack: "+" / ".join(levelstack)
+                else:
+                    levelstack.pop()
+            elif message["action"]==reporting.PROGRESS:
+                if self._importance<=message["importance"]:
+                    print "PROGRESS: %d of %d (%s)" % (message["message"][0], message["message"][1], message["origin"].name)
+            elif message["action"]==reporting.INFO:
+                if self._importance<=message["importance"]:
+                    print "INFO: %s (%s)" % (message["message"], message["origin"].name)
+            elif message["action"]==reporting.ALERT:
+                if self._importance<=message["importance"]:
+                    print "ALERT: %s (%s)" % (message["message"], message["origin"].name)
+            elif message["action"]==reporting.EXCEPTION:
+                print "EXCEPTION: %s (%s)" % (message["message"], message["origin"].name)
+            elif message["action"]==reporting.TABLE:
+                if self._importance<=message["importance"]:
+                    print "TABLE %s FROM %s" % (message["title"], message["origin"].name,)
+                    pprint.pprint(message["message"])
+            elif message["action"]==reporting.TREE:
+                if self._importance<=message["importance"]:
+                    print "TREE %s FROM %s" % (message["title"], message["origin"].name,)
+                    pprint.pprint(message["message"])
+            else:
+                print "FIXME: Unknown message action %d!!" % (message["action"],)
+                print message
 
 def usage(name):
     print """Usage:
@@ -145,7 +183,11 @@ if __name__=="__main__":
 
     singlerun = Tasker(Config)
 
-    outputThread = Output(singlerun.reporting())
+    if not Config.operation.verbose:
+        outputThread = Output(singlerun.reporting())
+    else:
+        outputThread = Output(singlerun.reporting(), importance = 0)
+
     outputThread.start()
 
     try:
diff --git a/plugins/passwd.py b/plugins/passwd.py
index fab9443..c55b64c 100644
--- a/plugins/passwd.py
+++ b/plugins/passwd.py
@@ -56,7 +56,7 @@ class PasswdPlugin(Plugin):
 
         print spawnvch(executable = "/usr/bin/passwd", args = ["/usr/bin/passwd", "root"], chroot = Config.system.root).communicate(input = newpasswd+"\n"+newpasswd+"\n")
 
-        self._reporting.info("Root password was reset to '%s'" % (newpasswd,), origin = self)
+        self._reporting.info("Root password was reset to '%s'" % (newpasswd,), level = PLUGIN, origin = self)
 
         self._result=Return
 
diff --git a/plugins/plugin_examples/sample1Plugin.py b/plugins/plugin_examples/sample1Plugin.py
index 22d033f..bb8b24e 100644
--- a/plugins/plugin_examples/sample1Plugin.py
+++ b/plugins/plugin_examples/sample1Plugin.py
@@ -16,8 +16,10 @@
 # Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
 
 from pyfirstaidkit.plugins import Plugin,Flow
+from pyfirstaidkit.reporting import PLUGIN
 from pyfirstaidkit.returns import *
 
+
 class Sample1Plugin(Plugin):
     """This plugin uses the predefined flow in the Plugin abstract class."""
     name = "Sample1Plugin"
@@ -29,27 +31,27 @@ class Sample1Plugin(Plugin):
 
     def prepare(self):
         self._result=ReturnSuccess
-        self.reporting.info("Sample1Plugin in Prepare task", self)
+        self.reporting.info("Sample1Plugin in Prepare task", origin = self, level = PLUGIN)
 
     def backup(self):
         self._result=ReturnSuccess
-        self.reporting.info("Sample1Plugin in backup task", self)
+        self.reporting.info("Sample1Plugin in backup task", origin = self, level = PLUGIN)
 
     def restore(self):
         self._result=ReturnSuccess
-        self.reporting.info("Sample1Plugin in Restore task", self)
+        self.reporting.info("Sample1Plugin in Restore task", origin = self, level = PLUGIN)
 
     def diagnose(self):
         self._result=ReturnSuccess
-        self.reporting.info("Sample1Plugin in diagnose task", self)
+        self.reporting.info("Sample1Plugin in diagnose task", origin = self, level = PLUGIN)
 
     def fix(self):
         self._result=ReturnFailure
-        self.reporting.info("Sample1Plugin in Fix task", self)
+        self.reporting.info("Sample1Plugin in Fix task", origin = self, level = PLUGIN)
 
     def clean(self):
         self._result=ReturnSuccess
-        self.reporting.info("Sample1Plugin in Clean task", self)
+        self.reporting.info("Sample1Plugin in Clean task", origin = self, level = PLUGIN)
 
 def get_plugin():
     return Sample1Plugin
diff --git a/pyfirstaidkit/__init__.py b/pyfirstaidkit/__init__.py
index bcf3b94..e7409b0 100644
--- a/pyfirstaidkit/__init__.py
+++ b/pyfirstaidkit/__init__.py
@@ -24,7 +24,9 @@ def initLogger(config=None):
     """We want to initialize loger when we have the filename."""
     Logger = logging.getLogger("firstaidkit")
     Logger.setLevel(logging.DEBUG)
-    if config.log.method == "stdout" or config.log.method == None:
+    if config.log.method == "none":
+        Logger.addHandler(logging.FileHandler("/dev/null"))
+    elif config.log.method == "stdout" or config.log.method == None:
         Logger.addHandler(logging.StreamHandler(sys.stdout))
     else:
         # if nothing else matches we just put it into the file.
diff --git a/pyfirstaidkit/interpret.py b/pyfirstaidkit/interpret.py
index 79f2f21..f6441bc 100644
--- a/pyfirstaidkit/interpret.py
+++ b/pyfirstaidkit/interpret.py
@@ -17,7 +17,7 @@
 
 import os
 from plugins import PluginSystem
-from reporting import Reports, TASKER
+from reporting import Reports, TASKER, PLUGINSYSTEM
 import logging
 import copy
 from errors import *
@@ -54,6 +54,8 @@ class RunDependencies(object):
 class Tasker:
     """The main interpret of tasks described in Config object"""
 
+    name = "Task interpreter"
+
     def __init__(self, cfg):
         self._provide = RunDependencies()
         self._config = cfg
@@ -71,14 +73,15 @@ class Tasker:
         self._reporting.end()
 
     def run(self):
+        self._reporting.start(level = TASKER, origin = self)
         pluginSystem = self.pluginSystem
 
         # Check the root privilegies
         if os.geteuid() == 0:
-            self._reporting.info("You are running the firstaidkit as root.", origin = TASKER)
+            self._reporting.info("You are running the firstaidkit as root.", level = TASKER, origin = self, importance = logging.WARNING)
             self._provide.provide("root")
         else:
-            self._reporting.info("You are not running the firstaidkit as root. Some plugins may not be available.", origin = TASKER)
+            self._reporting.info("You are not running the firstaidkit as root. Some plugins may not be available.", level = TASKER, origin = self, importance = logging.WARNING)
             self._provide.unprovide("root")
 
         #initialize the startup set of flags
@@ -97,12 +100,12 @@ class Tasker:
                 for plugin in oldlist:
                     #If plugin does not contain the automated flow or if it ran correctly, remove it from list
                     if (flow and not flow in pluginSystem.getplugin(plugin).getFlows()) or (not flow and not pluginSystem.getplugin(plugin).default_flow in pluginSystem.getplugin(plugin).getFlows()):
-                        self._reporting.info("Plugin %s does not contain flow %s" % (plugin, flow or pluginSystem.getplugin(plugin).default_flow,), origin = TASKER)
+                        self._reporting.info("Plugin %s does not contain flow %s" % (plugin, flow or pluginSystem.getplugin(plugin).default_flow,), level = TASKER, origin = self)
                         actlist.remove(plugin)
                     elif pluginSystem.autorun(plugin, flow = flow):
                         actlist.remove(plugin)
             for plugin in actlist:
-                self._reporting.info("Plugin %s was not called because of unsatisfied dependencies" % (plugin,), origin = TASKER, importance = logging.WARNING)
+                self._reporting.info("Plugin %s was not called because of unsatisfied dependencies" % (plugin,), level = TASKER, origin = self, importance = logging.WARNING)
         elif self._config.operation.mode == "flow":
             try:
                 pluginSystem.autorun(self._config.operation.plugin, flow = self._config.operation.flow, dependencies = False)
@@ -119,7 +122,7 @@ class Tasker:
                 p = pluginSystem.getplugin(k)
                 flowinfo = [ (f, p.getFlow(f).description) for f in p.getFlows() ]
                 rep.append((k, p.name, p.version, p.author, p.description, p.default_flow, flowinfo))
-            self._reporting.table(rep, origin = TASKER)
+            self._reporting.table(rep, level = TASKER, origin = self, title = "List of plugins")
         elif self._config.operation.mode == "info":
             #get info about plugin
             try:
@@ -129,9 +132,11 @@ class Tasker:
                 return False
             flowinfo = [ (f, p.getFlow(f).description) for f in p.getFlows() ]
             rep = {"id": self._config.operation.params, "name": p.name, "version": p.version, "author": p.author, "description": p.description, "flow": p.default_flow, "flows": flowinfo}
-            self._reporting.tree(rep, origin = TASKER)
+            self._reporting.tree(rep, level = TASKER, origin = self, title = "Information about plugin %s" % (self._config.operation.params,))
         else:
             Logger.error("Incorrect task specified")
+            self._reporting.stop(level = TASKER, origin = self)
             return False
 
+        self._reporting.stop(level = TASKER, origin = self)
         return True
diff --git a/pyfirstaidkit/plugins.py b/pyfirstaidkit/plugins.py
index 1c422c3..eb054fc 100644
--- a/pyfirstaidkit/plugins.py
+++ b/pyfirstaidkit/plugins.py
@@ -18,6 +18,7 @@
 from configuration import Config
 from returns import *
 from errors import *
+from reporting import *
 from copy import copy,deepcopy
 
 import FirstAidKit
@@ -348,9 +349,12 @@ class FlagTrackerPlugin(Plugin):
 class PluginSystem(object):
     """Encapsulate all plugin detection and import stuff"""
 
+    name = "Plugin System"
+
     def __init__(self, reporting, dependencies, config = Config):
         self._paths = Config.paths.valueItems()
         self._reporting = reporting
+        self._reporting.start(level = PLUGINSYSTEM, origin = self)
         self._deps = dependencies
         self._plugins = {}
 
@@ -359,16 +363,16 @@ class PluginSystem(object):
             importlist = set()
             for f in os.listdir(path):
                 fullpath = os.path.join(path, f)
-                Logger.debug("Processing file: %s", f)
+                self._reporting.debug("Processing file: %s" % (f,), level = PLUGINSYSTEM, origin = self)
                 if os.path.isdir(fullpath) and os.path.isfile(os.path.join(path, f, "__init__.py")):
                     importlist.add(f)
-                    Logger.debug("Adding python module (directory): %s", f)
+                    self._reporting.debug("Adding python module (directory): %s" % (f,), level = PLUGINSYSTEM, origin = self)
                 elif os.path.isfile(fullpath) and (f[-3:]==".so" or f[-3:]==".py"):
                     importlist.add(f[:-3])
-                    Logger.debug("Adding python module (file): %s", f)
+                    self._reporting.debug("Adding python module (file): %s" % (f,), level = PLUGINSYSTEM, origin = self)
                 elif os.path.isfile(fullpath) and (f[-4:]==".pyc" or f[-4:]==".pyo"):
                     importlist.add(f[:-4])
-                    Logger.debug("Adding python module (compiled): %s", f)
+                    self._reporting.debug("Adding python module (compiled): %s" % (f,), level = PLUGINSYSTEM, origin = self)
 
             #try to import the modules as FirstAidKit.plugins.modulename
             for m in importlist:
@@ -377,15 +381,15 @@ class PluginSystem(object):
 
                 imp.acquire_lock()
                 try:
-                    Logger.debug("Importing module %s from %s", m, path)
+                    self._reporting.debug("Importing module %s from %s" % (m, path), level = PLUGINSYSTEM, origin = self)
                     moduleinfo = imp.find_module(m, [path])
                     module = imp.load_module(".".join([FirstAidKit.__name__, m]), *moduleinfo)
-                    Logger.debug("... OK")
                 finally:
                     imp.release_lock()
 
                 self._plugins[m] = module
-                Logger.debug("Module %s successfully imported with basedir %s", m, os.path.dirname(module.__file__))
+                self._reporting.debug("Module %s successfully imported with basedir %s" % (m, os.path.dirname(module.__file__)),
+                        level = PLUGINSYSTEM, origin = self)
 
     def list(self):
         """Return the list of imported plugins"""
@@ -397,6 +401,8 @@ returns - True if conditions are fully satisfied
           False if there is something missing
           exception when some other error happens"""
 
+        self._reporting.start(level = PLUGIN, origin = self, message = plugin)
+
         pklass = self._plugins[plugin].get_plugin() #get top level class of plugin
         plugindir = os.path.dirname(self._plugins[plugin].__file__)
         Logger.info("Plugin information...")
@@ -411,7 +417,7 @@ returns - True if conditions are fully satisfied
 
         Logger.info("Using %s flow" % flowName)
         if flowName not in flows:
-            Logger.error("Flow %s does not exist in plugin %s", flowName, plugin)
+            self._reporting.exception(message = "Flow %s does not exist in plugin %s" % (flowName, plugin), level = PLUGINSYSTEM, origin = self)
             raise InvalidFlowNameException(flowName)
 
         if dependencies:
@@ -421,6 +427,7 @@ returns - True if conditions are fully satisfied
                 for d in deps:
                     if not self._deps.require(d):
                         Logger.info("depends on usatisfied condition: %s" % (d,))
+                        self._reporting.stop(level = PLUGIN, origin = self, message = plugin)
                         return False
             deps = pklass.getConflicts()
             if len(deps)>0:
@@ -428,13 +435,17 @@ returns - True if conditions are fully satisfied
                 for d in deps:
                     if self._deps.require(d):
                         Logger.info("depends on condition to be UNset: %s" % (d,))
+                        self._reporting.stop(level = PLUGIN, origin = self, message = plugin)
                         return False
 
         p = pklass(flowName, reporting = self._reporting, dependencies = self._deps, path = plugindir)
         for (step, rv) in p: #autorun all the needed steps
+            self._reporting.start(level = TASK, origin = p, message = step)
             Logger.info("Running step %s in plugin %s ...", step, plugin)
             Logger.info("%s is current step and %s is result of that step." % (step, rv))
+            self._reporting.stop(level = TASK, origin = p, message = step)
 
+        self._reporting.stop(level = PLUGIN, origin = self, message = plugin)
         return True
 
     def getplugin(self, plugin):
diff --git a/pyfirstaidkit/reporting.py b/pyfirstaidkit/reporting.py
index a31827d..1ee0e6b 100644
--- a/pyfirstaidkit/reporting.py
+++ b/pyfirstaidkit/reporting.py
@@ -18,6 +18,8 @@
 import Queue
 import logging
 
+Logger = logging.getLogger("firstaidkit")
+
 #semantics values
 #first the "task" levels for START and STOP
 FIRSTAIDKIT = 100
@@ -39,13 +41,21 @@ TREE = 7  #nested iterables organized as tree
 QUESTION = 999 #type of message which contains respond-to field
 END = 1000 #End of operations, final message
 
+class Origin(object):
+    """Class which defines mandatory interface for origin, when using the reporting system"""
+    name = "Origin:Unknown"
+
+    def __init__(self, name):
+        self.name = name
+
 class Reports(object):
     """Instances of this class are used as reporting mechanism by which the
     plugins can comminucate back to whatever frontend we are using.
 
     Message has four parts:
-    origin - who sent the message (name of the plugin, Pluginsystem, ...)
-    semantics - what action does the message describe
+    origin - who sent the message (instance of the plugin, Pluginsystem, ...)
+    level - which level of First Aid Kit sent the message (PLUGIN, TASKER, ..)
+    action - what action does the message describe
                 (INFO, ALERT, PROGRESS, START, STOP, DATA, END)
     importance - how is that message important (debug, info, error, ...)
                  this must be number, possibly the same as in logging module
@@ -63,10 +73,10 @@ class Reports(object):
         self._queue = Queue.Queue(maxsize = maxsize)
         self._mailboxes = []
 
-    def put(self, message, origin, semantics, importance = logging.INFO, reply = None, title = "", destination = None):
+    def put(self, message, level, origin, action, importance = logging.INFO, reply = None, title = "", destination = None):
         if destination is None:
             destination = self._queue
-        return destination.put({"origin": origin, "semantics": semantics, "importance": importance, "message": message, "reply": reply, "title": title})
+        return destination.put({"level": level, "origin": origin, "action": action, "importance": importance, "message": message, "reply": reply, "title": title})
 
     def get(self, mailbox = None, *args, **kwargs):
         if mailbox is None:
@@ -85,29 +95,35 @@ class Reports(object):
 
     #There will be helper methods inspired by logging module
     def end(self):
-        return self.put(None, None, END, importance = 1000)
-
-    def error(self, message, origin, semantics):
-        return self.put(message, origin, semantics, importance = logging.ERROR)
-
-    def start(self, message, origin, what = TASK):
-        return self.put(message, origin, START, importance = what)
-    def stop(self, message, origin, what = TASK):
-        return self.put(message, origin, START, importance = what)
-
-    def progress(self, position, maximum, origin, importance = logging.INFO):
-        return self.put((position, maximum), origin, PROGRESS, importance = importance)
-    def info(self, message, origin, importance = logging.INFO):
-        return self.put(message, origin, INFO, importance = importance)
-
-
-    def tree(self, message, origin, importance = logging.INFO):
-        return self.put(message, origin, TREE, importance = importance)
-    def table(self, message, origin, importance = logging.INFO):
-        return self.put(message, origin, TABLE, importance = importance)
-
-    def alert(self, message, origin, importance = logging.WARNING):
-        return self.put(message, origin, ALERT, importance = importance)
-    def exception(self, message, origin, importance = logging.ERROR):
-        return self.put(message, origin, EXCEPTION, importance = importance)
+        return self.put(None, FIRSTAIDKIT, None, END, importance = 1000)
+
+    def error(self, message, level, origin, action):
+        Logger.error(origin.name+": "+message)
+        return self.put(message, level, origin, action, importance = logging.ERROR)
+
+    def start(self, level, origin, message = ""):
+        return self.put(message, level, origin, START, importance = logging.DEBUG)
+    def stop(self, level, origin, message = ""):
+        return self.put(message, level, origin, STOP, importance = logging.DEBUG)
+
+    def progress(self, position, maximum, level, origin, importance = logging.INFO):
+        return self.put((position, maximum), level, origin, PROGRESS, importance = importance)
+
+    def info(self, message, level, origin, importance = logging.INFO):
+        Logger.info(origin.name+": "+message)
+        return self.put(message, level, origin, INFO, importance = importance)
+    def debug(self, message, level, origin, importance = logging.DEBUG):
+        Logger.debug(origin.name+": "+message)
+        return self.put(message, level, origin, INFO, importance = importance)
+
+    def tree(self, message, level, origin, importance = logging.INFO, title = ""):
+        return self.put(message, level, origin, TREE, importance = importance, title = title)
+    def table(self, message, level, origin, importance = logging.INFO, title = ""):
+        return self.put(message, level, origin, TABLE, importance = importance, title = title)
+
+    def alert(self, message, level, origin, importance = logging.WARNING):
+        return self.put(message, level, origin, ALERT, importance = importance)
+    def exception(self, message, level, origin, importance = logging.ERROR):
+        Logger.error(origin.name+": "+message)
+        return self.put(message, level, origin, EXCEPTION, importance = importance)