[Twisted-Python] crasher
Okay, I've discovered a _very very_ odd bug in Twisted. In trying to get this stupid web/issues conduit thing working on Mac IE, I was trying all kinds of crazy nonsense. In particular there was one bit where I tried to make issueconduit close the connection after the server sent each message, so it would be immediately displayed, and then have the browser re-open the connection after a second to retrieve any new messages. (Mac IE doesn't allow you to modify pages with Javascript that haven't been fully loaded for some reason.) I did this using js timeouts and setting the src attribute on a hidden iframe. What happened next was not what I expected at all. First, the server started sending me the welcome message in a loop. (This is probably just a bug in the conduit code, nothing serious.) However, when I entered something in the text field and hit "enter", twistd _locked up hard_. I couldn't even send it a SIGTERM. So I killed it and tried again a few times. It would reliably lock up after trying to send a message. Best of all, this does not normally happen: it is quite possible to interact with the server using the default js (with some trivial changes); the only problem is that the updates won't show up until the connection is finished. The only thing I could think of that would be useful for debugging info is strace, since it was wedged so hard and I didn't know where. Here's what I got: ... munmap(0x4001b000, 4096) = 0 close(9) = 0 gettimeofday({1035895791, 342136}, NULL) = 0 send(6, "HTTP/1.1 200 OK\r\nTransfer-encodi"..., 136, 0) = 136 send(6, "c3\r\n<IssueBot> A SUPPORT R"..., 201, 0) = 201 send(6, "0\r\n\r\n", 5, 0) = 5 gettimeofday({1035895791, 345729}, NULL) = 0 gettimeofday({1035895791, 346897}, NULL) = 0 write(1, "29/10/2002 06:49 [HTTPChannel,0,"..., 20529/10/2002 06:49 [HTTPChannel,0,64.123.27.109] 64.123.27.109 - - [29/Oct/2002:12:49:50 +0000] "<GET /issues.rpy/conduit?output=135 HTTP/1.1>" 200 195 "-" "Mozilla/4.0 (compatible; MSIE 5.14; Mac_PowerPC)" ) = 205 brk(0x846d000) = 0x846d000 old_mmap(NULL, 245760, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4035b000 brk(0x8433000) = 0x8433000 mremap(0x4035b000, 245760, 245760, MREMAP_MAYMOVE) = 0x4035b000 mremap(0x4035b000, 245760, 245760, MREMAP_MAYMOVE) = 0x4035b000 mremap(0x4035b000, 245760, 245760, MREMAP_MAYMOVE) = 0x4035b000 mremap(0x4035b000, 245760, 245760, MREMAP_MAYMOVE) = 0x4035b000 ... It then repeats "mremap" basically forever, and the various numbers there increase very gradually. So for some reason, Twisted is trying to allocate some huuuge chunk of memory. Is there a way to get gdb to tell me where in python this is happening? I am going out of my mind trying to figure out a way to debug this, so extra eyes are helpful, but I don't think this bug can be found through normal bughunting; you'd have to be pretty familiar with whatever code is causing the problem. I figure it might be either woven, twisted.protocols.http or twisted.internet. Help? :-) -- | <`'> | Glyph Lefkowitz: Traveling Sorcerer | | < _/ > | Lead Developer, the Twisted project | | < ___/ > | http://www.twistedmatrix.com |
On Tue, 29 Oct 2002 17:24:46 -0600 (CST), Glyph Lefkowitz <glyph@twistedmatrix.com> wrote:
Okay, I've discovered a _very very_ odd bug in Twisted.
I almost forgot: since the behavior is so hard to describe properly, a CVS tree with the appropriate changes to it is present in ~glyph/Projects/Twisted on pyramid. The changed files are twisted/issues/ui/templates/conduit_msie.js, twisted/issues/ui/issueconduit.py, and twisted/issues/ui/conduit.html. -- | <`'> | Glyph Lefkowitz: Traveling Sorcerer | | < _/ > | Lead Developer, the Twisted project | | < ___/ > | http://www.twistedmatrix.com |
On Tue, Oct 29, 2002 at 05:24:46PM -0600, Glyph Lefkowitz wrote:
Isn't there a hack you can do to sys.settracehook (or whatever it is) to print each python function call entry & exit? That would help narrow stuff down. I've also heard there's a gdb hack which lets it understand Python tracebacks, so that it correctly displays them intermingled with the C traceback when you issue a 'bt' command... but I can't seem to find it :( Also, this url from google looks promising: http://groups.google.com/groups?q=gdb+python+traceback&hl=en&lr=&ie=UTF-8&safe=off&selm=14201.27231.1003.466027%40anthem.cnri.reston.va.us&rnum=4 Choice quote: """ First, get the pid of the running Python process. Start up gdb on the python executable and at the gdb prompt type "attach XXX" where XXX is the pid. Now, at the gdb prompt, type the following: (gdb) call PyRun_SimpleString("import sys, traceback; sys.stderr=open('/tmp/tb','w',0); traceback.print_stack()") """ -Andrew.
On Wed, Oct 30, 2002 at 10:50:57AM +1100, Andrew Bennetts wrote:
Ok, I found where I saw this mentioned: http://mail.python.org/pipermail/python-dev/2002-July/027110.html But I can't seem to find the patch he refers to. There's also this, which apparently works, but slowly: http://mail.python.org/pipermail/python-dev/2001-June/015340.html -Andrew.
On Tue, 29 Oct 2002 17:24:46 -0600 (CST), Glyph Lefkowitz <glyph@twistedmatrix.com> wrote:
Okay, I've discovered a _very very_ odd bug in Twisted.
I almost forgot: since the behavior is so hard to describe properly, a CVS tree with the appropriate changes to it is present in ~glyph/Projects/Twisted on pyramid. The changed files are twisted/issues/ui/templates/conduit_msie.js, twisted/issues/ui/issueconduit.py, and twisted/issues/ui/conduit.html. -- | <`'> | Glyph Lefkowitz: Traveling Sorcerer | | < _/ > | Lead Developer, the Twisted project | | < ___/ > | http://www.twistedmatrix.com |
On Tue, Oct 29, 2002 at 05:24:46PM -0600, Glyph Lefkowitz wrote:
Isn't there a hack you can do to sys.settracehook (or whatever it is) to print each python function call entry & exit? That would help narrow stuff down. I've also heard there's a gdb hack which lets it understand Python tracebacks, so that it correctly displays them intermingled with the C traceback when you issue a 'bt' command... but I can't seem to find it :( Also, this url from google looks promising: http://groups.google.com/groups?q=gdb+python+traceback&hl=en&lr=&ie=UTF-8&safe=off&selm=14201.27231.1003.466027%40anthem.cnri.reston.va.us&rnum=4 Choice quote: """ First, get the pid of the running Python process. Start up gdb on the python executable and at the gdb prompt type "attach XXX" where XXX is the pid. Now, at the gdb prompt, type the following: (gdb) call PyRun_SimpleString("import sys, traceback; sys.stderr=open('/tmp/tb','w',0); traceback.print_stack()") """ -Andrew.
On Wed, Oct 30, 2002 at 10:50:57AM +1100, Andrew Bennetts wrote:
Ok, I found where I saw this mentioned: http://mail.python.org/pipermail/python-dev/2002-July/027110.html But I can't seem to find the patch he refers to. There's also this, which apparently works, but slowly: http://mail.python.org/pipermail/python-dev/2001-June/015340.html -Andrew.
participants (2)
-
Andrew Bennetts -
Glyph Lefkowitz