code: def timed_do_fn(f):
      
      def wrap(callable, *args, **kwargs):
          global _debug_id
  
          # get a description of the function that called us
          st = traceback.extract_stack(limit=2)
          file, line, name, _ = st[0]
  
          # and its locals
          frame = inspect.currentframe()
          locals = frame.f_locals
  
          # invent a unique ID for the description
          id, _debug_id = _debug_id, _debug_id + 1
  
          descr = "%s-%08x" % (name, id)
  
          start_time = time.time()
          log.msg("%s - before ('%s' line %d)" % (descr, file, line))
          for name in locals:
              if name in ('self', 'thd'):
                  continue
              log.msg("%s -   %s = %r" % (descr, name, locals[name]))
  
          # wrap the callable to log the begin and end of the actual thread
          # function
          def callable_wrap(*args, **kargs):
              log.msg("%s - thd start" % (descr,))
              try:
                  return callable(*args, **kwargs)
              finally:
                  log.msg("%s - thd end" % (descr,))
          d = f(callable_wrap, *args, **kwargs)
  
          @d.addBoth
          def after(x):
              end_time = time.time()
              elapsed = (end_time - start_time) * 1000
              log.msg("%s - after (%0.2f ms elapsed)" % (descr, elapsed))
              return x
          return d
      wrap.__name__ = f.__name__
      wrap.__doc__ = f.__doc__
      return wrap
docs: Decorate a do function to log before, after, and elapsed time,
      with the name of the calling function.  This is not speedy!