tests: Automatically time TAP tests
[lttng-tools.git] / tests / utils / tap-driver.sh
1 #! /bin/sh
2 # Copyright (C) 2011-2013 Free Software Foundation, Inc.
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 as published by
6 # the Free Software Foundation; either version 2, or (at your option)
7 # any later version.
8 #
9 # This program is distributed in the hope that it will be useful,
10 # but WITHOUT ANY WARRANTY; without even the implied warranty of
11 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 # GNU General Public License for more details.
13 #
14 # You should have received a copy of the GNU General Public License
15 # along with this program. If not, see <http://www.gnu.org/licenses/>.
16
17 # As a special exception to the GNU General Public License, if you
18 # distribute this file as part of a program that contains a
19 # configuration script generated by Autoconf, you may include it under
20 # the same distribution terms that you use for the rest of that program.
21
22 # This file is maintained in Automake, please report
23 # bugs to <bug-automake@gnu.org> or send patches to
24 # <automake-patches@gnu.org>.
25
26 scriptversion=2013-12-23.17; # UTC
27
28 # Make unconditional expansion of undefined variables an error. This
29 # helps a lot in preventing typo-related bugs.
30 set -u
31
32 me=tap-driver.sh
33
34 fatal ()
35 {
36 echo "$me: fatal: $*" >&2
37 exit 1
38 }
39
40 usage_error ()
41 {
42 echo "$me: $*" >&2
43 print_usage >&2
44 exit 2
45 }
46
47 print_usage ()
48 {
49 cat <<END
50 Usage:
51 tap-driver.sh --test-name=NAME --log-file=PATH --trs-file=PATH
52 [--expect-failure={yes|no}] [--color-tests={yes|no}]
53 [--enable-hard-errors={yes|no}] [--ignore-exit]
54 [--diagnostic-string=STRING] [--merge|--no-merge]
55 [--comments|--no-comments] [--post-script] [--] TEST-COMMAND
56 The '--test-name', '-log-file' and '--trs-file' options are mandatory.
57 END
58 }
59
60 # TODO: better error handling in option parsing (in particular, ensure
61 # TODO: $log_file, $trs_file and $test_name are defined).
62 test_name= # Used for reporting.
63 log_file= # Where to save the result and output of the test script.
64 trs_file= # Where to save the metadata of the test run.
65 post_script= # Script to be run after the test.
66 expect_failure=0
67 color_tests=0
68 merge=0
69 ignore_exit=0
70 comments=0
71 diag_string='#'
72 while test $# -gt 0; do
73 case $1 in
74 --help) print_usage; exit $?;;
75 --version) echo "$me $scriptversion"; exit $?;;
76 --test-name) test_name=$2; shift;;
77 --log-file) log_file=$2; shift;;
78 --trs-file) trs_file=$2; shift;;
79 --color-tests) color_tests=$2; shift;;
80 --expect-failure) expect_failure=$2; shift;;
81 --enable-hard-errors) shift;; # No-op.
82 --merge) merge=1;;
83 --no-merge) merge=0;;
84 --ignore-exit) ignore_exit=1;;
85 --comments) comments=1;;
86 --no-comments) comments=0;;
87 --diagnostic-string) diag_string=$2; shift;;
88 --post-script) post_script=$2; shift;;
89 --) shift; break;;
90 -*) usage_error "invalid option: '$1'";;
91 esac
92 shift
93 done
94
95 test $# -gt 0 || usage_error "missing test command"
96
97 case $expect_failure in
98 yes) expect_failure=1;;
99 *) expect_failure=0;;
100 esac
101
102 if test $color_tests = yes; then
103 init_colors='
104 color_map["red"]="\e[0;31m" # Red.
105 color_map["grn"]="\e[0;32m" # Green.
106 color_map["lgn"]="\e[1;32m" # Light green.
107 color_map["blu"]="\e[1;34m" # Blue.
108 color_map["mgn"]="\e[0;35m" # Magenta.
109 color_map["std"]="\e[m" # No color.
110 color_for_result["ERROR"] = "mgn"
111 color_for_result["PASS"] = "grn"
112 color_for_result["XPASS"] = "red"
113 color_for_result["FAIL"] = "red"
114 color_for_result["XFAIL"] = "lgn"
115 color_for_result["SKIP"] = "blu"'
116 else
117 init_colors=''
118 fi
119
120 TIME_SCRIPT="$(realpath -e -- "$(dirname "$0")")/tap/clock"
121
122 # :; is there to work around a bug in bash 3.2 (and earlier) which
123 # does not always set '$?' properly on redirection failure.
124 # See the Autoconf manual for more details.
125 :;{
126 (
127 # Ignore common signals (in this subshell only!), to avoid potential
128 # problems with Korn shells. Some Korn shells are known to propagate
129 # to themselves signals that have killed a child process they were
130 # waiting for; this is done at least for SIGINT (and usually only for
131 # it, in truth). Without the `trap' below, such a behaviour could
132 # cause a premature exit in the current subshell, e.g., in case the
133 # test command it runs gets terminated by a SIGINT. Thus, the awk
134 # script we are piping into would never seen the exit status it
135 # expects on its last input line (which is displayed below by the
136 # last `echo $?' statement), and would thus die reporting an internal
137 # error.
138 # For more information, see the Autoconf manual and the threads:
139 # <http://lists.gnu.org/archive/html/bug-autoconf/2011-09/msg00004.html>
140 # <http://mail.opensolaris.org/pipermail/ksh93-integration-discuss/2009-February/004121.html>
141 trap : 1 3 2 13 15
142 if test $merge -gt 0; then
143 exec 2>&1
144 else
145 exec 2>&3
146 fi
147 # Since stderr and stdout may go to the same file and the script
148 # may run in situations with different types of buffering, enforce
149 # line buffering for both FDs. This helps to prevent interleave between
150 # the outputs in the resulting file for half written lines, eg.
151 # ok 93 - Tes# PERROR - xxxx
152 # t some function
153 stdbuf -eL -oL -- "$@"
154 echo $?
155 ) | LC_ALL=C ${AM_TAP_AWK-awk} \
156 -v me="$me" \
157 -v test_script_name="$test_name" \
158 -v log_file="$log_file" \
159 -v trs_file="$trs_file" \
160 -v expect_failure="$expect_failure" \
161 -v merge="$merge" \
162 -v ignore_exit="$ignore_exit" \
163 -v comments="$comments" \
164 -v diag_string="$diag_string" \
165 -v time_script="${TIME_SCRIPT}" \
166 '
167 # TODO: the usages of "cat >&3" below could be optimized when using
168 # GNU awk, and/on on systems that supports /dev/fd/.
169
170 # Implementation note: in what follows, `result_obj` will be an
171 # associative array that (partly) simulates a TAP result object
172 # from the `TAP::Parser` perl module.
173
174 ## ----------- ##
175 ## FUNCTIONS ##
176 ## ----------- ##
177
178 function fatal(msg)
179 {
180 print me ": " msg | "cat >&2"
181 exit 1
182 }
183
184 function abort(where)
185 {
186 fatal("internal error " where)
187 }
188
189 # Convert a boolean to a "yes"/"no" string.
190 function yn(bool)
191 {
192 return bool ? "yes" : "no";
193 }
194
195 function add_test_result(result)
196 {
197 if (!test_results_index)
198 test_results_index = 0
199 test_results_list[test_results_index] = result
200 test_results_index += 1
201 test_results_seen[result] = 1;
202 }
203
204 # Whether the test script should be re-run by "make recheck".
205 function must_recheck()
206 {
207 for (k in test_results_seen)
208 if (k != "XFAIL" && k != "PASS" && k != "SKIP")
209 return 1
210 return 0
211 }
212
213 # Whether the content of the log file associated to this test should
214 # be copied into the "global" test-suite.log.
215 function copy_in_global_log()
216 {
217 for (k in test_results_seen)
218 if (k != "PASS")
219 return 1
220 return 0
221 }
222
223 function gettime_ns( r)
224 {
225 r = ""
226 if (time_script | getline r) {
227 r = r
228 }
229 close(time_script)
230 return sprintf("%f", r)
231 }
232
233 function get_global_test_result()
234 {
235 if ("ERROR" in test_results_seen)
236 return "ERROR"
237 if ("FAIL" in test_results_seen || "XPASS" in test_results_seen)
238 return "FAIL"
239 all_skipped = 1
240 for (k in test_results_seen)
241 if (k != "SKIP")
242 all_skipped = 0
243 if (all_skipped)
244 return "SKIP"
245 return "PASS";
246 }
247
248 function stringify_result_obj(result_obj)
249 {
250 if (result_obj["is_unplanned"] || result_obj["number"] != testno)
251 return "ERROR"
252
253 if (plan_seen == LATE_PLAN)
254 return "ERROR"
255
256 if (result_obj["directive"] == "TODO")
257 return result_obj["is_ok"] ? "XPASS" : "XFAIL"
258
259 if (result_obj["directive"] == "SKIP")
260 return result_obj["is_ok"] ? "SKIP" : COOKED_FAIL;
261
262 if (length(result_obj["directive"]))
263 abort("in function stringify_result_obj()")
264
265 return result_obj["is_ok"] ? COOKED_PASS : COOKED_FAIL
266 }
267
268 function decorate_result(result)
269 {
270 color_name = color_for_result[result]
271 if (color_name)
272 return color_map[color_name] "" result "" color_map["std"]
273 # If we are not using colorized output, or if we do not know how
274 # to colorize the given result, we should return it unchanged.
275 return result
276 }
277
278 function report(result, details)
279 {
280 if (result ~ /^(X?(PASS|FAIL)|SKIP|ERROR)/)
281 {
282 msg = ": " test_script_name
283 add_test_result(result)
284 }
285 else if (result == "#")
286 {
287 msg = " " test_script_name ":"
288 }
289 else
290 {
291 abort("in function report()")
292 }
293 if (length(details))
294 msg = msg " " details
295 # Output on console might be colorized.
296 print decorate_result(result) msg
297 # Flush stdout after each test result, this is useful when stdout
298 # is buffered, for example in a CI system.
299 fflush()
300 # Log the result in the log file too, to help debugging (this is
301 # especially true when said result is a TAP error or "Bail out!").
302 print result msg | "cat >&3";
303 }
304
305 function testsuite_error(error_message)
306 {
307 report("ERROR", "- " error_message)
308 }
309
310 function handle_tap_result()
311 {
312 details = result_obj["number"];
313 if (length(result_obj["description"]))
314 details = details " " result_obj["description"]
315
316 if (plan_seen == LATE_PLAN)
317 {
318 details = details " # AFTER LATE PLAN";
319 }
320 else if (result_obj["is_unplanned"])
321 {
322 details = details " # UNPLANNED";
323 }
324 else if (result_obj["number"] != testno)
325 {
326 details = sprintf("%s # OUT-OF-ORDER (expecting %d)",
327 details, testno);
328 }
329 else if (result_obj["directive"])
330 {
331 details = details " # " result_obj["directive"];
332 if (length(result_obj["explanation"]))
333 details = details " " result_obj["explanation"]
334 }
335
336 report(stringify_result_obj(result_obj), details)
337 }
338
339 # `skip_reason` should be empty whenever planned > 0.
340 function handle_tap_plan(planned, skip_reason)
341 {
342 planned += 0 # Avoid getting confused if, say, `planned` is "00"
343 if (length(skip_reason) && planned > 0)
344 abort("in function handle_tap_plan()")
345 if (plan_seen)
346 {
347 # Error, only one plan per stream is acceptable.
348 testsuite_error("multiple test plans")
349 return;
350 }
351 planned_tests = planned
352 # The TAP plan can come before or after *all* the TAP results; we speak
353 # respectively of an "early" or a "late" plan. If we see the plan line
354 # after at least one TAP result has been seen, assume we have a late
355 # plan; in this case, any further test result seen after the plan will
356 # be flagged as an error.
357 plan_seen = (testno >= 1 ? LATE_PLAN : EARLY_PLAN)
358 # If testno > 0, we have an error ("too many tests run") that will be
359 # automatically dealt with later, so do not worry about it here. If
360 # $plan_seen is true, we have an error due to a repeated plan, and that
361 # has already been dealt with above. Otherwise, we have a valid "plan
362 # with SKIP" specification, and should report it as a particular kind
363 # of SKIP result.
364 if (planned == 0 && testno == 0)
365 {
366 if (length(skip_reason))
367 skip_reason = "- " skip_reason;
368 report("SKIP", skip_reason);
369 }
370 }
371
372 function extract_tap_comment(line)
373 {
374 if (index(line, diag_string) == 1)
375 {
376 # Strip leading `diag_string` from `line`.
377 line = substr(line, length(diag_string) + 1)
378 # And strip any leading and trailing whitespace left.
379 sub("^[ \t]*", "", line)
380 sub("[ \t]*$", "", line)
381 # Return what is left (if any).
382 return line;
383 }
384 return "";
385 }
386
387 # When this function is called, we know that line is a TAP result line,
388 # so that it matches the (perl) RE "^(not )?ok\b".
389 function setup_result_obj(line)
390 {
391 # Get the result, and remove it from the line.
392 result_obj["is_ok"] = (substr(line, 1, 2) == "ok" ? 1 : 0)
393 sub("^(not )?ok[ \t]*", "", line)
394
395 # If the result has an explicit number, get it and strip it; otherwise,
396 # automatically assing the next progresive number to it.
397 if (line ~ /^[0-9]+$/ || line ~ /^[0-9]+[^a-zA-Z0-9_]/)
398 {
399 match(line, "^[0-9]+")
400 # The final `+ 0` is to normalize numbers with leading zeros.
401 result_obj["number"] = substr(line, 1, RLENGTH) + 0
402 line = substr(line, RLENGTH + 1)
403 }
404 else
405 {
406 result_obj["number"] = testno
407 }
408
409 if (plan_seen == LATE_PLAN)
410 # No further test results are acceptable after a "late" TAP plan
411 # has been seen.
412 result_obj["is_unplanned"] = 1
413 else if (plan_seen && testno > planned_tests)
414 result_obj["is_unplanned"] = 1
415 else
416 result_obj["is_unplanned"] = 0
417
418 # Strip trailing and leading whitespace.
419 sub("^[ \t]*", "", line)
420 sub("[ \t]*$", "", line)
421
422 # This will have to be corrected if we have a "TODO"/"SKIP" directive.
423 result_obj["description"] = line
424 result_obj["directive"] = ""
425 result_obj["explanation"] = ""
426
427 if (index(line, "#") == 0)
428 return # No possible directive, nothing more to do.
429
430 # Directives are case-insensitive.
431 rx = "[ \t]*#[ \t]*([tT][oO][dD][oO]|[sS][kK][iI][pP])[ \t]*"
432
433 # See whether we have the directive, and if yes, where.
434 pos = match(line, rx "$")
435 if (!pos)
436 pos = match(line, rx "[^a-zA-Z0-9_]")
437
438 # If there was no TAP directive, we have nothing more to do.
439 if (!pos)
440 return
441
442 # Let`s now see if the TAP directive has been escaped. For example:
443 # escaped: ok \# SKIP
444 # not escaped: ok \\# SKIP
445 # escaped: ok \\\\\# SKIP
446 # not escaped: ok \ # SKIP
447 if (substr(line, pos, 1) == "#")
448 {
449 bslash_count = 0
450 for (i = pos; i > 1 && substr(line, i - 1, 1) == "\\"; i--)
451 bslash_count += 1
452 if (bslash_count % 2)
453 return # Directive was escaped.
454 }
455
456 # Strip the directive and its explanation (if any) from the test
457 # description.
458 result_obj["description"] = substr(line, 1, pos - 1)
459 # Now remove the test description from the line, that has been dealt
460 # with already.
461 line = substr(line, pos)
462 # Strip the directive, and save its value (normalized to upper case).
463 sub("^[ \t]*#[ \t]*", "", line)
464 result_obj["directive"] = toupper(substr(line, 1, 4))
465 line = substr(line, 5)
466 # Now get the explanation for the directive (if any), with leading
467 # and trailing whitespace removed.
468 sub("^[ \t]*", "", line)
469 sub("[ \t]*$", "", line)
470 result_obj["explanation"] = line
471 }
472
473 function get_test_exit_message(status)
474 {
475 if (status == 0)
476 return ""
477 if (status !~ /^[1-9][0-9]*$/)
478 abort("getting exit status")
479 if (status < 127)
480 exit_details = ""
481 else if (status == 127)
482 exit_details = " (command not found?)"
483 else if (status >= 128 && status <= 255)
484 exit_details = sprintf(" (terminated by signal %d?)", status - 128)
485 else if (status > 256 && status <= 384)
486 # We used to report an "abnormal termination" here, but some Korn
487 # shells, when a child process die due to signal number n, can leave
488 # in $? an exit status of 256+n instead of the more standard 128+n.
489 # Apparently, both behaviours are allowed by POSIX (2008), so be
490 # prepared to handle them both. See also Austing Group report ID
491 # 0000051 <http://www.austingroupbugs.net/view.php?id=51>
492 exit_details = sprintf(" (terminated by signal %d?)", status - 256)
493 else
494 # Never seen in practice.
495 exit_details = " (abnormal termination)"
496 return sprintf("exited with status %d%s", status, exit_details)
497 }
498
499 function write_test_results()
500 {
501 print ":global-test-result: " get_global_test_result() > trs_file
502 print ":recheck: " yn(must_recheck()) > trs_file
503 print ":copy-in-global-log: " yn(copy_in_global_log()) > trs_file
504 print ":time-taken: " sprintf("%f", gettime_ns() - TIME_START) > trs_file
505 for (i = 0; i < test_results_index; i += 1)
506 print ":test-result: " test_results_list[i] > trs_file
507 close(trs_file);
508 }
509
510 BEGIN {
511
512 ## ------- ##
513 ## SETUP ##
514 ## ------- ##
515
516 '"$init_colors"'
517
518 # Properly initialized once the TAP plan is seen.
519 planned_tests = 0
520
521 COOKED_PASS = expect_failure ? "XPASS": "PASS";
522 COOKED_FAIL = expect_failure ? "XFAIL": "FAIL";
523
524 # Enumeration-like constants to remember which kind of plan (if any)
525 # has been seen. It is important that NO_PLAN evaluates "false" as
526 # a boolean.
527 NO_PLAN = 0
528 EARLY_PLAN = 1
529 LATE_PLAN = 2
530
531 testno = 0 # Number of test results seen so far.
532 bailed_out = 0 # Whether a "Bail out!" directive has been seen.
533
534 # Whether the TAP plan has been seen or not, and if yes, which kind
535 # it is ("early" is seen before any test result, "late" otherwise).
536 plan_seen = NO_PLAN
537
538 TIME_START = gettime_ns();
539 ## --------- ##
540 ## PARSING ##
541 ## --------- ##
542
543 is_first_read = 1
544
545 while (1)
546 {
547 # Involutions required so that we are able to read the exit status
548 # from the last input line.
549 st = getline
550 if (st < 0) # I/O error.
551 fatal("I/O error while reading from input stream")
552 else if (st == 0) # End-of-input
553 {
554 if (is_first_read)
555 abort("in input loop: only one input line")
556 break
557 }
558 if (is_first_read)
559 {
560 is_first_read = 0
561 nextline = $0
562 continue
563 }
564 else
565 {
566 curline = nextline
567 nextline = $0
568 $0 = curline
569 }
570 # Copy any input line verbatim into the log file.
571 print | "cat >&3"
572 # Parsing of TAP input should stop after a "Bail out!" directive.
573 if (bailed_out)
574 continue
575
576 # TAP test result.
577 if ($0 ~ /^(not )?ok$/ || $0 ~ /^(not )?ok[^a-zA-Z0-9_]/)
578 {
579 testno += 1
580 setup_result_obj($0)
581 handle_tap_result()
582 }
583 # TAP plan (normal or "SKIP" without explanation).
584 else if ($0 ~ /^1\.\.[0-9]+[ \t]*$/)
585 {
586 # The next two lines will put the number of planned tests in $0.
587 sub("^1\\.\\.", "")
588 sub("[^0-9]*$", "")
589 handle_tap_plan($0, "")
590 continue
591 }
592 # TAP "SKIP" plan, with an explanation.
593 else if ($0 ~ /^1\.\.0+[ \t]*#/)
594 {
595 # The next lines will put the skip explanation in $0, stripping
596 # any leading and trailing whitespace. This is a little more
597 # tricky in truth, since we want to also strip a potential leading
598 # "SKIP" string from the message.
599 sub("^[^#]*#[ \t]*(SKIP[: \t][ \t]*)?", "")
600 sub("[ \t]*$", "");
601 handle_tap_plan(0, $0)
602 }
603 # "Bail out!" magic.
604 # Older versions of prove and TAP::Harness (e.g., 3.17) did not
605 # recognize a "Bail out!" directive when preceded by leading
606 # whitespace, but more modern versions (e.g., 3.23) do. So we
607 # emulate the latter, "more modern" behaviour.
608 else if ($0 ~ /^[ \t]*Bail out!/)
609 {
610 bailed_out = 1
611 # Get the bailout message (if any), with leading and trailing
612 # whitespace stripped. The message remains stored in `$0`.
613 sub("^[ \t]*Bail out![ \t]*", "");
614 sub("[ \t]*$", "");
615 # Format the error message for the
616 bailout_message = "Bail out!"
617 if (length($0))
618 bailout_message = bailout_message " " $0
619 testsuite_error(bailout_message)
620 }
621 # Maybe we have too look for dianogtic comments too.
622 else if (comments != 0)
623 {
624 comment = extract_tap_comment($0);
625 if (length(comment))
626 report("#", comment);
627 }
628 }
629
630 ## -------- ##
631 ## FINISH ##
632 ## -------- ##
633
634 # A "Bail out!" directive should cause us to ignore any following TAP
635 # error, as well as a non-zero exit status from the TAP producer.
636 if (!bailed_out)
637 {
638 if (!plan_seen)
639 {
640 testsuite_error("missing test plan")
641 }
642 else if (planned_tests != testno)
643 {
644 bad_amount = testno > planned_tests ? "many" : "few"
645 testsuite_error(sprintf("too %s tests run (expected %d, got %d)",
646 bad_amount, planned_tests, testno))
647 }
648 if (!ignore_exit)
649 {
650 # Fetch exit status from the last line.
651 exit_message = get_test_exit_message(nextline)
652 if (exit_message)
653 testsuite_error(exit_message)
654 }
655 }
656
657 write_test_results()
658
659 exit 0
660
661 } # End of "BEGIN" block.
662 '
663
664 # TODO: document that we consume the file descriptor 3 :-(
665 } 3>"$log_file"
666
667 test $? -eq 0 || fatal "I/O or internal error"
668
669 if test ! -z $post_script ; then
670 $post_script
671 test $? -eq 0 || fatal "Post script returned an error. See $log_file"
672 fi
673
674 # Local Variables:
675 # mode: shell-script
676 # sh-indentation: 2
677 # eval: (add-hook 'write-file-hooks 'time-stamp)
678 # time-stamp-start: "scriptversion="
679 # time-stamp-format: "%:y-%02m-%02d.%02H"
680 # time-stamp-time-zone: "UTC"
681 # time-stamp-end: "; # UTC"
682 # End:
This page took 0.046495 seconds and 5 git commands to generate.