Page MenuHomePhabricator

Fatal AFPUserVisibleException when evaluating certain arrays
Closed, ResolvedPublicPRODUCTION ERROR

Description

I noticed a really weird behaviour with get_matches.
Try to go to Special:AbuseFilter/tools and insert the following expression:

a := [false, false];
b := [false, false];

a[0] != false & b[1] != false

and hit "Check syntax". Hooray, syntax is fine, let's evaluate it; try it, and you'll get an unknown error. Examinating the API response, an AFPUserVisibleException is thrown because, according to the message, you're trying to get an element from something that is not an array. However, both variables are of course arrays of length 2.

Apparently something is highly broken in there. And there's even more: if you replace the last line with its first or second condition, they work as expected, and the error only happens when there are both.

Important note: this doesn't only happen on Special:AbuseFilter/tools. In fact, try to create a filter with the code above but change the last line to

(a[0] != false & b[1] != false) | 1===1

the filter should always match, but if you make an edit, it actually won't.

UPDATE: this is not a regression, since it also happened at the time of get_matches introduction (which I first thought was the cause here).

Event Timeline

Daimona created this task.Sep 19 2018, 3:59 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptSep 19 2018, 3:59 PM
Daimona updated the task description. (Show Details)Sep 19 2018, 5:56 PM
Daimona renamed this task from Weird behaviour with get_matches and array to Weird behaviour with arrays.Sep 19 2018, 6:30 PM
Daimona triaged this task as High priority.
Daimona updated the task description. (Show Details)

It's hard to assess the risks of this error, but it may cause filters to fail silently. This actually happened on itwiki (logstash should bear the evidence).

Possibly operator precedence is weird? Perhaps the last expression is being parsed like (a[0] != false & b)[1] != false or something?

This evaluates successfully: a[0] != false & (b[1]) != false, so I'm pretty sure this is something wrong with operator precedence.

Krinkle renamed this task from Weird behaviour with arrays to Fatal AFPUserVisibleException on Special:AbuseFilter/tools when evaluating certain arrays.Sep 19 2018, 7:01 PM
Krinkle added a subscriber: Krinkle.

Seen in WMF Logstash starting with 1.32.0-wmf.20, and still seen on -wmf.22.

Error

Request ID: W6I6RgrAACgAAHhT@BUAAAAD

message
[{exception_id}] {exception_url}   AFPUserVisibleException from line 633 of /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php: Requesting array item of non-array at character 221.
stacktrace
#0 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(606): AbuseFilterParser->doLevelArrayElements(AFPData)
#1 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(567): AbuseFilterParser->doLevelUnarys(AFPData)
#2 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(557): AbuseFilterParser->doLevelSpecialWords(AFPData)
#3 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(529): AbuseFilterParser->doLevelBoolInvert(AFPData)
#4 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(508): AbuseFilterParser->doLevelPow(AFPData)
#5 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(482): AbuseFilterParser->doLevelMulRels(AFPData)
#6 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(460): AbuseFilterParser->doLevelSumRels(AFPData)
#7 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(442): AbuseFilterParser->doLevelCompares(AFPData)
#8 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(378): AbuseFilterParser->doLevelBoolOps(AFPData)
#9 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(299): AbuseFilterParser->doLevelConditions(AFPData)
#10 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(227): AbuseFilterParser->doLevelSet(AFPData)
#11 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(650): AbuseFilterParser->doLevelSemicolon(AFPData)
#12 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(617): AbuseFilterParser->doLevelBraces(AFPData)
#13 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(606): AbuseFilterParser->doLevelArrayElements(AFPData)
#14 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(567): AbuseFilterParser->doLevelUnarys(AFPData)
#15 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(557): AbuseFilterParser->doLevelSpecialWords(AFPData)
#16 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(529): AbuseFilterParser->doLevelBoolInvert(AFPData)
#17 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(508): AbuseFilterParser->doLevelPow(AFPData)
#18 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(482): AbuseFilterParser->doLevelMulRels(AFPData)
#19 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(460): AbuseFilterParser->doLevelSumRels(AFPData)
#20 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(431): AbuseFilterParser->doLevelCompares(AFPData)
#21 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(378): AbuseFilterParser->doLevelBoolOps(AFPData)
#22 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(299): AbuseFilterParser->doLevelConditions(AFPData)
#23 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(246): AbuseFilterParser->doLevelSet(AFPData)
#24 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(227): AbuseFilterParser->doLevelSet(AFPData)
#25 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(208): AbuseFilterParser->doLevelSemicolon(AFPData)
#26 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(194): AbuseFilterParser->doLevelEntry(AFPData)
#27 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/parser/AbuseFilterParser.php(178): AbuseFilterParser->intEval(string)
#28 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/AbuseFilter.php(500): AbuseFilterParser->evaluateExpression(string)
#29 /srv/mediawiki/php-1.32.0-wmf.20/extensions/AbuseFilter/includes/api/ApiAbuseFilterEvalExpression.php(10): AbuseFilter::evaluateExpression(string)
#30 /srv/mediawiki/php-1.32.0-wmf.20/includes/api/ApiMain.php(1587): ApiAbuseFilterEvalExpression->execute()
#31 /srv/mediawiki/php-1.32.0-wmf.20/includes/api/ApiMain.php(531): ApiMain->executeAction()
#32 /srv/mediawiki/php-1.32.0-wmf.20/includes/api/ApiMain.php(502): ApiMain->executeActionWithErrorHandling()
#33 /srv/mediawiki/php-1.32.0-wmf.20/api.php(87): ApiMain->execute()
Daimona renamed this task from Fatal AFPUserVisibleException on Special:AbuseFilter/tools when evaluating certain arrays to Fatal AFPUserVisibleException when evaluating certain arrays.Sep 20 2018, 7:59 AM
Daimona updated the task description. (Show Details)

@matmarex Yes, you may be correct. In fact, (a[0] != false) & (b[1] != false) evaluates correctly as well, and it would also explain why this only happens with both conditions. Needless to say, the problem is still serious, as it may make filters fail. @Krinkle May you please check in logstash how many of these errors we have? If I'm correct, there should be a spike in such errors on itwiki for yesterday.

As I'll have a bit more time I'll try a git bisect to see if this has been introduced by a specific patch, or it just never worked. Anyway, as written in the task description, this surely happened in 1.31.0-wmf.7 or so (November 2017).

Well, this already happened in REL1_27... I didn't go beyond because I'd need to install an older version of MediaWiki, which I don't have time to do now. We can surely say that this is not a regression introduced recently (although I'm not sure about the column in Wikimedia-production-error).
Also, the pattern seems to be correctly tokenized, so the problem is strictly inside AbuseFilterParser. To enrich the set of non-working examples: (a[0] != false & b[1]) != false produces the same result, i.e. syntax OK but then the same error on evaluation. Instead, it can't be (a[0] != false & b)[1] != false because this doesn't pass syntax check.
Something that could help debugging is that syntax check is passing. The main (and, I think, only) difference between evaluateExpression and checkSyntax is that the latter has $this->mAllowShort = false, so that short circuits aren't allowed. This means that the problem only happen when we try to short-circuit the evaluation.

UPDATE: arrays with one element produce the same result, so you can simplify the expression to

a := [false];
b := [false];

a[0] != false & b[0] != false

Thanks, I'll move it to pre-wmf.19 for now, which is where older issues go.

Daimona added a comment.EditedSep 21 2018, 11:17 AM

Hooray, I finally found the reason! There's an error in short circuit evaluation. This is how the parser behaves

  1. Sets variables correctly
  2. Evaluates a[0] != false and this is correctly parsed as false
  3. Then we have the & and $result is already false, so we enter in the short-circuit case
  4. It tries to evaluate the next token, which is b, and levels cascade until doLevelAtom
  5. Now doLevelAtom should get the value of the given variable (since b is AFPToken::TID).

What happens is: if shortCircuit is false, doLevelAtom returns the array of falses, and then other levels (ultimately, doLevelArrayElement) retrieve the value of b[0]. However, in this case, the short circuit prevents it and doLevelAtom returns the $result which we gave it, i.e. a NULL AFPData. Later on, as we would do without shortCircuit, we try to get b[0]. However, now b is null and, as one would expect, the parser throws because b is not an array.

I'm thinking about what would be the best solution. We could disable shortCircuit in doLevelAtom for arrays, but keeping it is useful for performance. Or, we could make it so that we skip the whole variable, i.e. b[0] and not just b (I have to figure out how). Or we could change $result to be an array (but it sounds like a dirty solution, not suitable for every case). I'll probably go ahead with option 2, as soon as I can make it work.

Oh, and BTW: this happens since arrays introduction, which was in 2009

Change 461937 had a related patch set uploaded (by Daimona Eaytoy; owner: Daimona Eaytoy):
[mediawiki/extensions/AbuseFilter@master] Unbreak short circuit for arrays

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

Daimona claimed this task.Sep 21 2018, 1:20 PM
Daimona added a project: User-Daimona.
Daimona moved this task from Backlog to Under review on the User-Daimona board.

Change 461937 merged by jenkins-bot:
[mediawiki/extensions/AbuseFilter@master] Unbreak short circuit for arrays

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

matmarex closed this task as Resolved.Oct 18 2018, 4:05 AM
matmarex removed a project: Patch-For-Review.
Daimona moved this task from Under review to Done on the User-Daimona board.Oct 18 2018, 7:27 AM
mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:08 PM