Checking the last 100 promoted users on de.wp:

Script that generated this table:

This might have been broken in rEFLRd97307825e14: Convert $wgMemc uses to WANObjectCache?

Change 627456 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling

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

In T262970#6464166, @matmarex wrote:

This might have been broken in rEFLRd97307825e14: Convert $wgMemc uses to WANObjectCache?

Indeed, I commented at https://gerrit.wikimedia.org/r/c/mediawiki/extensions/FlaggedRevs/+/538717 where it went wrong

Will need to be backported to 1.34 and 1.35 once merged

So to clarify, the problem is actually not that it "doesn't check" it, but rather it checks it and returns the opposite result?

In T262970#6464346, @matmarex wrote:

So to clarify, the problem is actually not that it "doesn't check" it, but rather it checks it and returns the opposite result?

Yes, that appears to be the case

Change 627456 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling

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

Change 627457 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling

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

Change 627458 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling

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

I +2'ed the cherry picks for 1.34 and 1.35. Given how long this has been an issue, I don't think it warrants cherry picking to the currently deployed version, and can wait for the train next week, but I'll leave that up to @matmarex

Change 627457 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling

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

Change 627458 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling

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

In T262970#6464372, @DannyS712 wrote:

I +2'ed the cherry picks for 1.34 and 1.35. Given how long this has been an issue, I don't think it warrants cherry picking to the currently deployed version, and can wait for the train next week, but I'll leave that up to @matmarex

So, the bug was introduced in that commit from 24 September 2019, but the code was not actually used at the time due to a bug in our configuration (T237191: FlaggedRevs: Automatic user promotion stopped working on some wikis on June 24, 2019), until I fixed that configuration yesterday. I'll do the backports later today.

Change 627461 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.8] Fix APCOND_FR_NEVERBLOCKED handling

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

Change 627462 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling

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

Scheduled: https://wikitech.wikimedia.org/wiki/Deployments#deploycal-item-20200915T2300

Change 627461 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.8] Fix APCOND_FR_NEVERBLOCKED handling

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

Change 627462 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling

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

Mentioned in SAL (#wikimedia-operations) [2020-09-15T23:18:42Z] <urbanecm@deploy1001> Synchronized php-1.36.0-wmf.8/extensions/FlaggedRevs/backend/FlaggedRevsHooks.php: rEFLR5beace32a396: Fix APCOND_FR_NEVERBLOCKED handling (T262970) (duration: 00m 58s)

Mentioned in SAL (#wikimedia-operations) [2020-09-15T23:20:33Z] <urbanecm@deploy1001> Synchronized php-1.36.0-wmf.9/extensions/FlaggedRevs/backend/FlaggedRevsHooks.php: rEFLR1c0b0d161fe1: Fix APCOND_FR_NEVERBLOCKED handling (T262970) (duration: 00m 56s)

@matmarex, @DannyS712 Hmm, weirdly enough at least two users one dewiki automatically got autoreview rights today despite having been blocked before:

• https://de.wikipedia.org/wiki/Spezial:Logbuch?type=&user=&page=Benutzer%3AAsmen&wpdate=&tagfilter=&wpfilters%5B%5D=newusers
• https://de.wikipedia.org/wiki/Spezial:Logbuch?type=&user=&page=Benutzer%3APublikkom&wpdate=&tagfilter=&wpfilters%5B%5D=newusers

I haven't gone through the whole list but something still seems amiss.

They are cached, but in your patch you added the negation "outside" the cache, so that shouldn't be the problem. Unless there's some other incorrect logic in there.

In T262970#6468369, @matmarex wrote:

They are cached, but in your patch you added the negation "outside" the cache, so that shouldn't be the problem. Unless there's some other incorrect logic in there.

@Urbanecm ran echo 'var_export( $wgAutopromoteOnce['onEdit'] );' | mwscript eval.php --wiki=dewiki | phaste to see what the actual criteria applied at run time is, and the result at P12614 shows that the APCOND_FR_NEVERBLOCKED is indeed being applied to autoreviewers.

I tested the condition manually on the beta cluster, and it correctly returns true for DannyS712:

> $u = User::newFromName( 'DannyS712' );

> $res = null;

> Hooks::runner()->onAutopromoteCondition( 70822, [], $u, $res );

> var_dump( $res );
bool(true)

But, when I found an account that has not been blocked, it still returned true - tested with DannyS712 test and the most recent account created on the beta cluster, MaryjoStrangways:

> $u = User::newFromName( 'DannyS712 test' );

> $res = null;

> Hooks::runner()->onAutopromoteCondition( 70822, [], $u, $res );

> var_dump( $res );
bool(true)

> $u = User::newFromName( 'MaryjoStrangways' );

> $res = null;

> Hooks::runner()->onAutopromoteCondition( 70822, [], $u, $res );

> var_dump( $res );
bool(true)

So it seems that regardless of if a user has been blocked before, the result is true.

Investigating further, I confirmed that the internal FlaggedRevsHooks::wasPreviouslyBlocked method should be working when the $cutoff_unixtime is the default 0

> echo( (int)Wikimedia\TestingAccessWrapper::newFromClass( FlaggedRevsHooks::class )->wasPreviouslyBlocked( User::newFromName( 'DannyS712' ), wfGetDB( DB_REPLICA ) ) );
1
> echo( (int)Wikimedia\TestingAccessWrapper::newFromClass( FlaggedRevsHooks::class )->wasPreviouslyBlocked( User::newFromName( 'DannyS712 test' ), wfGetDB( DB_REPLICA ) ) );
0

The relevant code:

$hasPriorBlock = (bool)$cache->getWithSetCallback(
	$cache->makeKey( 'flaggedrevs-autopromote-notblocked', $user->getId() ),
	$cache::TTL_SECOND,
	function ( $oldValue, &$ttl, array &$setOpts, $oldAsOf ) use ( $user ) {
		$dbr = wfGetDB( DB_REPLICA );
		$setOpts += Database::getCacheSetOptions( $dbr );
		return self::wasPreviouslyBlocked( $user, $dbr, $oldAsOf ?: 0 );
	},
	[ 'staleTTL' => $cache::TTL_WEEK ]
);
$result = !$hasPriorBlock;

passes the timestamp of the cached value, however. This means that the code only looks for blocks made since the last time it was checked. I suspect this was added so that once the cached value was that the user had a prior block, further checks would just return true, and if it was cached that they had no prior block, it would actually check the log to see if that had changed. This was the case prior to rEFLRd97307825e148c735427ab6808b351249216bc96

$key = wfMemcKey( 'flaggedrevs', 'autopromote-notblocked', $user->getId() );
$val = $wgMemc->get( $key );
if ( $val === 'false' ) {
	$result = false; // failed
} else {
	# Hit the DB if the result is not cached or if we need
	# to check if the user was blocked since the last check...
	$now_unix = time();
	$last_checked = is_int( $val ) ? $val : 0; // TS_UNIX
	$result = !self::wasPreviouslyBlocked( $user, $last_checked );
	$wgMemc->set( $key, $result ? $now_unix : 'false', 7 * 86400 );
}

Check the log, and if the user was previously blocked, say false, otherwise store the time of the latest check.
I'll sent a patch to restore this functionality, but the cached values may need to be cleared to ensure that there isn't pollution

Change 627803 had a related patch set uploaded (by DannyS712; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

I was just writing my own comment when you were writing yours… my understanding is:

(hopefully this is the same as yours, but less detailed, heh)

The negation should be inside, because:

• The value 'false' can't be cached, only 'true'
• When an outdated cached value is found, the code only checks the block log since the last time it was cached

As a result, if we cache 'true' for "the user has been blocked", the next time only recent block log will be checked, and (probably) no recent block will be found.

We must cache "true" for "the user has not been blocked", and then when only recent block log will be checked, the result will be correct.

@matmarex since the cache is only TTL_SECOND, I think its unlikely that cache pollution will be a problem. I've upload a patch to restore the old behavior and left detailed comments regarding how it worked

It has 'staleTTL' => $cache::TTL_WEEK though, so older values may be used somehow, I'm not sure if that matters.

I would just change the cache key to avoid messing with invalidation.

In T262970#6468577, @matmarex wrote:

It has 'staleTTL' => $cache::TTL_WEEK though, so older values may be used somehow, I'm not sure if that matters.

I would just change the cache key to avoid messing with invalidation.

Current cached values are only true and false, which should all be ignored - not === 'priorBlock' and fails is_int if I understand correctly

Change 627803 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627805 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.8] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627947 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627805 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.8] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627947 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Mentioned in SAL (#wikimedia-operations) [2020-09-16T23:40:02Z] <catrope@deploy1001> Synchronized php-1.36.0-wmf.9/extensions/FlaggedRevs: T262970 (duration: 01m 06s)

Mentioned in SAL (#wikimedia-operations) [2020-09-16T23:41:08Z] <catrope@deploy1001> Synchronized php-1.36.0-wmf.8/extensions/FlaggedRevs: T262970 (duration: 01m 06s)

Change 627948 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627949 had a related patch set uploaded (by Bartosz Dziewoński; owner: DannyS712):
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627948 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Change 627949 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling (part 2)

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

Also, for reference, here's the list of recently autopromoted users and whether any of them were blocked. Looks like the second problem only affected users on de.wp.

de.wikipedia.org

de.wiktionary.org

en.wikibooks.org

he.wikisource.org

pl.wikipedia.org

ru.wikisource.org

sq.wikipedia.org

Was the cache cleared? Here is the next account which was autopromoted despite being blocked:

• https://de.wikipedia.org/wiki/Spezial:Logbuch?type=&user=&page=Benutzer%3AVsler&wpdate=&tagfilter=&subtype=autopromote

In T262970#6469263, @Count_Count wrote:

Was the cache cleared? Here is the next account which was autopromoted despite being blocked:

• https://de.wikipedia.org/wiki/Spezial:Logbuch?type=&user=&page=Benutzer%3AVsler&wpdate=&tagfilter=&subtype=autopromote

No idea why, sorry. @matmarex thoughts?

Change 628189 had a related patch set uploaded (by Bartosz Dziewoński; owner: Bartosz Dziewoński):
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628206 had a related patch set uploaded (by Urbanecm; owner: Bartosz Dziewoński):
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628207 had a related patch set uploaded (by Urbanecm; owner: Bartosz Dziewoński):
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628208 had a related patch set uploaded (by Urbanecm; owner: Bartosz Dziewoński):
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628189 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@master] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628206 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_35] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628207 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@REL1_34] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Change 628208 merged by jenkins-bot:
[mediawiki/extensions/FlaggedRevs@wmf/1.36.0-wmf.9] Fix APCOND_FR_NEVERBLOCKED handling (part 3)

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

Mentioned in SAL (#wikimedia-operations) [2020-09-17T20:47:24Z] <urbanecm@deploy1001> Synchronized php-1.36.0-wmf.9/extensions/FlaggedRevs/backend/FlaggedRevsHooks.php: rEFLR19b9b9877ea3: Fix APCOND_FR_NEVERBLOCKED handling (part 3; T262970) (duration: 00m 57s)

List of affected users:
de.wikipedia.org

pl.wikipedia.org

@matmarex Looks good today, keeping my fingers crossed.

Interestingly enough the mildly annoying quirk that administrators and editors automatically get the autoreview right seems to have stopped as well (?)

@matmarex Should we inform admins somehow, or was that done?

In T262970#6474965, @Urbanecm wrote:

@matmarex Should we inform admins somehow, or was that done?

We have it covered for dewiki.

@Urbanecm It was discussed in more detail on T237191 and folks posted notices or fixed the rights (@Count_Count did dewiki, and also @Udo_T did dewiktionary and I did plwiki).