Page MenuHomePhabricator

revision page_user_timestamp index problematic on large wikis
Closed, DeclinedPublic

Description

MW schema has, for revision:

CREATE INDEX /*i*/page_user_timestamp ON /*_*/revision (rev_page,rev_user,rev_timestamp);

Several old wikis (enwiki included) do not yet have page_user_timestamp. After trialing it on enwiki slaves, it does not seem to offer much benefit over page_timestamp, and sometimes causes enough optimizer confusion that some normally fast queries jst time out. If specific queries do use it, perhaps those should be on a pager slave... or something.

This may be something that can be better controlled with another tilt at persistent engine-independent index statistics, but OTOH the chance to remove an index from an already-large table like revision is attractive. Need to investigate how the small/newer wikis are using the index (or not).

Event Timeline

Springle created this task.Jun 15 2015, 6:26 PM
Springle claimed this task.
Springle raised the priority of this task from to Needs Triage.
Springle updated the task description. (Show Details)
Springle added subscribers: Springle, jcrespo.
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 15 2015, 6:26 PM
Krinkle moved this task from Triage to Backlog on the DBA board.Sep 23 2015, 4:27 AM
Krinkle moved this task from Backlog to Triage on the DBA board.Sep 23 2015, 7:04 AM
Anomie added a subscriber: Anomie.Dec 23 2016, 2:24 AM
Anomie added a comment.Jan 4 2017, 2:59 PM

As far as usage, the API targets this index for ApiQueryContributors (although it only uses the prefix rev_page,rev_user) and for ApiQueryRevisions (when the rvuser parameter names an existing user, see T88084). At a quick grep I don't see anything else in core or deployed that looks like it would be using it.

Thanks again @Anomie! I wouldn't like to experiment with enwiki and for: T132416#2915953 I would just leave it there.
Maybe we can see the effect of removing it on some other smaller wiki

Anomie added a comment.EditedJan 4 2017, 3:58 PM

For experimenting with the lack of the index you could also take the queries and add IGNORE INDEX (page_user_timestamp), I believe.

For ApiQueryRevisions, the queries are something like

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 = '6818400' AND rev_user = '424450' AND ((rev_deleted & 4) = 0)
ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;

Possibly add a clause like AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)) in there.

Without the page_user_timestamp index it'll probably choose either page_timestamp or user_timestamp and filter rows without the matching rev_user or rev_page. Either one might turn out to be filtering out a lot of rows, since users typically edit many different pages and heavily-edited pages are usually edited by many different users.

For ApiQueryContributors, it should be (after I16e4a500) something like

SELECT rev_page AS `page`,COUNT(DISTINCT rev_user_text) AS `anons` FROM `revision` WHERE rev_page = 6818400 AND (rev_user = 0) AND ((rev_deleted & 4) = 0) GROUP BY rev_page

SELECT rev_page AS `page`,rev_user AS `user`,MAX(rev_user_text) AS `username` FROM `revision` WHERE rev_page = 6818400 AND (rev_user != 0) AND ((rev_deleted & 4) = 0) GROUP BY rev_page, rev_user ORDER BY rev_user LIMIT 5001

Here again, the second query might add AND (rev_page > 1 OR (rev_page = 1 AND rev_user >= 2)). These queries might also have multiple values for rev_page, with the ordering changed to rev_page, rev_user in that case.

Lacking the page_user_timestamp index, it'll probably fall back to rev_page_id or some other index that starts with rev_page. The second query will have to fetch all matching rows and filesort instead of being able to use the limit. For the first query, on WMF wikis it shouldn't make a difference after I16e4a500 since it'll be on a 'contributions' replica and only hit the "p1" partition which is just as good as using the index, but lacking that partitioning it'd have to fetch a lot more rows since it couldn't use the index to filter for rev_user=0.

Anomie added a comment.Jan 4 2017, 5:52 PM

I see https://gerrit.wikimedia.org/r/#/c/329340/ would add a use of the index in HistoryAction, similar to the use in ApiQueryRevisions.

@Anomie To clarify on the state of the ticket. This is one of the "we found this open ticket", which certainly is relevant to the work being done on revision, but without looking thoroughly, we do not know how accurate the initial claims are or the proposed soultions. Your comments are very helpful because of your wide knowledge and experience- I just want to reassure that no measure will be taken blindly, if that worries you.

Deleting things will only be done when there is a clear advantage and no problem. The problem is that we many times lack the context and we need first to understand the root issue, even if that means redoing the original steps from 0 of the reporter (we have the access but not necessarily all the history, and in general we -including us- are not that good at documenting non-mediawiki stuff).

Anomie added a comment.Jan 4 2017, 6:56 PM

Thanks, I wasn't worried. Sharing my knowledge and experience is why I'm commenting here, we can't make an informed decision unless someone identifies where the index is currently (supposed to be) being used and I'm able to do that.

For experimenting with the lack of the index you could also take the queries and add IGNORE INDEX (page_user_timestamp), I believe.

Thanks again for your helpful information and comments, really appreciated it.

For ApiQueryRevisions, the queries are something like

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 = '6818400' AND rev_user = '424450' AND ((rev_deleted & 4) = 0)
ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;

Possibly add a clause like AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)) in there.

Without the page_user_timestamp index it'll probably choose either page_timestamp or user_timestamp and filter rows without the matching rev_user or rev_page. Either one might turn out to be filtering out a lot of rows, since users typically edit many different pages and heavily-edited pages are usually edited by many different users.

This one is not using page_user_timestamp with and without the AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)).
It uses user_timestamp and page_timestamp depending on the AND clause.

For ApiQueryContributors, it should be (after I16e4a500) something like

SELECT rev_page AS `page`,COUNT(DISTINCT rev_user_text) AS `anons` FROM `revision` WHERE rev_page = 6818400 AND (rev_user = 0) AND ((rev_deleted & 4) = 0) GROUP BY rev_page

SELECT rev_page AS `page`,rev_user AS `user`,MAX(rev_user_text) AS `username` FROM `revision` WHERE rev_page = 6818400 AND (rev_user != 0) AND ((rev_deleted & 4) = 0) GROUP BY rev_page, rev_user ORDER BY rev_user LIMIT 5001

Here again, the second query might add AND (rev_page > 1 OR (rev_page = 1 AND rev_user >= 2)). These queries might also have multiple values for rev_page, with the ordering changed to rev_page, rev_user in that case.

Lacking the page_user_timestamp index, it'll probably fall back to rev_page_id or some other index that starts with rev_page. The second query will have to fetch all matching rows and filesort instead of being able to use the limit. For the first query, on WMF wikis it shouldn't make a difference after I16e4a500 since it'll be on a 'contributions' replica and only hit the "p1" partition which is just as good as using the index, but lacking that partitioning it'd have to fetch a lot more rows since it couldn't use the index to filter for rev_user=0.

These two queries do use page_user_timestamp.
For the first one the ignore index results in failing back to rev_page_id which doesn't look too much harmful, on the other hand the second query, as you suggested, does create temporary table and filesort, which isn't ideal.

I have enabled for a few minutes the userstat plugin on an API host and the index looks used:

root@PRODUCTION s1[enwiki]> select * from information_schema.index_statistics where table_name='revision' and index_name='page_user_timestamp';
+--------------+------------+---------------------+-----------+
| TABLE_SCHEMA | TABLE_NAME | INDEX_NAME          | ROWS_READ |
+--------------+------------+---------------------+-----------+
| enwiki       | revision   | page_user_timestamp |    288941 |
+--------------+------------+---------------------+-----------+
1 row in set (0.00 sec)
Anomie added a comment.Jan 5 2017, 2:55 PM

This one is not using page_user_timestamp with and without the AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)).
It uses user_timestamp and page_timestamp depending on the AND clause.

It looks like it is when I explain it:

mysql:wikiadmin@db1071 [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 = '6818400' AND rev_user = '424450' AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
+------+-------------+----------+-------+---------------------------------------------------------------+---------------------+---------+-------------+------+-------------+
| 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,user_timestamp,page_user_timestamp,rev_page_id | page_user_timestamp | 8       | const,const |  143 | Using where |
+------+-------------+----------+-------+---------------------------------------------------------------+---------------------+---------+-------------+------+-------------+

mysql:wikiadmin@db1071 [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 = '6818400' AND rev_user = '424450' AND ((rev_deleted & 4) = 0) AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
+------+-------------+----------+-------+-------------------------------------------------------------------------------------+---------------------+---------+-------+------+-------------+
| 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 | range | PRIMARY,rev_timestamp,page_timestamp,user_timestamp,page_user_timestamp,rev_page_id | page_user_timestamp | 28      | NULL  |  132 | Using where |
+------+-------------+----------+-------+-------------------------------------------------------------------------------------+---------------------+---------+-------+------+-------------+

I chose dewiki here because I remembered you just got done fixing the revision table indexes there in T148967, while enwiki's are still screwed up. If you're running the exact query against enwiki rather than dewiki, you might want to change the rev_page and rev_user values to something that has more than 2 revisions and someone who has made any edits, the query planner might have enough information to realize one or the other is so low and decide the shorter index would be faster. For example,

mysql:wikiadmin@db1065 [enwiki]> 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 = '5149102' AND rev_user = '301903' AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
+------+-------------+----------+-------+---------------------------------------------------------------+---------------------+---------+-------------+------+-------------+
| 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   | rev_page_id,page_timestamp,user_timestamp,page_user_timestamp | page_user_timestamp | 8       | const,const |   33 | Using where |
+------+-------------+----------+-------+---------------------------------------------------------------+---------------------+---------+-------------+------+-------------+

The same probably applies to other wikis. For the rev_timestamp and rev_id in the additional AND clause, the thing to do is to run the query first without it (maybe with a lower limit) and pull the values out of the last row. That's what the API does.

Indeed different behaviour with enwiki - I chose enwiki for no particular reason, but that is a good catch!

root@PRODUCTION s1[enwiki]> 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 = '6818400' AND rev_user = '424450' AND ((rev_deleted & 4) = 0) AND (rev_timestamp < '20151014154548' OR (rev_timestamp = '20151014154548' AND rev_id<=147002634)) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
+------+-------------+----------+-------+--------------------------------------------------------------------------------+---------+---------+-------+------+----------------+
| id   | select_type | table    | type  | possible_keys                                                                  | key     | key_len | ref   | rows | Extra          |
+------+-------------+----------+-------+--------------------------------------------------------------------------------+---------+---------+-------+------+----------------+
|    1 | SIMPLE      | page     | const | PRIMARY                                                                        | PRIMARY | 4       | const |    1 | Using filesort |
|    1 | SIMPLE      | revision | ref   | PRIMARY,rev_id,rev_timestamp,page_timestamp,user_timestamp,page_user_timestamp | PRIMARY | 4       | const |    2 | Using where    |
+------+-------------+----------+-------+--------------------------------------------------------------------------------+---------+---------+-------+------+----------------+
2 rows in set (0.00 sec)

root@PRODUCTION s1[enwiki]> 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 = '5149102' AND rev_user = '301903' AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
+------+-------------+----------+-------+-----------------------------------------------------------+---------------------+---------+-------------+------+------------------------------------+
| id   | select_type | table    | type  | possible_keys                                             | key                 | key_len | ref         | rows | Extra                              |
+------+-------------+----------+-------+-----------------------------------------------------------+---------------------+---------+-------------+------+------------------------------------+
|    1 | SIMPLE      | page     | const | PRIMARY                                                   | PRIMARY             | 4       | const       |    1 | Using filesort                     |
|    1 | SIMPLE      | revision | ref   | PRIMARY,page_timestamp,user_timestamp,page_user_timestamp | page_user_timestamp | 8       | const,const |   33 | Using index condition; Using where |
+------+-------------+----------+-------+-----------------------------------------------------------+---------------------+---------+-------------+------+------------------------------------+
2 rows in set (0.00 sec)

The stats I got from the INDEX_STATISTICS table were also from enwiki and it was clearly being used a lot there.

It looks like it is when I explain it:
Indeed different behaviour with enwiki

Make sure you use the handler stats/profiler in addition to explain- otherwise, you could get tricked by the optimizer giving a different query plan than the actually being used.

Anomie added a comment.Jan 5 2017, 3:45 PM

Make sure you use the handler stats/profiler in addition to explain- otherwise, you could get tricked by the optimizer giving a different query plan than the actually being used.

I know about SHOW STATUS like 'Hand%'; to see how many rows it actually touched and hint at the access pattern, but I don't know how to get it to tell me what plan was used.

I know about SHOW STATUS like 'Hand%'; to see how many rows it actually touched and hint at the access pattern, but I don't know how to get it to tell me what plan was used.

@Anomie Unless is is a very complex query, the plans can be gotten from analyzing the rows (you do not have the whole story, but in some cases you get more info than with explain, because post-execution:

root@db1071.eqiad.wmnet[dewiki]> 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 = '1' AND rev_user = '1' AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;
Empty set (0.01 sec)

root@db1071.eqiad.wmnet[dewiki]> SHOW STATUS like 'Hand%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 0     |
| Handler_icp_attempts       | 0     |
| Handler_icp_match          | 0     |
| Handler_mrr_init           | 0     |
| Handler_mrr_key_refills    | 0     |
| Handler_mrr_rowid_refills  | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 2     | <--- we entered 1 table and got no results; then we entered the other table using the index and got no results
| Handler_read_last          | 0     |
| Handler_read_next          | 0     |
| Handler_read_prev          | 0     |
| Handler_read_rnd           | 0     |
| Handler_read_rnd_deleted   | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_tmp_update         | 0     |
| Handler_tmp_write          | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
25 rows in set (0.00 sec)

root@db1071.eqiad.wmnet[dewiki]> 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 FROM revision WHERE rev_page = '1' AND rev_user = '0' AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;

root@db1071.eqiad.wmnet[dewiki]> SHOW STATUS like 'Hand%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 0     |
| Handler_icp_attempts       | 0     |
| Handler_icp_match          | 0     |
| Handler_mrr_init           | 0     |
| Handler_mrr_key_refills    | 0     |
| Handler_mrr_rowid_refills  | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 1     | <- we got the first results using the index "directly" (logn or in many cases constant time)
| Handler_read_last          | 0     |
| Handler_read_next          | 0     |
| Handler_read_prev          | 45    | <- then we scanned the table backwards with a "range scan". As the number of rows scanned is similar to the ones returned, this is very efficient
| Handler_read_rnd           | 0     |
| Handler_read_rnd_deleted   | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_tmp_update         | 0     |
| Handler_tmp_write          | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
25 rows in set (0.00 sec)

root@db1071.eqiad.wmnet[dewiki]> 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 FROM revision WHERE rev_page = '6108462' and rev_user BETWEEN 1 AND 1000000 AND ((rev_deleted & 4) = 0) ORDER BY rev_timestamp DESC, rev_id DESC LIMIT 5001;

5001 rows in set (5.18 sec)

root@db1071.eqiad.wmnet[dewiki]> SHOW STATUS like 'Hand%';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| Handler_commit             | 1     |
| Handler_delete             | 0     |
| Handler_discover           | 0     |
| Handler_external_lock      | 0     |
| Handler_icp_attempts       | 20567 | (readme last) But at least Index condition pushdown could be used, so instead of doing a full row scan, the index was used to read less data, even if an appropiate index could not be found (e.g. the last columns of the index were used, making it not ideal). Faster than doing row scans without an index, anyway
| Handler_icp_match          | 20567 |
| Handler_mrr_init           | 0     |
| Handler_mrr_key_refills    | 0     |
| Handler_mrr_rowid_refills  | 0     |
| Handler_prepare            | 0     |
| Handler_read_first         | 0     |
| Handler_read_key           | 1     | <-- starting row found directly using the index
| Handler_read_last          | 0     |
| Handler_read_next          | 20567 | <-- (readme 1st) then 20K rows have to be read in order (even if 5000 were returned), many were discarded
| Handler_read_prev          | 0     |
| Handler_read_rnd           | 0     |
| Handler_read_rnd_deleted   | 0     |
| Handler_read_rnd_next      | 0     |
| Handler_rollback           | 0     |
| Handler_savepoint          | 0     |
| Handler_savepoint_rollback | 0     |
| Handler_tmp_update         | 0     |
| Handler_tmp_write          | 0     |
| Handler_update             | 0     |
| Handler_write              | 0     |
+----------------------------+-------+
25 rows in set (0.00 sec)

For more insights, queries have the basic information stored on performance_schema:

root@db1071.eqiad.wmnet[sys]> SELECT * FROM statement_analysis LIMIT 1\G
*************************** 1. row ***************************
            query: SELECT `rev_id` , `rev_page` , ...  DESC , `rev_id` DESC LIMIT ?  <---- the full query is available on a separate table
               db: dewiki
        full_scan:                     <--- no full scan, good
       exec_count: 169128407 <-- times seen since last restart or manual stats flush
        err_count: 0              <-- the query never failed or gave a warning
       warn_count: 0
    total_latency: 4.82 w
      max_latency: 4.36 s
      avg_latency: 17.25 ms  <-- relatively fast query
     lock_latency: 2.65 h
        rows_sent: 324309247
    rows_sent_avg: 2           <-- very few rows returned (good)
    rows_examined: 0
rows_examined_avg: 0
    rows_affected: 0
rows_affected_avg: 0
       tmp_tables: 0            <--- it never requires temporary intermediate tables, neither on memory nor on disk
  tmp_disk_tables: 0
      rows_sorted: 838999828520 <--- it requires, however, some sort passes (without indexes), which slows down things a bit.
sort_merge_passes: 57395541
           digest: 45b77423b5b6587d9ce6d059f2706b9c <---- unique indentifier
       first_seen: 2016-06-21 09:24:55
        last_seen: 2017-01-05 16:34:55 <--- last time seen
1 row in set (0.04 sec)

More detailed performance is available, but it is not enabled by default: http://www.drdobbs.com/database/detailed-profiling-of-sql-activity-in-my/240154959

Profiling still works, although has been deprecated, but maybe it is simpler to use for now:

root@db1071.eqiad.wmnet[sys]> SET PROFILING=1;
Query OK, 0 rows affected (0.00 sec)

root@db1071.eqiad.wmnet[sys]> use dewiki
Database changed
root@db1071.eqiad.wmnet[dewiki]> 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 FROM revision WHERE rev_page = '6108462' and rev_user BETWEEN 1 AND 1000000 AND ((rev_deleted & 4) = 0) ORDER BY rev_ti
...

5001 rows in set (0.15 sec)

root@db1071.eqiad.wmnet[dewiki]> SHOW PROFILES;
+----------+------------+----------------------------------------------------------------------------------------------------------------------------
| Query_ID | Duration   | Query                                                                                                                      
+----------+------------+----------------------------------------------------------------------------------------------------------------------------
|        1 | 0.00013021 | SELECT DATABASE()                                                                                                          
|        2 | 0.14366797 | 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_
+----------+------------+----------------------------------------------------------------------------------------------------------------------------
2 rows in set (0.00 sec)

root@db1071.eqiad.wmnet[dewiki]> SHOW PROFILE FOR QUERY 2;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000066 |
| checking permissions | 0.000007 |
| Opening tables       | 0.000023 |
| After opening tables | 0.000006 |
| System lock          | 0.000005 |
| Table lock           | 0.000004 |
| After opening tables | 0.000007 |
| init                 | 0.000019 |
| optimizing           | 0.000014 |
| statistics           | 0.000190 |
| preparing            | 0.000023 |
| executing            | 0.000005 |
| Sorting result       | 0.137487 |
| Sending data         | 0.005755 |
| end                  | 0.000010 |
| query end            | 0.000006 |
| closing tables       | 0.000006 |
| freeing items        | 0.000007 |
| updating status      | 0.000011 |
| cleaning up          | 0.000017 |
+----------------------+----------+
20 rows in set (0.00 sec)

root@db1071.eqiad.wmnet[dewiki]> SET PROFILING = 0;
Query OK, 0 rows affected (0.00 sec)

I have enabled for a few minutes the userstat plugin on an API host and the index looks used:

@Marostegui That is a waste. We precisely chose performance_schema over userstats because it covers all usages of userstats and more. Example:

unused indexes
root@db1071.eqiad.wmnet[sys]> SELECT * FROM schema_unused_indexes;
+---------------+--------------------------------+------------------------------------+
| object_schema | object_name                    | index_name                         |
+---------------+--------------------------------+------------------------------------+
| dewiki        | abuse_filter                   | af_user                            |
| dewiki        | abuse_filter_history           | afh_user                           |
| dewiki        | abuse_filter_history           | afh_user_text                      |
| dewiki        | abuse_filter_log               | afl_log_id                         |
| dewiki        | abuse_filter_log               | afl_ip                             |
| dewiki        | abuse_filter_log               | afl_rev_id                         |
...
| dewiki        | revision                       | rev_page_id                        |
| dewiki        | revision                       | page_user_timestamp                |
| dewiki        | revision                       | usertext_timestamp                 |
| dewiki        | revision                       | user_timestamp                     |
| dewiki        | revision                       | page_timestamp                     |
| dewiki        | revision                       | rev_timestamp                      |
...
| wikidatawiki  | __wmf_checksums                | ts_db_tbl                          |
+---------------+--------------------------------+------------------------------------+
258 rows in set (0.02 sec)
redundant indexes
root@db1071.eqiad.wmnet[sys]> SELECT * FROM schema_redundant_indexes\G
*************************** 1. row ***************************
              table_schema: dewiki
                table_name: change_tag
      redundant_index_name: ct_log_id
   redundant_index_columns: ct_log_id,ct_tag
redundant_index_non_unique: 0
       dominant_index_name: change_tag_log_tag
    dominant_index_columns: ct_log_id,ct_tag
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`change_tag` DROP INDEX `ct_log_id`
*************************** 2. row ***************************
              table_schema: dewiki
                table_name: change_tag
      redundant_index_name: ct_rev_id
   redundant_index_columns: ct_rev_id,ct_tag
redundant_index_non_unique: 0
       dominant_index_name: change_tag_rev_tag
    dominant_index_columns: ct_rev_id,ct_tag
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`change_tag` DROP INDEX `ct_rev_id`
*************************** 3. row ***************************
              table_schema: dewiki
                table_name: change_tag
      redundant_index_name: ct_tag
   redundant_index_columns: ct_tag,ct_rc_id,ct_rev_id,ct_log_id
redundant_index_non_unique: 1
       dominant_index_name: change_tag_tag_id
    dominant_index_columns: ct_tag,ct_rc_id,ct_rev_id,ct_log_id
 dominant_index_non_unique: 1
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`change_tag` DROP INDEX `ct_tag`
*************************** 4. row ***************************
              table_schema: dewiki
                table_name: change_tag
      redundant_index_name: change_tag_rc_tag
   redundant_index_columns: ct_rc_id,ct_tag
redundant_index_non_unique: 1
       dominant_index_name: ct_rc_id
    dominant_index_columns: ct_rc_id,ct_tag
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`change_tag` DROP INDEX `change_tag_rc_tag`
*************************** 5. row ***************************
              table_schema: dewiki
                table_name: cur
      redundant_index_name: id_title_ns_red
   redundant_index_columns: cur_id,cur_title,cur_namespace,cur_is_redirect
redundant_index_non_unique: 1
       dominant_index_name: cur_id
    dominant_index_columns: cur_id
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`cur` DROP INDEX `id_title_ns_red`
*************************** 6. row ***************************
              table_schema: dewiki
                table_name: cur
      redundant_index_name: name_title_timestamp
   redundant_index_columns: cur_namespace,cur_title,inverse_timestamp
redundant_index_non_unique: 1
       dominant_index_name: name_title_dup_prevention
    dominant_index_columns: cur_namespace,cur_title
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`cur` DROP INDEX `name_title_timestamp`
*************************** 7. row ***************************
              table_schema: dewiki
                table_name: localisation_file_hash
      redundant_index_name: lfh_file_hash
   redundant_index_columns: lfh_file,lfh_hash
redundant_index_non_unique: 1
       dominant_index_name: lfh_file
    dominant_index_columns: lfh_file
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`localisation_file_hash` DROP INDEX `lfh_file_hash`
*************************** 8. row ***************************
              table_schema: dewiki
                table_name: moodbar_feedback_response
      redundant_index_name: mbfr_mbf_id
   redundant_index_columns: mbfr_mbf_id
redundant_index_non_unique: 1
       dominant_index_name: mbfr_mbf_mbfr_id
    dominant_index_columns: mbfr_mbf_id,mbfr_id
 dominant_index_non_unique: 1
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`moodbar_feedback_response` DROP INDEX `mbfr_mbf_id`
*************************** 9. row ***************************
              table_schema: dewiki
                table_name: page_restrictions
      redundant_index_name: pr_page
   redundant_index_columns: pr_page
redundant_index_non_unique: 1
       dominant_index_name: PRIMARY
    dominant_index_columns: pr_page,pr_type
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`page_restrictions` DROP INDEX `pr_page`
*************************** 10. row ***************************
              table_schema: dewiki
                table_name: tag_summary
      redundant_index_name: ts_log_id
   redundant_index_columns: ts_log_id
redundant_index_non_unique: 0
       dominant_index_name: tag_summary_log_id
    dominant_index_columns: ts_log_id
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`tag_summary` DROP INDEX `ts_log_id`
*************************** 11. row ***************************
              table_schema: dewiki
                table_name: tag_summary
      redundant_index_name: ts_rc_id
   redundant_index_columns: ts_rc_id
redundant_index_non_unique: 0
       dominant_index_name: tag_summary_rc_id
    dominant_index_columns: ts_rc_id
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`tag_summary` DROP INDEX `ts_rc_id`
*************************** 12. row ***************************
              table_schema: dewiki
                table_name: tag_summary
      redundant_index_name: ts_rev_id
   redundant_index_columns: ts_rev_id
redundant_index_non_unique: 0
       dominant_index_name: tag_summary_rev_id
    dominant_index_columns: ts_rev_id
 dominant_index_non_unique: 0
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `dewiki`.`tag_summary` DROP INDEX `ts_rev_id`
*************************** 13. row ***************************
              table_schema: wikidatawiki
                table_name: config
      redundant_index_name: cf_name_value
   redundant_index_columns: cf_name,cf_value
redundant_index_non_unique: 1
       dominant_index_name: PRIMARY
    dominant_index_columns: cf_name
 dominant_index_non_unique: 0
            subpart_exists: 1
            sql_drop_index: ALTER TABLE `wikidatawiki`.`config` DROP INDEX `cf_name_value`
*************************** 14. row ***************************
              table_schema: wikidatawiki
                table_name: ipblocks
      redundant_index_name: ipb_parent_block_id_2
   redundant_index_columns: ipb_parent_block_id
redundant_index_non_unique: 1
       dominant_index_name: ipb_parent_block_id
    dominant_index_columns: ipb_parent_block_id
 dominant_index_non_unique: 1
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `wikidatawiki`.`ipblocks` DROP INDEX `ipb_parent_block_id_2`
*************************** 15. row ***************************
              table_schema: wikidatawiki
                table_name: wb_terms
      redundant_index_name: wb_terms_language
   redundant_index_columns: term_language
redundant_index_non_unique: 1
       dominant_index_name: tmp1
    dominant_index_columns: term_language,term_type,term_entity_type,term_search_key
 dominant_index_non_unique: 1
            subpart_exists: 0
            sql_drop_index: ALTER TABLE `wikidatawiki`.`wb_terms` DROP INDEX `wb_terms_language`
15 rows in set (0.11 sec)
Anomie added a comment.Jan 5 2017, 5:27 PM

@jcrespo Thanks for all that!

root@db1071.eqiad.wmnet[sys]> SELECT * FROM statement_analysis LIMIT 1\G

Unfortunately I don't seem to have access to that one, at least not with the sql command run from terbium.

mysql:wikiadmin@db1071 [dewiki]> use sys;
ERROR 1044 (42000): Access denied for user 'wikiadmin'@'10.%' to database 'sys'
first_seen: 2016-06-21 09:24:55

I suppose that means the stats include times the query ran before T148967 fixed the indexes? I see from the data in that task that the query probably did filesort before 2016-12-02 since the (rev_page, rev_id) PK it had before seems to confuse the planner somehow.

@jcrespo Thanks for all that!

root@db1071.eqiad.wmnet[sys]> SELECT * FROM statement_analysis LIMIT 1\G

Unfortunately I don't seem to have access to that one, at least not with the sql command run from terbium.

mysql:wikiadmin@db1071 [dewiki]> use sys;
ERROR 1044 (42000): Access denied for user 'wikiadmin'@'10.%' to database 'sys'

Wikiadmin should not have access to sys- you should. We are rethinking user permissions, performance_schema should be on grafana, but we weren't allowed to export to the public one due to sensitive access data. There are plans to setup a private one with the same data, and historic trends for all NDA-signed users.

first_seen: 2016-06-21 09:24:55

I suppose that means the stats include times the query ran before T148967 fixed the indexes? I see from the data in that task that the query probably did filesort before 2016-12-02 since the (rev_page, rev_id) PK it had before seems to confuse the planner somehow.

Yes, in this particular case, things are grouped by digest, not plan- with the above planned setup we may be able to see the trends changing globally (among several servers).

@Anomie @Marostegui I want your thoughts on this- I would like to proceed with the plan for revision as stated here: T132416#3057955

That mostly would mean mark this ticket as declined, but maybe only temporarily. The idea going to a common schema, as close as mediawiki as practically possible, and later coming back to analyzing which indexes are used or redundant. What do you think?

@Anomie @Marostegui I want your thoughts on this- I would like to proceed with the plan for revision as stated here: T132416#3057955

That mostly would mean mark this ticket as declined, but maybe only temporarily. The idea going to a common schema, as close as mediawiki as practically possible, and later coming back to analyzing which indexes are used or redundant. What do you think?

I would say we should go ahead.
That index is already present on some large wikis and we have been adding it as part of the unifications: T147305, T150644, T148967:

enwiki:

root@neodymium:/home/marostegui/git/software/dbtools# for i in `cat s1.hosts | awk -F " " '{print $1}' | egrep -v "dbstore*|labs*|db1069|db1095"`; do echo $i; mysql --skip-ssl enwiki -h$i -e "show create table revision\G" | grep page_user_timestamp | wc -l;done
db2034.codfw.wmnet
1
db2042.codfw.wmnet
1
db2048.codfw.wmnet
1
db2055.codfw.wmnet
1
db2062.codfw.wmnet
1
db2069.codfw.wmnet
1
db2070.codfw.wmnet
1
db2016.codfw.wmnet
1
db1080.eqiad.wmnet
1
db1083.eqiad.wmnet
1
db1089.eqiad.wmnet
1
db1073.eqiad.wmnet
1
db1072.eqiad.wmnet
1
db1066.eqiad.wmnet
1
db1065.eqiad.wmnet
1
db1055.eqiad.wmnet
1
db1051.eqiad.wmnet
1
db1047.eqiad.wmnet
0
db1057.eqiad.wmnet
0
db1052.eqiad.wmnet
1

commons:

root@neodymium:/home/marostegui/git/software/dbtools# for i in `cat s4.hosts | awk -F " " '{print $1}' | egrep -v "dbstore*|labs*|db1069|db1095"`; do echo $i; mysql --skip-ssl commonswiki -h$i -e "show create table revision\G" | grep page_user_timestamp | wc -l;done
db2065.codfw.wmnet
1
db2058.codfw.wmnet
1
db2051.codfw.wmnet
1
db2044.codfw.wmnet
0
db2037.codfw.wmnet
0
db2019.codfw.wmnet
1
db1053.eqiad.wmnet
0
db1056.eqiad.wmnet
0
db1059.eqiad.wmnet
1
db1064.eqiad.wmnet
1
db1068.eqiad.wmnet
1
db1081.eqiad.wmnet
1
db1084.eqiad.wmnet
1
db1091.eqiad.wmnet
1
db1040.eqiad.wmnet
1

dewiki:

root@neodymium:/home/marostegui/git/software/dbtools# for i in `cat s5.hosts | awk -F " " '{print $1}' | egrep -v "dbstore*|labs*|db1069|db1095"`; do echo $i; mysql --skip-ssl dewiki -h$i -e "show create table revision\G" | grep page_user_timestamp | wc -l;done
db2038.codfw.wmnet
0
db2045.codfw.wmnet
1
db2052.codfw.wmnet
1
db2059.codfw.wmnet
1
db2066.codfw.wmnet
1
db2023.codfw.wmnet
1
db1026.eqiad.wmnet
0
db1045.eqiad.wmnet
1
db1070.eqiad.wmnet
1
db1071.eqiad.wmnet
1
db1082.eqiad.wmnet
1
db1087.eqiad.wmnet
1
db1092.eqiad.wmnet
1
db1049.eqiad.wmnet
1

wikidatawiki;

root@neodymium:/home/marostegui/git/software/dbtools# for i in `cat s5.hosts | awk -F " " '{print $1}' | egrep -v "dbstore*|labs*|db1069|db1095"`; do echo $i; mysql --skip-ssl wikidatawiki -h$i -e "show create table revision\G" | grep page_user_timestamp | wc -l;done
db2038.codfw.wmnet
1
db2045.codfw.wmnet
1
db2052.codfw.wmnet
1
db2059.codfw.wmnet
1
db2066.codfw.wmnet
1
db2023.codfw.wmnet
1
db1026.eqiad.wmnet
1
db1045.eqiad.wmnet
1
db1070.eqiad.wmnet
1
db1071.eqiad.wmnet
1
db1082.eqiad.wmnet
1
db1087.eqiad.wmnet
1
db1092.eqiad.wmnet
1
db1049.eqiad.wmnet
1

@Anomie @Marostegui I want your thoughts on this- I would like to proceed with the plan for revision as stated here: T132416#3057955

That mostly would mean mark this ticket as declined, but maybe only temporarily. The idea going to a common schema, as close as mediawiki as practically possible, and later coming back to analyzing which indexes are used or redundant. What do you think?

I like that plan. I'll add that if we later decide that page_user_timestamp or any other index doesn't work generally on the cluster for some reason, we should probably be removing it from tables.sql too.

jcrespo closed this task as Declined.Feb 27 2017, 3:30 PM

if we later decide that page_user_timestamp or any other index doesn't work generally on the cluster for some reason, we should probably be removing it from tables.sql too.

Of course, that should be always the plan.