Page MenuHomePhabricator

Wikimedia\Rdbms\Database::selectSQLText called from ApiBase::filterIDs with incorrect parameters: $conds must be a string or an array
Closed, ResolvedPublic

Description

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"

TODO

479210: ApiBase: Pass empty string, not null, for $conds to ->select

Event Timeline

zeljkofilipin triaged this task as Unbreak Now! priority.Dec 12 2018, 2:35 PM
zeljkofilipin created this task.
Restricted Application changed the subtype of this task from "Release" to "Task". · View Herald Transcript
Restricted Application added subscribers: Liuxinyu970226, TerraCodes, Aklapper. · View Herald Transcript

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

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

zeljkofilipin updated the task description. (Show Details)
Anomie moved this task from Unsorted to Needs Review on the MediaWiki-API board.Dec 12 2018, 2:38 PM
zeljkofilipin removed zeljkofilipin as the assignee of this task.Dec 12 2018, 2:38 PM
Anomie claimed this task.Dec 12 2018, 2:46 PM

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

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

Marostegui added a comment.EditedDec 12 2018, 3:02 PM

Seems unlikely to me. Is there a separate task with details on what queries were doing full scans?

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

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

Change 479219 merged by jenkins-bot:
[mediawiki/core@wmf/1.33.0-wmf.8] ApiBase: Pass empty string, not null, for $conds to ->select

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

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)

@Anomie

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.

Anomie closed this task as Resolved.Dec 12 2018, 3:37 PM