python: redone cmpi_logging

Module now contains enhanced tracing function decorators providing more
details. There is no global logger, each provider module should obtain
its own logger via get_logger() function.

Usage of LogManager is optional. It allows for logging's
reconfiguration, when config file is changed.

Exceptions logged with error(), exception() or critical() methods are
now logged twice:
  * First time for specified level with error message only.
  * Second time for TRACE_WARNING level with traceback.
This prevents the polution of syslog.

1 files changed, 19 insertions, 26 deletions

diff --git a/src/python/lmi/providers/TimerManager.py b/src/python/lmi/providers/TimerManager.py
index 76b2f5b..6d05bb2 100644
--- a/src/python/lmi/providers/TimerManager.py
+++ b/src/python/lmi/providers/TimerManager.py
@@ -56,6 +56,8 @@ import Queue
 from lmi.base import singletonmixin
 from lmi.providers import cmpi_logging
 
+LOG = cmpi_logging.get_logger(__name__)
+
 class TimerException(Exception):
     pass
 
@@ -114,7 +116,7 @@ class Timer(object):
         self._args = args
         self._kwargs = kwargs
 
-        cmpi_logging.logger.trace_info("Timer: Timer %s created" % name)
+        LOG().trace_info("Timer: Timer %s created", name)
 
     @cmpi_logging.trace_method
     def set_callback(self, callback, *args, **kwargs):
@@ -140,9 +142,8 @@ class Timer(object):
         self._timeout = timeout
         now = self._mgr.now()
         self._end_time = now + timeout
-        cmpi_logging.logger.trace_info(
-                "Timer: Timer %s started at %f for %f seconds"
-                % (self._name, now, self._timeout))
+        LOG().trace_info("Timer: Timer %s started at %f for %f seconds",
+                self._name, now, self._timeout)
         self._mgr._add_timer(self)
 
     @cmpi_logging.trace_method
@@ -151,8 +152,7 @@ class Timer(object):
         Cancel the timer. This method does not guarantee that the callback won't
         be called, the timer might be calling the callback right now,
         """
-        cmpi_logging.logger.trace_info("Timer: Timer %s cancelled"
-                % (self._name))
+        LOG().trace_info("Timer: Timer %s cancelled", self._name)
         self._mgr._remove_timer(self)
 
     @cmpi_logging.trace_method
@@ -164,8 +164,7 @@ class Timer(object):
         :returns: (``boolean``) ``True``, if the timer is expired.
         """
         if self._end_time <= now:
-            cmpi_logging.logger.trace_info("Timer: Timer %s has expired"
-                    % (self._name))
+            LOG().trace_info("Timer: Timer %s has expired", self._name)
             return True
         return False
 
@@ -174,8 +173,7 @@ class Timer(object):
         """
         Called when the timer expired. It calls the callback.
         """
-        cmpi_logging.logger.trace_info("Timer: Calling callback for timer %s"
-                % (self._name))
+        LOG().trace_info("Timer: Calling callback for timer %s", self._name)
         self._callback(*self._args, **self._kwargs)
 
 class TimerManager(singletonmixin.Singleton):
@@ -245,7 +243,7 @@ class TimerManager(singletonmixin.Singleton):
         """
         if broker:
             broker.AttachThread()
-        cmpi_logging.logger.info("Started Timer thread.")
+        LOG().info("Started Timer thread.")
         while True:
             self._handle_expired()
             timeout = self._find_timeout()
@@ -260,7 +258,7 @@ class TimerManager(singletonmixin.Singleton):
                 except Queue.Empty:
                     # Timeout has happened, ignore the exception.
                     pass
-        cmpi_logging.logger.info("Stopped Timer thread.")
+        LOG().info("Stopped Timer thread.")
 
     @cmpi_logging.trace_method
     def _handle_expired(self):
@@ -272,8 +270,7 @@ class TimerManager(singletonmixin.Singleton):
         # Get list of expired timers.
         with self._lock:
             now = self.now()
-            cmpi_logging.logger.trace_info(
-                    "Timer: Checking for expired, now=%f." % (now))
+            LOG().trace_info("Timer: Checking for expired, now=%f.", now)
             expired = [t for t in self._timers if t._expired(now)]
 
         # Call the callbacks (unlocked!).
@@ -284,8 +281,7 @@ class TimerManager(singletonmixin.Singleton):
         with self._lock:
             for t in expired:
                 try:
-                    cmpi_logging.logger.trace_info(
-                        "Timer: Removing %s" % (t._name))
+                    LOG().trace_info("Timer: Removing %s", t._name)
                     self._timers.remove(t)
                 except ValueError:
                     # The timer has already been removed.
@@ -304,18 +300,16 @@ class TimerManager(singletonmixin.Singleton):
         """
         with self._lock:
             if not self._timers:
-                cmpi_logging.logger.trace_info(
-                        "Timer: No timers scheduled, waiting forever.")
+                LOG().trace_info("Timer: No timers scheduled, waiting forever.")
                 return None
             closest = min(self._timers, key=lambda timer: timer._end_time)
             now = self.now()
             timeout = closest._end_time - now
             if timeout > 0:
-                cmpi_logging.logger.trace_info(
-                        "Timer: Waiting for %f seconds, now=%f."
-                        % (timeout, now))
+                LOG().trace_info("Timer: Waiting for %f seconds, now=%f.",
+                        timeout, now)
                 return timeout
-            cmpi_logging.logger.trace_info(
+            LOG().trace_info(
                     "Timer: Some timer has already expired, no waiting.")
             return 0
 
@@ -332,7 +326,7 @@ class TimerManager(singletonmixin.Singleton):
             self._timers.append(timer)
         # Wake up the timer manager thread.
         self._queue.put(self.COMMAND_RESCHEDULE)
-        cmpi_logging.logger.trace_info("Timer: Timer %s added" % (timer._name))
+        LOG().trace_info("Timer: Timer %s added", timer._name)
 
     @cmpi_logging.trace_method
     def _remove_timer(self, timer):
@@ -348,8 +342,7 @@ class TimerManager(singletonmixin.Singleton):
                 pass
         # Wake up the timer manager thread.
         self._queue.put(self.COMMAND_RESCHEDULE)
-        cmpi_logging.logger.trace_info("Timer: Timer %s removed"
-                % (timer._name))
+        LOG().trace_info("Timer: Timer %s removed", timer._name)
 
     def now(self):
         """
@@ -371,7 +364,7 @@ class TimerManager(singletonmixin.Singleton):
         self._timer_thread.join()
 
 if __name__ == "__main__":
-    cmpi_logging.logger = cmpi_logging.CMPILogger("")
+    LOG = cmpi_logging.CMPILogger("")
     import time
 
     class Env(object):