Second stage debugging:

started seriously using celery ⇒ deadlocks, memory leaks

• strace
  • not enough context in strace (who does that syscall? hard to tell)
• gdb
  • practically only useful for seeing the current stacktrace
  • fussy (needs debug symbols, debug builds of python)
• prints (still), manual monkeypatching
  • still tedious

Second stage debugging:

started seriously using celery ⇒ deadlocks, memory leaks

• manual tracer

  
  

  def mytracer(frame, event, args):
      print(frame.f_code.co_filename, ...
  
  import sys
  sys.settrace(mytracer)
  

  
  
  • slow as hell
  • still tedious (messy code, inconvenient to install)

Third stage debugging:

tool smithing (circa 2014)

• aspectlib (usecase: deadlocks) - fancy-pants monkeypatching to replace the previous tedious patch code

  
  

  aspectlib.weave('absolutely.anything.anywhere', aspectlib.debug.log,
                  subclasses=True, methods=NORMAL_METHODS,
                  lazy=False, aliases=True)
  

  
  
  • was too brittle (what to patch? which patching options? ⇒ non-portable configuration)

• manhole (usecase: memory leaks) - robust debugging shell (inspired by twisted.manole but no big dependencies, no insecure stuff)

Fourth stage debugging:

circling back to tracers (circa 2015)

• hunter (replacement for the fussy aspectlib) - tracer toolkit made to:
  • avoid dealing with the boring parts (getting the sys.settrace api right, figuring out all the f_/co_ fields, printing stuff etc) so you can focus on that nasty bug
  • not slow down your app a lot
  • have easy setup (env var activation, remote attach)
  • try really hard to not have side-effects

The defaults:

• Variables are displayed with a custom repr to avoid side-effects
• threading_support=False

It's verbose ("function" over "func", "CallPrinter" over "Print")

• clarity (not to confuse with the print builtin)
• extensibility (initially there was CodePrinter, then CallPrinter was added)
• helpers/brief api layer can be added later

Get a tree with just the calls/returns/exceptions:

trace(
    ~Q(kind="line"),
    ~Q(module_in=["six","pkg_resources"]),
    ~Q(module_contains=["importlib"]),
    ~Q(filename=""),
    stdlib=False
)

Breakpoints:

trace(
    Q(lambda ev: ev.locals.get("host") == "localhost", action=Debugger),
    module="redis.client"
)

def error():
    raise RuntimeError()

def silenced1():
    try:
        error()
    except Exception:
        pass

def silenced2():
    try:
        error()
    except Exception as exc:
        pass
    return 'x'

def silenced3():
    try:
        error()
    finally:
        return "mwhahaha"

Doesn't help:

grep -A 5 -R "except:" .

What if you could detect this with a tracer, instead of reading all the code?

The plan:

• show all exceptions
• show what happens until function returns
• but with a limit
  • no more than 10 events
  • don't drill into calls

class PlainDumpExceptions(hunter.CodePrinter):
    should_trace = False
    depth = 0
    count = 0
    def __call__(self, event):
        self.count += 1
        if event.kind == 'exception':  # something interesting happened ;)
            self.should_trace = True
            self.depth = event.depth
            self.count = 0
            self.output("{} tracing on exception: {}\n",
                        ">" * 46, self._try_repr(event.arg[1]))
            super(DumpExceptions, self).__call__(event)
        elif self.should_trace:
            super(DumpExceptions, self).__call__(event)
            if event.kind == 'return':  # stop if function returned
                self.should_trace = False
                self.output("{} function exit\n", "-" * 46)
            elif event.depth > self.depth + 1:  # too many details
                return
            elif self.count > 10:  # bail out on too many lines
                self.should_trace = False
                self.output("{:>46} too many lines\n", "-" * 46)

What's missing?

Colors:

self.output("{BRIGHT}{fore(BLUE)} ...",  ...

Skip cases where exception is reraised?

• Buffer up all the events up to a return
• If return is bad (not a reraise) dump all the events.

self.events.append(event)

Has some problems:

• Will hold reference to frame, local and global variables. Can create side-effects, eg:
  • Finalizers not called (files not closing, __del__ not called etc)
  • Weakref callbacks not called

Solution: strip event of "live" data like event.arg, event.globals, event.locals - who needs those?

self.events.append(event.detach())

Stripping event of "live" data:

self.events.append(event.detach())

Has some problems:

• call arguments are in event.locals
• return value is in event.arg

Solution: sanitize values by converting to string representations (we don't need anything else anyway):

self.events.append(event.detach(self.try_repr))

The usecase:

• big app, complete tracing would slow it too much
• want to look inside few functions

Solution:

• monkeypatch the interesting functions to have a tracer around them

def probe(qualname, *actions, **filters):
    def tracing_decorator(func):
        @functools.wraps(func)
        def tracing_wrapper(*args, **kwargs):
            # create the Tracer manually to avoid spending time
            # in likely useless things like:
            # - loading PYTHONHUNTERCONFIG
            # - setting up the clear_env_var or thread_support options
            # - atexit cleanup registration
            with hunter.Tracer().trace(
                hunter.When(hunter.Query(**filters), *actions)
            ):
                return func(*args, **kwargs)

        return tracing_wrapper

    aspectlib.weave(qualname, tracing_decorator)
    # module.func = tracing_decorator(module.func)

probe('module.func',
      hunter.VarsPrinter('var1', 'var2'),
      kind="return", depth=0)