Ticket #1089: sugar-base-trace.patch

src/sugar/logger.py

@@ -20 +20 @@
 STABLE.
 """
 
+import __builtin__
+import array
+import collections
 import errno
+import logging
 import sys
 import os
-import logging
+import repr
+import decorator
+
+
+# new loglevel TRACE for tracing function calls
+# use SUGAR_LOGGER_LEVEL=trace to enable
+TRACE=5
+logging.addLevelName(TRACE, 'TRACE')
+
 
 # Let's keep this self contained so that it can be easily
 # pasted in external sugar service like the datastore.
@@ -38 +50 @@
 _levels = { 'error'   : logging.ERROR,
             'warning' : logging.WARNING,
             'debug'   : logging.DEBUG,
-            'info'    : logging.INFO }
+            'info'    : logging.INFO,
+            'trace'   : TRACE,
+            'all'     : 0,
+}
 def set_level(level):
     if level in _levels:
         logging.getLogger('').setLevel(_levels[level])
@@ -61 +76 @@
         sys.excepthook = sys.__excepthook__
 
     sys.excepthook(exctype, value, traceback)
-        
+
 def start(log_filename=None):
     # remove existing handlers, or logging.basicConfig() won't have no effect.
     root_logger = logging.getLogger('')
     for handler in root_logger.handlers:
         root_logger.removeHandler(handler)
-    
+
     class SafeLogWrapper(object):
         """Small file-like wrapper to gracefully handle ENOSPC errors when
         logging."""
@@ -116 +131 @@
 
     sys.excepthook = _except_hook
 
+
+class TraceRepr(repr.Repr) :
+
+    # better handling of subclasses of basic types, e.g. for DBus
+    _types = [int, long, bool, tuple, list, array.array, set, frozenset,
+        collections.deque, dict, str]
+    def repr1(self, x, level):
+        for t in self._types :
+            if isinstance(x, t) :
+                return getattr(self, 'repr_'+t.__name__)(x, level)
+
+        return repr.Repr.repr1(self, x, level)
+
+    def repr_int(self, x, level) :
+        return __builtin__.repr(x)
+
+    def repr_bool(self, x, level) :
+        return __builtin__.repr(x)
+
+
+def trace(logger=None, logger_name=None, skip_args=[], skip_kwargs=[],
+    maxsize_list=30, maxsize_dict=30, maxsize_string=300) :
+
+    # size-limit repr()
+    _trace_repr = TraceRepr()
+    _trace_repr.maxlist = maxsize_list
+    _trace_repr.maxdict = maxsize_dict
+    _trace_repr.maxstring = maxsize_string
+    _trace_repr.maxother = maxsize_string
+    _trace_logger = logger or logging.getLogger(logger_name)
+
+    def _trace(f, *args, **kwargs) :
+        # don't do expensive formatting if loglevel TRACE is not enabled
+        enabled = _trace_logger.isEnabledFor(TRACE)
+        if enabled :
+            params_formatted = ", ".join(
+                [_trace_repr.repr(a)
+                    for (idx, a) in enumerate(args) if idx not in skip_args]+\
+                ['%s=%s' % (k,_trace_repr.repr(v))
+                    for (k,v) in kwargs.items() if k not in skip_kwargs])
+
+            _trace_logger.log(TRACE, "%s(%s) invoked", f.__name__,
+                params_formatted)
+
+        try :
+            res=f(*args, **kwargs)
+        except :
+            _trace_logger.exception("Exception occured in %s", f.__name__)
+            raise
+
+        if enabled :
+            _trace_logger.log(TRACE, "%s(%s) returned %s", f.__name__,
+                params_formatted, _trace_repr.repr(res))
+
+        return res
+
+    return decorator.decorator(_trace)
+
+