Simplify and reword --statistics code, tests, and docs.

This commit is contained in:
Daniel Nichter
2012-11-08 18:05:02 -07:00
parent 74cd9233c3
commit 1ec018fd82
4 changed files with 129 additions and 92 deletions

View File

@@ -7559,15 +7559,17 @@ my @drop_trigger_sqls;
$OUTPUT_AUTOFLUSH = 1; $OUTPUT_AUTOFLUSH = 1;
our %statistics;
sub main { sub main {
# Reset global vars else tests will fail.
local @ARGV = @_; local @ARGV = @_;
# Reset global vars else tests will fail.
$exit_status = 0;
$oktorun = 1; $oktorun = 1;
@drop_trigger_sqls = (); @drop_trigger_sqls = ();
$exit_status = 0; my %stats = (
INSERT => 0,
);
# ######################################################################## # ########################################################################
# Get configuration information. # Get configuration information.
@@ -8436,6 +8438,7 @@ sub main {
Retry => $retry, Retry => $retry,
Quoter => $q, Quoter => $q,
OptionParser => $o, OptionParser => $o,
stats => \%stats,
); );
PTDEBUG && _d('Nibble time:', $tbl->{nibble_time}); PTDEBUG && _d('Nibble time:', $tbl->{nibble_time});
@@ -8577,47 +8580,6 @@ sub main {
} }
$orig_tbl->{copied} = 1; # flag for cleanup tasks $orig_tbl->{copied} = 1; # flag for cleanup tasks
if ( $o->get('statistics') ) {
if ( keys %statistics ) {
my $report = new ReportFormatter(
line_width => 74,
);
$report->set_columns(
{ name => 'Event', },
{ name => 'Count', right_justify => 1 },
);
$report->add_line(
"INSERTS",
$statistics{INSERTS},
);
foreach my $code (keys %{$statistics{ignored_code}}) {
next unless $statistics{ignored_code}->{$code};
$report->add_line(
"Error $code",
$statistics{ignored_code}->{$code},
)
}
my $warnings_seen;
foreach my $code (keys %{$statistics{warned_code}}) {
$report->add_line(
"Error $code",
$statistics{warned_code}->{$code},
);
}
print $report->get_report();
if ( $warnings_seen ) {
print "#\n# The warnings seen were: \n$warnings_seen\n"
}
}
else {
print "# No statistics for errors or warnings.\n";
}
}
# XXX Auto-choose the alter fk method BEFORE swapping/renaming tables # XXX Auto-choose the alter fk method BEFORE swapping/renaming tables
# else everything will break because if drop_swap is chosen, then we # else everything will break because if drop_swap is chosen, then we
# most NOT rename tables or drop the old table. # most NOT rename tables or drop the old table.
@@ -8697,6 +8659,7 @@ sub main {
Quoter => $q, Quoter => $q,
Cxn => $cxn, Cxn => $cxn,
TableParser => $tp, TableParser => $tp,
stats => \%stats,
); );
} }
elsif ( $alter_fk_method eq 'drop_swap' ) { elsif ( $alter_fk_method eq 'drop_swap' ) {
@@ -8767,6 +8730,25 @@ sub main {
$orig_tbl->{success} = 1; # flag for cleanup tasks $orig_tbl->{success} = 1; # flag for cleanup tasks
$cleanup = undef; # exec cleanup tasks $cleanup = undef; # exec cleanup tasks
if ( $o->get('statistics') ) {
my $report = new ReportFormatter(
line_width => 74,
);
$report->set_columns(
{ name => 'Event', },
{ name => 'Count', right_justify => 1 },
);
foreach my $event ( sort keys %stats ) {
$report->add_line(
$event,
$stats{$event},
);
}
print $report->get_report();
}
return $exit_status; return $exit_status;
} }
@@ -9154,12 +9136,12 @@ sub determine_alter_fk_method {
sub rebuild_constraints { sub rebuild_constraints {
my ( %args ) = @_; my ( %args ) = @_;
my @required_args = qw(orig_tbl old_tbl child_tables my @required_args = qw(orig_tbl old_tbl child_tables stats
Cxn Quoter OptionParser TableParser); Cxn Quoter OptionParser TableParser);
foreach my $arg ( @required_args ) { foreach my $arg ( @required_args ) {
die "I need a $arg argument" unless $args{$arg}; die "I need a $arg argument" unless $args{$arg};
} }
my ($orig_tbl, $old_tbl, $child_tables, $cxn, $q, $o, $tp) my ($orig_tbl, $old_tbl, $child_tables, $stats, $cxn, $q, $o, $tp)
= @args{@required_args}; = @args{@required_args};
# MySQL has a "feature" where if the parent tbl is in the same db, # MySQL has a "feature" where if the parent tbl is in the same db,
@@ -9236,6 +9218,7 @@ sub rebuild_constraints {
if ( $o->get('execute') ) { if ( $o->get('execute') ) {
PTDEBUG && _d($sql); PTDEBUG && _d($sql);
$cxn->dbh()->do($sql); $cxn->dbh()->do($sql);
$stats->{rebuilt_constraint}++;
} }
} }
@@ -9420,11 +9403,11 @@ sub drop_triggers {
sub exec_nibble { sub exec_nibble {
my (%args) = @_; my (%args) = @_;
my @required_args = qw(Cxn tbl NibbleIterator Retry Quoter OptionParser); my @required_args = qw(Cxn tbl stats NibbleIterator Retry Quoter OptionParser);
foreach my $arg ( @required_args ) { foreach my $arg ( @required_args ) {
die "I need a $arg argument" unless $args{$arg}; die "I need a $arg argument" unless $args{$arg};
} }
my ($cxn, $tbl, $nibble_iter, $retry, $q, $o)= @args{@required_args}; my ($cxn, $tbl, $stats, $nibble_iter, $retry, $q, $o)= @args{@required_args};
my $dbh = $cxn->dbh(); my $dbh = $cxn->dbh();
my $sth = $nibble_iter->statements(); my $sth = $nibble_iter->statements();
@@ -9474,7 +9457,7 @@ sub exec_nibble {
); );
my $t_end = time; my $t_end = time;
$statistics{INSERTS}++; $stats->{INSERT}++;
# ################################################################### # ###################################################################
# End timing the query. # End timing the query.
@@ -9491,7 +9474,7 @@ sub exec_nibble {
my $code = ($warning->{code} || 0); my $code = ($warning->{code} || 0);
my $message = $warning->{message}; my $message = $warning->{message};
if ( $ignore_code{$code} ) { if ( $ignore_code{$code} ) {
$statistics{ignored_code}->{$code}++; $stats->{"mysql_warning_$code"}++;
PTDEBUG && _d('Ignoring warning:', $code, $message); PTDEBUG && _d('Ignoring warning:', $code, $message);
next; next;
} }
@@ -9499,17 +9482,23 @@ sub exec_nibble {
&& (!$warn_code{$code}->{pattern} && (!$warn_code{$code}->{pattern}
|| $message =~ m/$warn_code{$code}->{pattern}/) ) || $message =~ m/$warn_code{$code}->{pattern}/) )
{ {
if ( !$statistics{warned_code}->{$code} ) { # warn once per table if ( !$stats->{"mysql_warning_$code"}++ ) { # warn once
warn "Copying rows caused a MySQL error $code: " my $err
= "Copying rows caused a MySQL error $code: "
. ($warn_code{$code}->{message} . ($warn_code{$code}->{message}
? $warn_code{$code}->{message} ? $warn_code{$code}->{message}
: $message) : $message)
. "\nThis MySQL error is being ignored and further " . "\nThis MySQL error is being ignored ";
. "occurrences of it will not be reported, although " if ( $o->get('statistics') ) {
. "a total count will be shown if --statistics was " $err .= "but further occurrences will be reported "
. "specified.\n"; . "by --statistics when the tool finishes.\n";
}
else {
$err .= "and further occurrences will not be reported. "
. "Specify --statistics to see a count of all "
. "suppressed warnings and errors.\n";
}
} }
$statistics{warned_code}->{$code}++;
} }
else { else {
# This die will propagate to fail which will return 0 # This die will propagate to fail which will return 0
@@ -9529,6 +9518,7 @@ sub exec_nibble {
fail => sub { fail => sub {
my (%args) = @_; my (%args) = @_;
my $error = $args{error}; my $error = $args{error};
PTDEBUG && _d('Retry fail:', $error);
# The query failed/caused an error. If the error is one of these, # The query failed/caused an error. If the error is one of these,
# then we can possibly retry. # then we can possibly retry.
@@ -9538,17 +9528,30 @@ sub exec_nibble {
) { ) {
# These errors/warnings can be retried, so don't print # These errors/warnings can be retried, so don't print
# a warning yet; do that in final_fail. # a warning yet; do that in final_fail.
my $event
= $error =~ m/Lock wait timeout/ ? 'lock_wait_timeout'
: $error =~ m/Deadlock found/ ? 'deadlock'
: $error =~ m/execution was interrupted/ ? 'query_killed'
: 'unknown1';
$stats->{$event}++;
return 1; # try again return 1; # try again
} }
elsif ( $error =~ m/MySQL server has gone away/ elsif ( $error =~ m/MySQL server has gone away/
|| $error =~ m/Lost connection to MySQL server/ || $error =~ m/Lost connection to MySQL server/
) { ) {
# The 2nd pattern means that MySQL itself died or was stopped. # The 1st pattern means that MySQL itself died or was stopped.
# The 3rd pattern means that our cxn was killed (KILL <id>). # The 2nd pattern means that our cxn was killed (KILL <id>).
my $event
= $error =~ m/server has gone away/ ? 'lost_connection'
: $error =~ m/Lost connection/ ? 'connection_killed'
: 'unknown2';
$stats->{$event}++;
$dbh = $cxn->connect(); # connect or die trying $dbh = $cxn->connect(); # connect or die trying
return 1; # reconnected, try again return 1; # reconnected, try again
} }
$stats->{retry_fail}++;
# At this point, either the error/warning cannot be retried, # At this point, either the error/warning cannot be retried,
# or we failed to reconnect. Don't retry; call final_fail. # or we failed to reconnect. Don't retry; call final_fail.
return 0; return 0;
@@ -9741,8 +9744,16 @@ unless you specify L<"--alter-foreign-keys-method">.
=head1 OUTPUT =head1 OUTPUT
The tool prints information about its activities to STDOUT so that you can see The tool prints information about its activities to STDOUT so that you can see
what it is doing. During the data copy phase, it prints progress reports to what it is doing. During the data copy phase, it prints L<"--progress">
STDERR. You can get additional information with the L<"--print"> option. reports to STDERR. You can get additional information by specifying
L<"--print">.
If L<"--statistics"> is specified, a report of various internal event counts
is printed at the end, like:
# Event Count
# ====== =====
# INSERT 1
=head1 OPTIONS =head1 OPTIONS
@@ -10280,8 +10291,8 @@ Socket file to use for connection.
=item --statistics =item --statistics
Prints some statistics about the run. Currently, only prints how many times Print statistics about internal counters. This is useful to see how
any error code that warned or was ignored during the run propped up. many warnings were suppressed compared to the number of INSERT.
=item --[no]swap-tables =item --[no]swap-tables

View File

@@ -637,36 +637,28 @@ test_alter_table(
$sb->load_file('master', "$sample/bug_1045317.sql"); $sb->load_file('master', "$sample/bug_1045317.sql");
($output, $exit) = full_output( ok(
no_diff(
sub { pt_online_schema_change::main(@args, "$dsn,D=bug_1045317,t=bits", sub { pt_online_schema_change::main(@args, "$dsn,D=bug_1045317,t=bits",
'--dry-run', '--statistics', # We'll never get any statistics with --dry-run '--dry-run', '--statistics',
'--alter', "modify column val ENUM('M','E','H') NOT NULL") } '--alter', "modify column val ENUM('M','E','H') NOT NULL")
},
"$sample/stats-dry-run.txt",
),
"--statistics --dry-run"
); );
like( ok(
$output, no_diff(
qr/\#\Q No statistics for errors or warnings./,
"--statistics works as expected with --dry-run"
) or diag($output);
($output, $exit) = full_output(
sub { pt_online_schema_change::main(@args, "$dsn,D=bug_1045317,t=bits", sub { pt_online_schema_change::main(@args, "$dsn,D=bug_1045317,t=bits",
'--execute', '--statistics', '--execute', '--statistics',
'--alter', "modify column val ENUM('E','H') NOT NULL") } '--alter', "modify column val ENUM('M','E','H') NOT NULL")
},
"$sample/stats-execute.txt",
),
"--statistics --execute"
); );
like(
$output,
qr/\#\Q Event Count\E\s*
\#\Q ========== =====\E\s*
\#\Q INSERTS 1\E\s*
\#\Q Error 1592 1\E\s*
\#\Q Error 1265 1\E\s*/x,
"--statistics works as expected with 1 ignore & 1 warning"
);
$master_dbh->do(q{DROP DATABASE bug_1045317});
# ############################################################################# # #############################################################################
# Done. # Done.
# ############################################################################# # #############################################################################
@@ -674,4 +666,3 @@ $master_dbh->do("UPDATE mysql.proc SET created='2012-06-05 00:00:00', modified='
$sb->wipe_clean($master_dbh); $sb->wipe_clean($master_dbh);
ok($sb->ok(), "Sandbox servers") or BAIL_OUT(__FILE__ . " broke the sandbox"); ok($sb->ok(), "Sandbox servers") or BAIL_OUT(__FILE__ . " broke the sandbox");
done_testing; done_testing;
exit;

View File

@@ -0,0 +1,16 @@
Starting a dry run. `bug_1045317`.`bits` will not be altered. Specify --execute instead of --dry-run to alter the table.
Not dropping triggers because this is a dry run.
Dropping new table...
Dropped new table OK.
Dry run complete. `bug_1045317`.`bits` was not altered.
Creating new table...
Created new table bug_1045317._bits_new OK.
Altering new table...
Altered `bug_1045317`.`_bits_new` OK.
Not creating triggers because this is a dry run.
Not copying rows because this is a dry run.
Not swapping tables because this is a dry run.
Not dropping old table because this is a dry run.
# Event Count
# ====== =====
# INSERT 0

View File

@@ -0,0 +1,19 @@
Altering `bug_1045317`.`bits`...
Dropping triggers...
Dropped triggers OK.
Successfully altered `bug_1045317`.`bits`.
Creating new table...
Created new table bug_1045317._bits_new OK.
Altering new table...
Altered `bug_1045317`.`_bits_new` OK.
Creating triggers...
Created triggers OK.
Copying approximately 3 rows...
Copied rows OK.
Swapping tables...
Swapped original and new tables OK.
Dropping old table...
Dropped old table `bug_1045317`.`_bits_old` OK.
# Event Count
# ====== =====
# INSERT 1