Simplify test output
[hiphop-php.git] / hphp / test / verify
blobe455630eec4a6bf0e9f32b679be13b52c9cdb206
1 #!/usr/bin/perl -w
2 ################################################################################
4 # Test harness.
6 ################################################################################
8 use threads;
9 use threads::shared;
10 use Thread::Semaphore;
12 # Shut off buffering.
13 select(STDOUT);
14 $| = 1;
17 # Parse command-line arguments.
19 use Getopt::Long;
20 Getopt::Long::config("bundling"); # Allow -hv rather than forcing -h -v.
22 # Set option defaults for optional arguments.
23 $opt_help = 0;
24 $opt_verbose = 0;
25 $opt_quiet = 0;
26 $opt_srcdir = ".";
27 $opt_objdir = ".";
28 $opt_command = '%1$s/%3$s';
29 $opt_ustats = 0;
30 $opt_zero = 0;
31 $opt_server = 0;
32 $opt_port = 8080;
33 $opt_home = ".";
34 $opt_threads = `cat /proc/cpuinfo | grep '^processor' | wc -l`;
35 if ($opt_threads > 20) {
36 $opt_threads = 20;
38 $opt_reduce = "";
39 $opt_coverage = "";
40 $opt_hhvm = "hhvm";
41 $opt_hphp = "hphp";
42 $opt_repo = 0;
43 $opt_cpu_time_limit = 0;
44 $opt_real_time_limit = 0;
45 $opt_no_exp = 0;
47 $opt_retval =
48 &GetOptions("h|help" => \$opt_help,
49 "v|verbose" => \$opt_verbose,
50 "q|quiet" => \$opt_quiet,
51 "s|srcdir=s" => \$opt_srcdir,
52 "o|objdir=s" => \$opt_objdir,
53 "u|ustats" => \$opt_ustats,
54 "c|command=s" => \$opt_command,
55 "z|zero" => \$opt_zero,
56 "server" => \$opt_server,
57 "port:i" => \$opt_port,
58 "home:s" => \$opt_home,
59 "threads=i" => \$opt_threads,
60 "r|reduce=s" => \$opt_reduce,
61 "coverage=s" => \$opt_coverage,
62 "no-exp" => \$opt_no_exp,
63 "hhvm=s" => \$opt_hhvm,
64 "hphp=s" => \$opt_hphp,
65 "repo=i" => \$opt_repo,
66 "cpu-time-limit=i" => \$opt_cpu_time_limit,
67 "real-time-limit=i" => \$opt_real_time_limit,
70 # Munge directory paths if necessary.
71 if (defined($opt_srcdir) && $opt_srcdir eq "")
73 $opt_srcdir = ".";
75 if (defined($opt_objdir) && $opt_objdir eq "")
77 $opt_objdir = ".";
80 if ($opt_help)
82 &usage();
83 exit(0);
86 if ($opt_retval == 0)
88 &usage();
89 exit 1;
92 if ($opt_verbose && $opt_quiet)
94 print STDERR "-v and -q are incompatible\n";
95 &usage();
96 exit 1;
99 if ($#ARGV + 1 == 0)
101 while (<STDIN>) {
102 push @ARGV, split /\s+/;
104 @ARGV = grep !/^$/, @ARGV;
105 if (scalar @ARGV == 0) {
106 print STDERR "no files passed in or on stdin\n";
107 exit 1;
111 if ($opt_verbose)
113 print STDERR "Option values: h:$opt_help, v:$opt_verbose, "
114 . "s:\"$opt_srcdir\", o:\"$opt_objdir\" "
115 . "q:$opt_quiet, u:$opt_ustats, z:$opt_zero\n";
116 printf STDERR "Tests (%d total): @ARGV\n", $#ARGV + 1;
119 if ($opt_server)
121 $command = sprintf ($opt_command, $opt_home, $opt_port);
122 $server_pid = fork();
123 if ($server_pid == 0)
125 `sudo $command 2>&1 > /dev/null`;
127 else
129 # wait for server to warm up
130 `sleep 5`;
134 if (!$opt_threads) {
135 $opt_threads = 1;
139 # Create and print header.
141 @TSTATS =
143 "--------------------------------------------------------------------------\n",
144 "Test c_user c_system c_total chng\n",
145 " passed/FAILED h_user h_system h_total %% chng\n",
146 "--------------------------------------------------------------------------\n",
149 if (!$opt_quiet)
151 foreach $line (@TSTATS)
153 printf STDOUT "$line";
158 # Run sequence test(s).
160 $total_utime = 0.0; # Total user time.
161 $total_stime = 0.0; # Total system time.
162 $total_hutime = 0.0; # Total historical user time.
163 $total_hstime = 0.0; # Total historical system time.
164 $total_ntime = 0.0; # Total time for tests that have historical data.
166 @test_buckets = ();
167 %tests_okay = ();
168 %tests_num_failed_subtests = ();
169 %tests_num_subtests = ();
170 %tests_utime = ();
171 %tests_stime = ();
172 # Extra debugging info generated by reduce or coverage.
173 # We store them in tests_extra_dbg instead of directly printing them out is
174 # that the output might be interleaved when the tests are run concurrently.
175 %tests_extra_dbg = ();
176 share(%tests_okay);
177 share(%tests_num_failed_subtests);
178 share(%tests_num_subtests);
179 share(%tests_utime);
180 share(%tests_stime);
181 share(%tests_extra_dbg);
182 # Try to construct the buckets so the test results are ready in approximately
183 # alphabetical order
184 for ($i = 0; $i < $opt_threads; $i++)
186 push @test_buckets, [];
188 $i = 0;
189 foreach $test (@ARGV)
191 push @{$test_buckets[$i]}, $test;
192 $i = ($i + 1) % $opt_threads;
195 # Spawn off worker threads
196 for ($i = 0; $i < $opt_threads; $i++)
198 threads->create(\&run_tests, $test_buckets[$i]);
201 foreach $test (@ARGV)
203 # Strip out any whitespace in $test.
204 $test =~ s/^\s*(.*)\s*$/$1/;
206 $okay = 1;
208 my (@TSTATS);
209 my ($t_str);
211 $t_str = sprintf ("%s%s", $test, ' ' x (40 - length($test)));
212 @TSTATS = (@TSTATS, $t_str);
213 if (!$opt_quiet)
215 foreach $line (@TSTATS)
217 printf STDOUT "$line";
221 ($okay, $num_failed_subtests, $num_subtests, $utime, $stime) = wait_for_test($test);
222 # num_failed_subtests and num_subtests will be zero in the diff mode.
223 ($hutime, $hstime) = &print_stats($test, $okay, $num_failed_subtests, $num_subtests, $utime, $stime);
225 lock(%tests_okay);
226 print $tests_extra_dbg{$test};
229 # Print coverage on success, or run reduce on failure.
231 $total_hutime += $hutime;
232 $total_hstime += $hstime;
234 if ($okay)
236 $total_utime += $utime;
237 $total_stime += $stime;
239 else
241 @FAILED_TESTS = (@FAILED_TESTS, $test);
244 # If there were historical data, add the run time to the total time to
245 # compare against the historical run time.
246 if (0 < ($hutime + $hstime))
248 $total_ntime += $utime + $stime;
252 # Print summary stats.
253 $tt_str = sprintf ("%d / %d passed (%5.2f%%%%)",
254 ($#ARGV + 1) - ($#FAILED_TESTS + 1),
255 $#ARGV + 1,
256 (($#ARGV + 1) - ($#FAILED_TESTS + 1))
257 / ($#ARGV + 1) * 100);
259 $t_str = sprintf ("Totals %7.2f %7.2f %7.2f"
260 . " %7.2f\n"
261 . " %s %7.2f %7.2f %7.2f %7.2f%%%%\n",
262 $total_utime, $total_stime, $total_utime + $total_stime,
263 ($total_ntime - ($total_hutime + $total_hstime)),
264 $tt_str . ' ' x (40 - length($tt_str)),
265 $total_hutime, $total_hstime, $total_hutime + $total_hstime,
266 ($total_hutime + $total_hstime == 0.0) ? 0.0 :
267 (($total_ntime
268 - ($total_hutime + $total_hstime))
269 / ($total_hutime + $total_hstime) * 100));
271 $thread_warning = "";
272 if ($opt_threads > 1) {
273 $thread_warning = "WARNING: Multiple threads were used. CPU times "
274 . "are wildly inaccurate\n"
277 @TSTATS = ("--------------------------------------------------------------------------\n",
278 $thread_warning,
279 $t_str,
280 "--------------------------------------------------------------------------\n"
282 if (!$opt_quiet)
284 foreach $line (@TSTATS)
286 printf STDOUT "$line";
288 if (@FAILED_TESTS) {
289 printf STDOUT "failed tests:\n";
291 foreach $fail (@FAILED_TESTS)
293 printf STDOUT "%50s\n", $fail;
298 if ($opt_server)
300 kill 9, $server_pid;
301 `ps aux | grep hphpi | grep -v perl | cut -c10-15 | sudo xargs kill -9 \\
302 2>&1 >/dev/null`
305 if ($#FAILED_TESTS >= 0)
307 # One or more tests failed, so return an error.
308 exit 1;
310 # End of main execution.
312 sub run_tests
314 foreach my $test (@{$_[0]})
316 my ($okay, $num_failed_subtests, $num_subtests, $utime, $stime, $extra_dbg) = run_test($test);
318 lock(%tests_okay);
319 $tests_okay{$test} = $okay;
320 $tests_num_failed_subtests{$test} = $num_failed_subtests;
321 $tests_num_subtests{$test} = $num_subtests;
322 $tests_utime{$test} = $utime;
323 $tests_stime{$test} = $stime;
324 $tests_extra_dbg{$test} = $extra_dbg;
325 cond_signal(%tests_okay);
330 sub wait_for_test
332 my ($test) = @_;
333 while (1)
335 lock(%tests_okay);
336 if (exists $tests_okay{$test}) {
337 return ($tests_okay{$test},
338 $tests_num_failed_subtests{$test},
339 $tests_num_subtests{$test},
340 $tests_utime{$test},
341 $tests_stime{$test},
342 $tests_extra_dbg{$test});
344 cond_wait(%tests_okay);
348 sub run_test
350 my ($test) = @_;
351 my ($okay) = 1;
352 my ($num_failed_subtests) = 0;
353 my ($num_subtests) = 0;
354 my ($tutime, $tstime);
355 my ($extra_dbg) = "";
356 my ($utime, $stime, $cutime, $cstime);
357 my ($opts) = "";
359 if ($opt_server)
361 $command = "GET http://localhost:" . $opt_port . "/" . $test;
363 else
365 $command = sprintf ($opt_command, $opt_srcdir, $opt_objdir, $test);
366 if ($opt_cpu_time_limit)
368 $command = "(ulimit -t " . $opt_cpu_time_limit . "; "
369 . "timeout " . $opt_real_time_limit . " "
370 . $command . ")";
374 if (-e "$opt_objdir/$test.opts") {
375 open (FILE, "<$opt_objdir/$test.opts");
376 @lines = <FILE>;
377 close(FILE);
378 chomp(@lines);
379 $opts = join(' ', @lines);
383 if ($opt_repo) {
384 if ($test =~ m/\.hhas/) {
385 # We don't have a way to skip, I guess run non-repo?
386 } else {
387 my ($hphp_opts) = "";
388 if (-e "$opt_objdir/$test.hphp_opts") {
389 open (FILE, "<$opt_objdir/$test.hphp_opts");
390 @lines = <FILE>;
391 close(FILE);
392 chomp(@lines);
393 $hphp_opts = join(' ', @lines);
395 unlink "$opt_objdir/$test.repo/hhvm.hhbc";
396 `$opt_hphp -thhbc -l0 -k1 -o $opt_objdir/$test.repo $hphp_opts $opt_objdir/$test`;
397 $opts .= " -v Repo.Authoritative=true -v Repo.Central.Path=$opt_objdir/$test.repo/hhvm.hhbc";
401 ($utime, $stime, $cutime, $cstime) = times;
402 `$command $opts > $opt_objdir/$test.out 2>&1`;
403 ($utime, $stime, $tutime, $tstime) = times;
405 # Subtract the before time from the after time.
406 $tutime -= $cutime;
407 $tstime -= $cstime;
409 if ($opt_zero)
411 if ($?)
413 $okay = 0;
414 if ($opt_verbose)
416 print STDERR
417 "\"$opt_objdir/$test > $opt_objdir/$test.out 2>&1\" returned $?\n";
422 # Compare the results with the expected, and update "okay".
423 if (! -e "$opt_objdir/$test.out") {
424 $okay = 0;
425 if ($opt_verbose)
427 print STDERR
428 "Nonexistent output file \"$opt_objdir/$test.out\"\n";
431 elsif (-e "$opt_srcdir/$test.exp")
433 $okay = 0;
434 print STDERR "Rename your .exp file to .expect. See test/README.md";
436 elsif (!$opt_no_exp && -e "$opt_srcdir/$test.expect")
438 $diff_args = "--text -u";
439 `diff $diff_args $opt_srcdir/$test.expect $opt_objdir/$test.out > $opt_objdir/$test.diff 2>&1`;
440 if ($?)
442 # diff returns non-zero if there is a difference.
443 $okay = 0;
446 elsif (!$opt_no_exp && -e "$opt_srcdir/$test.expectf")
448 open (FILE, "<$opt_objdir/$test.expectf");
449 @lines = <FILE>;
450 close(FILE);
451 $wanted_re = join('', @lines);
453 open (FILE, "<$opt_objdir/$test.out");
454 @lines = <FILE>;
455 close(FILE);
456 $content = join('', @lines);
458 # from run-tests.php
459 $temp = "";
460 $r = "%r";
461 $startOffset = 0;
462 $length = length($wanted_re);
463 while ($startOffset < $length)
465 $start = index($wanted_re, $r, $startOffset);
466 if ($start != -1)
468 $end = index($wanted_re, $r, $start+2);
469 if ($end == -1)
471 # unbalanced tag, ignore it.
472 $end = $start = $length;
475 else
477 $start = $end = $length;
480 $temp = $temp . quotemeta(substr($wanted_re, $startOffset, $start - $startOffset));
481 if ($end > $start)
483 $temp = $temp . '(' . substr($wanted_re, $start+2, $end - $start-2) . ')';
486 $startOffset = $end + 2;
488 $wanted_re = $temp;
490 ## perl escapes % but we want to use %s as our replacement
491 $wanted_re =~ s/\\%/%/g;
493 $wanted_re =~ s/%binary_string_optional%/string/g;
494 $wanted_re =~ s/%unicode_string_optional%/string/g;
495 $wanted_re =~ s/%unicode\\\|string%/string/g;
496 $wanted_re =~ s/%string\\\|unicode%/string/g;
497 $wanted_re =~ s/%u\\\|b%//g;
498 $wanted_re =~ s/%b\\\|u%//g;
500 # Stick to basics;
501 $wanted_re =~ s/%e/\\\//g;
502 $wanted_re =~ s/%s/[^\r\n]+/g;
503 $wanted_re =~ s/%S/[^\r\n]*/g;
504 $wanted_re =~ s/%a/.+/g;
505 $wanted_re =~ s/%A/.*/g;
506 $wanted_re =~ s/%w/\\s*/g;
507 $wanted_re =~ s/%i/[+-]?\\d+/g;
508 $wanted_re =~ s/%d/\\d+/g;
509 $wanted_re =~ s/%x/[0-9a-fA-F]+/g;
510 $wanted_re =~ s/%f/[+-]?\\.?\\d+\\.?\\d*(?:[Ee][+-]?\\d+)?/g;
511 $wanted_re =~ s/%c/./g;
513 unless ($content =~ /^$wanted_re$/)
515 $okay = 0;
516 # a poor mans aide for debugging
517 $diff_args = "--text -u";
518 `diff $diff_args $opt_srcdir/$test.expectf $opt_objdir/$test.out > $opt_objdir/$test.diff 2>&1`;
521 elsif (!$opt_no_exp && -e "$opt_srcdir/$test.expectregex")
523 open (FILE, "<$opt_objdir/$test.expectregex");
524 @lines = <FILE>;
525 close(FILE);
526 $regex = join('', @lines);
528 open (FILE, "<$opt_objdir/$test.out");
529 @lines = <FILE>;
530 close(FILE);
531 $content = join('', @lines);
533 unless ($content =~ /$regex/)
535 $okay = 0;
538 else
540 # Sequence mode.
541 if (open (STEST_OUT, "<$opt_objdir/$test.out"))
543 $num_subtests = 0;
544 $num_failed_subtests = 0;
546 while (defined($line = <STEST_OUT>))
548 if ($line =~ /1\.\.(\d+)/)
550 $num_subtests = $1;
551 last;
554 if ($num_subtests == 0)
556 $okay = 0;
557 if ($opt_verbose)
559 print STDERR "Malformed or missing 1..n line\n";
562 else
564 for ($subtest = 1; $subtest <= $num_subtests; $subtest++)
566 while (defined($line = <STEST_OUT>))
568 if ($line =~ /^not\s+ok\s+(\d+)?/)
570 $not = 1;
571 $test_num = $1;
572 last;
574 elsif ($line =~ /^ok\s+(\d+)?/)
576 $not = 0;
577 $test_num = $1;
578 last;
581 if (defined($line))
583 if (defined($test_num) && ($test_num != $subtest))
585 # There was no output printed for one or more tests.
586 for (; $subtest < $test_num; $subtest++)
588 $num_failed_subtests++;
591 if ($not)
593 $num_failed_subtests++;
596 else
598 for (; $subtest <= $num_subtests; $subtest++)
600 $num_failed_subtests++;
605 if (0 < $num_failed_subtests)
607 $okay = 0;
611 else
613 if (!$opt_quiet)
615 print STDERR "Cannot open output file \"$opt_objdir/$test.out\"\n";
617 exit 1;
621 if ($okay == 0)
623 # Run reduce to pinpoint the tracelet that causes the error.
624 # For now, reduce has to be run sequentially, because it copies the input
625 # file to the same temporary place.
626 if ($opt_reduce ne "")
628 $cmd = $opt_reduce . " '" . $opt_hhvm . "' " . $test;
629 if ($opt_cpu_time_limit)
631 $cmd = join(" ",
632 $cmd,
633 $opt_cpu_time_limit,
634 $opt_real_time_limit);
636 $extra_dbg = `$cmd 2> /dev/null`;
639 else
641 # Print the coverage.
642 # Need run the command again in the tracing mode.
643 if ($opt_coverage ne "")
645 $command = sprintf($opt_command, $opt_srcdir, $opt_objdir, $test);
646 # Need calculate # of spills, reloads, and pushes/pops
647 # around natives which are logged in level 3.
648 $command = join("", "TRACE=tx64:3 ",
649 "HPHP_TRACE_FILE=", $test, ".log ",
650 $command);
651 `$command 2> /dev/null`;
652 $extra_dbg = `$opt_coverage < $test.log 2> /dev/null`;
656 return ($okay, $num_failed_subtests, $num_subtests, $tutime,
657 $tstime, $extra_dbg);
660 sub print_stats
662 my ($test, $okay, $failed_subtests, $subtests, $utime, $stime) = @_;
663 my ($hutime, $hstime);
664 # my (TEST_PERF);
665 my (@TSTATS);
666 my ($t_str, $pass_str);
668 $pass_str = $okay ? "" : "*** FAILED ***";
669 if ((0 != $subtests) && (!$okay))
671 $pass_str = $pass_str . " ($failed_subtests/$subtests failed)";
673 if (length($pass_str) > 0)
675 $pass_str = $pass_str . ' ' x (39 - length($pass_str));
678 if (-r "$test.perf")
680 if (!open (TEST_PERF, "<$opt_objdir/$test.perf"))
682 print STDERR "Unable to open \"$opt_objdir/$test.perf\"\n";
683 exit 1;
685 $_ = <TEST_PERF>;
687 ($hutime, $hstime) = split;
688 close TEST_PERF;
690 $t_str = sprintf (" %7.2f %7.2f %7.2f %7.2f\n"
691 . " %s %7.2f %7.2f %7.2f %7.2f%%%%\n",
692 $utime, $stime, $utime + $stime,
693 ($utime + $stime) - ($hutime + $hstime),
694 $pass_str,
695 $hutime, $hstime, $hutime + $hstime,
696 (($hutime + $hstime) == 0.0) ? 0.0 :
697 ((($utime + $stime) - ($hutime + $hstime))
698 / ($hutime + $hstime) * 100));
700 else
702 $hutime = 0.0;
703 $hstime = 0.0;
705 $t_str = sprintf (" %7.2f %7.2f %7.2f \n"
706 . "%s",
707 $utime, $stime, $utime + $stime,
708 length($pass_str) > 0 ? " $pass_str\n" : "");
710 @TSTATS = ($t_str);
711 if (!$opt_quiet)
713 foreach $line (@TSTATS)
715 printf STDOUT "$line";
719 if ($okay && $opt_ustats)
721 if (!open (TEST_PERF, ">$opt_objdir/$test.perf"))
723 if (!$opt_quiet)
725 print STDERR "Unable to update \"$opt_objdir/$test.perf\"\n";
728 else
730 print TEST_PERF "$utime $stime\n";
731 close TEST_PERF;
735 return ($hutime, $hstime);
738 sub usage
740 print <<EOF;
741 $0 usage:
742 $0 [<options>] <test>+
744 Option | Description
745 --------------+-------------------------------------------------------------
746 -h --help | Print usage and exit.
747 -v --verbose | Verbose (incompatible with quiet).
748 -q --quiet | Quiet (incompatible with verbose).
749 -s --srcdir | Path to source tree (default is ".").
750 -o --objdir | Path to object tree (default is ".").
751 -c --command | Command template, where the following substitutions are
752 | performed:
753 | %1\$s : srcdir (see --srcdir)
754 | %2\$s : objdir (see --objdir)
755 | %3\$s : <test>
756 | (default is '%1\$s/%3\$s').
757 -r --reduce | The path to the reduce tool.
758 | Do not run reduce if it is empty.
759 | (default is empty)
760 --coverage | The path to the coverage tool.
761 | Do not run coverage if it is empty.
762 | (default is empty)
763 -t | Set the time limit for each test case
764 | (default is unlimited).
765 -u --ustats | Update historical statistics (stored in "<test>.perf".
766 -z --zero | Consider non-zero exit code to be an error.
767 --no-exp | Don't diff with .exp files
768 --------------+-------------------------------------------------------------
770 If <test>.exp exists and --no-exp is not specified, <test>'s output is
771 diff'ed with <test>.exp. Any difference is considered failure.
773 If <test>.exp does not exist or --no-exp is specified, output to stdout of
774 the following form is expected:
776 1..<n>
777 {not }ok[ 1]
778 {not }ok[ 2]
780 {not }ok[ n]
782 1 <= <n> < 2^31
784 Lines which do not match the patterns shown above are ignored.
787 # vim:filetype=perl: