~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to tests/lib/mtr_report.pl

  • Committer: Brian Aker
  • Date: 2010-05-27 01:25:56 UTC
  • mfrom: (1567.1.4 new-staging)
  • Revision ID: brian@gaz-20100527012556-5zgkirkl7swbigd6
Merge of Brian, Paul. PBXT compile issue, and test framework cleanup. 

Show diffs side-by-side

added added

removed removed

Lines of Context:
56
56
    if defined $tinfo->{combination};
57
57
 
58
58
  _mtr_log($tname);
59
 
  printf "%-30s ", $tname;
 
59
  if ($::opt_subunit) {
 
60
    printf "test: $tname\n";
 
61
  } else {
 
62
    printf "%-60s ", $tname;
 
63
  }
60
64
}
61
65
 
62
66
sub mtr_report_test_skipped ($) {
63
67
  my $tinfo= shift;
 
68
  my $tname= $tinfo->{name};
 
69
  my $cause= "";
64
70
 
65
71
  $tinfo->{'result'}= 'MTR_RES_SKIPPED';
66
72
  if ( $tinfo->{'disable'} )
67
73
  {
68
 
    mtr_report("[ disabled ]  $tinfo->{'comment'}");
69
 
  }
70
 
  elsif ( $tinfo->{'comment'} )
71
 
  {
72
 
    mtr_report("[ skipped ]   $tinfo->{'comment'}");
73
 
  }
74
 
  else
75
 
  {
76
 
    mtr_report("[ skipped ]");
 
74
    $cause.= "disable";
 
75
  }
 
76
  else
 
77
  {
 
78
    $cause.= "skipped";
 
79
  }
 
80
  if ( $tinfo->{'comment'} )
 
81
  {
 
82
    if ($::opt_subunit) {
 
83
      mtr_report("skip: $tname [\ncause: $cause\n$tinfo->{'comment'}\n]");
 
84
    } else { 
 
85
      mtr_report("[ $cause ]   $tinfo->{'comment'}");
 
86
    }
 
87
  }
 
88
  else
 
89
  {
 
90
    if ($::opt_subunit) {
 
91
      mtr_report("skip: $tname");
 
92
    } else {
 
93
      mtr_report("[ $cause ]");
 
94
    }
77
95
  }
78
96
}
79
97
 
96
114
 
97
115
sub mtr_report_test_passed ($) {
98
116
  my $tinfo= shift;
 
117
  my $tname= $tinfo->{name};
99
118
 
100
119
  my $timer=  "";
101
120
  if ( $::opt_timer and -f "$::opt_vardir/log/timer" )
102
121
  {
103
122
    $timer= mtr_fromfile("$::opt_vardir/log/timer");
104
123
    $tot_real_time += ($timer/1000);
105
 
    $timer= sprintf "%12s", $timer;
 
124
    $timer= sprintf "%7s", $timer;
 
125
    ### XXX: How to format this as iso6801 datetime?
106
126
  }
107
127
  $tinfo->{'result'}= 'MTR_RES_PASSED';
108
 
  mtr_report("[ pass ]   $timer");
 
128
  if ($::opt_subunit) {
 
129
    mtr_report("success: $tname");
 
130
  } else {
 
131
    mtr_report("[ pass ] $timer");
 
132
  }
109
133
}
110
134
 
111
135
sub mtr_report_test_failed ($) {
112
136
  my $tinfo= shift;
 
137
  my $tname= $tinfo->{name};
 
138
  my $comment= "";
113
139
 
114
140
  $tinfo->{'result'}= 'MTR_RES_FAILED';
115
141
  if ( defined $tinfo->{'timeout'} )
116
142
  {
117
 
    mtr_report("[ fail ]  timeout");
118
 
    return;
119
 
  }
120
 
  else
121
 
  {
122
 
    mtr_report("[ fail ]");
123
 
  }
124
 
 
125
 
  if ( $tinfo->{'comment'} )
 
143
    $comment.= "timeout";
 
144
  }
 
145
  elsif ( $tinfo->{'comment'} )
126
146
  {
127
147
    # The test failure has been detected by mysql-test-run.pl
128
148
    # when starting the servers or due to other error, the reason for
129
149
    # failing the test is saved in "comment"
130
 
    mtr_report("\nERROR: $tinfo->{'comment'}");
 
150
    $comment.= "$tinfo->{'comment'}";
131
151
  }
132
152
  elsif ( -f $::path_timefile )
133
153
  {
134
154
    # Test failure was detected by test tool and it's report
135
155
    # about what failed has been saved to file. Display the report.
136
 
    print "\n";
137
 
    print mtr_fromfile($::path_timefile); # FIXME print_file() instead
138
 
    print "\n";
 
156
    $comment.= mtr_fromfile($::path_timefile);
139
157
  }
140
158
  else
141
159
  {
142
160
    # Neither this script or the test tool has recorded info
143
161
    # about why the test has failed. Should be debugged.
144
 
    mtr_report("\nUnexpected termination, probably when starting mysqld");;
 
162
    $comment.= "Unexpected termination, probably when starting mysqld";
 
163
  }
 
164
  if ($::opt_subunit) {
 
165
    mtr_report("failure: $tname [\n$comment\n]");
 
166
  } else {
 
167
    mtr_report("[ fail ]\n$comment");
145
168
  }
146
169
}
147
170
 
198
221
    print
199
222
      "The log files in var/log may give you some hint\n",
200
223
      "of what went wrong.\n",
201
 
      "If you want to report this error, please read first ",
202
 
      "the documentation at\n",
203
 
      "http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html\n";
 
224
      "If you want to report this error, go to:\n",
 
225
      "\thttp://bugs.launchpad.net/drizzle\n";
204
226
  }
205
227
  if (!$::opt_extern)
206
228
  {
215
237
               time - $BASETIME, "seconds executing testcases");
216
238
  }
217
239
 
218
 
  # ----------------------------------------------------------------------
219
 
  # If a debug run, there might be interesting information inside
220
 
  # the "var/log/*.err" files. We save this info in "var/log/warnings"
221
 
  # ----------------------------------------------------------------------
222
 
 
223
 
  if ( ! $::glob_use_running_server )
224
 
  {
225
 
    # Save and report if there was any fatal warnings/errors in err logs
226
 
 
227
 
    my $warnlog= "$::opt_vardir/log/warnings";
228
 
 
229
 
    unless ( open(WARN, ">$warnlog") )
230
 
    {
231
 
      mtr_warning("can't write to the file \"$warnlog\": $!");
232
 
    }
233
 
    else
234
 
    {
235
 
      # We report different types of problems in order
236
 
      foreach my $pattern ( "^Warning:",
237
 
                            "\\[Warning\\]",
238
 
                            "\\[ERROR\\]",
239
 
                            "^Error:", "^==.* at 0x",
240
 
                            "InnoDB: Warning",
241
 
                            "InnoDB: Error",
242
 
                            "^safe_mutex:",
243
 
                            "missing DBUG_RETURN",
244
 
                            "mysqld: Warning",
245
 
                            "allocated at line",
246
 
                            "Attempting backtrace", "Assertion .* failed" )
247
 
      {
248
 
        foreach my $errlog ( sort glob("$::opt_vardir/log/*.err") )
249
 
        {
250
 
          my $testname= "";
251
 
          unless ( open(ERR, $errlog) )
252
 
          {
253
 
            mtr_warning("can't read $errlog");
254
 
            next;
255
 
          }
256
 
          my $leak_reports_expected= undef;
257
 
          while ( <ERR> )
258
 
          {
259
 
            # There is a test case that purposely provokes a
260
 
            # SAFEMALLOC leak report, even though there is no actual
261
 
            # leak. We need to detect this, and ignore the warning in
262
 
            # that case.
263
 
            if (/Begin safemalloc memory dump:/) {
264
 
              $leak_reports_expected= 1;
265
 
            } elsif (/End safemalloc memory dump./) {
266
 
              $leak_reports_expected= undef;
267
 
            }
268
 
 
269
 
            # Skip some non fatal warnings from the log files
270
 
            if (
271
 
                /\"SELECT UNIX_TIMESTAMP\(\)\" failed on master/ or
272
 
                /Aborted connection/ or
273
 
                /Client requested master to start replication from impossible position/ or
274
 
                /Could not find first log file name in binary log/ or
275
 
                /Enabling keys got errno/ or
276
 
                /Error reading master configuration/ or
277
 
                /Error reading packet/ or
278
 
                /Event Scheduler/ or
279
 
                /Failed to open log/ or
280
 
                /Failed to open the existing master info file/ or
281
 
                /Forcing shutdown of [0-9]* plugins/ or
282
 
                /Can't open shared library .*\bha_example\b/ or
283
 
                /Couldn't load plugin .*\bha_example\b/ or
284
 
 
285
 
                # Due to timing issues, it might be that this warning
286
 
                # is printed when the server shuts down and the
287
 
                # computer is loaded.
288
 
                /Forcing close of thread \d+  user: '.*?'/ or
289
 
 
290
 
                /Got error [0-9]* when reading table/ or
291
 
                /Incorrect definition of table/ or
292
 
                /Incorrect information in file/ or
293
 
                /InnoDB: Warning: we did not need to do crash recovery/ or
294
 
                /Invalid \(old\?\) table or database name/ or
295
 
                /Lock wait timeout exceeded/ or
296
 
                /Log entry on master is longer than max_allowed_packet/ or
297
 
                /unknown option '--loose-/ or
298
 
                /unknown variable 'loose-/ or
299
 
                /You have forced lower_case_table_names to 0 through a command-line option/ or
300
 
                /Setting lower_case_table_names=2/ or
301
 
                /NDB Binlog:/ or
302
 
                /NDB: failed to setup table/ or
303
 
                /NDB: only row based binary logging/ or
304
 
                /Neither --relay-log nor --relay-log-index were used/ or
305
 
                /Query partially completed/ or
306
 
                /Slave I.O thread aborted while waiting for relay log/ or
307
 
                /Slave SQL thread is stopped because UNTIL condition/ or
308
 
                /Slave SQL thread retried transaction/ or
309
 
                /Slave \(additional info\)/ or
310
 
                /Slave: .*Duplicate column name/ or
311
 
                /Slave: .*master may suffer from/ or
312
 
                /Slave: According to the master's version/ or
313
 
                /Slave: Column [0-9]* type mismatch/ or
314
 
                /Slave: Can't DROP 'c7'; check that column.key exists Error_code: 1091/ or
315
 
                /Slave: Unknown column 'c7' in 't15' Error_code: 1054/ or
316
 
                /Slave: Key column 'c6' doesn't exist in table Error_code: 1072/ or
317
 
                /Slave: Error .* doesn't exist/ or
318
 
                /Slave: Error .*Deadlock found/ or
319
 
                /Slave: Error .*Unknown table/ or
320
 
                /Slave: Error in Write_rows event: / or
321
 
                /Slave: Field .* of table .* has no default value/ or
322
 
                /Slave: Field .* doesn't have a default value/ or
323
 
                /Slave: Query caused different errors on master and slave/ or
324
 
                /Slave: Table .* doesn't exist/ or
325
 
                /Slave: Table width mismatch/ or
326
 
                /Slave: The incident LOST_EVENTS occured on the master/ or
327
 
                /Slave: Unknown error.* 1105/ or
328
 
                /Slave: Can't drop database.* database doesn't exist/ or
329
 
                /Slave SQL:.*(?:Error_code: \d+|Query:.*)/ or
330
 
                
331
 
                # backup_errors test is supposed to trigger lots of backup related errors
332
 
                ($testname eq 'main.backup_errors') and
333
 
                (
334
 
                  /Backup:/ or /Restore:/ or /Can't open the online backup progress tables/
335
 
                ) or
336
 
                # The tablespace test triggers error below on purpose
337
 
                ($testname eq 'main.backup_tablespace') and
338
 
                (
339
 
                  /Restore: Tablespace .* needed by tables being restored has changed on the server/
340
 
                ) or
341
 
                
342
 
                /Sort aborted/ or
343
 
                /Time-out in NDB/ or
344
 
                /One can only use the --user.*root/ or
345
 
                /Setting lower_case_table_names=2/ or
346
 
                /Table:.* on (delete|rename)/ or
347
 
                /You have an error in your SQL syntax/ or
348
 
                /deprecated/ or
349
 
                /description of time zone/ or
350
 
                /equal MySQL server ids/ or
351
 
                /error .*connecting to master/ or
352
 
                /error reading log entry/ or
353
 
                /lower_case_table_names is set/ or
354
 
                /skip-name-resolve mode/ or
355
 
                /slave SQL thread aborted/ or
356
 
                /Slave: .*Duplicate entry/ or
357
 
                # Special case for Bug #26402 in show_check.test
358
 
                # Question marks are not valid file name parts
359
 
                # on Windows platforms. Ignore this error message. 
360
 
                /\QCan't find file: '.\test\????????.frm'\E/ or
361
 
                # Special case, made as specific as possible, for:
362
 
                # Bug #28436: Incorrect position in SHOW BINLOG EVENTS causes
363
 
                #             server coredump
364
 
                /\QError in Log_event::read_log_event(): 'Sanity check failed', data_len: 258, event_type: 49\E/ or
365
 
                /Statement is not safe to log in statement format/ or
366
 
 
367
 
                # test case for Bug#bug29807 copies a stray frm into database
368
 
                /InnoDB: Error: table `test`.`bug29807` does not exist in the InnoDB internal/ or
369
 
                /Cannot find or open table test\/bug29807 from/ or
370
 
 
371
 
                # innodb foreign key tests that fail in ALTER or RENAME produce this
372
 
                /InnoDB: Error: in ALTER TABLE `test`.`t[12]`/ or
373
 
                /InnoDB: Error: in RENAME TABLE table `test`.`t1`/ or
374
 
                /InnoDB: Error: table `test`.`t[12]` does not exist in the InnoDB internal/ or
375
 
 
376
 
                # Test case for Bug#14233 produces the following warnings:
377
 
                /Stored routine 'test'.'bug14233_1': invalid value in column mysql.proc/ or
378
 
                /Stored routine 'test'.'bug14233_2': invalid value in column mysql.proc/ or
379
 
                /Stored routine 'test'.'bug14233_3': invalid value in column mysql.proc/ or
380
 
 
381
 
                # BUG#29839 - lowercase_table3.test: Cannot find table test/T1
382
 
                #             from the internal data dictiona
383
 
                /Cannot find table test\/BUG29839 from the internal data dictionary/ or
384
 
                # BUG#32080 - Excessive warnings on Solaris: setrlimit could not
385
 
                #             change the size of core files
386
 
                /setrlimit could not change the size of core files to 'infinity'/ or
387
 
 
388
 
                # rpl_ndb_basic expects this error
389
 
                /Slave: Got error 146 during COMMIT Error_code: 1180/ or
390
 
 
391
 
                # rpl_extrColmaster_*.test, the slave thread produces warnings
392
 
                # when it get updates to a table that has more columns on the
393
 
                # master
394
 
                /Slave: Unknown column 'c7' in 't15' Error_code: 1054/ or
395
 
                /Slave: Can't DROP 'c7'.* 1091/ or
396
 
                /Slave: Key column 'c6'.* 1072/ or
397
 
 
398
 
                # BUG#32080 - Excessive warnings on Solaris: setrlimit could not
399
 
                #             change the size of core files
400
 
                /setrlimit could not change the size of core files to 'infinity'/ or
401
 
                # rpl_idempotency.test produces warnings for the slave.
402
 
                ($testname eq 'rpl.rpl_idempotency' and
403
 
                 (/Slave: Can\'t find record in \'t1\' Error_code: 1032/ or
404
 
                  /Slave: Cannot add or update a child row: a foreign key constraint fails .* Error_code: 1452/
405
 
                 )) or
406
 
 
407
 
                # These tests does "kill" on queries, causing sporadic errors when writing to logs
408
 
                (($testname eq 'rpl.rpl_skip_error' or
409
 
                  $testname eq 'rpl.rpl_err_ignoredtable' or
410
 
                  $testname eq 'binlog.binlog_killed_simulate' or
411
 
                  $testname eq 'binlog.binlog_killed') and
412
 
                 (/Failed to write to mysql\.\w+_log/
413
 
                 )) or
414
 
 
415
 
                # rpl_bug33931 has deliberate failures
416
 
                ($testname eq 'rpl.rpl_bug33931' and
417
 
                 (/Failed during slave.*thread initialization/
418
 
                  )) or
419
 
 
420
 
                # rpl_temporary has an error on slave that can be ignored
421
 
                ($testname eq 'rpl.rpl_temporary' and
422
 
                 (/Slave: Can\'t find record in \'user\' Error_code: 1032/
423
 
                 )) or
424
 
 
425
 
                # Test case for Bug#31590 produces the following error:
426
 
                /Out of sort memory; increase server sort buffer size/
427
 
                )
428
 
            {
429
 
              next;                       # Skip these lines
430
 
            }
431
 
            if ( /CURRENT_TEST: (.*)/ )
432
 
            {
433
 
              $testname= $1;
434
 
            }
435
 
            if ( /$pattern/ )
436
 
            {
437
 
              if ($leak_reports_expected) {
438
 
                next;
439
 
              }
440
 
              $found_problems= 1;
441
 
              print WARN basename($errlog) . ": $testname: $_";
442
 
            }
443
 
          }
444
 
        }
445
 
      }
446
 
 
447
 
      if ( $::opt_check_testcases )
448
 
      {
449
 
        # Look for warnings produced by mysqltest in testname.warnings
450
 
        foreach my $test_warning_file
451
 
          ( glob("$::glob_mysql_test_dir/r/*.warnings") )
452
 
        {
453
 
          $found_problems= 1;
454
 
          print WARN "Check myqltest warnings in $test_warning_file\n";
455
 
        }
456
 
      }
457
 
 
458
 
      if ( $found_problems )
459
 
      {
460
 
        mtr_warning("Got errors/warnings while running tests, please examine",
461
 
                    "\"$warnlog\" for details.");
462
 
      }
463
 
    }
464
 
  }
465
 
 
466
240
  print "\n";
467
241
 
468
242
  # Print a list of testcases that failed
516
290
##############################################################################
517
291
 
518
292
sub mtr_print_line () {
519
 
  print '-' x 55, "\n";
 
293
  print '-' x 80, "\n";
520
294
}
521
295
 
522
296
sub mtr_print_thick_line () {
523
 
  print '=' x 55, "\n";
 
297
  print '=' x 80, "\n";
524
298
}
525
299
 
526
300
sub mtr_print_header () {
527
 
  print "\n";
 
301
  print "DEFAULT STORAGE ENGINE: $::opt_engine\n";
528
302
  if ( $::opt_timer )
529
303
  {
530
 
    print "TEST                           RESULT         TIME (ms)\n";
 
304
    printf "%-61s%-9s%10s\n","TEST","RESULT","TIME (ms)";
531
305
  }
532
306
  else
533
307
  {