Noticed it in mediawiki-errors after deploying group1 wikis to 1.33.0-wmf.8.
2018-12-12 14:16 <zfilipin@deploy1001> Synchronized php: group1 wikis to 1.33.0-wmf.8 (duration: 00m 51s)
The problem went away after reverting group1 wikis to 1.33.0-wmf.6.
2018-12-12 14:29 <zfilipin@deploy1001> rebuilt and synchronized wikiversions files: Revert "group1 wikis to 1.33.0-wmf.8"
479210: ApiBase: Pass empty string, not null, for $conds to ->select
| Status | Subtype | Assigned | Task | ||
|---|---|---|---|---|---|
| Resolved | Release | zeljkofilipin | T206662 1.33.0-wmf.8 deployment blockers | ||
| Resolved | Anomie | T211769 Wikimedia\Rdbms\Database::selectSQLText called from ApiBase::filterIDs with incorrect parameters: $conds must be a string or an array |
Change 479210 had a related patch set uploaded (by Zfilipin; owner: Anomie):
[mediawiki/core@master] ApiBase: Pass empty string, not null, for $conds to ->select
The reason we reverted was the spike on full scans, which we don't know yet if it is or not related to this: https://grafana.wikimedia.org/render/d-solo/000000273/mysql?panelId=3&orgId=1&var-dc=eqiad%20prometheus%2Fops&var-server=db1084&var-port=9104&kiosk&refresh=10s&from=1544614804395&to=1544625604395&width=1000&height=500&tz=Europe%2FMadrid
Seems unlikely to me. Is there a separate task with details on what queries were doing full scans?
Change 479219 had a related patch set uploaded (by Ladsgroup; owner: Anomie):
[mediawiki/core@wmf/1.33.0-wmf.8] ApiBase: Pass empty string, not null, for $conds to ->select
No, I didn't have time to capture them live, but looking at sys by "first_seen" these are the ones and the time they first showed up and the last time they did so:
+-------------------------------------------------------------------+---------------------+---------------------+---------------+------------+---------------+-----------+ | query | first_seen | last_seen | total_latency | exec_count | rows_examined | rows_sent | +-------------------------------------------------------------------+---------------------+---------------------+---------------+------------+---------------+-----------+ | SELECT `oi_timestamp` AS `img_ ... Y `oi_timestamp` DESC LIMIT ? | 2018-12-12 14:27:52 | 2018-12-12 14:28:02 | 7.69 s | 2 | 8834514 | 2 | | SELECT `oi_timestamp` AS `img_ ... DER BY `oi_timestamp` LIMIT ? | 2018-12-12 14:27:56 | 2018-12-12 14:28:05 | 7.30 s | 2 | 8834714 | 102 | | SELECT * FROM `schema_tables_with_full_table_scans` | 2018-12-12 14:57:55 | 2018-12-12 14:57:55 | 42.16 ms | 1 | 610 | 31 | | SELECT QUERY , `first_seen` , ... ` LIKE ? AND QUERY NOT LIKE ? | 2018-12-12 15:01:38 | 2018-12-12 15:01:38 | 34.96 ms | 1 | 3722 | 9 | | SELECT QUERY , `first_seen` , ... ` LIKE ? AND QUERY NOT LIKE ? | 2018-12-12 15:02:16 | 2018-12-12 15:02:16 | 33.54 ms | 1 | 3726 | 11 | | SELECT QUERY , `first_seen` , ... ` LIKE ? AND QUERY NOT LIKE ? | 2018-12-12 15:01:58 | 2018-12-12 15:01:58 | 31.69 ms | 1 | 3724 | 10 | | SELECT QUERY , `first_seen` , ... ns` WHERE `first_seen` LIKE ? | 2018-12-12 15:00:55 | 2018-12-12 15:00:55 | 31.21 ms | 1 | 3721 | 9 | | SELECT `oi_timestamp` AS `img_ ... DER BY `oi_timestamp` LIMIT ? | 2018-12-12 14:27:39 | 2018-12-12 14:27:39 | 3.75 s | 1 | 4417357 | 51 | | SELECT * FROM `statements_with ... ns` WHERE `first_seen` LIKE ? | 2018-12-12 14:59:06 | 2018-12-12 14:59:06 | 28.10 ms | 1 | 3719 | 8 | | SELECT `oi_timestamp` AS `img_ ... DER BY `oi_timestamp` LIMIT ? | 2018-12-12 14:22:36 | 2018-12-12 14:28:07 | 27.71 s | 7 | 30920774 | 3 | | SELECT `oi_timestamp` AS `img_ ... Y `oi_timestamp` DESC LIMIT ? | 2018-12-12 14:22:40 | 2018-12-12 14:28:11 | 26.37 s | 7 | 30921366 | 299 | | SELECT `oi_timestamp` AS `img_ ... Y `oi_timestamp` DESC LIMIT ? | 2018-12-12 14:15:53 | 2018-12-12 14:28:56 | 2.18 m | 25 | 110432980 | 877 | +-------------------------------------------------------------------+---------------------+---------------------+---------------+------------+---------------+-----------+ 12 rows in set (0.03 sec)
Ugh, the "..." takes out most of the detail there. But I can tell from that that the scans aren't related to this task.
Change 479210 merged by jenkins-bot:
[mediawiki/core@master] ApiBase: Pass empty string, not null, for $conds to ->select
Change 479219 merged by jenkins-bot:
[mediawiki/core@wmf/1.33.0-wmf.8] ApiBase: Pass empty string, not null, for $conds to ->select
Mentioned in SAL (#wikimedia-operations) [2018-12-12T15:22:39Z] <ladsgroup@deploy1001> Synchronized php-1.33.0-wmf.8/includes/api/ApiBase.php: T211769 (duration: 00m 52s)
root@db1084.eqiad.wmnet[sys]> select query,first_seen,last_seen,total_latency,exec_count,rows_examined,rows_sent from x$statements_with_full_table_scans where first_seen like '2018-12-12%' and query not like '%statements_with_full_table_scans%'\G
*************************** 1. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? ORDER BY `oi_timestamp` DESC LIMIT ?
first_seen: 2018-12-12 14:15:53
last_seen: 2018-12-12 14:28:56
total_latency: 130627767982000
exec_count: 25
rows_examined: 110432980
rows_sent: 877
*************************** 2. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? AND ( `oi_timestamp` >= ? ) ORDER BY `oi_timestamp` LIMIT ?
first_seen: 2018-12-12 14:22:36
last_seen: 2018-12-12 14:28:07
total_latency: 27711608943000
exec_count: 7
rows_examined: 30920774
rows_sent: 3
*************************** 3. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? AND ( `oi_timestamp` < ? ) ORDER BY `oi_timestamp` DESC LIMIT ?
first_seen: 2018-12-12 14:22:40
last_seen: 2018-12-12 14:28:11
total_latency: 26374348551000
exec_count: 7
rows_examined: 30921366
rows_sent: 299
*************************** 4. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? AND ( `oi_timestamp` <= ? ) ORDER BY `oi_timestamp` DESC LIMIT ?
first_seen: 2018-12-12 14:27:52
last_seen: 2018-12-12 14:28:02
total_latency: 7693955058000
exec_count: 2
rows_examined: 8834514
rows_sent: 2
*************************** 5. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? AND ( `oi_timestamp` > ? ) ORDER BY `oi_timestamp` LIMIT ?
first_seen: 2018-12-12 14:27:56
last_seen: 2018-12-12 14:28:05
total_latency: 7299142771000
exec_count: 2
rows_examined: 8834714
rows_sent: 102
*************************** 6. row ***************************
query: SELECT `oi_timestamp` AS `img_timestamp` , `oi_name` AS `img_name` , `oi_name` AS `thumb` , `oi_size` AS `img_size` , ? AS `top` , COALESCE ( `comment_oi_description` . `comment_text` , `oi_description` ) AS `oi_description_text` , `comment_oi_description` . `comment_data` AS `oi_description_data` , `comment_oi_description` . `comment_id` AS `oi_description_cid` , ? AS `description_field` , `oi_user` AS `img_user` , `oi_user_text` AS `img_user_text` , ? AS `img_actor` FROM `oldimage` LEFT JOIN `comment` `comment_oi_description` ON ( ( `comment_oi_description` . `comment_id` = `oi_description_id` ) ) WHERE ( ( `oi_user` = ? ) ) AND `oi_deleted` = ? ORDER BY `oi_timestamp` LIMIT ?
first_seen: 2018-12-12 14:27:39
last_seen: 2018-12-12 14:27:39
total_latency: 3750216586000
exec_count: 1
rows_examined: 4417357
rows_sent: 51
*************************** 7. row ***************************
query: SELECT * FROM `schema_tables_with_full_table_scans`
first_seen: 2018-12-12 14:57:55
last_seen: 2018-12-12 14:57:55
total_latency: 42163868000
exec_count: 1
rows_examined: 610
rows_sent: 31
7 rows in set (0.03 sec)Note T211774: Full table scans on oldimage table was created for the full scan issue. Further discussion of that should take place there.