prop=revisions with rvdir=newer gives internal_api_error_DBQueryError for page with many version
Closed, ResolvedPublic

Description

The url gives an error:
https://de.wikipedia.org/w/api.php?format=xml&action=query&prop=revisions&titles=Wikipedia:Vandalismusmeldung&rvlimit=1&rvprop=ids&rvdir=newer

<?xml version="1.0"?>
<api servedby="mw1144">
<error info="[12dc9266] Database query error" code="internal_api_error_DBQueryError"/>
</api>

According to action=info there are 288.604 revisions. But it should be possible using the api to get the first one, action=info could find it.

https://de.wikipedia.org/w/index.php?title=Wikipedia:Vandalismusmeldung&action=info

Related Objects

Umherirrender updated the task description. (Show Details)
Umherirrender raised the priority of this task from to Needs Triage.
Umherirrender added a subscriber: Umherirrender.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptAug 13 2015, 5:56 PM
Umherirrender set Security to None.
2015-08-13 17:50:40 mw1144 dewiki exception ERROR: [12dc9266] /w/api.php?format=xml&action=query&prop=revisions&titles=Wikipedia:Vandalismusmeldung&rvlimit=1&rvprop=ids&rvdir=newer   DBQueryError from line 1131 of /srv/mediawiki/php-1.26wmf17/includes/db/Database.php: A database error has occurred. Did you forget to run maintenance/update.php after upgrading?  See: https://www.mediawiki.org/wiki/Manual:Upgrading#Run_the_update_script
Query: SELECT  rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len  FROM `revision` INNER JOIN `page` ON ((page_id = rev_page))  WHERE rev_page = '7165976'  ORDER BY rev_timestamp,rev_id LIMIT 2  
Function: ApiQueryRevisions::run
Error: 2013 Lost connection to MySQL server during query (10.64.16.34)
Anomie added a subscriber: Anomie.

For some unknown reason, db1024 (10.64.16.34) is deciding to use the rev_timestamp index here instead of page_timestamp.

Umherirrender edited subscribers, added: Springle; removed: Spage.Aug 15 2015, 9:26 AM

For some unknown reason, db1024 (10.64.16.34) is deciding to use the rev_timestamp index here instead of page_timestamp.

Is that still the case, and is it worth investigating?

Restricted Application added a subscriber: StudiesWorld. · View Herald TranscriptNov 14 2015, 4:56 PM

For some unknown reason, db1024 (10.64.16.34) is deciding to use the rev_timestamp index here instead of page_timestamp.

Is that still the case, and is it worth investigating?

It is still the case. Although now dewiki 'api' is on db1045 instead of db1024, the bad plan remains.

Reiterating, the query in question is

SELECT  rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len  FROM `revision` INNER JOIN `page` ON ((page_id = rev_page))  WHERE rev_page = '7165976'  ORDER BY rev_timestamp,rev_id LIMIT 2

On db1045, EXPLAIN says:

+------+-------------+----------+-------+------------------------+---------------+---------+-------+------+-------------+
| id   | select_type | table    | type  | possible_keys          | key           | key_len | ref   | rows | Extra       |
+------+-------------+----------+-------+------------------------+---------------+---------+-------+------+-------------+
|    1 | SIMPLE      | page     | const | PRIMARY                | PRIMARY       | 4       | const |    1 |             |
|    1 | SIMPLE      | revision | index | PRIMARY,page_timestamp | rev_timestamp | 16      | NULL  |  398 | Using where |
+------+-------------+----------+-------+------------------------+---------------+---------+-------+------+-------------+

It seems odd that it thinks it'll only have to check 398 rows from rev_timestamp to find two with rev_page = 7165976.

Anomie merged a task: Restricted Task.Feb 6 2017, 1:54 AM
Anomie added subscribers: DerHexer, jcrespo.

Since we have altered revision table on dewiki (T148967#2853843 and T148967#2868434) the query plan has changed a bit:

root@PRODUCTION s5[dewiki]> explain SELECT  rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len  FROM `revision` INNER JOIN `page` ON ((page_id = rev_page))  WHERE rev_page = '7165976'  ORDER BY rev_timestamp,rev_id LIMIT 2;
+------+-------------+----------+-------+------------------------------------------------+----------------+---------+-------+--------+-------------+
| id   | select_type | table    | type  | possible_keys                                  | key            | key_len | ref   | rows   | Extra       |
+------+-------------+----------+-------+------------------------------------------------+----------------+---------+-------+--------+-------------+
|    1 | SIMPLE      | page     | const | PRIMARY                                        | PRIMARY        | 4       | const |      1 |             |
|    1 | SIMPLE      | revision | ref   | page_timestamp,rev_page_id,page_user_timestamp | page_timestamp | 4       | const | 898410 | Using where |
+------+-------------+----------+-------+------------------------------------------------+----------------+---------+-------+--------+-------------+
2 rows in set (0.00 sec)
root@PRODUCTION s5[dewiki]> show create table revision\G
*************************** 1. row ***************************
       Table: revision
Create Table: CREATE TABLE `revision` (
  `rev_id` int(8) unsigned NOT NULL AUTO_INCREMENT,
  `rev_page` int(8) unsigned NOT NULL DEFAULT '0',
  `rev_text_id` int(8) unsigned NOT NULL DEFAULT '0',
  `rev_comment` varbinary(255) NOT NULL,
  `rev_user` int(5) unsigned NOT NULL DEFAULT '0',
  `rev_user_text` varbinary(255) NOT NULL DEFAULT '',
  `rev_timestamp` varbinary(14) NOT NULL DEFAULT '',
  `rev_minor_edit` tinyint(1) unsigned NOT NULL DEFAULT '0',
  `rev_deleted` tinyint(1) unsigned NOT NULL DEFAULT '0',
  `rev_len` int(8) unsigned DEFAULT NULL,
  `rev_parent_id` int(8) unsigned DEFAULT NULL,
  `rev_sha1` varbinary(32) NOT NULL DEFAULT '',
  `rev_content_model` varbinary(32) DEFAULT NULL,
  `rev_content_format` varbinary(64) DEFAULT NULL,
  PRIMARY KEY (`rev_id`),
  KEY `rev_timestamp` (`rev_timestamp`),
  KEY `page_timestamp` (`rev_page`,`rev_timestamp`),
  KEY `user_timestamp` (`rev_user`,`rev_timestamp`),
  KEY `usertext_timestamp` (`rev_user_text`,`rev_timestamp`),
  KEY `rev_page_id` (`rev_page`,`rev_id`),
  KEY `page_user_timestamp` (`rev_page`,`rev_user`,`rev_timestamp`)
) ENGINE=InnoDB AUTO_INCREMENT=162365285 DEFAULT CHARSET=binary
1 row in set (0.00 sec)
Anomie added a comment.Feb 6 2017, 4:31 PM

While it seems to be fixed for rev_page = '7165976', db1070 and db1071 (the current replicas for the 'api' group on s5) still report the bad plan for some queries:

mysql:wikiadmin@db1070 [dewiki]> explain SELECT  rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len  FROM `revision` INNER JOIN `page` ON ((page_id = rev_page))   WHERE (rev_timestamp>='20010115145600') AND rev_page = '4049681'  ORDER BY rev_timestamp,rev_id LIMIT 2;
+------+-------------+----------+-------+--------------------------------------------------------------+---------------+---------+-------+-------+-------------+
| id   | select_type | table    | type  | possible_keys                                                | key           | key_len | ref   | rows  | Extra       |
+------+-------------+----------+-------+--------------------------------------------------------------+---------------+---------+-------+-------+-------------+
|    1 | SIMPLE      | page     | const | PRIMARY                                                      | PRIMARY       | 4       | const |     1 |             |
|    1 | SIMPLE      | revision | index | rev_timestamp,page_timestamp,page_user_timestamp,rev_page_id | rev_timestamp | 16      | NULL  | 10445 | Using where |
+------+-------------+----------+-------+--------------------------------------------------------------+---------------+---------+-------+-------+-------------+

The removal of the (rev_timestamp>='20010115145600') AND bit makes little difference:

mysql:wikiadmin@db1070 [dewiki]> explain SELECT  rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_user_text,rev_user,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,rev_content_format,rev_content_model,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len  FROM `revision` INNER JOIN `page` ON ((page_id = rev_page))   WHERE rev_page = '4049681'  ORDER BY rev_timestamp,rev_id LIMIT 2;
+------+-------------+----------+-------+------------------------------------------------+---------------+---------+-------+-------+-------------+
| id   | select_type | table    | type  | possible_keys                                  | key           | key_len | ref   | rows  | Extra       |
+------+-------------+----------+-------+------------------------------------------------+---------------+---------+-------+-------+-------------+
|    1 | SIMPLE      | page     | const | PRIMARY                                        | PRIMARY       | 4       | const |     1 |             |
|    1 | SIMPLE      | revision | index | page_timestamp,page_user_timestamp,rev_page_id | rev_timestamp | 16      | NULL  | 10445 | Using where |
+------+-------------+----------+-------+------------------------------------------------+---------------+---------+-------+-------+-------------+

The only difference seems to be that rev_timestamp isn't included in possible_keys, even though it still chooses to use it for some reason.

Marostegui closed this task as Resolved.Tue, Sep 4, 5:26 AM

This is now using the page_timestamp for all the hosts in s5. Probably this has been fixed with all the multiple schema changes + migration to 10.1
The query now takes 0 seconds

2 rows in set (0.00 sec)

The original URL reported works too without any problem.
I am considering this fixed.