Page MenuHomePhabricator

xml_parser_free: Parser cannot be freed while it is parsing
Closed, ResolvedPublic

Description

Parser cannot be freed while it is parsing. in /srv/mediawiki/php-1.25wm
f16/includes/media/XMP.php on line 156

Offending code:

⠀⠀⠀/** Destroy the xml parser
⠀⠀⠀ *
⠀⠀⠀ * Not sure if this is actually needed.                                     
⠀⠀⠀ */
⠀⠀⠀function __destruct() {
⠀⠀⠀⠀⠀⠀// not sure if this is needed.
⠀⠀⠀⠀⠀⠀xml_parser_free( $this->xmlParser );
⠀⠀⠀}

Event Timeline

bd808 created this task.Feb 14 2015, 2:05 AM
bd808 updated the task description. (Show Details)
bd808 raised the priority of this task from to Needs Triage.
bd808 added a subscriber: bd808.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 14 2015, 2:05 AM
Aklapper triaged this task as Low priority.Feb 20 2015, 10:48 AM

@bd808: Is that really in a MW extension? Code line looks like this is core instead?

bd808 added a comment.Feb 20 2015, 5:01 PM

@bd808: Is that really in a MW extension? Code line looks like this is core instead?

Nope, just bad autocomplete when I tried to add MediaWiki-General-or-Unknown (which really should come up when I type "mediawiki" IMO but there is a task tracking that ...somewhere...).

The bit of code is from mediawiki/core and it comes from r70232 from July 2010 by Brian @Bawolff Wolff (cced).

mmodell raised the priority of this task from Low to Normal.Apr 14 2015, 6:09 PM
mmodell added a subscriber: mmodell.

This is now the #1 fatal error with nearly 1000 hits in the latest 1000 lines of the hhvm.log

Aklapper raised the priority of this task from Normal to High.Apr 15 2015, 4:30 PM

Change 213761 had a related patch set uploaded (by Brian Wolff):
Move xml_free_parser out of destructor.

https://gerrit.wikimedia.org/r/213761

hashar removed a subscriber: hashar.May 27 2015, 8:40 PM
hashar assigned this task to Bawolff.Jun 1 2015, 9:04 PM
hashar added a subscriber: hashar.

Thanks for the patch Brian, I am assuming you are taking care of it :-)

Change 213761 merged by jenkins-bot:
Move xml_free_parser out of destructor.

https://gerrit.wikimedia.org/r/213761

demon closed this task as Resolved.Jun 12 2015, 6:30 PM
demon added a subscriber: demon.
demon reopened this task as Open.Jun 12 2015, 6:44 PM

Whoops spoke too soon

Does that mean my patch did not work? I couldnt reproduce locally so it was just a guess.

The bug was closed too fast as the error is still occurring:

Warning: Parser cannot be freed while it is parsing. in /srv/mediawiki/php-1.26wmf11/includes/media/XMP.php on line 167

210 occurrences over 24 hours, so that it is probably an improvement. For the last 30 days from logstash:

Logstash now says:

"Parser cannot be freed" (244) count per 12h | (244 hits)

Does someone plan to investigate more (assignee is set to @Bawolff)? Is this still high priority?

demon lowered the priority of this task from High to Normal.Aug 20 2015, 3:27 PM
mmodell raised the priority of this task from Normal to Unbreak Now!.Aug 27 2015, 6:17 PM

This is the #1 logged error in fatalmonitor on wmf20 branch, and wmf20 hasn't even gone out to group2 yet. This is a high priority as it's blocking the train deployment now.

bd808 added a comment.Aug 27 2015, 6:30 PM

Looking at the HHVM source code, it appears that this warning is raised when the isparsing internal flag is set. Based on that and the flow I see in the code:

p->isparsing = 1;
ret = XML_Parse(p->parser, (const XML_Char*)data.data(), data.size(),
                isFinal);
p->isparsing = 0;

seeing the error means that we are trying to free when the XML_Parse() function from libexpat has interrupted the normal code path via a longjmp of some type (or been interrupted by the interpreter in some way). This could easily happen due to a tag handler that we have registered with the parser raising an Exception. This *should* mean that we've ended up in the catch block of XMP::parse(). That block tries to log the exception that it has caught. In WMF production we don't have logging enabled for the XMP log channel those messages are sent to so we can't verify this today.

I think if we remove the call to XMP::destroyXMLParser() in the catch block of XMP::parse() these errors will all go away. A related question is whether or not we should enable logging for the XMP channel and see the resulting exception data.

@bd808: I'm gonna try it..

And thank you for the deep debugging!

Change 234407 had a related patch set uploaded (by BryanDavis):
XMP: log structured data for halting errors

https://gerrit.wikimedia.org/r/234407

Change 234425 had a related patch set uploaded (by BryanDavis):
Enable logging of XMP debug log channel for severity >=warning

https://gerrit.wikimedia.org/r/234425

mmodell closed this task as Resolved.Aug 27 2015, 9:07 PM

Change 234428 had a related patch set uploaded (by Legoktm):
Don't free the parser in the catch() block of parse()

https://gerrit.wikimedia.org/r/234428

Change 234407 merged by jenkins-bot:
XMP: log structured data for halting errors

https://gerrit.wikimedia.org/r/234407

mmodell reopened this task as Open.Aug 27 2015, 9:11 PM

Premature resolution.

Change 234428 merged by jenkins-bot:
Don't free the parser in the catch() block of parse()

https://gerrit.wikimedia.org/r/234428

I'm not seeing this one in production anymore. Safe to resolve this task?

bd808 closed this task as Resolved.Sep 3 2015, 5:20 AM

Team effort for the win.

hashar awarded a token.Sep 3 2015, 9:02 AM

Change 234425 merged by jenkins-bot:
Enable logging of XMP debug log channel for severity >=warning

https://gerrit.wikimedia.org/r/234425