pt-online-schema-change doesn't report how many warnings it suppressed

[Simon J Mudd]

I've been using pt-online-schema-change and am trying to convert a table to a partitioned table (no other changes). I notice that I get an error message such as this:

...
Altered `db`.`_MyTable_new` OK.
Creating triggers...
Created triggers OK.
Copying approximately 39934116 rows...
Copying rows caused a MySQL error 1265: Data truncated for column 'date_cancelled' at row 334
This MySQL error is being ignored and further occurrences of it will not be reported.
Copying `db`.`MyTable`: 0% 02:08:21 remain
...

Given the command used was :

pt-online-schema-change --critical-load="Threads_running:10" --max-load "Threads_running:5" --recurse=0 F=/root/.my.cnf,D=user,t=MyTable --alter "PARTITION BY HASH ( user_id ) PARTITIONS 64" --chunk-time=0.1 --execute

I can't really see why this warning may be happening, yet converting a large table suddenly worries me.
Using the direct ALTER TABLE statement I don't get this.

When using PTDEBUG=1 .... I see there's an INSERT LOW_PRIORITY IGNORE statement and in this particular case there are 6 parameters shown as '?', and the logging shows:

# Retry:2745 14391 Try 1 of 3
# pt_online_schema_change:7133 14391 INSERT LOW_PRIORITY IGNORE INTO `db`.`_MyTable_new` (`user_id`, `t_id`, `hr_id`, `h_id`, `ci`, `co`, `p`, `cc`, `status`, `dc`, `created`, `a_id`, `rp`, `bp`, `obi`, `v`) SELECT `user_id`, `t_id`, `hr_id`, `h_id`, `ci`, `co`, `p`, `cc`, `status`, `dc`, `created`, `a_id`, `rp`, `bp`, `obi`, `v` FROM `db`.`MyTable` FORCE INDEX(`PRIMARY`)
 WHERE ((`user_id` > ?) OR (`user_id` = ? AND `t_id` >= ?)) AND ((`user_id` < ?) OR (`user_id` = ? AND `t_id` <= ?)) /*pt-online-schema-change 14391 copy nibble*/ lower boundary: 0 0 3900754
2 upper boundary: 0 0 167958864

but I don't know how to figure out the 6 parameters that need to be passed to the SQL command to test this manually and see
why this may be giving this warning.

Therefore:

(1) Please consider making the debug output show explicitly the parameters that are used in the SQL query, and how they refer to the boundaries that are mentioned, as this may clarify if the truncation is occurring on the inserted data or some conversion used as part of the where clause.

The current definition is: (sorry for obfuscating the column names )

CREATE TABLE `UserBooking` (
  `user_id` int(10) unsigned NOT NULL,
  `t_id` int(10) unsigned NOT NULL,
  `hr_id` int(10) unsigned NOT NULL DEFAULT '0',
  `h_id` mediumint(9) NOT NULL DEFAULT '0',
  `ci` date DEFAULT NULL,
  `co` date DEFAULT NULL,
  `p` double NOT NULL DEFAULT '0',
  `cc` char(3) DEFAULT NULL,
  `status` enum('value1','value2','value3','value4','value5','value6','unknown') NOT NULL DEFAULT 'unknown',
  `date_cancelled` date DEFAULT NULL,
  `created` timestamp NOT NULL DEFAULT '1970-01-01 01:00:01',
  `a_id` int(10) unsigned NOT NULL DEFAULT '0',
  `rp` tinyint(3) unsigned NOT NULL DEFAULT '1',
  `bp` tinyint(3) unsigned NOT NULL DEFAULT '1',
  `obi` tinyint(3) unsigned DEFAULT '0',
  `v` enum('value1','value2') DEFAULT 'value1',
  PRIMARY KEY (`user_id`,`t_id`),
  KEY `hr_id` (`hr_id`),
  KEY `created` (`created`),
  KEY `transaction_id` (`t_id`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1

(2) Don't do this: This MySQL error is being ignored and further occurrences of it will not be reported.

Please collect a counter of the warnings and since you know the number of inserts it would be good to write at the end of the run:

XXXX inserts completed into the new table: `db`.`MyTable`
XXX warnings found when executing those inserts.

This gives the DBA a better clue as to whether the issue was a one off or not which when modifying multiple GB tables is really an absolute must. Otherwise it seems to be "trust the script and hope for the best", something I'd like to do but only if it tells me all I need to know.

Seen this on:
* MySQL-server-5.5.16
* CentOS 5.6, x86_64
* percona-toolkit-2.1.2-1

I can provide more detailed log files if needed.

[Daniel Nichter (daniel-nichter)]

We can do (1). Imo, it's important to warn about this once in case the user isn't expecting it. We can add a --statistics like pt-query-digest has to print counts of important events/warnings/etc.

Brian: to do (1), search for "ignore_code" in the tool and look at the surrounding code, i.e. the retry() call. See pqd for how it collects and prints --statistics (though pt-osc will be a lot simpler, less stats).

[Brian Fraser (fraserbn)]

Daniel actually meant that we should do (2), since (1) is already done:

# pt_online_schema_change:7133 14391 INSERT LOW_PRIORITY IGNORE INTO `db`.`_MyTable_new` (`user_id`, `t_id`, `hr_id`, `h_id`, `ci`, `co`, `p`, `cc`, `status`, `dc`, `created`, `a_id`, `rp`, `bp`, `obi`, `v`) SELECT `user_id`, `t_id`, `hr_id`, `h_id`, `ci`, `co`, `p`, `cc`, `status`, `dc`, `created`, `a_id`, `rp`, `bp`, `obi`, `v` FROM `db`.`MyTable` FORCE INDEX(`PRIMARY`)
 WHERE ((`user_id` > ?) OR (`user_id` = ? AND `t_id` >= ?)) AND ((`user_id` < ?) OR (`user_id` = ? AND `t_id` <= ?)) /*pt-online-schema-change 14391 copy nibble*/ lower boundary: 0 0 3900754
2 upper boundary: 0 0 167958864

Those 6 values at the end (0,0,3900754,0,0,167958864) are the values used in the query. We won't replace the question marks though, because we are using client-side prepared statements, so DBI eventually interpolates those on its own. This saves us from a huge can of worms that isn't worth any amount of trouble to do manually.

[Shahriyar Rzayev (rzayev-sehriyar)]

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