# Debug helpers

Debug helpers.

pykka.debug.log_thread_tracebacks(*_args: Any, **_kwargs: Any) → None

  Log a traceback for each running thread at `logging.CRITICAL` level.

  This can be a convenient tool for debugging deadlocks.

  The function accepts any arguments so that it can easily be used as e.g. a signal handler, but it does not use the arguments for anything.

  To use this function as a signal handler, setup logging with a `logging.CRITICAL` threshold or lower and make your main thread register this with the `signal` module:

      import logging
      import signal

      import pykka.debug

      logging.basicConfig(level=logging.DEBUG)
      signal.signal(signal.SIGUSR1, pykka.debug.log_thread_tracebacks)

  If your application deadlocks, send the SIGUSR1 signal to the process:

      kill -SIGUSR1 <pid of your process>

  Signal handler caveats:

  - The function must be registered as a signal handler by your main thread. If not, `signal.signal()` will raise a `ValueError`.

  - All signals in Python are handled by the main thread. Thus, the signal will only be handled, and the tracebacks logged, if your main thread is available to do some work. Making your main thread idle using `time.sleep()` is OK. The signal will awaken your main thread. Blocking your main thread on e.g. `queue.Queue.get()` or `pykka.Future.get()` will break signal handling, and thus you won’t be able to signal your process to print the thread tracebacks.

  The morale is: setup signals using your main thread, start your actors, then let your main thread relax for the rest of your application’s life cycle.

  Added in version 1.1.

## Deadlock debugging

This is a complete example of how to use `log_thread_tracebacks()` to debug deadlocks:

    #!/usr/bin/env python3

    import logging
    import os
    import signal
    import time

    import pykka
    import pykka.debug

    class DeadlockActorA(pykka.ThreadingActor):
        def foo(self, b):
            logging.debug("This is foo calling bar")
            return b.bar().get()

    class DeadlockActorB(pykka.ThreadingActor):
        def __init__(self, a):
            super().__init__()
            self.a = a

        def bar(self):
            logging.debug("This is bar calling foo; BOOM!")
            return self.a.foo().get()

    if __name__ == "__main__":
        print("Setting up logging to get output from signal handler...")
        logging.basicConfig(level=logging.DEBUG)

        print("Registering signal handler...")
        signal.signal(signal.SIGUSR1, pykka.debug.log_thread_tracebacks)

        print("Starting actors...")
        a = DeadlockActorA.start().proxy()
        b = DeadlockActorB.start(a).proxy()

        print("Now doing something stupid that will deadlock the actors...")
        a.foo(b)

        time.sleep(0.01)  # Yield to actors, so we get output in a readable order

        pid = os.getpid()
        print("Making main thread relax; not block, not quit")
        print(f"1) Use `kill -SIGUSR1 {pid:d}` to log thread tracebacks")
        print(f"2) Then `kill {pid:d}` to terminate the process")
        while True:
            time.sleep(1)

Running the script outputs the following:

    Setting up logging to get output from signal handler...
    Registering signal handler...
    Starting actors...
    DEBUG:pykka:Registered DeadlockActorA (urn:uuid:60803d09-cf5a-46cc-afdc-0c813e2e6647)
    DEBUG:pykka:Starting DeadlockActorA (urn:uuid:60803d09-cf5a-46cc-afdc-0c813e2e6647)
    DEBUG:pykka:Registered DeadlockActorB (urn:uuid:626adc83-ae35-439c-866a-85a3e29fd42c)
    DEBUG:pykka:Starting DeadlockActorB (urn:uuid:626adc83-ae35-439c-866a-85a3e29fd42c)
    Now doing something stupid that will deadlock the actors...
    DEBUG:root:This is foo calling bar
    DEBUG:root:This is bar calling foo; BOOM!
    Making main thread relax; not block, not quit
    1) Use `kill -SIGUSR1 2284` to log thread tracebacks
    2) Then `kill 2284` to terminate the process

The two actors are now deadlocked waiting for each other while the main thread is idling, ready to process any signals.

To debug the deadlock, send the `SIGUSR1` signal to the process, which has PID 2284 in this example:

    kill -SIGUSR1 2284

This makes the main thread log the current traceback for each thread. The logging output shows that the two actors are both waiting for data from the other actor:

    CRITICAL:pykka:Current state of DeadlockActorB-2 (ident: 140151493752576):
    File "/usr/lib/python3.6/threading.py", line 884, in _bootstrap
        self._bootstrap_inner()
    File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
        self.run()
    File "/usr/lib/python3.6/threading.py", line 864, in run
        self._target(*self._args, **self._kwargs)
    File ".../pykka/actor.py", line 195, in _actor_loop
        response = self._handle_receive(message)
    File ".../pykka/actor.py", line 297, in _handle_receive
        return callee(*message['args'], **message['kwargs'])
    File "examples/deadlock_debugging.py", line 25, in bar
        return self.a.foo().get()
    File ".../pykka/threading.py", line 47, in get
        self._data = self._queue.get(True, timeout)
    File "/usr/lib/python3.6/queue.py", line 164, in get
        self.not_empty.wait()
    File "/usr/lib/python3.6/threading.py", line 295, in wait
        waiter.acquire()

    CRITICAL:pykka:Current state of DeadlockActorA-1 (ident: 140151572883200):
    File "/usr/lib/python3.6/threading.py", line 884, in _bootstrap
        self._bootstrap_inner()
    File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
        self.run()
    File "/usr/lib/python3.6/threading.py", line 864, in run
        self._target(*self._args, **self._kwargs)
    File ".../pykka/actor.py", line 195, in _actor_loop
        response = self._handle_receive(message)
    File ".../pykka/actor.py", line 297, in _handle_receive
        return callee(*message['args'], **message['kwargs'])
    File "examples/deadlock_debugging.py", line 15, in foo
        return b.bar().get()
    File ".../pykka/threading.py", line 47, in get
        self._data = self._queue.get(True, timeout)
    File "/usr/lib/python3.6/queue.py", line 164, in get
        self.not_empty.wait()
    File "/usr/lib/python3.6/threading.py", line 295, in wait
        waiter.acquire()

    CRITICAL:pykka:Current state of MainThread (ident: 140151593330496):
    File ".../examples/deadlock_debugging.py", line 49, in <module>
        time.sleep(1)
    File ".../pykka/debug.py", line 63, in log_thread_tracebacks
        stack = ''.join(traceback.format_stack(frame))