[gnue] r9929 - in trunk/gnue-common/src: apps base

[reinhard]

Author: reinhard
Date: 2009-10-05 17:16:50 -0500 (Mon, 05 Oct 2009)
New Revision: 9929

Modified:
   trunk/gnue-common/src/apps/GDebug.py
   trunk/gnue-common/src/base/log.py
Log:
Finish work on new log module.

issue123 testing


Modified: trunk/gnue-common/src/apps/GDebug.py
===================================================================
--- trunk/gnue-common/src/apps/GDebug.py        2009-10-05 19:57:53 UTC (rev 
9928)
+++ trunk/gnue-common/src/apps/GDebug.py        2009-10-05 22:16:50 UTC (rev 
9929)
@@ -22,6 +22,8 @@
 # $Id$
 
 """
+Deprecated module.
+
 Support for debugging messages with independent debug levels and redirection of
 messages to a file.
 """
@@ -81,7 +83,8 @@
 def gDebug (level, message, *args):
     """
     Write a message to the debug-output. This function is available in the
-    global namespace.
+    global namespace. DEPRECATED. Use the logging functions in
+    L{gnue.common.base.logging} instead.
 
     @param level: the debug-level the message will be logged in
     @param message: the message to be logged
@@ -101,6 +104,7 @@
     """
     Write information about the current function and its parameters to
     debug-output. This function is available in the global namespace.
+    DEPRECATED. Use L{gnue.common.base.logging.logged_f} instead.
 
     assert gEnter is intended to be called at the begin of a function.
 
@@ -158,6 +162,7 @@
     """
     Write information about the current function and its return value to
     debug-output. This function is available in the global namespace.
+    DEPRECATED. Use L{gnue.common.base.logging.logged_f} instead.
 
     gLeave is intended to be called at the end of a function.
 
@@ -202,7 +207,9 @@
 
 def setDebug (level, file = None):
     """
-    Initialize and configure the debug message system
+    Initialize and configure the debug message system.
+    DEPRECATED. Use the logging functions in L{gnue.common.base.logging}
+    instead.
 
     @param level: A string with the debug levels to output, e.g. "0-3,5,7"
     @param file: Filename to output debug messages to (instead of stderr)
@@ -249,6 +256,7 @@
 
 def printMesg (level, message):
     """
-    This function is deprecated - use gDebug instead
+    DEPRECATED. Use the logging functions in L{gnue.common.base.logging}
+    instead.
     """
     __builtin__.__dict__ ['gDebug'] (level, message)

Modified: trunk/gnue-common/src/base/log.py
===================================================================
--- trunk/gnue-common/src/base/log.py   2009-10-05 19:57:53 UTC (rev 9928)
+++ trunk/gnue-common/src/base/log.py   2009-10-05 22:16:50 UTC (rev 9929)
@@ -25,8 +25,73 @@
 # pylint: disable-msg=W0142
 
 """
-The log module extends the standard logging module with some convenience
-functions related to the logging schema used in GNU Enterprise.
+Convenience functions for logging.
+
+Logging in GNU Enterprise
+=========================
+
+Logging in GNU Enterprise is based on Python's standard C{logging} module. This
+module defines a number of convenience functions to allow for consistent
+logging.
+
+All convenience functions return C{True}, so they can be used with an assert
+statement to disable logging in optimized code::
+    assert logging.debug("This is not an important message")
+
+Standard Logger
+---------------
+
+Any module can define a standard logger by assigning a string with its name to
+the global variable C{__gnue_logger__}. Each of the convenience functions
+defined here has a variant logging to the standard logger and a variant logging
+to an explicitly named logger.
+
+If the global variable C{__gnue_logger__} is not defined in a module, it is
+searched for in the parent modules. If it isn't found there either, the name of
+the module will be used as the logger name.
+
+Explicit logging
+----------------
+
+The functions L{debug}, L{info}, L{warning}, L{deprecated}, L{error}, and
+L{critical} are available for direct logging to the standard logger with the
+respective log level. The I{deprecated} level is a newly introduced level
+between I{warning} and I{error} to indicate use of a deprecated feature.
+
+The functions L{debug_n}, L{info_n}, L{warning_n}, L{deprecated_n}, L{error_n},
+and L{critical_n} are available for direct logging to an explicitly named
+logger with the respective log level.
+
+Function logging
+----------------
+
+The L{logged_f} and L{logged_f_n} decorators are available to indicate that
+each entry into and exit from this function should be logged with I{debug}
+level. The log message for the function entry contains the values of all
+parameters, the log message for the function exit contains the return value.
+
+Since logging can include time stamps, this is also useful to measure the
+(real, not CPU) time spent in a function.
+
+The L{deprecated_f} and L{deprecated_f_n} decorators can be used to indicate
+that a function is dprecated. Each call to this function will be logged.
+
+Exception handling and stack traces
+-----------------------------------
+
+This module sets an exception hook in module initialization code, which logs
+each unhandled exception to a logger named C{exception.}I{group.name}. This is
+especially useful to direct exceptions to different loggers depending on the
+exception group (C{system}, C{admin}, C{application}, and C{user}).
+
+The functions L{exception} and L{exception_n} are similar to L{error} and
+L{error_n}, but they add a traceback of the currently handled exception to the
+logfile. These functions can be used in an exception handler to log an
+exception before it is processed or discarded.
+
+The functions L{stack} and L{stack_n} log the current call stack I{at any point
+in the code}. This is useful to log how a function was called without raising
+an exception.
 """
 
 import inspect
@@ -35,6 +100,7 @@
 import sys
 import traceback
 
+from gnue.common.lib import modules
 from gnue.common.base import errors, utils
 
 __all__ = ['logged_f', 'deprecated_f',
@@ -46,14 +112,13 @@
         'debug_n', 'info_n', 'warning_n', 'deprecated_n', 'error_n',
         'critical_n']
 
-# TODO:
-# - allow for __gnue_logger__ module global variable to use as a logger name
-#   instead of the module name (make a function in utils.py to search and cache
-#   module global variables in the module hierarchy)
 
+# =============================================================================
+# Function decorators
+# =============================================================================
 
 # -----------------------------------------------------------------------------
-# Function decorators
+# Standard logger
 # -----------------------------------------------------------------------------
 
 def logged_f(func):
@@ -78,6 +143,7 @@
     @return: Function with the logging wrapper.
     @rtype: function
     """
+
     def __new_f(*args, **kwargs):
         name = func.func_globals['__name__']
         __enter(name, func)
@@ -110,13 +176,17 @@
     @return: Function with the deprecation warning wrapper.
     @rtype: function
     """
+
     def __new_f(*args, **kwargs):
         name = func.func_globals['__name__']
         __deprecated(name, func)
         return func(*args, **kwargs)
     return __new_f
 
+
 # -----------------------------------------------------------------------------
+# Explicit logger
+# -----------------------------------------------------------------------------
 
 def logged_f_n(name):
     """
@@ -142,6 +212,7 @@
         above to understand this).
     @rtype: function
     """
+
     def __logged_f(func):
         def __new_f(*args, **kwargs):
             __enter(name, func)
@@ -177,6 +248,7 @@
         usage example above to understand this).
     @rtype: function
     """
+
     def __deprecated_f(func):
         def __new_f(*args, **kwargs):
             __deprecated(name, func)
@@ -184,7 +256,10 @@
         return __new_f
     return __deprecated_f
 
+
 # -----------------------------------------------------------------------------
+# Helper functions
+# -----------------------------------------------------------------------------
 
 def __enter(name, func):
 
@@ -294,6 +369,10 @@
     return fname
 
 
+# =============================================================================
+# Exception handling
+# =============================================================================
+
 # -----------------------------------------------------------------------------
 # Exception hooks
 # -----------------------------------------------------------------------------
@@ -309,6 +388,7 @@
     @param etraceback: Exception traceback
     @type etraceback: traceback
     """
+
     (group, name, message, detail) = errors.format_exception(etype, evalue,
             etraceback)
     logger = "exception.%s.%s" % (group, name)
@@ -317,12 +397,12 @@
 
 
 # -----------------------------------------------------------------------------
-# Exception and call stack logging
+# Exception and call stack logging to standard logger
 # -----------------------------------------------------------------------------
 
 def exception(msg, *args, **kwargs):
     """
-    Log an exception to the logger named after the calling module.
+    Log an exception to the standard logger.
 
     This function can be used in a try...except block to log an exception
     before it is discarded.
@@ -332,19 +412,25 @@
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return exception_n(__caller(), msg, *args, **kwargs)
 
+    __logger().exception(msg, *args, **kwargs)
+    return True
+
 # -----------------------------------------------------------------------------
 
 def stack(msg, *args, **kwargs):
     """
-    Write a debug message to the logger named after the calling module
-    including information about the current call stack.
+    Write a debug message to the standard logger including information about
+    the current call stack.
     """
+
     debug(msg + '\n' + ''.join(traceback.format_stack(
         inspect.currentframe().f_back)), *args, **kwargs)
 
+
 # -----------------------------------------------------------------------------
+# Exception and call stack logging to explicit logger
+# -----------------------------------------------------------------------------
 
 def exception_n(name, msg, *args, **kwargs):
     """
@@ -360,6 +446,7 @@
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
+
     logging.getLogger(name).exception(msg, *args, **kwargs)
     return True
 
@@ -367,102 +454,121 @@
 
 def stack_n(name, msg, *args, **kwargs):
     """
-    Write a debug message to the logger named after the calling module
+    Write a debug message to the logger defined through the C{name} parameter
     including information about the current call stack.
     """
+
     debug_n(name, msg + '\n' + ''.join(traceback.format_stack(
         inspect.currentframe().f_back)), *args, **kwargs)
 
 
 # -----------------------------------------------------------------------------
-# Log to the logger named after the calling module
+# Explicit logging to standard logger
 # -----------------------------------------------------------------------------
 
 def debug(msg, *args, **kwargs):
     """
-    Write a debug message to the logger named after the calling module.
+    Write a debug message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: Always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return debug_n(__caller(), msg, *args, **kwargs)
+    __logger().debug(msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
 def info(msg, *args, **kwargs):
     """
-    Write an info message to the logger named after the calling module.
+    Write an info message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return info_n(__caller(), msg, *args, **kwargs)
+    __logger().info(msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
 def warning(msg, *args, **kwargs):
     """
-    Write a warning message to the logger named after the calling module.
+    Write a warning message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return warning_n(__caller(), msg, *args, **kwargs)
+    __logger().warning(msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
 def deprecated(msg, *args, **kwargs):
     """
-    Write a deprecation warning message to the logger named after the calling
-    module.
+    Write a deprecation warning message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return deprecated_n(__caller(), msg, *args, **kwargs)
+    __logger().log(31, msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
 def error(msg, *args, **kwargs):
     """
-    Write an error message to the logger named after the calling module.
+    Write an error message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return error_n(__caller(), msg, *args, **kwargs)
+    __logger().error(msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
 def critical(msg, *args, **kwargs):
     """
-    Write a critical error message to the logger named after the calling 
module.
+    Write a critical error message to the standard logger.
 
     @param msg: Message to log.
     @type msg: string or unicode
     @return: always True, so the call can be prefixed with assert.
     @rtype: bool
     """
-    return critical_n(__caller(), msg, *args, **kwargs)
+    __logger().critical(msg, *args, **kwargs)
+    return True
 
 # -----------------------------------------------------------------------------
 
-def __caller():
-    return inspect.stack()[2][0].f_globals['__name__']
+__LOGGERS = {}
 
+# -----------------------------------------------------------------------------
 
+def __logger():
+
+    caller_module = modules.caller_module()
+
+    if not __LOGGERS.has_key(caller_module):
+        logger_name = modules.find_global('__gnue_logger__')
+        if logger_name is None:
+            logger_name = caller_module
+        __LOGGERS[caller_module] = logging.getLogger(logger_name)
+
+    return __LOGGERS[caller_module]
+
+
 # -----------------------------------------------------------------------------
-# Log to a certain logger
+# Explicit logging to explicit logger
 # -----------------------------------------------------------------------------
 
 def debug_n(name, msg, *args, **kwargs):
@@ -563,7 +669,7 @@
 
 
 # -----------------------------------------------------------------------------
-# Derivate from standard Logger to output correct caller information
+# Derivate from standard Logger class to output correct caller information
 # -----------------------------------------------------------------------------
 
 class Logger(logging.Logger):