Live output from --show-output-of-passing-tests

[jglick]

Is your feature request related to a problem? Please describe.
--show-output-of-passing-tests displays test output but only after the test completes. For tests which normally take many minutes to complete, or which appear to be hung, it is therefore difficult to tell what is going on. For example you may be checking a build log in a CI system to see if your new test is actually progressing or got stuck somewhere, but there is no way to see that until it completes (or times out, or is aborted).

Example:

@test "incremental output" {
  for x in 0 1 2 3 4 5 6 7 8 9
  do
    date
    sleep 3
  done
}

run as

$ bats --show-output-of-passing-tests x.sh
x.sh
 ✓ incremental output
   Fri Jan 19 04:45:42 PM EST 2024
   Fri Jan 19 04:45:45 PM EST 2024
   Fri Jan 19 04:45:48 PM EST 2024
   Fri Jan 19 04:45:51 PM EST 2024
   Fri Jan 19 04:45:54 PM EST 2024
   Fri Jan 19 04:45:57 PM EST 2024
   Fri Jan 19 04:46:00 PM EST 2024
   Fri Jan 19 04:46:03 PM EST 2024
   Fri Jan 19 04:46:06 PM EST 2024
   Fri Jan 19 04:46:09 PM EST 2024

1 test, 0 failures

initially prints only the test name; the full output only appears 30s later, all at once.

Describe the solution you'd like
Output should be streamed to the bats stdout/stderr as it is processed.

Describe alternatives you've considered
tail -f /tmp/bats-run-<something>/bats.<something>.out can be used as a workaround, but the filenames are unpredictable, and you cannot use a wildcard because there are two *.out files, one of which is empty AFAICT.

[martin-schulze-vireso]

Implementing this would probably require deep changes, as the buffering happens on multiple levels.

Additionally, the formatters would need to be adapted, as their output is not consistent with this requirement.

[wkoot]

We're also running into this problem, especially for calling longer running tests (sometimes up to 1 hour).
It would be very nice to be able to tell bats to pipe through any stdout/stderr it gets, with a flag such as --show-output-of-passing-tests.
Is this something that's doable, perhaps as a separate stream such as tee? It wouldn't be a huge issue if the full output is produced twice imo

[jglick]

Without knowing anything about Bats internals or exotic options, I find it hard to understand how this could require deep changes. The text I want to see is already being streamed to a file in real time, so any questions of buffering are already resolved by that point. I just want an option for that stream to be copied to stderr. No special formatting, just exactly what is in that file.

There is a workaround, it is just ugly and fragile (for example it presumes that the container/VM is only running one Bats test at a time, and leaves a stopped process behind):

(sleep 10; tail -f $(ls -1 /tmp/bats-run-*/bats.*.out | tail -1)) &
bats x.sh --report-formatter junit --output surefire

If the test fails its output is repeated which is not ideal but tolerable. I did not find any option opposite to --show-output-of-passing-tests to not show output even on failing tests, which would be independently useful when you are generating reports as in the above example.

[wkoot]

Sadly, this workaround did not work. The files in /tmp/bats-run-*/ are not being written to until the bats file has finished processing.
Both assumptions hold; the container is only running one bats test at a time and it leaves a stopped process behind.
The bats test starts an ansible-playbook which takes a long time to execute, but it produces output continuously.
This output does end up in the bats log (given that the test is failing), but only when it has completely finished.
Whether or not --show-output-of-passing-tests was passed, did not matter (tried both).

[jglick]

Maybe you are passing some options which block streaming output even to the file? I tested the sample test script given in the issue description with this workaround using Bats 1.10.0. (In a terminal, in case it matters.)

[martin-schulze-vireso]

I tried to implement something like that some time ago and then opted for allowing CTRL+C as a quick fix workaround. In essence, the problem lies in multiple layers of caching which are not necessarily file based.

Allowing to print as we go would require deep changes in the way Bats' internals communicate right now. Basically, we have each layer (exec-test, exec-files, exec-suite) do their own caching/forwarding to the (report-)formatter. To achieve what you want here, we would need to let the formatter do the caching.

This might not even be that complicated but I don't think this is as high of a priority and my capacity for this project is severely limited right now.

[wkoot]

I tried with Bats 1.11.0 running in a container - for each spec file in a folder:

/sbin/bats --show-output-of-passing-tests --report-formatter junit --output /test-results/ /specs/${SPECFILE}

To inspect the output, I docker exec'ed into the container. I can see that the test is being ran but no output :)

[jglick]

Maybe that breaks the workaround just by creating multiple out files?

The following seems to print output at least for a single test and in a terminal:

diff --git a/libexec/bats-core/bats-exec-test b/libexec/bats-core/bats-exec-test
index 1289446..2c5b9ee 100755
--- a/libexec/bats-core/bats-exec-test
+++ b/libexec/bats-core/bats-exec-test
@@ -349,11 +349,12 @@ bats_perform_test() {
   fi
 
   get_mills_since_epoch BATS_TEST_START_TIME
+  set -o pipefail
   {
     bats_set_stacktrace_limit
     setup "$@"
     "$@"
-  } >>"$BATS_OUT" 2>&1 4>&1
+  } 2>&1 4>&1 | tee /dev/stderr >>"$BATS_OUT"
 
   BATS_TEST_COMPLETED=1
   # shellcheck disable=SC2064

Might not work from a ttyless CI build, and would surely need to be refined to be enabled by an option, display (live) output from setup/teardown phases, etc.