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): _______________________________________________ commit-gnue mailing list commit-gnue@gnu.org http://lists.gnu.org/mailman/listinfo/commit-gnue