Martin Aspeli wrote:
Hi,
I'm not sure if this is a Python issue or a zope issue. We're getting a segfault on 64-bit SuSE Linux (SLES 11), originating from z3c.autoinclude, which in turn called zope.configuration's<include /> implementation. This calls expat, which then crashes (no error, log message, or core file, but it has all the markings of a segfault) during parsing of the file.
The weird thing is that it's not parsing of any file: it happens during a standard configure.zcml (for the collective.xdv package), but z3c.autoinclude itself is invoked from another ZCML file, so it must've been able to read that.
I tried running it through gdb, and got: (gdb) run Starting program: /home/osc/python-env/bin/python2.6 ./bin/instance1 fg (no debugging symbols found) (no debugging symbols found) (no debugging symbols found) (no debugging symbols found) [Thread debugging using libthread_db enabled] (no debugging symbols found) (no debugging symbols found) (no debugging symbols found) (no debugging symbols found) (no debugging symbols found) 2010-04-07 09:38:22 INFO ZServer HTTP server started at Wed Apr 7 09:38:22 2010 Hostname: 0.0.0.0 Port: 8801 /home/osc/osc/eggs/collective.wtf-1.0b9-py2.6.egg/collective/wtf/exportimport.py:8: DeprecationWarning: InitializeClass is deprecated. import from App.class_init instead from Globals import InitializeClass Program exited normally. .. which is not very helpful. The status code is indeed zero. (python-env)osc@lwpn-osb-webback-2:~/osc> ./bin/instance1 fg2010-04-07 09:39:21 INFO ZServer HTTP server started at Wed Apr 7 09:39:21 2010 Hostname: 0.0.0.0 Port: 8801 /home/osc/osc/eggs/collective.wtf-1.0b9-py2.6.egg/collective/wtf/exportimport.py:8: DeprecationWarning: InitializeClass is deprecated. import from App.class_init instead from Globals import InitializeClass (python-env)osc@lwpn-osb-webback-2:~/osc> echo $? 0 Next, I tried to pdb from roughly where I know it dies. Sorry about the long text here. It's a bit weird, but I'll explain what's happening. (python-env)osc@lwpn-osb-webback-2:~/osc> ./bin/instance1 fg2010-04-07 09:47:37 INFO ZServer HTTP server started at Wed Apr 7 09:47:37 2010 Hostname: 0.0.0.0 Port: 8801 This is where the brekapoint was set, in z3c.autoinclude's <includePlugins /> handler. This looks for packages with a particular entry point and loads their meta.zcml, then configure.zcml. The problem happens during configure.zcml loading.
/home/osc/osc/eggs/z3c.autoinclude-0.3.2-py2.6.egg/z3c/autoinclude/zcml.py(104)includePluginsDirective() -> for filename in zcml_to_look_for: <snip /> We've now stepped into the function that does the real work: -> def includeZCMLGroup(_context, info, filename, override=False): (Pdb) l 10 from z3c.autoinclude.plugin import PluginFinder 11 12 import logging 13 log = logging.getLogger("z3c.autoinclude") 14 15 -> def includeZCMLGroup(_context, info, filename, override=False): 16 includable_zcml = info[filename] 17 # ^^ a key error would mean that we are trying to include a group of ZCML 18 # with a filename that wasn't ever searched for. that *should* be an error 19 20 zcml_context = repr(_context.info) <snip /> This quickly gets to here, where it's loading a package and calling zope.configuration's <include /> handler. (Pdb) l 22 for dotted_name in includable_zcml: 23 log.debug('including file %s from package %s at %s', filename, dotted_name, zcml_context) 24 25 for dotted_name in includable_zcml: 26 includable_package = resolve(dotted_name) 27 -> if override: 28 includeOverrides(_context, filename, includable_package) 29 else: 30 include(_context, filename, includable_package) 31 32 (Pdb) n
/home/osc/osc/eggs/z3c.autoinclude-0.3.2-py2.6.egg/z3c/autoinclude/zcml.py(30)includeZCMLGroup() -> include(_context, filename, includable_package) It's not na override, so we end up in zope.configuration now. --Call--
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(487)include() -> def include(_context, file=None, package=None, files=None): (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(493)include() -> if files: (Pdb) l 488 """Include a zcml file 489 490 See examples in tests/text_xmlconfig.py 491 """ 492 493 -> if files: 494 if file: 495 raise ValueError("Must specify only one of file or files") 496 elif not file: 497 file = 'configure.zcml' 498 (Pdb) l 499 # BBB 2006/12/19 -- to be removed after 12 months 500 # This is a backward-compatibility support for old site.conf 501 502 if package and (package.__name__ == 'zope.app'): 503 try: 504 import zope.app.zcmlfiles 505 except ImportError: 506 pass # maybe this is an old zope without zope.app.zcmlfiles 507 else: 508 dirpath, filename = os.path.split(file) 509 # be careful, because zope.app is a namespace package (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(496)include() -> elif not file: (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(502)include() -> if package and (package.__name__ == 'zope.app'): (Pdb) l 497 file = 'configure.zcml' 498 499 # BBB 2006/12/19 -- to be removed after 12 months 500 # This is a backward-compatibility support for old site.conf 501 502 -> if package and (package.__name__ == 'zope.app'): 503 try: 504 import zope.app.zcmlfiles 505 except ImportError: 506 pass # maybe this is an old zope without zope.app.zcmlfiles 507 else: (Pdb) pp package.__name__ 'lw.portal' This is "our" package. You'll see the ZCML it's loading in a moment. Note that this is the first package it's trying to load. (Pdb) pp file 'configure.zcml' (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(524)include() -> context = config.GroupingContextDecorator(_context) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(525)include() -> if package is not None: (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(526)include() -> context.package = package (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(527)include() -> context.basepath = None (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(529)include() -> if files: (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(535)include() -> paths = [context.path(file)] (Pdb) l 530 paths = glob(context.path(files)) 531 paths = zip([path.lower() for path in paths], paths) 532 paths.sort() 533 paths = [path for (l, path) in paths] 534 else: 535 -> paths = [context.path(file)] 536 537 for path in paths: 538 if context.processFile(path): 539 f = openInOrPlain(path) 540 logger.debug("include %s" % f.name) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(537)include() -> for path in paths: (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(538)include() -> if context.processFile(path): (Pdb) l 533 paths = [path for (l, path) in paths] 534 else: 535 paths = [context.path(file)] 536 537 for path in paths: 538 -> if context.processFile(path): 539 f = openInOrPlain(path) 540 logger.debug("include %s" % f.name) 541 542 context.basepath = os.path.dirname(path) 543 context.includepath = _context.includepath + (f.name, ) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(539)include() -> f = openInOrPlain(path) (Pdb) l 534 else: 535 paths = [context.path(file)] 536 537 for path in paths: 538 if context.processFile(path): 539 -> f = openInOrPlain(path) 540 logger.debug("include %s" % f.name) 541 542 context.basepath = os.path.dirname(path) 543 context.includepath = _context.includepath + (f.name, ) 544 _context.stack.append(config.GroupingStackItem(context)) (Pdb) s --Call--
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(383)openInOrPlain() -> def openInOrPlain(filename): (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(426)openInOrPlain() -> try: (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(427)openInOrPlain() -> fp = open(filename) (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(437)openInOrPlain() -> return fp (Pdb) --Return--
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(437)openInOrPlain()-><open fi...x5dc1608> -> return fp (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(540)include() -> logger.debug("include %s" % f.name) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(542)include() -> context.basepath = os.path.dirname(path) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(543)include() -> context.includepath = _context.includepath + (f.name, ) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(544)include() -> _context.stack.append(config.GroupingStackItem(context)) (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(546)include() -> processxmlfile(f, context) (Pdb) l 541 542 context.basepath = os.path.dirname(path) 543 context.includepath = _context.includepath + (f.name, ) 544 _context.stack.append(config.GroupingStackItem(context)) 545 546 -> processxmlfile(f, context) 547 f.close() 548 assert _context.stack[-1].context is context 549 _context.stack.pop() 550 551 def exclude(_context, file=None, package=None, files=None): (Pdb) s --Call--
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(367)processxmlfile() -> def processxmlfile(file, context, testing=False): (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(372)processxmlfile() -> src = InputSource(getattr(file, 'name', '<string>')) (Pdb) l 367 def processxmlfile(file, context, testing=False): 368 """Process a configuration file 369 370 See examples in tests/text_xmlconfig.py 371 """ 372 -> src = InputSource(getattr(file, 'name', '<string>')) 373 src.setByteStream(file) 374 parser = make_parser() 375 parser.setContentHandler(ConfigurationHandler(context, testing=testing)) 376 parser.setFeature(feature_namespaces, True) 377 try: (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(373)processxmlfile() -> src.setByteStream(file) (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(374)processxmlfile() -> parser = make_parser() (Pdb) pp src <xml.sax.xmlreader.InputSource instance at 0x5f6d950> (Pdb) l 369 370 See examples in tests/text_xmlconfig.py 371 """ 372 src = InputSource(getattr(file, 'name', '<string>')) 373 src.setByteStream(file) 374 -> parser = make_parser() 375 parser.setContentHandler(ConfigurationHandler(context, testing=testing)) 376 parser.setFeature(feature_namespaces, True) 377 try: 378 parser.parse(src) 379 except SAXParseException: (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(375)processxmlfile() -> parser.setContentHandler(ConfigurationHandler(context, testing=testing)) (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(376)processxmlfile() -> parser.setFeature(feature_namespaces, True) (Pdb)
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(377)processxmlfile() -> try: (Pdb) n
/home/osc/osc/eggs/zope.configuration-3.6.0-py2.6.egg/zope/configuration/xmlconfig.py(378)processxmlfile() -> parser.parse(src) (Pdb) s --Call--
/usr/lib64/python2.6/xml/sax/expatreader.py(100)parse() -> def parse(self, source): (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(102)parse() -> source = saxutils.prepare_input_source(source) (Pdb) l 97 98 # XMLReader methods 99 100 def parse(self, source): 101 "Parse an XML document from a URL or an InputSource." 102 -> source = saxutils.prepare_input_source(source) 103 104 self._source = source 105 self.reset() 106 self._cont_handler.setDocumentLocator(ExpatLocator(self)) 107 xmlreader.IncrementalParser.parse(self, source) (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(104)parse() -> self._source = source (Pdb) /usr/lib64/python2.6/xml/sax/expatreader.py(105)parse() -> self.reset() (Pdb) /usr/lib64/python2.6/xml/sax/expatreader.py(106)parse() -> self._cont_handler.setDocumentLocator(ExpatLocator(self)) (Pdb) /usr/lib64/python2.6/xml/sax/expatreader.py(107)parse() -> xmlreader.IncrementalParser.parse(self, source) (Pdb) l 102 source = saxutils.prepare_input_source(source) 103 104 self._source = source 105 self.reset() 106 self._cont_handler.setDocumentLocator(ExpatLocator(self)) 107 -> xmlreader.IncrementalParser.parse(self, source) 108 109 def prepareParser(self, source): 110 if source.getSystemId() is not None: 111 self._parser.SetBase(source.getSystemId()) 112 (Pdb) s --Call-- /usr/lib64/python2.6/xml/sax/xmlreader.py(115)parse() -> def parse(self, source): (Pdb) n /usr/lib64/python2.6/xml/sax/xmlreader.py(116)parse() -> import saxutils (Pdb) /usr/lib64/python2.6/xml/sax/xmlreader.py(117)parse() -> source = saxutils.prepare_input_source(source) (Pdb) l 112 self._bufsize = bufsize 113 XMLReader.__init__(self) 114 115 def parse(self, source): 116 import saxutils 117 -> source = saxutils.prepare_input_source(source) 118 119 self.prepareParser(source) 120 file = source.getByteStream() 121 buffer = file.read(self._bufsize) 122 while buffer != "": (Pdb) n /usr/lib64/python2.6/xml/sax/xmlreader.py(119)parse() -> self.prepareParser(source) (Pdb) /usr/lib64/python2.6/xml/sax/xmlreader.py(120)parse() -> file = source.getByteStream() (Pdb) /usr/lib64/python2.6/xml/sax/xmlreader.py(121)parse() -> buffer = file.read(self._bufsize) (Pdb) /usr/lib64/python2.6/xml/sax/xmlreader.py(122)parse() -> while buffer != "":
Now we know what it's read, and is about to parse: the configure.zcml file from the package lw.portal. (Pdb) pp buffer '<configure\n xmlns="http://namespaces.zope.org/zope"\n xmlns:genericsetup="http://namespaces.zope.org/genericsetup"\n xmlns:monkey="http://namespaces.plone.org/monkey"\n i18n_domain="lw.portal">\n\n <includeDependencies package="." />\n \n <genericsetup:registerProfile\n name="default"\n title="Lotterywest portal policy"\n description="Configures Plone to become the Lotterywest portal"\n for="Products.CMFPlone.interfaces.IPloneSiteRoot"\n provides="Products.GenericSetup.interfaces.EXTENSION"\n directory="profiles/default"\n />\n \n <genericsetup:importStep\n name="lw.portal"\n title="Lotterywest portal policy"\n description="Imperative configuration for lw.portal"\n handler="lw.portal.setuphandlers.setupVarious"\n />\n\n</configure>\n' (Pdb) n
/usr/lib64/python2.6/xml/sax/xmlreader.py(123)parse() -> self.feed(buffer) (Pdb) l 118 119 self.prepareParser(source) 120 file = source.getByteStream() 121 buffer = file.read(self._bufsize) 122 while buffer != "": 123 -> self.feed(buffer) 124 buffer = file.read(self._bufsize) 125 self.close() 126 127 def feed(self, data): 128 """This method gives the raw XML data in the data parameter to (Pdb) s --Call-- /usr/lib64/python2.6/xml/sax/expatreader.py(196)feed() -> def feed(self, data, isFinal = 0): (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(197)feed() -> if not self._parsing: (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(198)feed() -> self.reset() (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(199)feed() -> self._parsing = 1 (Pdb) l 194 # IncrementalParser methods 195 196 def feed(self, data, isFinal = 0): 197 if not self._parsing: 198 self.reset() 199 -> self._parsing = 1 200 self._cont_handler.startDocument() 201 202 try: 203 # The isFinal parameter is internal to the expat reader. 204 # If it is set to true, expat will check validity of the entire (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(200)feed() -> self._cont_handler.startDocument() (Pdb) s --Call-- /usr/lib64/python2.6/xml/sax/handler.py(80)startDocument() -> def startDocument(self): (Pdb) n /usr/lib64/python2.6/xml/sax/handler.py(80)startDocument() -> def startDocument(self): (Pdb) l 75 Note that the locator will return correct information only 76 during the invocation of the events in this interface. The 77 application should not attempt to use it at any other time.""" 78 self._locator = locator 79 80 -> def startDocument(self): 81 """Receive notification of the beginning of a document. 82 83 The SAX parser will invoke this method only once, before any 84 other methods in this interface or in DTDHandler (except for 85 setDocumentLocator).""" (Pdb) n --Return-- /usr/lib64/python2.6/xml/sax/handler.py(80)startDocument()->None -> def startDocument(self): (Pdb) /usr/lib64/python2.6/xml/sax/expatreader.py(202)feed() -> try: (Pdb) /usr/lib64/python2.6/xml/sax/expatreader.py(207)feed() -> self._parser.Parse(data, isFinal) (Pdb) l 202 try: 203 # The isFinal parameter is internal to the expat reader. 204 # If it is set to true, expat will check validity of the entire 205 # document. When feeding chunks, they are not normally final - 206 # except when invoked from close. 207 -> self._parser.Parse(data, isFinal) 208 except expat.error, e: 209 exc = SAXParseException(expat.ErrorString(e.code), e, self) 210 # FIXME: when to invoke error()? 211 self._err_handler.fatalError(exc) 212 (Pdb) s
Now we're in C land. --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl() (Pdb) n --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl()->None (Pdb) s --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl()->None (Pdb) s --Call--
/usr/lib64/python2.6/xml/sax/expatreader.py(359)start_namespace_decl() -> def start_namespace_decl(self, prefix, uri): (Pdb) n /usr/lib64/python2.6/xml/sax/expatreader.py(360)start_namespace_decl() -> self._cont_handler.startPrefixMapping(prefix, uri) (Pdb) n --Return--
/usr/lib64/python2.6/xml/sax/expatreader.py(360)start_namespace_decl()->None -> self._cont_handler.startPrefixMapping(prefix, uri) (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(839)StartNamespaceDecl()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(604)StartElement()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(604)StartElement()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(479)CharacterData()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(604)StartElement()->None (Pdb) --Return--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(604)StartElement()->None (Pdb) --Call--
/usr/src/packages/BUILD/Python-2.6/Modules/pyexpat.c(656)EndElement()->None (Pdb) At this point, something is printed to the console. collective.wtf is a dependency of lw.portal, and its ZCML is being included from lw.portal. /home/osc/osc/eggs/collective.wtf-1.0b9-py2.6.egg/collective/wtf/exportimport.py:8: DeprecationWarning: InitializeClass is deprecated. import from App.class_init instead from Globals import InitializeClass At this point, it quits with status 0. If this makes sense to anyone, please do speak up. ;-) Martin