Page MenuHomePhabricator

AbuseFilter throttle seemingly not working as expected
Closed, InvalidPublic

Description

This is about the private filter https://sv.wikipedia.org/wiki/Special:Missbruksfilter/122 on Swedish Wikipedia. I considered creating this as a private task, but that wouldn't make any sense as private tasks are made public after any code change is deployed, but the filter would not be any less private after that. My apologies in advance for being so vague.

Filter 122 on svwiki has a throttle. The action that was prevented by the filter on March 23 would have been correct without a throttle, but I can't find any action in the corresponding public log that would consume the number of allowed actions in the throttle within the time interval specified in the filter. You can find a link to this public log in the notes in the filter, if that helps. The link is in the comment written on March 20. I've tested this both with /examine and /tools and none of the actions match the filter. I've also tested the actions in the relevant time frame in public log without the subtype parameter that the link in the filter notes has, in case that was the problem, but I can't find any action that would make the filter prevent the next action.

Event Timeline

Maybe I should also add that the filter has correctly ignored actions that are sparse enough for the filter's throttle.

Daimona subscribed.

I see the following on mwlog1001:

$ zgrep "svwiki:abusefilter:throttle:122" AbuseFilter.log-20210324
2021-03-23 16:14:32 [34a0c5e1-368f-4cfa-956d-89680b3b5db1] mw1329 svwiki 1.36.0-wmf.35 AbuseFilter DEBUG: New value is 1 for throttle key svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab. Maximum is 1. {"newCount":1,"key":"svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab","rateCount":1}
2021-03-23 16:14:32 [34a0c5e1-368f-4cfa-956d-89680b3b5db1] mw1329 svwiki 1.36.0-wmf.35 AbuseFilter DEBUG: Increasing throttle key svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab {"key":"svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab"}
2021-03-23 16:41:21 [a6a6f9b3-4571-4c61-ab6e-7f359cb2ce8f] mw1330 svwiki 1.36.0-wmf.35 AbuseFilter DEBUG: New value is 2 for throttle key svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab. Maximum is 1. {"newCount":2,"key":"svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab","rateCount":1}
2021-03-23 16:41:21 [a6a6f9b3-4571-4c61-ab6e-7f359cb2ce8f] mw1330 svwiki 1.36.0-wmf.35 AbuseFilter DEBUG: Increasing throttle key svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab {"key":"svwiki:abusefilter:throttle:122:site:356a192b7913b04c54574d18c28d46e6395428ab"}

The first entries means that at 16:14:32 UTC something caused the throttle key to be increased without reaching the limit [1]. Then at 16:41:21 another account creation triggered the filter, which caused the throttle limit to be reached. This is the one that you can see in the AbuseLog.

Now the question is: what caused the entry at 16:14, given that there's no corresponding entry in the public log? The answer is that there's been an account creation attempt which failed the captcha at that time. Since AbuseFilter runs before ConfirmEdit, it registered the account creation (which matched that filter), but then the account creator apparently gave up after the wrong captcha, which is why you can't see any account being created at the time.


There's no real solution for this. The only option would be to run AbuseFilter after ConfirmEdit, but this would have a lot of implications and I'm not very comfortable doing that. FTR, this ordering is explicit in the configuration:

ConfirmEdit extension.json
"AuthManagerAutoConfig": {
	"preauth": {
		"CaptchaPreAuthenticationProvider": {
			"class": "CaptchaPreAuthenticationProvider",
			"sort": 10
		}
	}
},
AbuseFilter RegistrationCallback.php
$wgAuthManagerAutoConfig['preauth'][AbuseFilterPreAuthenticationProvider::class] = [
	'class' => AbuseFilterPreAuthenticationProvider::class,
	// Run after normal preauth providers to keep the log cleaner
	'sort' => 5,
];

The "sort" parameters indicate that ConfirmEdit should run after AbuseFilter. As such, I'm closing this task as invalid.


[1] - It says "new value is 1" because it locally increases the value by 1 before printing, but the key actually had value = 0 (i.e. was unset). The increased value is then compared with < to the max count, so it would be 1 < 1 which fails.