classification
Title: profiling with xml parsing asserts
Type: Stage:
Components: Library (Lib) Versions: Python 2.2
process
Status: closed Resolution: accepted
Dependencies: Superseder:
Assigned To: loewis Nosy List: ainsinga, andrewl, gvanrossum, loewis, tim.peters
Priority: normal Keywords:

Created on 2002-03-25 21:15 by ainsinga, last changed 2002-08-04 08:27 by loewis. This issue is now closed.

Files
File name Uploaded Description Edit
profilexmlcrash.txt ainsinga, 2002-03-25 21:19
traceback.txt tim.peters, 2002-07-01 15:55 A failing run under CVS on Windows
expat.diff loewis, 2002-07-02 07:05
Messages (15)
msg9974 - (view) Author: Aron K. Insinga (ainsinga) Date: 2002-03-25 21:15
I'm getting a 'bad call' assertion error when using the
profiler when parsing XML.  (It works ok without the
profiler, and if I don't call SAXparser.parse it
doesn't happen.)


Python 2.2 (#1, Dec 23 2001, 09:30:32)
[GCC 2.96 20000731 (Red Hat Linux 7.1 2.96-98)] on
linux2
Type "help", "copyright", "credits" or "license" for
more information.
>>> import t4crash
start document
end document
>>> import profile
>>> t4crash.test()
start document
end document
>>> profile.run('t4crash.test()')
start document
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
  File "/usr/lib/python2.2/profile.py", line 71, in run
    prof = prof.run(statement)
  File "/usr/lib/python2.2/profile.py", line 404, in
run
    return self.runctx(cmd, dict, dict)
  File "/usr/lib/python2.2/profile.py", line 410, in
runctx
    exec cmd in globals, locals
  File "<string>", line 1, in ?
  File "t4crash.py", line 46, in test
    main(files)
  File "t4crash.py", line 39, in main
    SAXparser.parse(fileName)
  File
"/var/tmp/python2-2.2-root/usr/lib/python2.2/xml/sax/expatreader.py",
line 53, in parse
  File
"/var/tmp/python2-2.2-root/usr/lib/python2.2/xml/sax/xmlreader.py",
line
123, in parse  File
"/var/tmp/python2-2.2-root/usr/lib/python2.2/xml/sax/expatreader.py",
line 106,
in feed
  File
"/var/tmp/python2-2.2-root/usr/lib/python2.2/xml/sax/expatreader.py",
line 179, in start_element
  File "/usr/lib/python2.2/profile.py", line 214, in
trace_dispatch_i
    if self.dispatch[event](self, frame,t):
  File "/usr/lib/python2.2/profile.py", line 260, in
trace_dispatch_call
    assert rframe.f_back is frame.f_back, ("Bad call",
rfn,
AssertionError: ('Bad call',
('/var/tmp/python2-2.2-root/usr/lib/python2.2/xml/sax/expatreader.py',
95,
'feed'), <frame object at 0x81d5454>, <frame object at
0x81c82e4>, <frame object
at 0x81d50b4>, <frame object at 0x81d5284>)
>>>
[ainsinga@ainsinga index_xml]$ cat t4crash.py
#!/usr/bin/env python2

# t4crash.py by Aron K. Insinga (aron.insinga@av.com)
25-Mar-2002

import xml.sax
import sys
import string
import re


class ContentHandler(xml.sax.ContentHandler):
    """ Handle callbacks from the SAX XML parser. """

    def __init__(selfy):
        pass

    def setDocumentLocator(self, locator):
        pass

    def startDocument(self):
        print 'start document'

    def endDocument(self):
        print 'end document'

    def startElement(self, name, attrs):
        pass

    def endElement(self, name):
        pass


def main(files):
    SAXparser = xml.sax.make_parser()
    chand = ContentHandler()
    SAXparser.setContentHandler(chand)
    try:
        for fileName in files:
            SAXparser.parse(fileName)
    except xml.sax.SAXParseException:
        sys.stderr.write("%s; processing aborted\n" %
(xml.sax.SAXParseException))
        sys.exit(1)

def test():
    files = ['doc0.xml']
    main(files)

test()
[ainsinga@ainsinga index_xml]$ cat doc0.xml
<?xml version="1.0" encoding="ISO-8859-1"?>
<html>
  <head>
    <title>Gettysburg Address</title>
  </head>
  <body>
    <p>
      Four score and seven years ago...<br/>
    </p>
  </body>
  <info>
    <author>
     
<lastname>Lincoln</lastname><firstname>Abraham</firstname>
    </author>
    <date>
      <month>11</month><day>19</day><year>1863</year>
    </date>
    <editor /><!-- editor name="aki"/ -->
    <editor/>
  </info>
</html>
[ainsinga@ainsinga index_xml]$ which python
/usr/bin/python
[ainsinga@ainsinga index_xml]$ set | grep PATH
LD_LIBRARY_PATH=/home/ainsinga/adabas/lib:/home/ainsinga/adabas/lib:/home/ainsinga/adabas/lib:/home/ainsinga/adabas/lib:/home/ainsinga/adabas/lib:
PATH=$'/home/ainsinga/adabas/bin:/home/ainsinga/adabas/pgm:.:/home/ainsinga/adabas/bin:/home/ainsinga/adabas/pgm:.:/home/ainsinga/adabas/bin:/home/ainsinga/adabas/pgm:.:/home/ainsinga/adabas/bin:/home/ainsinga/adabas/pgm:.:.:/home/ainsinga/bin:/home/ainsinga/adabas/bin:/home/ainsinga/adabas/pgm:.:/bin:/usr/bin:/usr/X11R6/bin:/usr/local/bin:~/staroffice6.0:/home/ainsinga/mozilla:~/staroffice6.0:/home/ainsinga/mozilla:~/staroffice6.0:/home/ainsinga/mozilla:~/staroffice6.0:/home/ainsinga/mozilla:~/
staroffice6.0:/home/ainsinga/mozilla'
[ainsinga@ainsinga index_xml]$ set | grep -i py
[ainsinga@ainsinga index_xml]$uname -a
Linux ainsinga 2.4.7-10 #1 Thu Sep 6 17:27:27 EDT 2001
i686 unknown
[ainsinga@ainsinga index_xml]$
msg9975 - (view) Author: Aron K. Insinga (ainsinga) Date: 2002-03-25 21:19
Logged In: YES 
user_id=496408

attached is the sample program (which ought to have
indenting preserved!)
msg9976 - (view) Author: Tim Peters (tim.peters) * (Python committer) Date: 2002-03-25 22:27
Logged In: YES 
user_id=31435

Assigned to Fred.
msg9977 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2002-03-27 12:30
Logged In: YES 
user_id=21627

I can't reproduce the crash, with 2.3a0.
msg9978 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2002-07-01 05:55
Logged In: YES 
user_id=21627

I can't reproduce it with the Python 2.2 that ships with
SuSE 8.0, either.
msg9979 - (view) Author: Tim Peters (tim.peters) * (Python committer) Date: 2002-07-01 15:55
Logged In: YES 
user_id=31435

I reproduced this with current CVS Python on Windows; 
see attached traceback.txt, which shows a screen dump of 
the offending <wink> interactive session.
msg9980 - (view) Author: Andrew P. Lentvorski, Jr. (andrewl) Date: 2002-07-01 22:57
Logged In: YES 
user_id=28733

There is another filing on this problem at:

http://mail.python.org/pipermail/xml-sig/2002-April/007632.html

Also, I reproduced this on another FreeBSD box today as
well.

andrewl@taz:andrewl$ python
Python 2.2.1 (#1, May 27 2002, 16:42:22) 
[GCC 2.95.3 20010315 (release) [FreeBSD]] on freebsd4

-a
msg9981 - (view) Author: Andrew P. Lentvorski, Jr. (andrewl) Date: 2002-07-02 00:01
Logged In: YES 
user_id=28733

Here is a session log for a much more self-contained
regression file (xmltest.py):

andrewl@taz:andrewl$ python
Python 2.2.1 (#1, May 27 2002, 16:42:22) 
[GCC 2.95.3 20010315 (release) [FreeBSD]] on freebsd4
Type "help", "copyright", "credits" or "license" for more
information.
>>> import profile
>>> import xmltest
>>> profile.run('xmltest.main()')
Traceback (most recent call last):
  File "<stdin>", line 1, in ?
  File "/usr/local/lib/python2.2/profile.py", line 71, in
run
    prof = prof.run(statement)
  File "/usr/local/lib/python2.2/profile.py", line 404, in
run
    return self.runctx(cmd, dict, dict)
  File "/usr/local/lib/python2.2/profile.py", line 410, in
runctx
    exec cmd in globals, locals
  File "<string>", line 1, in ?
  File "xmltest.py", line 24, in main
    xml.sax.parseString(testxml, chand)
  File "/usr/local/lib/python2.2/xml/sax/__init__.py", line
49, in parseString
    parser.parse(inpsrc)
  File "/usr/local/lib/python2.2/xml/sax/expatreader.py",
line 90, in parse
    xmlreader.IncrementalParser.parse(self, source)
  File "/usr/local/lib/python2.2/xml/sax/xmlreader.py", line
123, in parse
    self.feed(buffer)
  File "/usr/local/lib/python2.2/xml/sax/expatreader.py",
line 143, in feed
    self._parser.Parse(data, isFinal)
  File "/usr/local/lib/python2.2/xml/sax/expatreader.py",
line 216, in start_element
    def start_element(self, name, attrs):
  File "/usr/local/lib/python2.2/profile.py", line 214, in
trace_dispatch_i
    if self.dispatch[event](self, frame,t):
  File "/usr/local/lib/python2.2/profile.py", line 260, in
trace_dispatch_call
    assert rframe.f_back is frame.f_back, ("Bad call", rfn,
AssertionError: ('Bad call',
('/usr/local/lib/python2.2/xml/sax/expatreader.py', 132,
'feed'), <frame object at 0x81a880c>, <frame object at
0x81a840c>, <frame object at 0x81bb60c>, <frame object at
0x81a8a0c>)
msg9982 - (view) Author: Andrew P. Lentvorski, Jr. (andrewl) Date: 2002-07-02 00:13
Logged In: YES 
user_id=28733

The xmltest.py program follows since I appear to be too
stupid to figure out how to attach a file to a bug report on
SourceForge.

-a

#!/usr/bin/env python

import xml.sax

testxml = \
"""
<html />
"""

class ContentHandler(xml.sax.ContentHandler):
    """ Handle callbacks from the SAX XML parser. """

    def __init__(self):
        pass

    def startElement(self, name, attrs):
        print "start element"

    def endElement(self, name):
        print "end element"

def main():
    chand = ContentHandler()
    xml.sax.parseString(testxml, chand)

if __name__ == "__main__":
    main()
msg9983 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2002-07-02 07:05
Logged In: YES 
user_id=21627

Attached is a patch that fixes the problem.
msg9984 - (view) Author: Andrew P. Lentvorski, Jr. (andrewl) Date: 2002-08-01 08:57
Logged In: YES 
user_id=28733

I took a quick look in the browsable CVS repository, and the
diff to expat.c doesn't seem to be committed.  Is there
something further that I need to do so that this bug can get
closed?

-a
msg9985 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2002-08-01 10:56
Logged In: YES 
user_id=21627

Confirming that the patch solves the problem for you would help.
msg9986 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2002-08-02 20:06
Logged In: YES 
user_id=6380

It solves the isolated test case submitted by Andrew P.
Lentvorski to python-dev on July 1, so I propose to check
this in.
msg9987 - (view) Author: Andrew P. Lentvorski, Jr. (andrewl) Date: 2002-08-02 21:21
Logged In: YES 
user_id=28733

I didn't realize you were waiting for confirmation from me
directly.  Preliminary runs look like the problem is fixed.

Please commit the patch and mark this bug as closed.
msg9988 - (view) Author: Martin v. Löwis (loewis) * (Python committer) Date: 2002-08-04 08:27
Logged In: YES 
user_id=21627

Committed as pyexpat.c 2.72 and 2.57.6.1.
History
Date User Action Args
2002-03-25 21:15:27ainsingacreate