Merge pull request #491 from TApplencourt/timeout

Add timeout support

docs/CHANGELOG.md

@@ -20,6 +20,7 @@ The format is based on [Keep a Changelog][kac] and this project adheres to
 * Docker tags `latest-no-faccessat2` and `<bats-version\>-no-faccessat2` for
   avoiding `bash: bats: No such file or directory` on `docker<20.10` (or
   `runc<v1.0.0-rc93`) (#622)
+* `BATS_TEST_TIMEOUT` variable to force a timeout on test (including `setup()`) (#491)
 
 #### Documentation
 

docs/source/faq.rst

@@ -145,7 +145,8 @@ If you need the library inside `setup_file` or `teardown_file` you need to load
 How to set a test timeout in bats?
 ----------------------------------
 
-Unfortunately, this is not possible yet. Please contribute to issue `#396 <https://github.com/bats-core/bats-core/issues/396>`_ for further progress.
+Set the variable `$BATS_TEST_TIMEOUT` before `setup()` starts. This means you can set it either on the command line,
+in free code in the test file or in `setup_file()`.
 
 How can I lint/shell-format my bats tests?
 ------------------------------------------

docs/source/writing-tests.md

@@ -379,6 +379,10 @@ There are several global variables you can use to introspect on Bats tests:
 - `BATS_TEST_RETRIES` is the maximum number of additional attempts that will be
   made on a failed test before it is finally considered failed.
   The default of 0 means the test must pass on the first attempt.
+- `BATS_TEST_TIMEOUT` is the number of seconds after which a test (including setup)
+  will be aborted and marked as failed. Updates to this value in `setup()` or `@test`
+  cannot change the running timeout countdown, so the latest useful update location
+  is `setup_file()`.
 - `$BATS_TEST_NUMBER` is the (1-based) index of the current test case in the test file.
 - `$BATS_SUITE_TEST_NUMBER` is the (1-based) index of the current test case in the test suite (over all files).
 - `$BATS_TMPDIR` is the base temporary directory used by bats to create its

lib/bats-core/formatter.bash

@@ -1,14 +1,25 @@
 #!/usr/bin/env bash
 
 # reads (extended) bats tap streams from stdin and calls callback functions for each line
+#
+# Segmenting functions
+# ==================== 
 # bats_tap_stream_plan <number of tests>                                      -> when the test plan is encountered
+# bats_tap_stream_suite <file name>                                           -> when a new file is begun WARNING: extended only
 # bats_tap_stream_begin <test index> <test name>                              -> when a new test is begun WARNING: extended only
-# bats_tap_stream_ok [--duration <milliseconds] <test index> <test name>      -> when a test was successful
-# bats_tap_stream_not_ok [--duration <milliseconds>] <test index> <test name> -> when a test has failed
+#
+# Test result functions
+# =====================
+# If timing was enabled, BATS_FORMATTER_TEST_DURATION will be set to their duration in milliseconds
+# bats_tap_stream_ok <test index> <test name>                                 -> when a test was successful
+# bats_tap_stream_not_ok <test index> <test name>                             -> when a test has failed. If the failure was due to a timeout,
+#                                                                                BATS_FORMATTER_TEST_TIMEOUT is set to the timeout duration in seconds
 # bats_tap_stream_skipped <test index> <test name> <skip reason>              -> when a test was skipped
+#
+# Context functions
+# =================
 # bats_tap_stream_comment <comment text without leading '# '> <scope>         -> when a comment line was encountered, 
 #                                                                                scope tells the last encountered of plan, begin, ok, not_ok, skipped, suite
-# bats_tap_stream_suite <file name>                                           -> when a new file is begun WARNING: extended only
 # bats_tap_stream_unknown <full line> <scope>                                 -> when a line is encountered that does not match the previous entries,
 #                                                                                scope @see bats_tap_stream_comment
 # forwards all input as is, when there is no TAP test plan header
@@ -26,6 +37,7 @@ function bats_parse_internal_extended_tap() {
 
     ok_line_regexpr="ok ([0-9]+) (.*)"
     skip_line_regexpr="ok ([0-9]+) (.*) # skip( (.*))?$"
+    timeout_line_regexpr="not ok ([0-9]+) (.*) # timeout after ([0-9]+)s$"
     not_ok_line_regexpr="not ok ([0-9]+) (.*)"
 
     timing_expr="in ([0-9]+)ms$"
@@ -34,6 +46,7 @@ function bats_parse_internal_extended_tap() {
     index=0
     scope=plan
     while IFS= read -r line; do
+        unset BATS_FORMATTER_TEST_DURATION BATS_FORMATTER_TEST_TIMEOUT
         case "$line" in
         'begin '*) # this might only be called in extended tap output
             ((++begin_index))
@@ -50,11 +63,18 @@ function bats_parse_internal_extended_tap() {
                     scope=skipped
                     test_name="${BASH_REMATCH[2]}" # cut off name before "# skip"
                     local skip_reason="${BASH_REMATCH[4]}"
-                    bats_tap_stream_skipped "$ok_index" "$test_name" "$skip_reason"
+                    if [[ "$test_name" =~ $timing_expr ]]; then
+                        local BATS_FORMATTER_TEST_DURATION="${BASH_REMATCH[1]}"
+                        test_name="${test_name% in "${BATS_FORMATTER_TEST_DURATION}"ms}"
+                        bats_tap_stream_skipped "$ok_index" "$test_name" "$skip_reason"
+                    else
+                        bats_tap_stream_skipped "$ok_index" "$test_name" "$skip_reason"
+                    fi
                 else
                     scope=ok
                     if [[ "$line" =~ $timing_expr ]]; then
-                        bats_tap_stream_ok --duration "${BASH_REMATCH[1]}" "$ok_index" "$test_name"
+                        local BATS_FORMATTER_TEST_DURATION="${BASH_REMATCH[1]}"
+                        bats_tap_stream_ok "$ok_index" "${test_name% in "${BASH_REMATCH[1]}"ms}"
                     else
                         bats_tap_stream_ok "$ok_index" "$test_name"
                     fi
@@ -70,11 +90,18 @@ function bats_parse_internal_extended_tap() {
             if [[ "$line" =~ $not_ok_line_regexpr ]]; then
                 not_ok_index="${BASH_REMATCH[1]}"
                 test_name="${BASH_REMATCH[2]}"
-                if [[ "$line" =~ $timing_expr ]]; then
-                    bats_tap_stream_not_ok --duration "${BASH_REMATCH[1]}" "$not_ok_index" "$test_name"
-                else
-                    bats_tap_stream_not_ok "$not_ok_index" "$test_name"
+                if [[ "$line" =~ $timeout_line_regexpr ]]; then
+                    not_ok_index="${BASH_REMATCH[1]}"
+                    test_name="${BASH_REMATCH[2]}"
+                    # shellcheck disable=SC2034 # used in bats_tap_stream_ok
+                    local BATS_FORMATTER_TEST_TIMEOUT="${BASH_REMATCH[3]}"
+                fi
+                if [[ "$test_name" =~ $timing_expr ]]; then
+                    # shellcheck disable=SC2034 # used in bats_tap_stream_ok
+                    local BATS_FORMATTER_TEST_DURATION="${BASH_REMATCH[1]}"
+                    test_name="${test_name% in "${BASH_REMATCH[1]}"ms}"
                 fi
+                bats_tap_stream_not_ok "$not_ok_index" "$test_name"
             else
                 printf "ERROR: could not match not ok line: %s" "$line" >&2
                 exit 1

lib/bats-core/tracing.bash

@@ -102,6 +102,12 @@ bats_print_failed_command() {
 	bats_quote_code quoted_failed_command "$failed_command"
 	printf '#   %s ' "${quoted_failed_command}"
 
+	if [[ "${BATS_TIMED_OUT-NOTSET}" != NOTSET ]]; then
+		# the other values can be safely overwritten here,
+		# as the timeout is the primary reason for failure
+		BATS_ERROR_SUFFIX=" due to timeout"
+	fi
+
 	if [[ "$BATS_ERROR_STATUS" -eq 1 ]]; then
 		printf 'failed%s\n' "$BATS_ERROR_SUFFIX"
 	else
@@ -251,7 +257,9 @@ bats_debug_trap() {
 
 	# don't update the trace within library functions or we get backtraces from inside traps
 	# also don't record new stack traces while handling interruptions, to avoid overriding the interrupted command
-	if [[ -z "$file_excluded" && "${BATS_INTERRUPTED-NOTSET}" == NOTSET ]]; then
+	if [[ -z "$file_excluded" && 
+			"${BATS_INTERRUPTED-NOTSET}" == NOTSET &&
+			"${BATS_TIMED_OUT-NOTSET}" == NOTSET ]]; then
 		BATS_DEBUG_LASTLAST_STACK_TRACE=(
 			${BATS_DEBUG_LAST_STACK_TRACE[@]+"${BATS_DEBUG_LAST_STACK_TRACE[@]}"}
 		)

libexec/bats-core/bats-exec-test

@@ -86,6 +86,12 @@ source "$BATS_ROOT/lib/bats-core/tracing.bash"
 bats_teardown_trap() {
   bats_check_status_from_trap
   local bats_teardown_trap_status=0
+
+  # `bats_teardown_trap` is always called with one parameter (BATS_TEARDOWN_STARTED)
+  # The second parameter is optional and corresponds for to the killer pid
+  # that will be forwarded to the exit trap to kill it if necesary
+  local killer_pid=${2:-}
+
   # mark the start of this function to distinguish where skip is called
   # parameter 1 will signify the reason why this function was called
   # this is used to identify when this is called as exit trap function
@@ -99,26 +105,33 @@ bats_teardown_trap() {
     BATS_ERROR_STATUS="$bats_teardown_trap_status"
   fi
 
-  bats_exit_trap
+  bats_exit_trap "$killer_pid"
 }
 
 # shellcheck source=lib/bats-core/common.bash
 source "$BATS_ROOT/lib/bats-core/common.bash"
 
 bats_exit_trap() {
   local status
-  local skipped=''
+  local exit_metadata=''
+  local killer_pid=${1:-}
   trap - ERR EXIT
+  if [[ -n "${BATS_TEST_TIMEOUT:-}" ]]; then
+    # Kill the watchdog in the case of of kernel finished before the timeout
+    bats_abort_timeout_countdown "$killer_pid" || status=1
+  fi
 
   if [[ -n "$BATS_TEST_SKIPPED" ]]; then
-    skipped=' # skip'
+    exit_metadata=' # skip'
     if [[ "$BATS_TEST_SKIPPED" != '1' ]]; then
-      skipped+=" $BATS_TEST_SKIPPED"
+        exit_metadata+=" $BATS_TEST_SKIPPED"
     fi
+  elif [[ "${BATS_TIMED_OUT-NOTSET}" != NOTSET ]]; then
+     exit_metadata=" # timeout after ${BATS_TEST_TIMEOUT}s"
   fi
 
   BATS_TEST_TIME=''
-  if [[ -z "${skipped}" && -n "$BATS_ENABLE_TIMING" ]]; then
+  if [[ -n "$BATS_ENABLE_TIMING" ]]; then
     BATS_TEST_TIME=" in "$(( $(get_mills_since_epoch) - BATS_TEST_START_TIME ))"ms"
   fi
 
@@ -143,7 +156,7 @@ bats_exit_trap() {
       status=126 # signify retry
       rm -r "$BATS_TEST_TMPDIR" # clean up for retry
     else
-      printf 'not ok %d %s\n' "$BATS_SUITE_TEST_NUMBER" "${BATS_TEST_NAME_PREFIX:-}${BATS_TEST_DESCRIPTION}${BATS_TEST_TIME}" >&3
+      printf 'not ok %d %s%s\n' "$BATS_SUITE_TEST_NUMBER" "${BATS_TEST_NAME_PREFIX:-}${BATS_TEST_DESCRIPTION}${BATS_TEST_TIME}" "$exit_metadata" >&3
       local stack_trace
       bats_get_failure_stack_trace stack_trace
       bats_print_stack_trace "${stack_trace[@]}" >&3
@@ -159,7 +172,7 @@ bats_exit_trap() {
     fi
   else
     printf 'ok %d %s%s\n' "$BATS_SUITE_TEST_NUMBER" "${BATS_TEST_NAME_PREFIX:-}${BATS_TEST_DESCRIPTION}${BATS_TEST_TIME}" \
-      "$skipped" >&3
+      "$exit_metadata" >&3
     status=0
     local state=passed
   fi
@@ -182,6 +195,81 @@ bats_exit_trap() {
   exit "$status"
 }
 
+# Marks the test as failed due to timeout.
+# The actual termination of subprocesses is done via pkill in the background 
+# process in bats_start_timeout_countdown
+bats_timeout_trap() {
+  BATS_TIMED_OUT=1
+  BATS_DEBUG_LAST_STACK_TRACE_IS_VALID=
+  exit 1
+}
+
+bats_get_child_processes_of() { # <parent-pid>
+    local -ri parent_pid=${1?}
+    {
+      read -ra header
+      local pid_col ppid_col
+      for (( i = 0; i < ${#header[@]}; ++i )); do
+        if [[ ${header[$i]} == "PID" ]]; then
+          pid_col=$i
+        fi
+        if [[ ${header[$i]} == "PPID" ]]; then
+          ppid_col=$i
+        fi
+      done
+      while read -ra row; do
+        if (( ${row[$ppid_col]} == parent_pid )); then
+          printf "%d\n" "${row[$pid_col]}"
+        fi
+      done
+    } < <(ps -ef "$parent_pid")
+}
+
+bats_kill_childprocesses_of() { # <parent-pid>
+  local -ir parent_pid="${1?}"
+  if command -v pkill; then
+    pkill -P "$parent_pid"
+  else
+    # kill in reverse order (latest first)
+    while read -r pid; do
+      kill "$pid"
+    done < <(bats_get_child_processes_of "$parent_pid" | sort -r)
+  fi &>/dev/null
+}
+
+# sets a timeout for this process
+#
+# using SIGABRT for interprocess communication.
+# Ruled out:
+# USR1/2 - not available on Windows
+# SIGALRM - interferes with sleep:
+#           "sleep(3) may be implemented using SIGALRM; mixing calls to alarm() 
+#           and sleep(3) is a bad idea." ~ https://linux.die.net/man/2/alarm
+bats_start_timeout_countdown() { # <timeout>
+  local -ri timeout=$1
+  local -ri target_pid=$$
+  # shellcheck disable=SC2064
+  trap "bats_timeout_trap $target_pid" ABRT
+  # Start another process to kill the children of this process
+  (
+     sleep "$timeout" &
+     # sleep won't recieve signals, so we use wait below
+     # and kill sleep explicitly when signalled to do so
+     # shellcheck disable=SC2064
+     trap "kill $!; exit 0" ABRT
+     wait
+     if kill -ABRT "$target_pid"; then
+        # get rid of signal blocking child processes (like sleep)
+        bats_kill_childprocesses_of "$target_pid"
+     fi  &> /dev/null
+  ) &
+}
+
+bats_abort_timeout_countdown() {
+  # kill the countdown process, don't care if its still there
+  kill -ABRT "$1" &>/dev/null || true
+}
+
 get_mills_since_epoch() {
   local ms_since_epoch
   ms_since_epoch=$(date +%s%N)
@@ -202,20 +290,27 @@ bats_perform_test() {
     exit 1
   fi
 
+  local BATS_killer_pid=''
+  if [[ -n "${BATS_TEST_TIMEOUT:-}" ]]; then
+    bats_start_timeout_countdown "$BATS_TEST_TIMEOUT"
+    BATS_killer_pid=$!
+  fi
   BATS_TEST_COMPLETED=
   BATS_TEST_SKIPPED=
   BATS_TEARDOWN_COMPLETED=
   BATS_ERROR_STATUS=
   bats_setup_tracing
-  # mark this call as trap call
-  trap 'bats_teardown_trap as-exit-trap' EXIT
+  # use parameter to mark this call as trap call
+  # shellcheck disable=SC2064
+  trap "bats_teardown_trap as-exit-trap $BATS_killer_pid" EXIT
 
   BATS_TEST_START_TIME=$(get_mills_since_epoch)
   "$BATS_TEST_NAME" >>"$BATS_OUT" 2>&1 4>&1
 
   BATS_TEST_COMPLETED=1
-  trap 'bats_exit_trap' EXIT
-  bats_teardown_trap "" # pass empty parameter to signify call outside trap
+  # shellcheck disable=SC2064
+  trap "bats_exit_trap $BATS_killer_pid" EXIT
+  bats_teardown_trap "" "$BATS_killer_pid" # pass empty parameter to signify call outside trap
 }
 
 trap bats_interrupt_trap INT

libexec/bats-core/bats-format-junit

@@ -186,34 +186,27 @@ bats_tap_stream_begin() { # <test index> <test name>
   name="$2"
 }
 
-bats_tap_stream_ok() { # [--duration <milliseconds] <test index> <test name>
-  if [[ "$1" == "--duration" ]]; then
-    test_exec_time="${BASH_REMATCH[1]}"
-  else
-    test_exec_time=0
-  fi
+bats_tap_stream_ok() { # <test index> <test name>
+  test_exec_time=${BATS_FORMATTER_TEST_DURATION:-0}
   ((file_count += 1))
   test_result_state='ok'
   file_exec_time="$((file_exec_time + test_exec_time))"
   suite_test_exec_time=$((suite_test_exec_time + test_exec_time))
 }
 
 bats_tap_stream_skipped() { # <test index> <test name> <skip reason>
+  test_exec_time=${BATS_FORMATTER_TEST_DURATION:-0}
   ((file_count += 1))
   ((file_skipped += 1))
   test_result_state='skipped'
   test_exec_time=0
   test_skip_message="$3"
 }
 
-bats_tap_stream_not_ok() { # [--duration <milliseconds>] <test index> <test name>
+bats_tap_stream_not_ok() { # <test index> <test name>
+  test_exec_time=${BATS_FORMATTER_TEST_DURATION:-0}
   ((file_count += 1))
   ((file_failures += 1))
-  if [[ "$1" == "--duration" ]]; then
-    test_exec_time="${BASH_REMATCH[1]}"
-  else
-    test_exec_time=0
-  fi
   test_result_state=not_ok
   file_exec_time="$((file_exec_time + test_exec_time))"
   suite_test_exec_time=$((suite_test_exec_time + test_exec_time))