pt-osc segfaults on mysql alter errors

Bug #1446928 reported by Agustín on 2015-04-22
56
This bug affects 11 people
Affects Status Importance Assigned to Milestone
Percona Toolkit moved to https://jira.percona.com/projects/PT
Fix Released
High
Frank Cizmich

Bug Description

It would be useful to have the tool report more meaningful errors, like mysql does. Take the following two examples:

mysql> ALTER TABLE t2 ADD COLUMN created_at DATETIME DEFAULT now();
ERROR 1067 (42000): Invalid default value for 'created_at'

mysql> ALTER TABLE t2 ADD COLUMN created_at non_existent_datatype;
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'non_existent_datatype' at line 1

pt-osc, instead, silently fails with a strange "Bus error" line at the end:

shell> pt-online-schema-change --execute --alter "ADD COLUMN created_at DATETIME DEFAULT now()" S=/tmp/mysql_sandbox5542.sock,u=msandbox,p=msandbox,D=test,t=t2
No slaves found. See --recursion-method if host bm-support01 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`.`t2`...
Creating new table...
Created new table test._t2_new OK.
Altering new table...
2015-04-21T21:08:38 Dropping new table...
2015-04-21T21:08:38 Dropped new table OK.
`test`.`t2` was not altered.
Bus error

shell> pt-online-schema-change --execute --alter "ADD COLUMN created_at non_existent_datatype" S=/tmp/mysql_sandbox5542.sock,u=msandbox,p=msandbox,D=test,t=t2
No slaves found. See --recursion-method if host bm-support01 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`.`t2`...
Creating new table...
Created new table test._t2_new OK.
Altering new table...
2015-04-21T21:10:00 Dropping new table...
2015-04-21T21:10:00 Dropped new table OK.
`test`.`t2` was not altered.
Bus error

Snippet from using PTDEBUG=1:

shell> PTDEBUG=1 pt-online-schema-change --execute --alter "ADD COLUMN created_at non_existent_datatype" S=/tmp/mysql_sandbox5542.sock,u=msandbox,p=msandbox,D=test,t=t2

[...]
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
# pt_online_schema_change:10054 6242 Finding child tables
# pt_online_schema_change:10060 6242 SELECT table_schema, table_name FROM information_schema.key_column_usage WHERE referenced_table_schema='test' AND referenced_table_name='t2'
# pt_online_schema_change:10063 6242 No child tables found
Altering `test`.`t2`...
# CleanupTask:6170 6242 Created cleanup task CODE(0x1aca270)
# pt_online_schema_change:9737 6242 Renamed columns (old => new): $VAR1 = {};
#
# Percona::XtraDB::Cluster:7621 6242 bm-support01 SHOW VARIABLES LIKE 'wsrep_on'
# Percona::XtraDB::Cluster:7623 6242 $VAR1 = undef;
#
# TableParser:3119 6242 /*!40101 SET @OLD_SQL_MODE := @@SQL_MODE, @@SQL_MODE := '', @OLD_QUOTE := @@SQL_QUOTE_SHOW_CREATE, @@SQL_QUOTE_SHOW_CREATE := 1 */
# TableParser:3124 6242 DBI::db=HASH(0x1a31410) USE `test`
# TableParser:3128 6242 SHOW CREATE TABLE `test`.`t2`
# TableParser:3138 6242 /*!40101 SET @@SQL_MODE := @OLD_SQL_MODE, @@SQL_QUOTE_SHOW_CREATE := @OLD_QUOTE */
Creating new table...
# pt_online_schema_change:9866 6242 CREATE TABLE `test`.`_t2_new` (
# `id` int(11) NOT NULL AUTO_INCREMENT,
# PRIMARY KEY (`id`)
# ) ENGINE=InnoDB AUTO_INCREMENT=5 DEFAULT CHARSET=latin1
Created new table test._t2_new OK.
Altering new table...
# pt_online_schema_change:8819 6242 ALTER TABLE `test`.`_t2_new` ADD COLUMN created_at non_existent_datatype
# CleanupTask:6178 6242 Calling cleanup task CODE(0x1aca270)
# pt_online_schema_change:8710 6242 Clean up new table
# TableParser:3290 6242 Checking `test`.`_t2_new`
# TableParser:3294 6242 SHOW TABLES FROM `test` LIKE '\_t2\_new'
# TableParser:3308 6242 Table test _t2_new exists
# pt_online_schema_change:8716 6242 New table exists: yes
2015-04-21T21:14:21 Dropping new table...
# pt_online_schema_change:8752 6242 DROP TABLE IF EXISTS `test`.`_t2_new`;
2015-04-21T21:14:21 Dropped new table OK.
# pt_online_schema_change:8587 6242 Clean up done, report if orig table was altered
`test`.`t2` was not altered.
Bus error

More information on versions used, etc:

shell> pt-online-schema-change --version
pt-online-schema-change 2.2.13

mysql> SHOW VARIABLES LIKE '%version%';
+-------------------------+------------------------------------------------------+
| Variable_name | Value |
+-------------------------+------------------------------------------------------+
| innodb_version | 5.5.42-37.1 |
| protocol_version | 10 |
| slave_type_conversions | |
| version | 5.5.42-37.1 |
| version_comment | Percona Server (GPL), Release 37.1, Revision 39acee0 |
| version_compile_machine | x86_64 |
| version_compile_os | Linux |
+-------------------------+------------------------------------------------------+
7 rows in set (0.00 sec)

mysql> SHOW CREATE TABLE test.t2\G
*************************** 1. row ***************************
       Table: t2
Create Table: CREATE TABLE `t2` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=5 DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

Changed in percona-toolkit:
status: New → In Progress
importance: Undecided → High
assignee: nobody → Frank Cizmich (frank-cizmich)
tags: added: pt-online-schema-change
Frank Cizmich (frank-cizmich) wrote :

Attached a patch for this. The problem was a loop in the error handling routines.

Agustín (agustin-gallego) wrote :

Confirming this patch helps with this. Thanks Frank!

agustin.gallego@bm-support01:~/tmp$ ./pt-online-schema-change --execute --alter "ADD COLUMN created_at non_existent_datatype" S=/tmp/mysql_sandbox5542.sock,u=msandbox,p=msandbox,D=test,t=t2
[...]
2015-04-23T18:43:41 Dropping new table...
2015-04-23T18:43:41 Dropped new table OK.
`test`.`t2` was not altered.
Error altering new table `test`.`_t2_new`: DBD::mysql::db do failed: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'non_existent_datatype' at line 1 [for Statement "ALTER TABLE `test`.`_t2_new` ADD COLUMN created_at non_existent_datatype"] at ./pt-online-schema-change line 8821.

agustin.gallego@bm-support01:~/tmp$ ./pt-online-schema-change --execute --alter "ADD COLUMN created_at DATETIME DEFAULT now()" S=/tmp/mysql_sandbox5542.sock,u=msandbox,p=msandbox,D=test,t=t2
[...]
2015-04-23T18:46:31 Dropping new table...
2015-04-23T18:46:31 Dropped new table OK.
`test`.`t2` was not altered.
Error altering new table `test`.`_t2_new`: DBD::mysql::db do failed: Invalid default value for 'created_at' [for Statement "ALTER TABLE `test`.`_t2_new` ADD COLUMN created_at DATETIME DEFAULT now()"] at ./pt-online-schema-change line 8821.

Changed in percona-toolkit:
milestone: none → 2.3.1
Daniël van Eeden (dveeden) wrote :

I've tested this and the patch seems to fix it. I now get a useful error. (pt-online-schema-change 2.2.13)

Changed in percona-toolkit:
status: In Progress → Fix Committed
Changed in percona-toolkit:
milestone: 2.3.1 → none
Changed in percona-toolkit:
milestone: none → 2.2.15
Changed in percona-toolkit:
status: Fix Committed → Fix Released
summary: - pt-online-schema-change not reporting meaningful errors.
+ pt-online-schema-change not reporting meaningful errors due to
+ segfaulting on alter errors
Frank Cizmich (frank-cizmich) wrote :

changed title to something I think is more descriptive of the real issue.

summary: - pt-online-schema-change not reporting meaningful errors due to
- segfaulting on alter errors
+ pt-osc segfaults on mysql alter errors

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

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

Other bug subscribers