Page MenuHomePhabricator

Costly IP block queries triggered by long x-forwarded-for
Open, In Progress, MediumPublic

Description

In T390510#10754750, @Ladsgroup noted intermittent spikes in queried rows in s1 consistent with full table scans.

Through a combination of rdbms channel mediawiki logs in logstash [0] and setting the slow-query log threshold to 3s on db1218, it became clear that these are due to IP block queries with stack traces such as:

from /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/TransactionProfiler.php(558)
#0 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/TransactionProfiler.php(363): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated(string, Wikimedia\Rdbms\GeneralizedSql, float, string, string)
#1 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/TransactionManager.php(574): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, float, bool, int, string, string)
#2 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/Database.php(858): Wikimedia\Rdbms\TransactionManager->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, float, bool, int, string)
#3 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/Database.php(711): Wikimedia\Rdbms\Database->attemptQuery(Wikimedia\Rdbms\Query, string, bool)
#4 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/Database.php(638): Wikimedia\Rdbms\Database->executeQuery(Wikimedia\Rdbms\Query, string, int)
#5 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/Database.php(1367): Wikimedia\Rdbms\Database->query(Wikimedia\Rdbms\Query, string)
#6 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/DBConnRef.php(127): Wikimedia\Rdbms\Database->select(array, array, array, string, array, array)
#7 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/database/DBConnRef.php(351): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#8 /srv/mediawiki/php-1.44.0-wmf.25/includes/libs/rdbms/querybuilder/SelectQueryBuilder.php(762): Wikimedia\Rdbms\DBConnRef->select(array, array, array, string, array, array)
#9 /srv/mediawiki/php-1.44.0-wmf.25/includes/block/DatabaseBlockStore.php(562): Wikimedia\Rdbms\SelectQueryBuilder->fetchResultSet()
#10 /srv/mediawiki/php-1.44.0-wmf.25/includes/block/BlockManager.php(522): MediaWiki\Block\DatabaseBlockStore->newListFromIPs(array, bool, bool)
#11 /srv/mediawiki/php-1.44.0-wmf.25/includes/block/BlockManager.php(475): MediaWiki\Block\BlockManager->getBlocksForIPList(array, bool, bool)
#12 /srv/mediawiki/php-1.44.0-wmf.25/includes/block/BlockManager.php(212): MediaWiki\Block\BlockManager->getXffBlocks(string, array, bool, bool)
#13 /srv/mediawiki/php-1.44.0-wmf.25/includes/user/User.php(1489): MediaWiki\Block\BlockManager->getBlock(MediaWiki\User\User, MediaWiki\Request\WebRequest, bool)
#14 /srv/mediawiki/php-1.44.0-wmf.25/includes/block/BlockManager.php(764): MediaWiki\User\User->getBlock()
#15 /srv/mediawiki/php-1.44.0-wmf.25/includes/MediaWikiEntryPoint.php(408): MediaWiki\Block\BlockManager->trackBlockWithCookie(MediaWiki\User\User, MediaWiki\Request\WebResponse)
#16 /srv/mediawiki/php-1.44.0-wmf.25/includes/MediaWikiEntryPoint.php(191): MediaWiki\MediaWikiEntryPoint->commitMainTransaction()
#17 /srv/mediawiki/php-1.44.0-wmf.25/includes/actions/ActionEntryPoint.php(206): MediaWiki\MediaWikiEntryPoint->doPrepareForOutput()
#18 /srv/mediawiki/php-1.44.0-wmf.25/includes/MediaWikiEntryPoint.php(174): MediaWiki\Actions\ActionEntryPoint->doPrepareForOutput()
#19 /srv/mediawiki/php-1.44.0-wmf.25/includes/actions/ActionEntryPoint.php(153): MediaWiki\MediaWikiEntryPoint->prepareForOutput()
#20 /srv/mediawiki/php-1.44.0-wmf.25/includes/MediaWikiEntryPoint.php(202): MediaWiki\Actions\ActionEntryPoint->execute()
#21 /srv/mediawiki/php-1.44.0-wmf.25/index.php(58): MediaWiki\MediaWikiEntryPoint->run()
#22 /srv/mediawiki/w/index.php(3): require(string)
#23 {main}

Looking specifically at the queries, we can see a large number of terms in the predicate of the WHERE clause, for example [1]:

SELECT  bl_id,bt_address,bt_user,bt_user_text,bl_timestamp,bt_auto,bl_anon_only,bl_create_account,bl_enable_autoblock,bl_expiry,bl_deleted,bl_block_email,bl_allow_usertalk,bl_parent_block_id,bl_sitewide,bl_by_actor,block_by_actor.actor_user AS `bl_by`,block_by_actor.actor_name AS `bl_by_text`,comment_bl_reason.comment_text AS `bl_reason_text`,comment_bl_reason.comment_data AS `bl_reason_data`,comment_bl_reason.comment_id AS `bl_reason_cid`,bt_range_start,bt_range_end  FROM `block` JOIN `block_target` ON ((bt_id=bl_target)) JOIN `actor` `block_by_actor` ON ((actor_id=bl_by_actor)) JOIN `comment` `comment_bl_reason` ON ((comment_bl_reason.comment_id = bl_reason_id))   WHERE ((((bt_ip_hex = '2F4FD5F9' AND bt_range_start IS NULL) OR (bt_range_start LIKE '2F4F%' ESCAPE '`' AND bt_range_start <= '2F4FD5F9' AND bt_range_end >= '2F4FD5F9'))) OR (((bt_ip_hex = 'AC44A453' AND bt_range_start IS NULL) OR (bt_range_start LIKE 'AC44%' ESCAPE '`' AND bt_range_start <= 'AC44A453' AND bt_range_end >= 'AC44A453'))) OR (((bt_ip_hex = '7F000001' AND bt_range_start IS NULL) OR (bt_range_start LIKE '7F00%' ESCAPE '`' AND bt_range_start <= '7F000001' AND bt_range_end >= '7F000001')))

In short, we're seeing queries with complex WHERE clauses due to unusually long inbound X-Forwarded-For headers (note the getXffBlocks in the stack trace). Correlating these with samples httpd access logs (e.g., by reqId), these appear to be short-lived spikes of action=edit calls on enwiki from a specific client IP [2], which in turn pile up.

@Daimona had the insight that these kinds of queries will result in full table scans - i.e., paring down to one predicate avoids that, but it may also be possible to take advantage of the index with some changes to the structure of the combined predicate.

We have not seen a repeat of these events since ~ 15:20 UTC.

[0] https://logstash.wikimedia.org/goto/cce5e059226c57232c4ebc97aa7be0be

[1] https://logstash.wikimedia.org/app/discover#/doc/logstash-*/logstash-mediawiki-1-7.0.0-1-2025.04.18?id=8GxASZYBF1zH-YDacqg1

[2] https://logstash.wikimedia.org/goto/e28d44590c3262d208148291d7881d96

Event Timeline

In P75285 I pasted the problematic query and its explain, then a trimmed-down version that still reproduces the issue (i.e., index isn't used with > 1 predicates), and a potential fix: P75285#302739. We're essentially just grouping common subexpressions in the query. This really is just playing with the optimizer, but the manual for index_merge actually suggests something similar: https://dev.mysql.com/doc/refman/8.4/en/index-merge-optimization.html

I imagine the fix could be along the lines of: introducing a new method to DatabaseBlockStore, similar to getRangeCond but accepting multiple ranges. Internally, the method would essentially just loop over all ranges and do what it already does, except that the $start === $end case is deduplicated by keeping track of all the relevant $start values, and making a single condition with all of them at the end.

And perhaps that could be done publicly in gerrit? It could easily be disguised as a refactoring / interface improvement / query readability change.

In general though, I'm not sure if changing the query will be enough to convince the optimizer for all possible inputs. And then there's the question of how other DBMSs will behave. Introducing a new composite index on (bt_ip_hex, bt_range_start, bt_range_end) to avoid the index_merge should also solve the problem.

@tstarling Hi what do you think of the above comment? Since you did the block refactor.

I imagine the fix could be along the lines of: introducing a new method to DatabaseBlockStore, similar to getRangeCond but accepting multiple ranges. Internally, the method would essentially just loop over all ranges and do what it already does, except that the $start === $end case is deduplicated by keeping track of all the relevant $start values, and making a single condition with all of them at the end.

And perhaps that could be done publicly in gerrit? It could easily be disguised as a refactoring / interface improvement / query readability change.

Sounds good. Do you want me to write it?

In general though, I'm not sure if changing the query will be enough to convince the optimizer for all possible inputs. And then there's the question of how other DBMSs will behave. Introducing a new composite index on (bt_ip_hex, bt_range_start, bt_range_end) to avoid the index_merge should also solve the problem.

A schema change would be more work -- maybe we can bundle this with T389028 if we decide to add an index for that. I suggest deploying the query and monitoring the logs to see if we still have a problem.

If anyone has a million blocks in PostgreSQL and complains that their queries are slow, we can just tell them to migrate to MariaDB.

I imagine the fix could be along the lines of: introducing a new method to DatabaseBlockStore, similar to getRangeCond but accepting multiple ranges. Internally, the method would essentially just loop over all ranges and do what it already does, except that the $start === $end case is deduplicated by keeping track of all the relevant $start values, and making a single condition with all of them at the end.

And perhaps that could be done publicly in gerrit? It could easily be disguised as a refactoring / interface improvement / query readability change.

Sounds good. Do you want me to write it?

Thank you, I'll write it now and commit it as a cleanup.

Thank you, I'll write it now and commit it as a cleanup.

https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1138500

Erring on the side of caution, I didn't tag this task. But maybe that'd be fine?

Patch merged. It'll go out with the train next week, but I imagine it could be cherry-picked to wmf.25 if needed. Do we want to backport the patch to the applicable release branches too? I just realized this task was NDA and not security, so tagging Security-Team now for input...

I imagine it could be cherry-picked to wmf.25 if needed.

With this task still private and the gerrit change set being fairly benign IMO, I don't think this necessitates a late-Thursday or Friday deployment. I'm happy to deploy it early on Monday the 28th though, if we don't want to wait for it to roll out with the train.

Do we want to backport the patch to the applicable release branches too?

Yes. We should definitely try to backport to the current, supported release branches, if possible.

I imagine it could be cherry-picked to wmf.25 if needed.

With this task still private and the gerrit change set being fairly benign IMO, I don't think this necessitates a late-Thursday or Friday deployment. I'm happy to deploy it early on Monday the 28th though, if we don't want to wait for it to roll out with the train.

Make sense, and I imagine this would be up to SRE anyway (depending on whether we get more instances of the expensive query).

Do we want to backport the patch to the applicable release branches too?

Yes. We should definitely try to backport to the current, supported release branches, if possible.

Can I go ahead and do that in gerrit, or would you rather wait for the next security release?

Yes. We should definitely try to backport to the current, supported release branches, if possible.

Can I go ahead and do that in gerrit, or would you rather wait for the next security release?

Since the change set for master is already public and merged, I think it's fine to backport now. @Reedy can decide if he wants to additionally mention this issue with T389302.

Reedy changed the edit policy from "Custom Policy" to "Custom Policy".

I looked into backporting but it's messy... In REL1_43, we need to make it work for the old block schema. In REL1_42 the code is different due to r1023560; maybe that one should be backported first? Other release branches don't have this method, or the new block schema for that matter.

sbassett changed the task status from Open to In Progress.May 12 2025, 4:47 PM
sbassett triaged this task as Medium priority.
sbassett changed the visibility from "Custom Policy" to "Public (No Login Required)".
sbassett changed the edit policy from "Custom Policy" to "All Users".
A_smart_kitten subscribed.

(assuming based on the above that this task is no longer NDAed)