From 00d5e9272667605c6b5bb83746dcdea54bfa3977 Mon Sep 17 00:00:00 2001 From: John Dennis Date: Mon, 12 Jan 2015 10:47:37 -0500 Subject: Add source code context information to debug log messages The log.debug() function helpfully adds the name of the function invoking it but in a complicated software package there are many functions/methods which share the same name. Thus a debug message lke this: DEBUG(__init__): xxx does not give you much context, there are probably hundreds of __init__ methods. It would help to qualify the method name which it's class name, that gives a lot more context when reading the log. Sometimes it's also helpful to know the file and line number. This patch adds the class name to the function and included the filename and line number as well. The file path is trimmed to the last 3 components, sufficient to give context but not too verbose. Now the debug message might look like this instead: DEBUG(ipsilon/providers/common.py:129 LoadProviders.__init__()): xxx Also included is a config option 'stacktrace_on_error' which will include a stacktrace when the log.error function is called. It can be very useful to see a stacktrace when logging an error, it defaults to off. Signed-off-by: John Dennis --- ipsilon/util/log.py | 67 ++++++++++++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 64 insertions(+), 3 deletions(-) diff --git a/ipsilon/util/log.py b/ipsilon/util/log.py index fb2c620..2001675 100644 --- a/ipsilon/util/log.py +++ b/ipsilon/util/log.py @@ -3,15 +3,74 @@ # See the file named COPYING for the project license import cherrypy +import cStringIO import inspect - +import os +import traceback class Log(object): + @staticmethod + def stacktrace(): + buf = cStringIO.StringIO() + + stack = traceback.extract_stack() + traceback.print_list(stack[:-2], file=buf) + + stacktrace_string = buf.getvalue() + buf.close() + return stacktrace_string + + @staticmethod + def get_class_from_frame(frame_obj): + ''' + Taken from: + http://stackoverflow.com/questions/2203424/ + python-how-to-retrieve-class-information-from-a-frame-object + + At the frame object level, there does not seem to be any way + to find the actual python function object that has been + called. + + However, if your code relies on the common convention of naming + the instance parameter of a method self, then you could do this. + ''' + + args, _, _, value_dict = inspect.getargvalues(frame_obj) + # Is the functions first parameter named 'self'? + if len(args) and args[0] == 'self': + # in that case, 'self' will be referenced in value_dict + instance = value_dict.get('self', None) + if instance: + # return its class + return getattr(instance, '__class__', None) + # return None otherwise + return None + + @staticmethod + def call_location(): + frame = inspect.stack()[2] + frame_obj = frame[0] + filename = frame[1] + line_number = frame[2] + func = frame[3] + + # Only report the last 3 components of the path + filename = os.sep.join(filename.split(os.sep)[-3:]) + + cls = Log.get_class_from_frame(frame_obj) + if cls: + location = '%s:%s %s.%s()' % \ + (filename, line_number, cls.__name__, func) + else: + location = '%s:%s %s()' % (filename, line_number, func) + return location + + def debug(self, fact): if cherrypy.config.get('debug', False): - s = inspect.stack() - cherrypy.log('DEBUG(%s): %s' % (s[1][3], fact)) + location = Log.call_location() + cherrypy.log('DEBUG(%s): %s' % (location, fact)) # for compatibility with existing code _debug = debug @@ -21,3 +80,5 @@ class Log(object): def error(self, fact): cherrypy.log.error('ERROR: %s' % fact) + if cherrypy.config.get('stacktrace_on_error', False): + cherrypy.log.error(Log.stacktrace()) -- cgit