pt-upgrade: HTML encoding is re-encoded in output

[Valerie Parham-Thompson]

Using
======
pt-upgrade 2.2.20
Perl 5.10.1
CentOS Linux release 7.1.1503
5.6.27-log MySQL Community Server (GPL)
and
5.7.16-10-log Percona Server (GPL), Release 10, Revision a0c7d0d
GNU bash, version 4.2.46(1)-release (x86_64-redhat-linux-gnu)

Given the tables
================
CREATE TABLE `tbo` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
   primary key (`id`)
) ENGINE=InnoDB;

CREATE TABLE `tno` (
  `column1` int(11) NOT NULL,
  `column2` text COLLATE utf8_bin NOT NULL,
  `column3` int(11) NOT NULL,
  `column4` int(11) NOT NULL,
  `column5` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  PRIMARY KEY (`column1`),
  CONSTRAINT `myfk` FOREIGN KEY (`column4`) REFERENCES `tbo`(`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin;

And the slow log using a value that is html-encoded
===================================================
/usr/sbin/mysqld, Version: 5.6.27-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock
Time Id Command Argument
# Time: 161018 15:21:55
# User@Host: root[root] @ localhost [] Id: 348081
# Query_time: 11.924815 Lock_time: 0.000143 Rows_sent: 349148 Rows_examined: 349148
SET timestamp=1476818515;
INSERT INTO mysqlslap.tno (column1, column2, column3, column4) VALUES(1,'http://google.com/%E3%82%AF%E3%83%AD%E3%83%83%E3%82%AF',1,2);

And the pt-upgrade statement
============================
pt-upgrade h=192.168.56.19 h=192.168.56.83 -uxxxx -pxxxx --no-read-only /root/slow.log 1>/root/ptupgrade/v56results/results-compare.log 2>/root/ptupgrade/v56results/running-err.log

The query does not get logged to the results
============================================
...
########################################################################
# Query class 6D51BCBEA2D449AB
########################################################################

Reporting class because it has SQL errors, but hasn't been reported yet.

Total queries 1
Unique queries 1
Discarded queries 0

insert into mysqlslap.tno (column?, column?, column?, column?) values(?+)

##
## SQL errors: 1
##

-- 1.
                           ####<<<<<<<<<<<<<<<<< see the query is missing here
#-----------------------------------------------------------------------
# Stats
#-----------------------------------------------------------------------

failed_queries 1
not_select 0
queries_filtered 0
queries_no_diffs 0
queries_read 1
queries_with_diffs 0
queries_with_errors 0

Because the query string is being re-encoded, to an unknown format
==================================================================
$VAR1 = {
  discarded => 0,
  errors => [],
  failures => [
    [
      'INSERT INTO mysqlslap.tno (column1, column2, column3, column4) VALUES(1,\'http://google.com/%E3%82%AF%E3%83%AD%E3%83%83%E3%82%AF\',1,2)',
      'DBD::mysql::st execute failed: Cannot add or update a child row: a foreign key constraint fails (`mysqlslap`.`tno`, CONSTRAINT `myfk` FOREIGN KEY (`column4`) REFERENCES `tbo` (`id`)) [for Statement "INSERT INTO mysqlslap.tno (column1, column2, column3, column4) VALUES(1,\'http://google.com/6.571073E-3223 %AF0.000000E+003 %AD2.293852E-3173 %830.000000E+003 %AF\',1,2)"]',
      'DBD::mysql::st execute failed: Cannot add or update a child row: a foreign key constraint fails (`mysqlslap`.`tno`, CONSTRAINT `myfk` FOREIGN KEY (`column4`) REFERENCES `tbo` (`id`)) [for Statement "INSERT INTO mysqlslap.tno (column1, column2, column3, column4) VALUES(1,\'http://google.com/6.571073E-3223 %AF0.000000E+003 %AD2.293852E-3173 %830.000000E+003 %AF\',1,2)"]'
    ]
  ],
  fingerprint => 'insert into mysqlslap.tno (column?, column?, column?, column?) values(?+)',
  id => '6D51BCBEA2D449AB',
  query_time_diffs => [],
  row_diffs => [],
  total_queries => 1,
  unique_queries => {
    'INSERT INTO mysqlslap.tno (column1, column2, column3, column4) VALUES(1,\'http://google.com/%E3%82%AF%E3%83%AD%E3%83%83%E3%82%AF\',1,2)' => 1
  },
  warning_diffs => []
};
Error reporting query class 6D51BCBEA2D449AB: Invalid conversion in printf: "%A" at /usr/bin/pt-upgrade line 6074.

==========

I forced this error to provide a simple, reproducible outcome that I believe to be related to the root cause of https://bugs.launchpad.net/percona-toolkit/+bug/1657611 but it is a different particular test case.

[Valerie Parham-Thompson (valerie-o)]

The line breaks did not come through in the paste, but there are line breaks and spaces before each % here:
'http://google.com/6.571073E-3223 %AF0.000000E+003 %AD2.293852E-3173 %830.000000E+003 %AF\',1,2)"]'

[Fernando Ipar (fipar)]

I'm not sure printf is really needed on 6074 (_print_failures), seems to me print should be enough, and I don't get the error if print is used.

[Sveta Smirnova (svetasmirnova)]

Thank you for the report.

Verified as described with versions 2.2.20 and 3.0.2.

[Shahriyar Rzayev (rzayev-sehriyar)]

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