Test hangs when trying basic usage of background-process when output does not match

[marascio]

Framework, Bash, and operating system version information

_GO_CORE_VERSION:         v1.7.0
BASH_VERSION:             3.2.57(1)-release
OSTYPE:                   darwin16
_GO_PLATFORM_ID:          macos
_GO_PLATFORM_VERSION_ID:  10.12.6

Description

When trying to use background-process based on the basic usage documentation at the top of a file, a simple test case hangs indefinitely if there is no match in the output.

Consider the following, where support/testfx also sources background-process and helpers.

 #!/usr/bin/env bats                                                                                                                          
                                                                                                                                              
 load support/testfx                                                                                                                          
                                                                                                                                              
 setup() {                                                                                                                                    
     mkdir "$BATS_TEST_ROOTDIR"                                                                                                               
 }                                                                                                                                            
                                                                                                                                              
 teardown() {                                                                                                                                 
     remove_bats_test_dirs                                                                                                                    
 }                                                                                                                                            
                                                                                                                                              
 @test "works" {                                                                                                                              
     skip_if_missing_background_utilities                                                                                                     
     run_in_background bash -c 'echo hi; sleep 60'                                                                                            
     wait_for_background_output 'hi' '1'                                                                                                          
     stop_background_run                                                                                                                      
 }                                                                                                                                            
                                                                                                                                              
 @test "fails" {                                                                                                                              
     skip_if_missing_background_utilities                                                                                                     
     run_in_background bash -c 'echo hi; sleep 60'                                                                                            
     wait_for_background_output 'fail' '1'                                                                                                     
     stop_background_run                                                                                                                      
 } 

The output of the test is then:

 ✓ works
 ✗ fails
   (in test file /sanitized/test.bats, line 23)
     `wait_for_background_output 'fail'' failed
   /sanitized/go-script-bash-dl/lib/bats/background-process: line 101: 82517 Terminated: 15          "${input_cmd[@]}"
   Output did not match regular expression:
     'fail'
   
   OUTPUT:
   ------
   hi

2 tests, 1 failure

real	1m0.206s
user	0m0.158s
sys	0m0.073s

The only reason the fails test exits is because the sleep 60 finally completes. In reality, it should be terminated much sooner after wait_for_background_output times out after 1 second. Leaving off the manual timeout and using the default timeout for wait_for_background_output provides the same result.

Looking through the bats-background-process test cases I don't see any that use the recommended usage pattern. They all seem to use a different pattern and even invoke wait_for_background_output using the bats run function.

Are the docs out of date? Is this a bug? It sure seems like a bug since testing a background process implies the process should not have to exit for the test to work.

[marascio]

After some debugging this seems to be related to sstephenson/bats#80 from the old bats repository. The problem doesn't seem to be related to whether the output matches or doesn't, but simply that the last test case using background-process hangs.

Applying this patch fixes the issue:

diff --git a/lib/bats/background-process b/lib/bats/background-process
index e39241c..ab3bd0c 100644
--- a/lib/bats/background-process
+++ b/lib/bats/background-process
@@ -64,7 +64,7 @@ run_in_background() {
   export BATS_BACKGROUND_RUN_OUTPUT
   BATS_BACKGROUND_RUN_OUTPUT="$BATS_TEST_ROOTDIR/background-run-output.txt"
   printf '' >"$BATS_BACKGROUND_RUN_OUTPUT"
-  "$@" >"$BATS_BACKGROUND_RUN_OUTPUT" 2>&1 &
+  "$@" >"$BATS_BACKGROUND_RUN_OUTPUT" 2>&1 3>&- &
   export BATS_BACKGROUND_RUN_PID="$!"
   restore_bats_shell_options
 }

A revised test case run using go test is:

#! /usr/bin/env bats

load environment
load "$_GO_CORE_DIR/lib/bats/background-process"

setup() {
  mkdir "$BATS_TEST_ROOTDIR"
}

teardown() {
  remove_bats_test_dirs
}

@test "$SUITE: found" {
  skip_if_missing_background_utilities
  run_in_background bash -c 'echo start; sleep 60;'
  wait_for_background_output 'start'
  stop_background_run
}

@test "$SUITE: not found" {
  skip_if_missing_background_utilities
  run_in_background bash -c 'echo start; sleep 60;'
  wait_for_background_output 'fail'
  stop_background_run
}

@test "$SUITE: found 2" {
  skip_if_missing_background_utilities
  run_in_background bash -c 'echo start; sleep 60;'
  wait_for_background_output 'start'
  stop_background_run
}

Without the above patch the last test case always hangs and is terminated after 60 seconds when the bash process exits. With the patch the last test is properly terminated after wait_for_background_output matches. Were the last test case one that does not match it would terminate after the timeout in wait_for_background_output.

[mbland]

Sorry I didn't get around to responding over Thanksgiving; will try to carve out some time to respond in the next evening or two.

In the meanwhile, you've done quite a bit of work already—feel free to convert it into a pull request if you like.

[mbland]

Finally gave this a try locally and confirmed your fix works. Thanks for digging in and digging up sstephenson/bats#80 so I didn't have to!

As for the example case at the top of the file, I think I got in the rhythm of always wrapping things in run_test_script_in_background and forgot to both add test cases for the bare run_in_background and to add example documentation for run_test_script_in_background.

I have to run right now, but will put together a PR to add your new test cases and fix, to update the file documentation—and to cover a new corner case I discovered where running run_test_script_in_background "echo hi; sleep 60" fails when it shouldn't.