Page MenuHomePhabricator

Expectation (readQueryTime <= 5) by MediaWiki\Actions\ActionEntryPoint::execute not met (actual: {actualSeconds}) in trx #{trxId}:{query}
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error
  • mwversion: 1.46.0-wmf.23
  • timestamp: 2026-04-10T14:27:48.440Z
  • phpversion: 8.3.30
  • reqId: 825c8cf6-9de8-42ed-82c5-8cb113b4c399
  • Find reqId in Logstash
normalized_message
Expectation (readQueryTime <= 5) by MediaWiki\Actions\ActionEntryPoint::execute not met (actual: {actualSeconds}) in trx #{trxId}:
{query}
FrameLocationCall
from/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/TransactionProfiler.php(569)
#0/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/TransactionProfiler.php(375)Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated(string, Wikimedia\Rdbms\GeneralizedSql, float, string, string)
#1/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/TransactionManager.php(571)Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, float, bool, int, string, string)
#2/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/Database.php(850)Wikimedia\Rdbms\TransactionManager->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, float, bool, int, string)
#3/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/Database.php(708)Wikimedia\Rdbms\Database->attemptQuery(Wikimedia\Rdbms\Query, string, bool)
#4/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/Database.php(635)Wikimedia\Rdbms\Database->executeQuery(Wikimedia\Rdbms\Query, string, int)
#5/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/Database.php(1368)Wikimedia\Rdbms\Database->query(Wikimedia\Rdbms\Query, string)
#6/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/DBConnRef.php(129)Wikimedia\Rdbms\Database->select(array, array, array, string, array, array)
#7/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/Database/DBConnRef.php(386)Wikimedia\Rdbms\DBConnRef->__call(string, array)
#8/srv/mediawiki/php-1.46.0-wmf.23/includes/libs/Rdbms/QueryBuilder/SelectQueryBuilder.php(761)Wikimedia\Rdbms\DBConnRef->select(array, array, array, string, array, array)
#9/srv/mediawiki/php-1.46.0-wmf.23/includes/Pager/IndexPager.php(468)Wikimedia\Rdbms\SelectQueryBuilder->fetchResultSet()
#10/srv/mediawiki/php-1.46.0-wmf.23/includes/Pager/IndexPager.php(259)MediaWiki\Pager\IndexPager->reallyDoQuery(string, int, bool)
#11/srv/mediawiki/php-1.46.0-wmf.23/includes/Pager/IndexPager.php(596)MediaWiki\Pager\IndexPager->doQuery()
#12/srv/mediawiki/php-1.46.0-wmf.23/includes/Specials/SpecialNewFiles.php(124)MediaWiki\Pager\IndexPager->getBody()
#13/srv/mediawiki/php-1.46.0-wmf.23/includes/SpecialPage/SpecialPage.php(714)MediaWiki\Specials\SpecialNewFiles->execute(null)
#14/srv/mediawiki/php-1.46.0-wmf.23/includes/SpecialPage/SpecialPageFactory.php(1714)MediaWiki\SpecialPage\SpecialPage->run(null)
#15/srv/mediawiki/php-1.46.0-wmf.23/includes/Actions/ActionEntryPoint.php(505)MediaWiki\SpecialPage\SpecialPageFactory->executePath(string, MediaWiki\Context\RequestContext)
#16/srv/mediawiki/php-1.46.0-wmf.23/includes/Actions/ActionEntryPoint.php(145)MediaWiki\Actions\ActionEntryPoint->performRequest()
#17/srv/mediawiki/php-1.46.0-wmf.23/includes/MediaWikiEntryPoint.php(180)MediaWiki\Actions\ActionEntryPoint->execute()
#18/srv/mediawiki/php-1.46.0-wmf.23/index.php(44)MediaWiki\MediaWikiEntryPoint->run()
#19/srv/mediawiki/w/index.php(3)require(string)
#20{main}
Impact
Notes

Related Objects

View Standalone Graph
This task is connected to more than 200 other tasks. Only direct parents and subtasks are shown here. Use View Standalone Graph to show more of the graph.

Event Timeline

wikiadmin2023@10.64.32.35(enwiki)> analyze SELECT  /*! STRAIGHT_JOIN */ file_name,fr_timestamp,actor_user,actor_name  FROM `file` JOIN `filerevision` ON ((file_latest=fr_id)) JOIN `actor` ON ((actor_id=fr_actor)) LEFT JOIN `user_groups` ON (ug_group = 'bot' AND (ug_user = actor_user) AND ((ug_expiry IS NULL OR ug_expiry >= '20260410142742')))   WHERE ug_group IS NULL  ORDER BY fr_timestamp DESC,file_name DESC LIMIT 51  ;
+------+-------------+--------------+--------+----------------------------+---------+---------+-------------------------------+---------+------------+----------+------------+---------------------------------+
| id   | select_type | table        | type   | possible_keys              | key     | key_len | ref                           | rows    | r_rows     | filtered | r_filtered | Extra                           |
+------+-------------+--------------+--------+----------------------------+---------+---------+-------------------------------+---------+------------+----------+------------+---------------------------------+
|    1 | SIMPLE      | file         | ALL    | file_latest                | NULL    | NULL    | NULL                          | 1018833 | 1003200.00 |   100.00 |     100.00 | Using temporary; Using filesort |
|    1 | SIMPLE      | filerevision | eq_ref | PRIMARY,fr_actor_timestamp | PRIMARY | 8       | enwiki.file.file_latest       | 1       | 0.96       |   100.00 |     100.00 |                                 |
|    1 | SIMPLE      | actor        | eq_ref | PRIMARY                    | PRIMARY | 8       | enwiki.filerevision.fr_actor  | 1       | 1.00       |   100.00 |     100.00 |                                 |
|    1 | SIMPLE      | user_groups  | eq_ref | PRIMARY,ug_group,ug_expiry | PRIMARY | 261     | enwiki.actor.actor_user,const | 1       | 0.28       |    50.53 |     100.00 | Using where; Not exists         |
+------+-------------+--------------+--------+----------------------------+---------+---------+-------------------------------+---------+------------+----------+------------+---------------------------------+
4 rows in set (6.654 sec)

wikiadmin2023@10.64.32.35(enwiki)>

This is what the read old query looks like.

wikiadmin2023@10.64.32.35(enwiki)> analyze SELECT  /*! STRAIGHT_JOIN */ img_name,img_timestamp,actor_user,actor_name  FROM `image` JOIN `actor` ON ((actor_id=img_actor)) LEFT JOIN `user_groups` ON (ug_group = 'bot' AND (ug_user = actor_user) AND ((ug_expiry IS NULL OR ug_expiry >= '20260410144340')))   WHERE ug_group IS NULL  ORDER BY img_timestamp DESC,img_name DESC LIMIT 51  ;
+------+-------------+-------------+--------+----------------------------+---------------+---------+-------------------------------+--------+--------+----------+------------+-------------------------+
| id   | select_type | table       | type   | possible_keys              | key           | key_len | ref                           | rows   | r_rows | filtered | r_filtered | Extra                   |
+------+-------------+-------------+--------+----------------------------+---------------+---------+-------------------------------+--------+--------+----------+------------+-------------------------+
|    1 | SIMPLE      | image       | index  | img_actor_timestamp        | img_timestamp | 14      | NULL                          | 833611 | 51.00  |   100.00 |     100.00 |                         |
|    1 | SIMPLE      | actor       | eq_ref | PRIMARY                    | PRIMARY       | 8       | enwiki.image.img_actor        | 1      | 1.00   |   100.00 |     100.00 |                         |
|    1 | SIMPLE      | user_groups | eq_ref | PRIMARY,ug_group,ug_expiry | PRIMARY       | 261     | enwiki.actor.actor_user,const | 1      | 0.00   |    50.53 |     100.00 | Using where; Not exists |
+------+-------------+-------------+--------+----------------------------+---------------+---------+-------------------------------+--------+--------+----------+------------+-------------------------+
3 rows in set (0.003 sec)

wikiadmin2023@10.64.32.35(enwiki)>

If we query file_revision first and stop doing a secondary sort by the file name, it fixes the query.

wikiadmin2023@10.64.32.35(enwiki)> explain SELECT /*! STRAIGHT_JOIN */ file_name,fr_timestamp,actor_user,actor_name FROM `filerevision` JOIN `file` ON ((file_latest=fr_id)) JOIN `actor` ON ((actor_id=fr_actor)) LEFT JOIN `user_groups` ON (ug_group = 'bot' AND (ug_user = actor_user) AND ((ug_expiry IS NULL OR ug_expiry >= '20260410152454'))) WHERE ug_group IS NULL ORDER BY fr_timestamp DESC LIMIT 51;
+------+-------------+--------------+--------+----------------------------+--------------+---------+-------------------------------+------+-------------------------+
| id   | select_type | table        | type   | possible_keys              | key          | key_len | ref                           | rows | Extra                   |
+------+-------------+--------------+--------+----------------------------+--------------+---------+-------------------------------+------+-------------------------+
|    1 | SIMPLE      | filerevision | index  | PRIMARY,fr_actor_timestamp | fr_timestamp | 14      | NULL                          | 100  |                         |
|    1 | SIMPLE      | file         | ref    | file_latest                | file_latest  | 8       | enwiki.filerevision.fr_id     | 1    |                         |
|    1 | SIMPLE      | actor        | eq_ref | PRIMARY                    | PRIMARY      | 8       | enwiki.filerevision.fr_actor  | 1    |                         |
|    1 | SIMPLE      | user_groups  | eq_ref | PRIMARY,ug_group,ug_expiry | PRIMARY      | 261     | enwiki.actor.actor_user,const | 1    | Using where; Not exists |
+------+-------------+--------------+--------+----------------------------+--------------+---------+-------------------------------+------+-------------------------+
4 rows in set (0.001 sec)

wikiadmin2023@10.64.32.35(enwiki)>

Change #1270055 had a related patch set uploaded (by Zabe; author: Zabe):

[mediawiki/core@master] NewFilesPager: Make sure file_revision is queried before file

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

Change #1270055 merged by jenkins-bot:

[mediawiki/core@master] NewFilesPager: Make sure filerevision is queried before file

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

Change #1270068 had a related patch set uploaded (by Zabe; author: Zabe):

[mediawiki/core@wmf/1.46.0-wmf.23] NewFilesPager: Make sure filerevision is queried before file

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

Change #1270068 merged by jenkins-bot:

[mediawiki/core@wmf/1.46.0-wmf.23] NewFilesPager: Make sure filerevision is queried before file

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

Mentioned in SAL (#wikimedia-operations) [2026-04-13T18:40:21Z] <zabe@deploy1003> Started scap sync-world: Backport for [[gerrit:1270068|NewFilesPager: Make sure filerevision is queried before file (T422946)]]

Mentioned in SAL (#wikimedia-operations) [2026-04-13T18:41:56Z] <zabe@deploy1003> zabe: Backport for [[gerrit:1270068|NewFilesPager: Make sure filerevision is queried before file (T422946)]] synced to the testservers (see https://wikitech.wikimedia.org/wiki/Mwdebug). Changes can now be verified there.

Change #1270515 had a related patch set uploaded (by Zabe; author: Zabe):

[mediawiki/core@master] NewFilePager: Add fr_id to fields for file read new

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

Change #1270515 merged by jenkins-bot:

[mediawiki/core@master] NewFilePager: Add fr_id to fields for file read new

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