~drizzle-trunk/drizzle/development

« back to all changes in this revision

Viewing changes to tests/lib/mtr_report.pl

  • Committer: Brian Aker
  • Date: 2009-01-24 09:43:35 UTC
  • Revision ID: brian@gir-3.local-20090124094335-6qdtvc35gl5fvivz
Adding in an example singe thread scheduler

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
 
  if ($::opt_subunit) {
60
 
    printf "test: $tname\n";
61
 
  } else {
62
 
    printf "%-60s ", $tname;
63
 
  }
 
59
  printf "%-30s ", $tname;
64
60
}
65
61
 
66
62
sub mtr_report_test_skipped ($) {
67
63
  my $tinfo= shift;
68
 
  my $tname= $tinfo->{name};
69
 
  my $cause= "";
70
64
 
71
65
  $tinfo->{'result'}= 'MTR_RES_SKIPPED';
72
66
  if ( $tinfo->{'disable'} )
73
67
  {
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
 
    }
 
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 ]");
95
77
  }
96
78
}
97
79
 
114
96
 
115
97
sub mtr_report_test_passed ($) {
116
98
  my $tinfo= shift;
117
 
  my $tname= $tinfo->{name};
118
99
 
119
100
  my $timer=  "";
120
101
  if ( $::opt_timer and -f "$::opt_vardir/log/timer" )
121
102
  {
122
103
    $timer= mtr_fromfile("$::opt_vardir/log/timer");
123
104
    $tot_real_time += ($timer/1000);
124
 
    $timer= sprintf "%7s", $timer;
125
 
    ### XXX: How to format this as iso6801 datetime?
 
105
    $timer= sprintf "%12s", $timer;
126
106
  }
127
107
  $tinfo->{'result'}= 'MTR_RES_PASSED';
128
 
  if ($::opt_subunit) {
129
 
    mtr_report("success: $tname");
130
 
  } else {
131
 
    mtr_report("[ pass ] $timer");
132
 
  }
 
108
  mtr_report("[ pass ]   $timer");
133
109
}
134
110
 
135
111
sub mtr_report_test_failed ($) {
136
112
  my $tinfo= shift;
137
 
  my $tname= $tinfo->{name};
138
 
  my $comment= "";
139
113
 
140
114
  $tinfo->{'result'}= 'MTR_RES_FAILED';
141
115
  if ( defined $tinfo->{'timeout'} )
142
116
  {
143
 
    $comment.= "timeout";
144
 
  }
145
 
  elsif ( $tinfo->{'comment'} )
 
117
    mtr_report("[ fail ]  timeout");
 
118
    return;
 
119
  }
 
120
  else
 
121
  {
 
122
    mtr_report("[ fail ]");
 
123
  }
 
124
 
 
125
  if ( $tinfo->{'comment'} )
146
126
  {
147
127
    # The test failure has been detected by mysql-test-run.pl
148
128
    # when starting the servers or due to other error, the reason for
149
129
    # failing the test is saved in "comment"
150
 
    $comment.= "$tinfo->{'comment'}";
 
130
    mtr_report("\nERROR: $tinfo->{'comment'}");
151
131
  }
152
132
  elsif ( -f $::path_timefile )
153
133
  {
154
134
    # Test failure was detected by test tool and it's report
155
135
    # about what failed has been saved to file. Display the report.
156
 
    $comment.= mtr_fromfile($::path_timefile);
 
136
    print "\n";
 
137
    print mtr_fromfile($::path_timefile); # FIXME print_file() instead
 
138
    print "\n";
157
139
  }
158
140
  else
159
141
  {
160
142
    # Neither this script or the test tool has recorded info
161
143
    # about why the test has failed. Should be debugged.
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");
 
144
    mtr_report("\nUnexpected termination, probably when starting mysqld");;
168
145
  }
169
146
}
170
147
 
221
198
    print
222
199
      "The log files in var/log may give you some hint\n",
223
200
      "of what went wrong.\n",
224
 
      "If you want to report this error, go to:\n",
225
 
      "\thttp://bugs.launchpad.net/drizzle\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";
226
204
  }
227
205
  if (!$::opt_extern)
228
206
  {
237
215
               time - $BASETIME, "seconds executing testcases");
238
216
  }
239
217
 
 
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
 
240
466
  print "\n";
241
467
 
242
468
  # Print a list of testcases that failed
290
516
##############################################################################
291
517
 
292
518
sub mtr_print_line () {
293
 
  print '-' x 80, "\n";
 
519
  print '-' x 55, "\n";
294
520
}
295
521
 
296
522
sub mtr_print_thick_line () {
297
 
  print '=' x 80, "\n";
 
523
  print '=' x 55, "\n";
298
524
}
299
525
 
300
526
sub mtr_print_header () {
301
527
  print "DEFAULT STORAGE ENGINE: $::opt_engine\n";
302
528
  if ( $::opt_timer )
303
529
  {
304
 
    printf "%-61s%-9s%10s\n","TEST","RESULT","TIME (ms)";
 
530
    print "TEST                           RESULT         TIME (ms)\n";
305
531
  }
306
532
  else
307
533
  {