diff --git a/docs/changes.rst b/docs/changes.rst index a01eb1c7..a36ee180 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -88,6 +88,10 @@ backends: - Added support for search by filename to local backend. +- Added optional background thread for debugging deadlocks. When the feature is + enabled via the ``--debug-thread`` or ``settings.DEBUG_THREAD`` a ``SIGUSR1`` + signal will dump the traceback for all running threads. + **Bug fixes** - :issue:`218`: The MPD commands ``listplaylist`` and ``listplaylistinfo`` now diff --git a/docs/development.rst b/docs/development.rst index 6cab7bf1..00a1d46a 100644 --- a/docs/development.rst +++ b/docs/development.rst @@ -284,6 +284,17 @@ Using this setup you can now run Mopidy with ``PROFILE=silent,spotify mopidy`` if you for instance want to test Spotify without any actual audio output. +Debugging deadlocks +=================== + +Between the numerous pykka threads and gstreamer interactions there can +sometimes be a potential for deadlocks. In an effort to make these slightly +simpler to debug ``settings.DEBUG_THREAD`` or ``--debug-thread`` +can be used to turn on an extra debug thread. This thread is not linked to +the regular program flow, and it's only task is to dump traceback showing +the other threads state when we get a ``SIGUSR1``. + + Writing documentation ===================== diff --git a/mopidy/__main__.py b/mopidy/__main__.py index 75f847e4..de905d15 100644 --- a/mopidy/__main__.py +++ b/mopidy/__main__.py @@ -41,8 +41,15 @@ logger = logging.getLogger('mopidy.main') def main(): signal.signal(signal.SIGTERM, process.exit_handler) + loop = gobject.MainLoop() options = parse_options() + + if options.debug_thread or settings.DEBUG_THREAD: + debug_thread = process.DebugThread() + debug_thread.start() + signal.signal(signal.SIGUSR1, debug_thread.handler) + try: log.setup_logging(options.verbosity_level, options.save_debug_log) check_old_folders() @@ -99,6 +106,10 @@ def parse_options(): '--list-deps', action='callback', callback=deps.list_deps_optparse_callback, help='list dependencies and their versions') + parser.add_option( + '--debug-thread', + action='store_true', dest='debug_thread', + help='run background thread that dumps tracebacks on SIGUSR1') return parser.parse_args(args=mopidy_args)[0] diff --git a/mopidy/settings.py b/mopidy/settings.py index fbc71f0e..12acd281 100644 --- a/mopidy/settings.py +++ b/mopidy/settings.py @@ -45,6 +45,14 @@ DEBUG_LOG_FORMAT = u'%(levelname)-8s %(asctime)s' + \ #: DEBUG_LOG_FILENAME = u'mopidy.log' DEBUG_LOG_FILENAME = u'mopidy.log' +#: If we should start a background thread that dumps thread's traceback when we +#: get a SIGUSR1. Mainly a debug tool for figuring out deadlocks. +#: +#: Default:: +#: +#: DEBUG_THREAD = False +DEBUG_THREAD = False + #: Location of the Mopidy .desktop file. #: #: Used by :mod:`mopidy.frontends.mpris`. diff --git a/mopidy/utils/process.py b/mopidy/utils/process.py index b3f90150..c6b27533 100644 --- a/mopidy/utils/process.py +++ b/mopidy/utils/process.py @@ -1,7 +1,9 @@ import logging import signal +import sys import thread import threading +import traceback from pykka import ActorDeadError from pykka.registry import ActorRegistry @@ -10,6 +12,8 @@ from mopidy import exceptions logger = logging.getLogger('mopidy.utils.process') +SIGNALS = dict((k, v) for v, k in signal.__dict__.iteritems() + if v.startswith('SIG') and not v.startswith('SIG_')) def exit_process(): logger.debug(u'Interrupting main...') @@ -19,9 +23,7 @@ def exit_process(): def exit_handler(signum, frame): """A :mod:`signal` handler which will exit the program on signal.""" - signals = dict((k, v) for v, k in signal.__dict__.iteritems() - if v.startswith('SIG') and not v.startswith('SIG_')) - logger.info(u'Got %s signal', signals[signum]) + logger.info(u'Got %s signal', SIGNALS[signum]) exit_process() @@ -71,3 +73,27 @@ class BaseThread(threading.Thread): def run_inside_try(self): raise NotImplementedError + +class DebugThread(threading.Thread): + daemon = True + name = 'DebugThread' + + event = threading.Event() + + def handler(self, signum, frame): + logger.info(u'Got %s signal', SIGNALS[signum]) + self.event.set() + + def run(self): + while True: + self.event.wait() + threads = dict((t.ident, t.name) for t in threading.enumerate()) + + for ident, frame in sys._current_frames().items(): + if self.ident != ident: + stack = ''.join(traceback.format_stack(frame)) + logger.debug('Current state of %s (%s):\n%s', + threads[ident], ident, stack) + del frame + + self.event.clear()