wxWidgets/wxPython/samples/ide/activegrid/util/aglogging.py

#----------------------------------------------------------------------------
# Name:         aglogging.py
# Purpose:      Utilities to help with logging
#
# Author:       Jeff Norton
#
# Created:      01/04/05
# CVS-ID:       $Id$
# Copyright:    (c) 2005 ActiveGrid, Inc.
# License:      wxWindows License
#----------------------------------------------------------------------------

import sys
import os
import re
import traceback
import logging
import logging.config
from activegrid.util.lang import *
import activegrid.util.objutils as objutils
import activegrid.util.sysutils as sysutils
import activegrid.util.appdirs as appdirs

LEVEL_FATAL = logging.FATAL
LEVEL_ERROR = logging.ERROR
LEVEL_WARN = logging.WARN
LEVEL_INFO = logging.INFO
LEVEL_DEBUG = logging.DEBUG

EXCEPTION_INFO = 'exceptionInfo'
loggingInitialized = False

LOG_MODE_IDE = 1
LOG_MODE_TESTRUN = 2
LOG_MODE_RUN = 3
def initLogging(mode, force=False):
    global ag_debugLogger, loggingInitialized
    if (force or not loggingInitialized):
        loggingInitialized = True
        configFile = None
        if (mode == LOG_MODE_IDE):
            configFile = os.getenv("AG_LOGCONFIG_IDE")
        elif (mode == LOG_MODE_TESTRUN):
            configFile = os.getenv("AG_LOGCONFIG_PYTESTRUN")
        else:
            configFile = os.getenv("AG_LOGCONFIG_RUN")
        if ((configFile == None) or not os.path.exists(configFile)):
            if (mode == LOG_MODE_IDE):
                configFile = "IDELog"
            elif (mode == LOG_MODE_TESTRUN):
                configFile = "TestRunLog"
            else:
                configFile = "RunLog"
            configFile = os.path.join(appdirs.getSystemDir(appdirs.AG_LOGS_DIR), "py" + configFile + ".ini")
        if (os.path.exists(configFile)):
            print "Using logging configuration file: %s" % configFile
            fileConfig(configFile)
        else:
            print "*** Cannot find logging configuration file (%s) -- setting default logging level to WARN ***" % (configFile)
            defaultStream = sys.stderr
            if (mode == LOG_MODE_RUN):
                defaultStream = sys.stdout
            handler = logging.StreamHandler(defaultStream)
            handler.setLevel(logging.DEBUG)
            handler.setFormatter(logging.Formatter("%(asctime)s %(name)s %(levelname)s: %(message)s"))
            logging.getLogger().addHandler(handler)
            logging.getLogger().setLevel(logging.WARN)
        ag_debugLogger = logging.getLogger("activegrid.debug")
        ag_debugLogger.setLevel(logging.DEBUG)
        return configFile
    
ag_debugLogger = logging.getLogger("activegrid.debug")

def log(logger, level, msg, *params):
    if (logger == None):
        logger = ag_debugLogger
    apply(logger.log, (level, msg) + params)

def fatal(logger, msg, *params):
    apply(logger.fatal, (msg,) + params)

def error(logger, msg, *params):
    apply(logger.error, (msg,) + params)

def warn(logger, msg, *params):
    apply(logger.warn, (msg,) + params)

def info(logger, msg, *params):
    apply(logger.info, (msg,) + params)

def debug(logger, msg, *params):
    if (logger == None):
        logger = ag_debugLogger
    apply(logger.debug, (msg,) + params)
    
def setLevelFatal(logger):
    logger.setLevel(LEVEL_FATAL)
    
def setLevelError(logger):
    logger.setLevel(LEVEL_ERROR)
    
def setLevelWarn(logger):
    logger.setLevel(LEVEL_WARN)
    
def setLevelInfo(logger):
    logger.setLevel(LEVEL_INFO)
    
def setLevelDebug(logger):
    logger.setLevel(LEVEL_DEBUG)
    
def isEnabledForError(logger):
    return logger.isEnabledFor(LEVEL_ERROR)

def isEnabledForWarn(logger):
    return logger.isEnabledFor(LEVEL_WARN)

def isEnabledForInfo(logger):
    return logger.isEnabledFor(LEVEL_INFO)

def isEnabledForDebug(logger):
    return logger.isEnabledFor(LEVEL_DEBUG)

TEST_MODE_NONE = 0
TEST_MODE_DETERMINISTIC = 1
TEST_MODE_NON_DETERMINISTIC = 2

global agTestMode
agTestMode = TEST_MODE_NONE

def setTestMode(mode):
    global agTestMode
    agTestMode = mode
        
def getTestMode():
    global agTestMode
    return agTestMode
    
def testMode(normalObj, testObj=None, nonDeterministicObj=None):
    testMode = getTestMode()
    if testMode > TEST_MODE_NONE:
        if ((nonDeterministicObj != None) and (testMode == TEST_MODE_NON_DETERMINISTIC)):
            return nonDeterministicObj
        return testObj
    return normalObj

pythonFileRefPattern = asString(r'(?<=File ")[^"]*(#[^#]*")(, line )[0-9]*')
phpFileRefPattern = asString(r'( in ).*#([^#]*#[^ ]*)(?= on line )')
pathSepPattern = os.sep
if (pathSepPattern == "\\"):
    pathSepPattern = "\\\\"
pythonFileRefPattern = pythonFileRefPattern.replace("#", pathSepPattern)
pythonFileRefPattern = re.compile(pythonFileRefPattern)
phpFileRefPattern = phpFileRefPattern.replace("#", pathSepPattern)
phpFileRefPattern = re.compile(phpFileRefPattern)

def removeFileRefs(str):
    str = pythonFileRefPattern.sub(_fileNameReplacement, str)
    str = phpFileRefPattern.sub(_fileNameReplacementPHP, str)
    return str
    
def removePHPFileRefs(str):
    str = phpFileRefPattern.sub(_fileNameReplacementPHP, str)
    return str
    
def _fileNameReplacement(match):
    return "...%s" % match.group(1).replace(os.sep, "/")
    
def _fileNameReplacementPHP(match):
    return "%s...%s" % (match.group(1), match.group(2).replace(os.sep, "/"))
    
def formatTraceback(tb=None):
    if (tb == None):
        extype, val, tb = sys.exc_info()
    tbs = "\n" + "".join(traceback.format_tb(tb))
    return tbs

def formatExceptionCause(cause, stacktrace=False):
    if (cause == None):
        return ""
    tbs = ""
    if (stacktrace):
        tbs = formatTraceback()
    return "Caused by %s.%s: %s%s" % (cause.__module__, cause.__class__.__name__, str(cause), tbs)

def addExceptionInfo(e, key, value):
    if not hasattr(e, EXCEPTION_INFO):
        try:
            setattr(e, EXCEPTION_INFO, {})
        except:
            return # Make sure we still report the real exception even if we can't add the extra info
    if not e.exceptionInfo.has_key(key): # Never overwrite exception info since we assume earlier info is more specific
        e.exceptionInfo[key] = value
            
def reportException(exception, out=None, stacktrace=False, diffable=False):
    exstr = exceptionToString(exception, stacktrace, diffable)
    if (out == None):
        print exstr
    else:
        print >> out, exstr

def exceptionToString(exception, stacktrace=False, diffable=False):
    extype = objutils.typeToString(exception)
    val = exception
    if (stacktrace):
        e,v,t = sys.exc_info()
    if (diffable):
        exstr = removeFileRefs(str(val))
    else:
        exstr = str(val)
    if hasattr(val, EXCEPTION_INFO):
        firstTime = True
        for infoKey, infoValue in getattr(val, EXCEPTION_INFO).items():
            if firstTime:
                prefix = " EXTRA INFO:"
                firstTime = False
            else:
                prefix = ","
            exstr += ("%s %s=%s" % (prefix, infoKey, infoValue))
    result = "Got Exception = %s: %s" % (extype, exstr)
    if (stacktrace):
        fmt = traceback.format_exception(extype, val, t)
        for s in fmt:
            if (diffable):
                s = removeFileRefs(s)
            result = result + "\n" + s
    return result
    
def fileConfig(fname, defaults=None):
    """
    This is copied from logging.config so that we could fix the class lookup of
    handlers.  Previously handlers had to be defined in logging.handlers and we
    need to be able to define our own.
    """
    import ConfigParser, string

    cp = ConfigParser.ConfigParser(defaults)
    if hasattr(cp, 'readfp') and hasattr(fname, 'readline'):
        cp.readfp(fname)
    else:
        cp.read(fname)
    #first, do the formatters...
    flist = cp.get("formatters", "keys")
    if len(flist):
        flist = string.split(flist, ",")
        formatters = {}
        for form in flist:
            sectname = "formatter_%s" % form
            opts = cp.options(sectname)
            if "format" in opts:
                fs = cp.get(sectname, "format", 1)
            else:
                fs = None
            if "datefmt" in opts:
                dfs = cp.get(sectname, "datefmt", 1)
            else:
                dfs = None
            f = logging.Formatter(fs, dfs)
            formatters[form] = f
    #next, do the handlers...
    #critical section...
    logging._acquireLock()
    try:
##        try:
            #first, lose the existing handlers...
            logging._handlers.clear()
            #now set up the new ones...
            hlist = cp.get("handlers", "keys")
            if len(hlist):
                hlist = string.split(hlist, ",")
                handlers = {}
                fixups = [] #for inter-handler references
                for hand in hlist:
##                    try:
                        sectname = "handler_%s" % hand
                        classname = cp.get(sectname, "class")
                        opts = cp.options(sectname)
                        if "formatter" in opts:
                            fmt = cp.get(sectname, "formatter")
                        else:
                            fmt = ""
                        klass = None
                        try:
                            klass = eval(classname, vars(logging))
                        except:
                            pass
                        if (klass == None):
                            klass = objutils.classForName(classname)
                        args = cp.get(sectname, "args")
                        args = eval(args, vars(logging))
                        h = apply(klass, args)
                        if "level" in opts:
                            level = cp.get(sectname, "level")
                            h.setLevel(logging._levelNames[level])
                        if len(fmt):
                            h.setFormatter(formatters[fmt])
                        #temporary hack for FileHandler and MemoryHandler.
                        if klass == logging.handlers.MemoryHandler:
                            if "target" in opts:
                                target = cp.get(sectname,"target")
                            else:
                                target = ""
                            if len(target): #the target handler may not be loaded yet, so keep for later...
                                fixups.append((h, target))
                        handlers[hand] = h
##                    except Exception, e:     #if an error occurs when instantiating a handler, too bad
##                        pass    #this could happen e.g. because of lack of privileges
                #now all handlers are loaded, fixup inter-handler references...
                for fixup in fixups:
                    h = fixup[0]
                    t = fixup[1]
                    h.setTarget(handlers[t])
            #at last, the loggers...first the root...
            llist = cp.get("loggers", "keys")
            llist = string.split(llist, ",")
            llist.remove("root")
            sectname = "logger_root"
            root = logging.root
            log = root
            opts = cp.options(sectname)
            if "level" in opts:
                level = cp.get(sectname, "level")
                log.setLevel(logging._levelNames[level])
            for h in root.handlers[:]:
                root.removeHandler(h)
            hlist = cp.get(sectname, "handlers")
            if len(hlist):
                hlist = string.split(hlist, ",")
                for hand in hlist:
                    log.addHandler(handlers[hand])
            #and now the others...
            #we don't want to lose the existing loggers,
            #since other threads may have pointers to them.
            #existing is set to contain all existing loggers,
            #and as we go through the new configuration we
            #remove any which are configured. At the end,
            #what's left in existing is the set of loggers
            #which were in the previous configuration but
            #which are not in the new configuration.
            existing = root.manager.loggerDict.keys()
            #now set up the new ones...
            for log in llist:
                sectname = "logger_%s" % log
                qn = cp.get(sectname, "qualname")
                opts = cp.options(sectname)
                if "propagate" in opts:
                    propagate = cp.getint(sectname, "propagate")
                else:
                    propagate = 1
                logger = logging.getLogger(qn)
                if qn in existing:
                    existing.remove(qn)
                if "level" in opts:
                    level = cp.get(sectname, "level")
                    logger.setLevel(logging._levelNames[level])
                for h in logger.handlers[:]:
                    logger.removeHandler(h)
                logger.propagate = propagate
                logger.disabled = 0
                hlist = cp.get(sectname, "handlers")
                if len(hlist):
                    hlist = string.split(hlist, ",")
                    for hand in hlist:
                        logger.addHandler(handlers[hand])
            #Disable any old loggers. There's no point deleting
            #them as other threads may continue to hold references
            #and by disabling them, you stop them doing any logging.
            for log in existing:
                root.manager.loggerDict[log].disabled = 1
##        except:
##            import traceback
##            ei = sys.exc_info()
##            traceback.print_exception(ei[0], ei[1], ei[2], None, sys.stderr)
##            del ei
    finally:
        logging._releaseLock()