Skip to content

Commit

Permalink
Work around Bash buffering bug causing test failures (#766)
Browse files Browse the repository at this point in the history
The boot tests run several iterations inside a single 'heroku run', as rthis drastically reduces the overall time taken for tests.

Some Bash 5.0 bug (it seems to happen only on heroku-20) causes output from a command (that is still running through a tee process substitution) to arrive a bit after the next echo statement, and as a result, sometimes, the last line of a delimited chunk is not the exit status, but output from the program, causing the test to fail.

So we just write outputs to files, and cat them together at the end.
  • Loading branch information
dzuelke authored Nov 22, 2024
1 parent 1e872f0 commit ba38c2a
Show file tree
Hide file tree
Showing 2 changed files with 11 additions and 5 deletions.
11 changes: 8 additions & 3 deletions test/spec/php_boot_shared.rb
Original file line number Diff line number Diff line change
Expand Up @@ -126,11 +126,16 @@ def self.gencmd(args)
# there are very rare cases of stderr and stdout getting read (by the dyno runner) slightly out of order
# if that happens, the last stderr line(s) from the program might get picked up after the next thing we echo
# for that reason, we redirect stderr to stdout
# there is also still a bash buffering issue where the last line from the program's exit trap ("Shutdown complete") may show up after the echo that prints $?
# this is presumably due to the process substitutions that tee stdout and stderr in waitforit.sh, but an explicit wait call in there (which should wait for process substitutions to terminate since Bash 5.0) does not help
# so we simply write it all to files instead and at the end cat everything together
# (shell globbing sorts alnum for us thankfully)
# jq does not have a "individual raw file slurp" mode, so we cannot elegantly produce a JSON array of outputs/statuses
run_cmds = examples
.map { |example| "#{example[:cmd]} 2>&1; echo $'\\n'$?" }
.join("; echo -n '#{delimiter}'; ")
.map.with_index { |example, i| "i='#{"%03d" % i}'; #{example[:cmd]} >run.$i.out 2>&1; echo $'\\n'$? >run.$i.status" }
.join("; echo -n '#{delimiter}' >run.$i.xdelim; ")
retry_until retry: 3, sleep: 5 do
@run = @app.run(run_cmds).split(delimiter)
@run = @app.run("#{run_cmds}; sleep 1; cat run.*").split(delimiter)
end
end

Expand Down
5 changes: 3 additions & 2 deletions test/utils/waitforit.sh
Original file line number Diff line number Diff line change
Expand Up @@ -55,8 +55,9 @@ duration=$1; shift
text=$1; shift

pipeout=
# check if stdout is a pipeline (we can't -p /dev/stdout, so a TTY check on FD 1 is the next closest thing), in which case we'll behave differently
[[ -t 1 ]] || pipeout=1
# check if stdout is a pipeline, in which case we'll behave differently (another program can "attach" to us and execute something after a match)
# we use -p on FD 1 so that redirecting our output to a file does not change behavior
[[ -p /proc/$$/fd/1 ]] && pipeout=1

if [[ $pipeout ]]; then
grepargs="-m1"
Expand Down

0 comments on commit ba38c2a

Please sign in to comment.