Stack Traces in Python Threads
I mentioned before that I'm using XMLRPC to debug a mutli-threaded Python application.
One of the things I'd like to get from this new debugging tool is a stack trace for the various threads my application is running. Sometimes, it appears to get stuck, and I'd like to know what it's doing. A deadlock of some sort is a likely cause, but I would really like to know where that deadlock is happening, and log output is not quite as detailed as I'd like, plus adding more logging just to tell me where I am required frequent restarts, which is a major drag.
It seems, however, that there is no way in Python to get a list of all running threads. Nor can you, from one thread, get a stack trace for another thread. However, in my program, I'm creating a set of worker threads, and I'm keeping track of them already, so I don't have to ask for a list of all of the threads. The trick part is then to get stack traces from these threads. Lacking the ability to inspect another thread directly, I found that Python's tracing utilities, which facilitate the Python debugging and profiling tools, can be used to get that information. Each worker thread calls sys.settrace(self._trace) in its run() method, and implements this tracing method:
def _trace(self, frame, event, arg):
self._frame = frame
In the main thread, a status() method returns a trace for each thread:
def status(self):
import inspect
self._lock.acquire()
try:
status = "Available threads:\n"
for worker in self._available_threads:
status = status + " " + worker.getName() + ":\n"
frame = worker._frame
if frame:
status = status + " stack:\n"
for frame, filename, line, function_name, context, index in inspect.getouterframes(frame):
status = status + " " + function_name + " @ " + filename + " # " + str(line) + "\n"
status = status + "\n"
return status
finally:
self._lock.release()
I'm building up a string here because it's a return value that can be sent over XMLRPC and printed. Structured data may be more useful, but hopefully you get the idea. Now I can not only inspect my programs state remotely, but see exactly what it's doing:
[bluntman:~] wsanchez% python
Python 2.3 (#1, Sep 13 2003, 00:49:11)
[GCC 3.3 20030304 (Apple Computer, Inc. build 1495)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import xmlrpclib
>>> p = xmlrpclib.ServerProxy("http://localhost:8001", allow_none = 1)
>>> p.status()
Available threads:
thread01:
stack:
_release_save@/System/Library/Frameworks/Python.framework/Versions/2.3/lib/python2.3/threading.py#181
wait@/System/Library/Frameworks/Python.framework/Versions/2.3/lib/python2.3/threading.py#223
wait@/System/Library/Frameworks/Python.framework/Versions/2.3/lib/python2.3/threading.py#350
run@/Users/wsanchez/Python/test/Manager.py#20
__bootstrap@/System/Library/Frameworks/Python.framework/Versions/2.3/lib/python2.3/threading.py#436
One downside to this approach is that we're now incurring a fair bit of overhead because of all of the tracing; every statement the runtime executes now includes invoking the trace method and storing the frame. If performance is a concern, this can be problematic. However, it's easy enough to comment out the sys.settrace() call and uncomment it only when this level of debugging is desired.
Comments
if not wheel.reinvent() .. :)
If you're using the "high level" threading package, you have threading.enumerate() which will return a list of all active or in-limbo (in the process of starting) Thread instances. You can also threading.settrace(func) which will set a trace hook for all threads started from then on (but you obviously can't do that for threads that already exist).
Do you really need to write a multithreaded Python application in the first place? There are good frameworks (plug: Twisted) for doing most things asynchronously. Most of the async ones even have ways to actually do threads behind the scenes for you in a sane way when you really do need them to call some blocking C function (plug: Twisted).
Posted by: Bob Ippolito | June 9, 2004 02:30 PM
The threadframe module should give you what you want.
I wrote it to debug deadlocks in multi-threaded CORBA servers (using omniORB).
Posted by: Fazal Majid | June 9, 2004 02:37 PM
Bob:
I'm aware of threading.settrace, but that sets one function up for all threads. I want to be able to ask each thread for its stack frame, so I find it prefereable to instead call sys.settrace() in the run() method and have it register a method on the thread which can store the frame as an ivar in the thread. The difference is mostly cosmetic, but it at least limits the tracing to threads I'm interested in, possible cutting down on the tracing overhead.
I managed to miss threading.enumerate() in the docs. If there was also a way to inspect another thread's stack, that'd be the right way to add gdb-like thread inspection. But I'm tracking my threads anyway, and since I only want to trace specific threads, I don't think a list of all threads is useful in my case.
As to why threads… Yes, Twisted sounds really cool. But Twisted is a large framework which I haven't gotten my head around (yet; will when I have time), and what I'm doing doesn't seem complicated enough to justify adding another dependancy into my project. Perhaps I'll have a change of heart when I have time to play with it.
I'm not threading work out in order to handle concurrent networking requests (I run the XMLRPC server in a single SocketServer thread, not with the multi-threaded mix-in), but I need several tasks doing both network and disk I/O tasks which are very long-lived. The threads thing is working out pretty well for me, modulo a couple of small hang-ups which this tracing business is helped me track down pretty readily.
Posted by: Wilfredo Sanchez | June 9, 2004 03:02 PM
Fazal: threadframe looks perfect. I'll give it a spin. Thanks!
Posted by: Wilfredo Sanchez | June 9, 2004 03:05 PM
Here's a setup.py for threadframe.. that Makefile will probably do you no good:
from distutils.core import setup
from distutils.extension import Extension
setup(
name = 'threadframe',
version = '0.1',
description = "Advanced thread debugging extension",
long_description = "Obtaining tracebacks on other threads than the current thread",
url = 'http://www.majid.info/mylos/weblog/2002/10/11-1.html',
maintainer = 'Fazal Majid',
maintainer_email = 'weblog@majid.info',
license = 'Python',
platforms = [],
keywords = ['threading', 'thread'],
ext_modules=[
Extension('threadframe',
['threadframemodule.c'],
),
],
)
Posted by: Bob Ippolito | June 9, 2004 03:07 PM
Oh, and maybe it's just because I'm looking at the Python 2.4 source, but I definitely see a thread_id member in the PyThreadState struct... This was probably added in 2.3, I guess?
Posted by: Bob Ippolito | June 9, 2004 03:13 PM
Sweet. Thanks, Bob.
Posted by: Wilfredo Sanchez | June 9, 2004 07:07 PM
So threadframe doesn't appear give me what I want, which is the ability to inspect another thread. How does threadframe.threadframes() differ from inspect.getouterframes()?
Posted by: Wilfredo Sanchez | June 9, 2004 11:30 PM
threadframe.threadframes() returns the frame stack for all threads, inspect.getouterframes() returns the frame stack for the current thread. In order to inspect a particular thread, you will need to make some modifications to threadframemodule such that it returns a dict of { tstate->thread_id, }, or just returns a particular thread_id on demand. thread.get_ident() and thread.startnew(...) return the same integer as is stored in the tstate.
Since the change was trivial, I went ahead and did it.. http://undefined.org/python/threadframe_2.3.tgz has a new threadframe module with a slightly different API.
Posted by: Bob Ippolito | June 10, 2004 12:40 AM
Thanks for the setup.py, Bob. I gues I'm just lazy and never got around to grokking distutils, even though I've been using Python since 1.1 in 1994 or so...
Posted by: Fazal Majid | June 10, 2004 09:21 AM
By the way, the thread_id was added by GvR about a year ago (in the late stages of 2.3rc1), along with an interesting C-only API that allows a form of thread cancellation.
Posted by: Fazal Majid | June 10, 2004 04:19 PM
Using distutils is pretty essential to having things work on OS X and other *nix platforms at the same time with minimal effort. Needless to say, I know it well enough, and for simple things like threadframe it's really trivial to do.
I did see the thread cancellation API while I was in there. Stackless has something like this too, for tasklets, but it's actually exposed to Python :)
Posted by: Bob Ippolito | June 10, 2004 07:04 PM
I incorporated Bob's changes in a version 0.2 of the module. To maintain backwards compatibility for Python 2.2 users, the new dictionary function Bob implemented is threadframe.dict(), and threadframe.threadframe() continues to return a list.
I also produced a Python 2.3.4 executable for Windows users. A Makefile is still necessary for generation using MinGW, as the distutils use Microsoft Visual Studio, which I don't have (I believe Microsoft has made its command-line compilers freely available, however).
By the way, when your apps spend the bulk of their time in Oracle, as mine do, threading is not a nice to have, it is a necessity. It could be done using a pool of processes and pipes or SYSV IPC, but at the cost of considerable complexity and manageability issues.
Posted by: Fazal Majid | June 10, 2004 08:04 PM
you really think it's a good idea to shadow the builtin "dict"?
Posted by: Bob Ippolito | June 11, 2004 12:08 PM