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