LP #1509561: pt-online-schema-change errors out while updating foreign key constraints

**Reported in Launchpad by Pritpal last update 23-10-2015 22:47:08

• Complete commandline used to run the tool

pt-online-schema-change --alter="add <column_name> varchar(45)" --set-vars innodb_lock_wait_timeout=50 --alter-foreign-keys-method rebuild_constraints --recursion-method=none --execute h=hostname,P=****,u=user,p=password,D=schema_name,t=table_name

• Tool version
  2.2.13

• MySQL version of all servers involved
  innodb_version | 5.6.19
  version | 5.6.19-log

• Output from the tool including STDERR
  Is there a way to obtain more logs than what is mentioned below.

No slaves found. See --recursion-method if host ip-10-47-168-108 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
Child tables:
`schema_name`.`referencing_table_name` (approx. 25465033 rows)
Will use the rebuild_constraints method to update foreign keys.
Altering `schema_name`.`table_name`...
Creating new table...
Created new table schema_name._table_name_new OK.
Altering new table...
Altered `schema_name`.`_table_name_new` OK.
2015-10-22T22:53:00 Creating triggers...
2015-10-22T22:53:00 Created triggers OK.
2015-10-22T22:53:00 Copying approximately 23415900 rows...
Copying `schema_name`.`table_name`: 2% 20:42 remain
Copying `schema_name`.`table_name`: 3% 27:06 remain
Copying `schema_name`.`table_name`: 4% 29:31 remain
Copying `schema_name`.`table_name`: 7% 24:32 remain
Copying `schema_name`.`table_name`: 10% 21:57 remain
Copying `schema_name`.`table_name`: 13% 20:03 remain
Copying `schema_name`.`table_name`: 15% 18:39 remain
Copying `schema_name`.`table_name`: 19% 16:42 remain
Copying `schema_name`.`table_name`: 23% 15:10 remain
Copying `schema_name`.`table_name`: 26% 13:53 remain
Copying `schema_name`.`table_name`: 30% 12:41 remain
Copying `schema_name`.`table_name`: 33% 11:46 remain
Copying `schema_name`.`table_name`: 37% 10:53 remain
Copying `schema_name`.`table_name`: 41% 10:05 remain
Copying `schema_name`.`table_name`: 44% 09:30 remain
Copying `schema_name`.`table_name`: 46% 09:06 remain
Copying `schema_name`.`table_name`: 50% 08:23 remain
Copying `schema_name`.`table_name`: 53% 07:43 remain
Copying `schema_name`.`table_name`: 57% 07:03 remain
Copying `schema_name`.`table_name`: 61% 06:24 remain
Copying `schema_name`.`table_name`: 64% 05:46 remain
Copying `schema_name`.`table_name`: 68% 05:10 remain
Copying `schema_name`.`table_name`: 71% 04:31 remain
Copying `schema_name`.`table_name`: 75% 03:55 remain
Copying `schema_name`.`table_name`: 78% 03:22 remain
Copying `schema_name`.`table_name`: 81% 02:52 remain
Copying `schema_name`.`table_name`: 85% 02:18 remain
Copying `schema_name`.`table_name`: 88% 01:44 remain
Copying `schema_name`.`table_name`: 92% 01:12 remain
Copying `schema_name`.`table_name`: 95% 00:39 remain
Copying `schema_name`.`table_name`: 99% 00:06 remain
2015-10-22T23:09:57 Copied rows OK.
2015-10-22T23:09:57 Swapping tables...
2015-10-22T23:09:57 Swapped original and new tables OK.
2015-10-22T23:09:57 Rebuilding foreign key constraints...
2015-10-23T01:10:02 Dropping triggers...
2015-10-23T01:10:02 Dropped triggers OK.
Altered `schema_name`.`table_name` but there were errors or warnings.
Error updating foreign key constraints: 2015-10-23T01:10:02 DBD::mysql::db do failed: Can't write; duplicate key in table '#sql-151c_40b1c9' [for Statement "ALTER TABLE `schema_name`.`referencing_table_name` DROP FOREIGN KEY `FK_referenced_column_name`, ADD CONSTRAINT `_FK_referenced_column_name` FOREIGN KEY (`referenced_column_name`) REFERENCES `schema_name`.`table_name` (`referenced_column_name`)"] at /usr/bin/pt-online-schema-change line 10220.

• Input files (log/dump/config files, etc.)
  None

The tool took a long amount of time(about 1 hour) at "Rebuilding foreign key contraints" stage. Also, there was no information as to what was happening. Is there a switch etc that we can use to make the tool more interactive and also to find the Dump of what happened last time.

To provide more information
– Referencing table has about 28 million rows.
– Referenced table has about 25 million rows.

We suspect that it is similar to https://bugs.launchpad.net/percona-toolkit/+bug/1498128 but we need to be sure because we are again going to be using this tool soon to make similar changes.

Please advise.