Percona Server moved to https://jira.percona.com/projects/PS

Bad execution plan after running pt-osc

  1. Series 5.6
  2. Bug #1490548
Bug #1490548 reported by Miguel Angel Nieto
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Triaged
Medium
Unassigned
5.7
Triaged
Medium
Unassigned

Bug Description

In PS 5.6 with innodb_stats_persistent using pt-osc to add a column will change the execution path to "Full scan" on the new table.

CREATE TABLE `companies` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`site_id` int(11) NOT NULL,
`name` varchar(255) NOT NULL,
`custom1` varchar(255) DEFAULT NULL,
`custom2` varchar(255) DEFAULT NULL,
`custom3` varchar(255) DEFAULT NULL,
`custom4` varchar(255) DEFAULT NULL,
`custom5` varchar(255) DEFAULT NULL,
`custom6` varchar(255) DEFAULT NULL,
`custom7` varchar(255) DEFAULT NULL,
`custom8` varchar(255) DEFAULT NULL,
`custom9` varchar(255) DEFAULT NULL,
`custom10` varchar(255) DEFAULT NULL,
`created_at` datetime DEFAULT NULL,
`updated_at` datetime DEFAULT NULL,
`custom11` varchar(255) DEFAULT NULL,
`custom12` varchar(255) DEFAULT NULL,
`custom13` varchar(255) DEFAULT NULL,
`custom14` varchar(255) DEFAULT NULL,
`custom15` varchar(255) DEFAULT NULL,
`custom16` varchar(255) DEFAULT NULL,
`custom17` varchar(255) DEFAULT NULL,
`custom18` varchar(255) DEFAULT NULL,
`custom19` varchar(255) DEFAULT NULL,
`custom20` varchar(255) DEFAULT NULL,
`custom21` varchar(255) DEFAULT NULL,
`custom22` varchar(255) DEFAULT NULL,
`custom23` varchar(255) DEFAULT NULL,
`custom24` varchar(255) DEFAULT NULL,
`custom25` varchar(255) DEFAULT NULL,
`ticket_count` mediumint(8) unsigned DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB;

INSERT INTO companies (id) VALUES (NULL);
INSERT INTO companies (id) VALUES (NULL);
INSERT INTO companies (id) VALUES (NULL);
... up to 30 times for example.

Good execution plan:

# Query_time: 0.000296 Lock_time: 0.000113 Rows_sent: 5 Rows_examined: 5 Rows_affected: 0
# Bytes_sent: 2168 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# InnoDB_trx_id: 1130
# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000
# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000
# InnoDB_pages_distinct: 1
SET timestamp=1441022038;
SELECT `companies`.* FROM `companies` WHERE `companies`.`id` IN (1,2, 3, 4, 5);

Now, add a column with pt-osc:

pt-online-schema-change \
--nocheck-replication-filters \
--execute \
--chunk-size-limit=0 \
--max-load Threads_running=50 \
--critical-load Threads_running=500 \
--alter "
ADD COLUMN label_array text
" u=root,D=test,t=companies

and run the same query:

# Query_time: 0.000575 Lock_time: 0.000390 Rows_sent: 5 Rows_examined: 34 Rows_affected: 0
# Bytes_sent: 2243 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0
# InnoDB_trx_id: 115C
# QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0
# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000
# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000
# InnoDB_pages_distinct: 3
SET timestamp=1441022050;
SELECT `companies`.* FROM `companies` WHERE `companies`.`id` IN (1, 2, 3, 4, 5);

FULL TABLE scan.

With innodb_stats_persistent disabled it works as expected.

Tags: i58783
Revision history for this message
Miguel Angel Nieto (miguelangelnieto) wrote :
Download full text (7.5 KiB)

I can reproduce the same problem on Oracle MySQL, but only using pt-osc. If I run the same commands that pt-osc runs on the background it works well!

SELECT @@SQL_MODE;
SHOW VARIABLES LIKE 'innodb\_lock_wait_timeout';
SHOW VARIABLES LIKE 'lock\_wait_timeout';
SHOW VARIABLES LIKE 'wait\_timeout';
SET SESSION wait_timeout=10000;
SET @@SQL_QUOTE_SHOW_CREATE = 1/*!40101, @@SQL_MODE='NO_AUTO_VALUE_ON_ZERO,STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION'*/;
SELECT @@server_id /*!50038 , @@hostname*/;
SELECT @@SQL_MODE;
SHOW VARIABLES LIKE 'innodb\_lock_wait_timeout';
SET SESSION innodb_lock_wait_timeout=1;
SHOW VARIABLES LIKE 'lock\_wait_timeout';
SET SESSION lock_wait_timeout=60;
SHOW VARIABLES LIKE 'wait\_timeout';
SET SESSION wait_timeout=10000;
SET @@SQL_QUOTE_SHOW_CREATE = 1/*!40101, @@SQL_MODE='NO_AUTO_VALUE_ON_ZERO,STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION'*/;
SHOW VARIABLES LIKE 'wsrep_on';
SHOW VARIABLES LIKE 'version%';
SHOW ENGINES;
SHOW VARIABLES LIKE 'innodb_version';
SELECT @@SERVER_ID;
SHOW GRANTS FOR CURRENT_USER();
SHOW PROCESSLIST;
SHOW SLAVE HOSTS;
SHOW GLOBAL STATUS LIKE 'Threads_running';
SHOW GLOBAL STATUS LIKE 'Threads_running';
SELECT CONCAT(@@hostname, @@port);
SHOW TABLES FROM `test` LIKE 'companies';
SELECT @@server_id /*!50038 , @@hostname*/;
SHOW TRIGGERS FROM `test` LIKE 'companies';
/*!40101 SET @OLD_SQL_MODE := @@SQL_MODE, @@SQL_MODE := '', @OLD_QUOTE := @@SQL_QUOTE_SHOW_CREATE, @@SQL_QUOTE_SHOW_CREATE := 1 */;
USE `test`;
SHOW CREATE TABLE `test`.`companies`;
/*!40101 SET @@SQL_MODE := @OLD_SQL_MODE, @@SQL_QUOTE_SHOW_CREATE := @OLD_QUOTE */;
EXPLAIN SELECT * FROM `test`.`companies` WHERE 1=1;
SELECT table_schema, table_name FROM information_schema.key_column_usage WHERE referenced_table_schema='test' AND referenced_table_name='companies';
SHOW VARIABLES LIKE 'wsrep_on';
/*!40101 SET @OLD_SQL_MODE := @@SQL_MODE, @@SQL_MODE := '', @OLD_QUOTE := @@SQL_QUOTE_SHOW_CREATE, @@SQL_QUOTE_SHOW_CREATE := 1 */;
USE `test`;
SHOW CREATE TABLE `test`.`companies`;
/*!40101 SET @@SQL_MODE := @OLD_SQL_MODE, @@SQL_QUOTE_SHOW_CREATE := @OLD_QUOTE */;
CREATE TABLE `test`.`_companies_new` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `site_id` int(11) DEFAULT NULL,
  `name` varchar(255) DEFAULT NULL,
  `custom1` varchar(255) DEFAULT NULL,
  `custom2` varchar(255) DEFAULT NULL,
  `custom3` varchar(255) DEFAULT NULL,
  `custom4` varchar(255) DEFAULT NULL,
  `custom5` varchar(255) DEFAULT NULL,
  `custom6` varchar(255) DEFAULT NULL,
  `custom7` varchar(255) DEFAULT NULL,
  `custom8` varchar(255) DEFAULT NULL,
  `custom9` varchar(255) DEFAULT NULL,
  `custom10` varchar(255) DEFAULT NULL,
  `created_at` datetime DEFAULT NULL,
  `updated_at` datetime DEFAULT NULL,
  `custom11` varchar(255) DEFAULT NULL,
  `custom12` varchar(255) DEFAULT NULL,
  `custom13` varchar(255) DEFAULT NULL,
  `custom14` varchar(255) DEFAULT NULL,
  `custom15` varchar(255) DEFAULT NULL,
  `custom16` varchar(255) DEFAULT NULL,
  `custom17` varchar(255) DEFAULT NULL,
  `custom18` varchar(255) DEFAULT NULL,
  `custom19` varchar(255) DEFAULT NULL,
  `custom20` varchar(255) DEFAULT NULL,
  `custom21` varchar(255) DEFAULT NULL,
  `custom22` varchar(255) DEFAULT NULL,
  `custom23` ...

Read more...

Revision history for this message
Miguel Angel Nieto (miguelangelnieto) wrote :

I cannot reproduce the problem without pt-osc.

Revision history for this message
Miguel Angel Nieto (miguelangelnieto) wrote :

Workarounds:

- Disable innodb_stats_persistent globally or...
- Run ANALYZE table to fix the problem or...
- Wait some time and the execution plan will get back to normal.

Revision history for this message
Michael Wang (xw73) wrote :

I just wanted to comment on that "Wait some time and the execution plan will get back to normal" is not a workaround for a busy server because the accumulated full table scan process will render the server irresponsible, and eventually crash the server.

Nilnandan Joshi (nilnandan-joshi)
Changed in percona-server:
status: New → Confirmed
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (3.5 KiB)

Verified with PS 5.6.25.

mysql> CREATE TABLE `companies` (
    -> `id` int(11) NOT NULL AUTO_INCREMENT,
    -> `site_id` int(11) NOT NULL,
    -> `name` varchar(255) NOT NULL,
    -> `custom1` varchar(255) DEFAULT NULL,
    -> `custom2` varchar(255) DEFAULT NULL,
    -> `custom3` varchar(255) DEFAULT NULL,
    -> `custom4` varchar(255) DEFAULT NULL,
    -> `custom5` varchar(255) DEFAULT NULL,
    -> `custom6` varchar(255) DEFAULT NULL,
    -> `custom7` varchar(255) DEFAULT NULL,
    -> `custom8` varchar(255) DEFAULT NULL,
    -> `custom9` varchar(255) DEFAULT NULL,
    -> `custom10` varchar(255) DEFAULT NULL,
    -> `created_at` datetime DEFAULT NULL,
    -> `updated_at` datetime DEFAULT NULL,
    -> `custom11` varchar(255) DEFAULT NULL,
    -> `custom12` varchar(255) DEFAULT NULL,
    -> `custom13` varchar(255) DEFAULT NULL,
    -> `custom14` varchar(255) DEFAULT NULL,
    -> `custom15` varchar(255) DEFAULT NULL,
    -> `custom16` varchar(255) DEFAULT NULL,
    -> `custom17` varchar(255) DEFAULT NULL,
    -> `custom18` varchar(255) DEFAULT NULL,
    -> `custom19` varchar(255) DEFAULT NULL,
    -> `custom20` varchar(255) DEFAULT NULL,
    -> `custom21` varchar(255) DEFAULT NULL,
    -> `custom22` varchar(255) DEFAULT NULL,
    -> `custom23` varchar(255) DEFAULT NULL,
    -> `custom24` varchar(255) DEFAULT NULL,
    -> `custom25` varchar(255) DEFAULT NULL,
    -> `ticket_count` mediumint(8) unsigned DEFAULT NULL,
    -> PRIMARY KEY (`id`)
    -> ) ENGINE=InnoDB;
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO companies (id) VALUES (NULL);
Query OK, 1 row affected, 2 warnings (0.01 sec)

mysql> INSERT INTO companies (id) VALUES (NULL);
Query OK, 1 row affected, 2 warnings (0.01 sec)
....

# User@Host: root[root] @ localhost [] Id: 50
# Schema: Last_errno: 0 Killed: 0
# Query_time: 0.000195 Lock_time: 0.000092 Rows_sent: 5 Rows_examined: 5 Rows_affected: 0
# Bytes_sent: 2168
SET timestamp=1441176328;
SELECT companies.* FROM test.companies WHERE companies.id IN (1,2, 3, 4, 5);

After run pt-osc,

root@desktop:/var/lib/mysql# pt-online-schema-change --nocheck-replication-filters --execute --chunk-size-limit=0 --max-load Threads_running=50 --critical-load Threads_running=500 --alter "ADD COLUMN label_array text" u=root,p=root,D=test,t=companies
No slaves found. See --recursion-method if host desktop has slaves.
Not checking slave lag because no slaves were found and --check-slave-lag was not specified.
Operation, tries, wait:
  copy_rows, 10, 0.25
  create_triggers, 10, 1
  drop_triggers, 10, 1
  swap_tables, 10, 1
  update_foreign_keys, 10, 1
Altering `test`.`companies`...
Creating new table...
Created new table test._companies_new OK.
Altering new table...
Altered `test`.`_companies_new` OK.
2015-09-02T12:15:28 Creating triggers...
2015-09-02T12:15:28 Created triggers OK.
2015-09-02T12:15:28 Copying approximately 57 rows...
2015-09-02T12:15:28 Copied rows OK.
2015-09-02T12:15:28 Swapping tables...
2015-09-02T12:15:28 Swapped original and new tables OK.
2015-09-02T12:15:28 Dropping old table...
2015-09-02T12:15:28 Dropped old table `test`.`_companies_old` OK.
2015-09-02T12:15:28 Dropping triggers...
2015-09-02T12:15:28 Drop...

Read more...

Miguel Angel Nieto (miguelangelnieto)
tags: added: i58783
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :

Unable to reproduce with PS 5.5.44

mysql> select count(*) from companies;
+----------+
| count(*) |
 +----------+
| 20 |
 +----------+
1 row in set (0.02 sec)

mysql>

# Time: 150907 6:05:15
# User@Host: msandbox[msandbox] @ localhost []
# Thread_id: 3 Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.000747 Lock_time: 0.000167 Rows_sent: 5 Rows_examined: 5 Rows_affected: 0 Rows_read: 5
# Bytes_sent: 2168
SET timestamp=1441620315;
SELECT `companies`.* FROM `companies` WHERE `companies`.`id` IN (1,2, 3, 4, 5);

After run pt-osc.

# Time: 150907 6:06:12
# User@Host: msandbox[msandbox] @ localhost []
# Thread_id: 6 Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.000545 Lock_time: 0.000149 Rows_sent: 5 Rows_examined: 5 Rows_affected: 0 Rows_read: 5
# Bytes_sent: 2243
SET timestamp=1441620372;
SELECT `companies`.* FROM `companies` WHERE `companies`.`id` IN (1,2, 3, 4, 5);

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1647

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.