1# -*- cperl -*- 2# Copyright (c) 2004, 2010, Oracle and/or its affiliates. All rights reserved. 3# 4# This program is free software; you can redistribute it and/or modify 5# it under the terms of the GNU General Public License, version 2.0, 6# as published by the Free Software Foundation. 7# 8# This program is also distributed with certain software (including 9# but not limited to OpenSSL) that is licensed under separate terms, 10# as designated in a particular file or component or in included license 11# documentation. The authors of MySQL hereby grant you an additional 12# permission to link the program and your derivative works with the 13# separately licensed software that they have included with MySQL. 14# 15# This program is distributed in the hope that it will be useful, 16# but WITHOUT ANY WARRANTY; without even the implied warranty of 17# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 18# GNU General Public License, version 2.0, for more details. 19# 20# You should have received a copy of the GNU General Public License 21# along with this program; if not, write to the Free Software 22# Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA 23 24# This is a library file used by the Perl version of mysql-test-run, 25# and is part of the translation of the Bourne shell script with the 26# same name. 27 28use strict; 29use warnings; 30 31sub mtr_report_test_name($); 32sub mtr_report_test_passed($); 33sub mtr_report_test_failed($); 34sub mtr_report_test_skipped($); 35sub mtr_report_test_not_skipped_though_disabled($); 36 37sub mtr_report_stats ($); 38sub mtr_print_line (); 39sub mtr_print_thick_line (); 40sub mtr_print_header (); 41sub mtr_report (@); 42sub mtr_warning (@); 43sub mtr_error (@); 44sub mtr_child_error (@); 45sub mtr_debug (@); 46sub mtr_verbose (@); 47 48my $tot_real_time= 0; 49 50 51 52############################################################################## 53# 54# 55# 56############################################################################## 57 58sub mtr_report_test_name ($) { 59 my $tinfo= shift; 60 my $tname= $tinfo->{name}; 61 62 $tname.= " '$tinfo->{combination}'" 63 if defined $tinfo->{combination}; 64 65 _mtr_log($tname); 66 printf "%-30s ", $tname; 67} 68 69sub mtr_report_test_skipped ($) { 70 my $tinfo= shift; 71 72 $tinfo->{'result'}= 'MTR_RES_SKIPPED'; 73 if ( $tinfo->{'disable'} ) 74 { 75 mtr_report("[ disabled ] $tinfo->{'comment'}"); 76 } 77 elsif ( $tinfo->{'comment'} ) 78 { 79 mtr_report("[ skipped ] $tinfo->{'comment'}"); 80 } 81 else 82 { 83 mtr_report("[ skipped ]"); 84 } 85} 86 87sub mtr_report_tests_not_skipped_though_disabled ($) { 88 my $tests= shift; 89 90 if ( $::opt_enable_disabled ) 91 { 92 my @disabled_tests= grep {$_->{'dont_skip_though_disabled'}} @$tests; 93 if ( @disabled_tests ) 94 { 95 print "\nTest(s) which will be run though they are marked as disabled:\n"; 96 foreach my $tinfo ( sort {$a->{'name'} cmp $b->{'name'}} @disabled_tests ) 97 { 98 printf " %-20s : %s\n", $tinfo->{'name'}, $tinfo->{'comment'}; 99 } 100 } 101 } 102} 103 104sub mtr_report_test_passed ($) { 105 my $tinfo= shift; 106 107 my $timer= ""; 108 if ( $::opt_timer and -f "$::opt_vardir/log/timer" ) 109 { 110 $timer= mtr_fromfile("$::opt_vardir/log/timer"); 111 $tot_real_time += ($timer/1000); 112 $timer= sprintf "%12s", $timer; 113 } 114 $tinfo->{'result'}= 'MTR_RES_PASSED'; 115 mtr_report("[ pass ] $timer"); 116} 117 118sub mtr_report_test_failed ($) { 119 my $tinfo= shift; 120 121 $tinfo->{'result'}= 'MTR_RES_FAILED'; 122 if ( defined $tinfo->{'timeout'} ) 123 { 124 mtr_report("[ fail ] timeout"); 125 return; 126 } 127 else 128 { 129 mtr_report("[ fail ]"); 130 } 131 132 if ( $tinfo->{'comment'} ) 133 { 134 # The test failure has been detected by mysql-test-run.pl 135 # when starting the servers or due to other error, the reason for 136 # failing the test is saved in "comment" 137 mtr_report("\nERROR: $tinfo->{'comment'}"); 138 } 139 elsif ( -f $::path_timefile ) 140 { 141 # Test failure was detected by test tool and it's report 142 # about what failed has been saved to file. Display the report. 143 print "\n"; 144 print mtr_fromfile($::path_timefile); # FIXME print_file() instead 145 print "\n"; 146 } 147 else 148 { 149 # Neither this script or the test tool has recorded info 150 # about why the test has failed. Should be debugged. 151 mtr_report("\nUnexpected termination, probably when starting mysqld");; 152 } 153} 154 155sub mtr_report_stats ($) { 156 my $tests= shift; 157 158 # ---------------------------------------------------------------------- 159 # Find out how we where doing 160 # ---------------------------------------------------------------------- 161 162 my $tot_skiped= 0; 163 my $tot_passed= 0; 164 my $tot_failed= 0; 165 my $tot_tests= 0; 166 my $tot_restarts= 0; 167 my $found_problems= 0; # Some warnings in the logfiles are errors... 168 169 foreach my $tinfo (@$tests) 170 { 171 if ( $tinfo->{'result'} eq 'MTR_RES_SKIPPED' ) 172 { 173 $tot_skiped++; 174 } 175 elsif ( $tinfo->{'result'} eq 'MTR_RES_PASSED' ) 176 { 177 $tot_tests++; 178 $tot_passed++; 179 } 180 elsif ( $tinfo->{'result'} eq 'MTR_RES_FAILED' ) 181 { 182 $tot_tests++; 183 $tot_failed++; 184 } 185 if ( $tinfo->{'restarted'} ) 186 { 187 $tot_restarts++; 188 } 189 } 190 191 # ---------------------------------------------------------------------- 192 # Print out a summary report to screen 193 # ---------------------------------------------------------------------- 194 195 if ( ! $tot_failed ) 196 { 197 print "All $tot_tests tests were successful.\n"; 198 } 199 else 200 { 201 my $ratio= $tot_passed * 100 / $tot_tests; 202 print "Failed $tot_failed/$tot_tests tests, "; 203 printf("%.2f", $ratio); 204 print "\% were successful.\n\n"; 205 print 206 "The log files in var/log may give you some hint\n", 207 "of what went wrong.\n", 208 "If you want to report this error, please read first ", 209 "the documentation at\n", 210 "http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html\n"; 211 } 212 if (!$::opt_extern) 213 { 214 print "The servers were restarted $tot_restarts times\n"; 215 } 216 217 if ( $::opt_timer ) 218 { 219 use English; 220 221 mtr_report("Spent", sprintf("%.3f", $tot_real_time),"of", 222 time - $BASETIME, "seconds executing testcases"); 223 } 224 225 # ---------------------------------------------------------------------- 226 # If a debug run, there might be interesting information inside 227 # the "var/log/*.err" files. We save this info in "var/log/warnings" 228 # ---------------------------------------------------------------------- 229 230 if ( ! $::glob_use_running_server ) 231 { 232 # Save and report if there was any fatal warnings/errors in err logs 233 234 my $warnlog= "$::opt_vardir/log/warnings"; 235 236 unless ( open(WARN, ">$warnlog") ) 237 { 238 mtr_warning("can't write to the file \"$warnlog\": $!"); 239 } 240 else 241 { 242 # We report different types of problems in order 243 foreach my $pattern ( "^Warning:", 244 "\\[Warning\\]", 245 "\\[ERROR\\]", 246 "^Error:", "^==.* at 0x", 247 "InnoDB: Warning", 248 "InnoDB: Error", 249 "^safe_mutex:", 250 "missing DBUG_RETURN", 251 "mysqld: Warning", 252 "allocated at line", 253 "Attempting backtrace", "Assertion .* failed" ) 254 { 255 foreach my $errlog ( sort glob("$::opt_vardir/log/*.err") ) 256 { 257 my $testname= ""; 258 unless ( open(ERR, $errlog) ) 259 { 260 mtr_warning("can't read $errlog"); 261 next; 262 } 263 while ( <ERR> ) 264 { 265 # Skip some non fatal warnings from the log files 266 if ( 267 /\"SELECT UNIX_TIMESTAMP\(\)\" failed on master/ or 268 /Aborted connection/ or 269 /Client requested master to start replication from impossible position/ or 270 /Could not find first log file name in binary log/ or 271 /Enabling keys got errno/ or 272 /Error reading master configuration/ or 273 /Error reading packet/ or 274 /Event Scheduler/ or 275 /Failed to open log/ or 276 /Failed to open the existing master info file/ or 277 /Forcing shutdown of [0-9]* plugins/ or 278 /Can't open shared library .*\bha_example\b/ or 279 /Couldn't load plugin .*\bha_example\b/ or 280 281 # Due to timing issues, it might be that this warning 282 # is printed when the server shuts down and the 283 # computer is loaded. 284 /Forcing close of thread \d+ user: '.*?'/ or 285 286 /Got error [0-9]* when reading table/ or 287 /Incorrect definition of table/ or 288 /Incorrect information in file/ or 289 /InnoDB: Warning: we did not need to do crash recovery/ or 290 /Invalid \(old\?\) table or database name/ or 291 /Lock wait timeout exceeded/ or 292 /Log entry on master is longer than max_allowed_packet/ or 293 /unknown option '--loose-/ or 294 /unknown variable 'loose-/ or 295 /You have forced lower_case_table_names to 0 through a command-line option/ or 296 /Setting lower_case_table_names=2/ or 297 /NDB Binlog:/ or 298 /NDB: failed to setup table/ or 299 /NDB: only row based binary logging/ or 300 /Neither --relay-log nor --relay-log-index were used/ or 301 /Query partially completed/ or 302 /Slave I.O thread aborted while waiting for relay log/ or 303 /Slave SQL thread is stopped because UNTIL condition/ or 304 /Slave SQL thread retried transaction/ or 305 /Slave \(additional info\)/ or 306 /Slave: .*Duplicate column name/ or 307 /Slave: .*master may suffer from/ or 308 /Slave: According to the master's version/ or 309 /Slave: Column [0-9]* type mismatch/ or 310 /Slave: Error .* doesn't exist/ or 311 /Slave: Deadlock found/ or 312 /Slave: Error .*Unknown table/ or 313 /Slave: Error in Write_rows event: / or 314 /Slave: Field .* of table .* has no default value/ or 315 /Slave: Field .* doesn't have a default value/ or 316 /Slave: Query caused different errors on master and slave/ or 317 /Slave: Table .* doesn't exist/ or 318 /Slave: Table width mismatch/ or 319 /Slave: The incident LOST_EVENTS occured on the master/ or 320 /Slave: Unknown error.* 1105/ or 321 /Slave: Can't drop database.* database doesn't exist/ or 322 /Slave SQL:.*(?:Error_code: \d+|Query:.*)/ or 323 /Sort aborted/ or 324 /Time-out in NDB/ or 325 /One can only use the --user.*root/ or 326 /Table:.* on (delete|rename)/ or 327 /You have an error in your SQL syntax/ or 328 /deprecated/ or 329 /description of time zone/ or 330 /equal MySQL server ids/ or 331 /error .*connecting to master/ or 332 /error reading log entry/ or 333 /lower_case_table_names is set/ or 334 /skip-name-resolve mode/ or 335 /slave SQL thread aborted/ or 336 /Slave: .*Duplicate entry/ or 337 # Special case for Bug #26402 in show_check.test 338 # Question marks are not valid file name parts 339 # on Windows platforms. Ignore this error message. 340 /\QCan't find file: '.\test\????????.frm'\E/ or 341 # Special case, made as specific as possible, for: 342 # Bug #28436: Incorrect position in SHOW BINLOG EVENTS causes 343 # server coredump 344 /\QError in Log_event::read_log_event(): 'Sanity check failed', data_len: 258, event_type: 49\E/ or 345 /Statement is not safe to log in statement format/ or 346 347 # test case for Bug#bug29807 copies a stray frm into database 348 /InnoDB: Error: table `test`.`bug29807` does not exist in the InnoDB internal/ or 349 /InnoDB: Cannot open table test\/bug29807 from/ or 350 351 # innodb foreign key tests that fail in ALTER or RENAME produce this 352 /InnoDB: Error: in ALTER TABLE `test`.`t[12]`/ or 353 /InnoDB: Error: in RENAME TABLE table `test`.`t1`/ or 354 /InnoDB: Error: table `test`.`t[12]` does not exist in the InnoDB internal/ or 355 356 # Test case for Bug#14233 produces the following warnings: 357 /Stored routine 'test'.'bug14233_1': invalid value in column mysql.proc/ or 358 /Stored routine 'test'.'bug14233_2': invalid value in column mysql.proc/ or 359 /Stored routine 'test'.'bug14233_3': invalid value in column mysql.proc/ or 360 361 # BUG#29839 - lowercase_table3.test: Cannot find table test/T1 362 # from the internal data dictiona 363 /Cannot find table test\/BUG29839 from the internal data dictionary/ or 364 # BUG#32080 - Excessive warnings on Solaris: setrlimit could not 365 # change the size of core files 366 /setrlimit could not change the size of core files to 'infinity'/ or 367 368 # rpl_extrColmaster_*.test, the slave thread produces warnings 369 # when it get updates to a table that has more columns on the 370 # master 371 /Slave: Unknown column 'c7' in 't15' Error_code: 1054/ or 372 /Slave: Can't DROP 'c7'.* 1091/ or 373 /Slave: Key column 'c6'.* 1072/ or 374 375 # Warnings generated until bug#42147 is properly resolved 376 /Found lock of type 6 that is write and read locked/ or 377 378 # rpl_idempotency.test produces warnings for the slave. 379 ($testname eq 'rpl.rpl_idempotency' and 380 (/Slave: Can\'t find record in \'t1\' Error_code: 1032/ or 381 /Slave: Cannot add or update a child row: a foreign key constraint fails .* Error_code: 1452/ 382 )) or 383 384 # These tests does "kill" on queries, causing sporadic errors when writing to logs 385 (($testname eq 'rpl.rpl_skip_error' or 386 $testname eq 'rpl.rpl_err_ignoredtable' or 387 $testname eq 'binlog.binlog_killed_simulate' or 388 $testname eq 'binlog.binlog_killed') and 389 (/Failed to write to mysql\.\w+_log/ 390 )) or 391 392 # rpl_bug33931 has deliberate failures 393 ($testname eq 'rpl.rpl_bug33931' and 394 (/Failed during slave.*thread initialization/ 395 )) or 396 397 # rpl_temporary has an error on slave that can be ignored 398 ($testname eq 'rpl.rpl_temporary' and 399 (/Slave: Can\'t find record in \'user\' Error_code: 1032/ 400 )) or 401 402 # Test case for Bug#31590 produces the following error: 403 /Out of sort memory; increase server sort buffer size/ or 404 405 # Bug#35161, test of auto repair --myisam-recover 406 /able.*_will_crash/ or 407 408 # lowercase_table3 using case sensitive option on 409 # case insensitive filesystem (InnoDB error). 410 /InnoDB: Cannot open table test\/BUG29839 from/ or 411 412 # When trying to set lower_case_table_names = 2 413 # on a case sensitive file system. Bug#37402. 414 /lower_case_table_names was set to 2, even though your the file system '.*' is case sensitive. Now setting lower_case_table_names to 0 to avoid future problems./ 415 ) 416 { 417 next; # Skip these lines 418 } 419 if ( /CURRENT_TEST: (.*)/ ) 420 { 421 $testname= $1; 422 } 423 if ( /$pattern/ ) 424 { 425 $found_problems= 1; 426 print WARN basename($errlog) . ": $testname: $_"; 427 } 428 } 429 } 430 } 431 432 if ( $::opt_check_testcases ) 433 { 434 # Look for warnings produced by mysqltest in testname.warnings 435 foreach my $test_warning_file 436 ( glob("$::glob_mysql_test_dir/r/*.warnings") ) 437 { 438 $found_problems= 1; 439 print WARN "Check myqltest warnings in $test_warning_file\n"; 440 } 441 } 442 443 if ( $found_problems ) 444 { 445 mtr_warning("Got errors/warnings while running tests, please examine", 446 "\"$warnlog\" for details."); 447 } 448 } 449 } 450 451 print "\n"; 452 453 # Print a list of testcases that failed 454 if ( $tot_failed != 0 ) 455 { 456 my $test_mode= join(" ", @::glob_test_mode) || "default"; 457 print "mysql-test-run in $test_mode mode: *** Failing the test(s):"; 458 459 foreach my $tinfo (@$tests) 460 { 461 if ( $tinfo->{'result'} eq 'MTR_RES_FAILED' ) 462 { 463 print " $tinfo->{'name'}"; 464 } 465 } 466 print "\n"; 467 468 } 469 470 # Print a list of check_testcases that failed(if any) 471 if ( $::opt_check_testcases ) 472 { 473 my @check_testcases= (); 474 475 foreach my $tinfo (@$tests) 476 { 477 if ( defined $tinfo->{'check_testcase_failed'} ) 478 { 479 push(@check_testcases, $tinfo->{'name'}); 480 } 481 } 482 483 if ( @check_testcases ) 484 { 485 print "Check of testcase failed for: "; 486 print join(" ", @check_testcases); 487 print "\n\n"; 488 } 489 } 490 491 if ( $tot_failed != 0 || $found_problems) 492 { 493 mtr_error("there were failing test cases"); 494 } 495} 496 497############################################################################## 498# 499# Text formatting 500# 501############################################################################## 502 503sub mtr_print_line () { 504 print '-' x 55, "\n"; 505} 506 507sub mtr_print_thick_line () { 508 print '=' x 55, "\n"; 509} 510 511sub mtr_print_header () { 512 print "\n"; 513 if ( $::opt_timer ) 514 { 515 print "TEST RESULT TIME (ms)\n"; 516 } 517 else 518 { 519 print "TEST RESULT\n"; 520 } 521 mtr_print_line(); 522 print "\n"; 523} 524 525 526############################################################################## 527# 528# Log and reporting functions 529# 530############################################################################## 531 532use IO::File; 533 534my $log_file_ref= undef; 535 536sub mtr_log_init ($) { 537 my ($filename)= @_; 538 539 mtr_error("Log is already open") if defined $log_file_ref; 540 541 $log_file_ref= IO::File->new($filename, "a") or 542 mtr_warning("Could not create logfile $filename: $!"); 543} 544 545sub _mtr_log (@) { 546 print $log_file_ref join(" ", @_),"\n" 547 if defined $log_file_ref; 548} 549 550sub mtr_report (@) { 551 # Print message to screen and log 552 _mtr_log(@_); 553 print join(" ", @_),"\n"; 554} 555 556sub mtr_warning (@) { 557 # Print message to screen and log 558 _mtr_log("WARNING: ", @_); 559 print STDERR "mysql-test-run: WARNING: ",join(" ", @_),"\n"; 560} 561 562sub mtr_error (@) { 563 # Print message to screen and log 564 _mtr_log("ERROR: ", @_); 565 print STDERR "mysql-test-run: *** ERROR: ",join(" ", @_),"\n"; 566 mtr_exit(1); 567} 568 569sub mtr_child_error (@) { 570 # Print message to screen and log 571 _mtr_log("ERROR(child): ", @_); 572 print STDERR "mysql-test-run: *** ERROR(child): ",join(" ", @_),"\n"; 573 exit(1); 574} 575 576sub mtr_debug (@) { 577 # Only print if --script-debug is used 578 if ( $::opt_script_debug ) 579 { 580 _mtr_log("###: ", @_); 581 print STDERR "####: ",join(" ", @_),"\n"; 582 } 583} 584 585sub mtr_verbose (@) { 586 # Always print to log, print to screen only when --verbose is used 587 _mtr_log("> ",@_); 588 if ( $::opt_verbose ) 589 { 590 print STDERR "> ",join(" ", @_),"\n"; 591 } 592} 593 5941; 595