Since this post I’ve tested this on more platforms (including cfarm machines
with dejagnu-1.5.1 and tcl 8.5).
If there’s concern about applying it everywhere, I could make a second version
of fixed_host_execute and have that called conditionally on Darwin.
The Jit testsuite is unusable without this, and really I cannot enable Jit
reliably on Darwin since one failure mode is a deadlocked expect instance
so that the testsuite never completes until that is killed manually.
thanks
Iain
> On 19 Aug 2021, at 19:59, Iain Sandoe <i...@sandoe.co.uk> wrote:
>
> Hi,
>
> Preface:
>
> this is the last patch for now in my series - with this applied Darwin
> reports the same results as Linux (at least, for modern x86_64
> platform versions).
>
> Note
> a) that the expect expression in {fixed}host_execute seems to depend
> on the assumption that the dejagnu.h output is used by the testcase
> and that the executable’s output can be seen to end with the totals
> produced there (which might in itself be erroneous, see 3).
>
> b) the main GCC testsuite processing does not do this; rather the expect
> expression is somewhat simple and the output from the executable
> is copied into a secondary buffer, which is then processed by
> prune expressions and then to find the requisite matches (so most
> of the issues seen below do not occur there).
>
> ==== patch discussion
>
> The current 'fixed_host_execute' implementation fails on Darwin
> platforms for a number of reasons:
>
> 1/ If the sub-process spawn fails (e.g. because of missing or mal-
> formed params); rather than reporting the fail output into the
> match stream, as indicated by the expect manual, it terminates
> the script.
>
> - We fix this by (a) checking that the executable is valid as well
> as existing (b) we put the spawn into a catch block and report
> a failure.
>
> 2/ There is no recovery path at all for a buffer-full case (and we
> do see buffer-full events with the default sizes).
>
> - Added by the patch here, however it is not as sophisticated as
> the methods used by dejagnu internally. Here we set the process
> to be "nowait" and then close the connection - with the intent
> that this will terminate the spawned process.
>
> 3/ The expect logic assumes that 'Totals:' is a valid indicator
> for the end of the spawned process output. This is not true
> even for the default dejagnu header (there are a number of
> additional reporting lines after). In addition to this, there
> are some tests that intentionally produce more output after
> the totals report (and there are tests that do not use that
> mechanism at all).
>
> The effect is the we might arrive at the "wait" for the spawned
> process to finish - but that process might not have completed
> all its output. For Darwin, at least that causes a deadlock
> between expect and the spawnee - the latter is doing a non-
> cancellable write and the former is waiting for the latter to
> terminate. For some reason this does not seem to affect Linux
> perhaps the pty implementation allows the write(s) are able to
> proceed even though there is no reader.
>
> - This is fixed by modifying the loop termination condition to be
> either EOF (which will be the 'correct' condition) or a timeout
> which would represent an error either in the runtime or in the
> parsing of the output. As added precautions, we only try to
> wait if there is a correcly-spawned process, and we are also
> specific about which process we are waiting for.
>
> 4/ Darwin appears to have a bug in either the tcl or termios
> 'cooking' code that ocassionally inserts an additional CR char
> into the stream - thus '\n' => '\r\r\n' instead of '\r\n'. The
> original program output is correct (it only contains a single
> \n) - the additional character is being inserted somewhere in
> the translations applied before the output reaches expect.
>
> The logic of this expect implementation does not tolerate single
> \r or \n characters (it will fail with a timeout or buffer-full
> if that occurs).
>
> - This is fixed by having a line-end match that is adjusted for
> Darwin.
>
> 5/ The default buffer size does seem to be too small in some cases
> noting that GCC uses 10000 as the match buffer size and the
> default is 2000.
>
> - Fixed by increasing the size to 8192.
>
> 6/ There is a somewhat arbitrary dumping of output where we match
> ^$prefix\tSOMETHING... and then process the something. This
> essentially allows the match to start at any place in the buffer
> following any collection of non-line-end chars.
>
> - Fixed by amending the match for 'general' lines to accommodate
> these cases, and reporting such lines to the log. At least this
> should allow debugging of any cases where output that should be
> recognized is being dropped.
>
> tested on i686, x86_64-darwin, x86_64,powerpc64-linux,
> OK for master?
> thanks
> Iain
>
> Signed-off-by: Iain Sandoe <i...@sandoe.co.uk>
>
> gcc/testsuite/ChangeLog:
>
> * jit.dg/jit.exp (fixed_local_execute): Amend the match and
> exit conditions to cater for more platforms.
> ---
> gcc/testsuite/jit.dg/jit.exp | 123 +++++++++++++++++++++++------------
> 1 file changed, 83 insertions(+), 40 deletions(-)
>
> diff --git a/gcc/testsuite/jit.dg/jit.exp b/gcc/testsuite/jit.dg/jit.exp
> index 005ba01601a..8541a44e1b2 100644
> --- a/gcc/testsuite/jit.dg/jit.exp
> +++ b/gcc/testsuite/jit.dg/jit.exp
> @@ -167,6 +167,9 @@ proc fixed_host_execute {args} {
> if {![file exists ${executable}]} {
> perror "The executable, \"$executable\" is missing" 0
> return "No source file found"
> + } elseif {![file executable ${executable}]} {
> + perror "The executable, \"$executable\" is not usable" 0
> + return "Bad executable found"
> }
>
> verbose "params: $params" 2
> @@ -194,60 +197,100 @@ proc fixed_host_execute {args} {
> set args [concat $args ${params}]
> verbose "args: $args" 2
>
> - eval spawn -noecho $args
> -
> - expect_after full_buffer { error "got full_buffer" }
> + # We checked that the executable exists above, and can be executed, but
> + # that does not cover other reasons that the launch could fail (e.g.
> + # missing or malformed params); catch such cases here and report them.
> + set err [catch "spawn -noecho $args" pid]
> + set sub_proc_id $spawn_id
> + if { $pid <= 0 || $err != 0 || $sub_proc_id < 0 } {
> + warning "failed to spawn : $args : err = $err"
> + }
> +
> + # Increase the buffer size, if needed to avoid spurious buffer-full
> + # events; GCC uses 10000; chose a power of two here.
> + set current_max_match [match_max -i $sub_proc_id]
> + if { $current_max_match < 8192 } {
> + match_max -i $sub_proc_id 8192
> + set used [match_max -i $sub_proc_id]
> + }
> +
> + # If we get a buffer-full error, that seems to be unrecoverable so try to
> + # exit in a reasonable manner to avoid wedged processes.
> + expect_after full_buffer {
> + verbose -log "fixed_host_execute: $args FULL BUFFER"
> + # FIXME: this all assumes that closing the connection will cause the
> + # sub-process to terminate (but that is not going to be the case if,
> + # for example, there is something started with -nohup somewhere).
> + # We should explicitly kill it here.
> + # Set the process to be a nowait exit.
> + wait -nowait -i $sub_proc_id
> + catch close
> + perror "${executable} got full_buffer"
> + return "${executable} got full_buffer"
> + }
>
> set prefix "\[^\r\n\]*"
> + # Work around a Darwin tcl or termios bug that sometimes inserts extra
> + # CR characters into the cooked tty stream
> + set endline "\r\n"
> + if { [istarget *-*-darwin*] } {
> + set endline "\r(\r)*\n"
> + }
> +
> + # Note that the logic here assumes that we cannot (validly) get single
> + # carriage return or line feed characters in the stream. If those occur,
> + # it will stop any further matching. We arange for the matching to be
> + # at the start of the buffer - so that if there is any spurious output
> + # to be discarded, it must be done explicitly - not by matching part-way
> + # through the buffer.
> expect {
> - -re "^$prefix\[0-9\]\[0-9\]:..:..:${text}*\r\n" {
> + -re "^$prefix\[0-9\]\[0-9\]:..:..:${text}*$endline" {
> regsub "\[\n\r\t\]*NOTE: $text\r\n" $expect_out(0,string) "" output
> verbose "$output" 3
> set timetol 0
> exp_continue
> }
> - -re "^$prefix\tNOTE:\[^\r\n\]+\r\n" {
> - regsub "\[\n\r\t\]*NOTE: $text\r\n" $expect_out(0,string) "" output
> - set output [string range $output 6 end-2]
> - verbose "$output" 2
> + -re "^\tNOTE: (\[^\r\n\]+)$endline" {
> + # discard notes.
> + verbose "Ignored note: $expect_out(1,string)" 2
> set timetol 0
> exp_continue
> }
> - -re "^$prefix\tPASSED:\[^\r\n\]+\r\n" {
> - regsub "\[\n\r\t\]*PASSED: $text\r\n" $expect_out(0,string) ""
> output
> - set output [string range $output 8 end-2]
> - pass "$output"
> + -re "^\tPASSED: (\[^\r\n\]+)$endline" {
> + pass "$expect_out(1,string)"
> set timetol 0
> exp_continue
> }
> - -re "^$prefix\tFAILED:\[^\r\n\]+\r\n" {
> - regsub "\[\n\r\t\]*FAILED: $text\r\n" $expect_out(0,string) ""
> output
> - set output [string range $output 8 end-2]
> - fail "$output"
> + -re "^\tFAILED: (\[^\r\n\]+)$endline" {
> + fail "$expect_out(1,string)"
> set timetol 0
> exp_continue
> }
> - -re "^$prefix\tUNTESTED:\[^\r\n\]+\r\n" {
> - regsub "\[\n\r\t\]*TESTED: $text\r\n" $expect_out(0,string) ""
> output
> - set output [string range $output 8 end-2]
> - untested "$output"
> + -re "^\tUNTESTED: (\[^\r\n\]+)$endline" {
> + untested "$expect_out(1,string)"
> set timetol 0
> exp_continue
> }
> - -re "^$prefix\tUNRESOLVED:\[^\r\n\]+\r\n" {
> - regsub "\[\n\r\t\]*UNRESOLVED: $text\r\n" $expect_out(0,string) ""
> output
> - set output [string range $output 8 end-2]
> - unresolved "$output"
> + -re "^\tUNRESOLVED: (\[^\r\n\]+)$endline" {
> + unresolved "$expect_out(1,string)"
> set timetol 0
> exp_continue
> }
> - -re "^Totals" {
> - verbose "All done" 2
> + -re "^$prefix$endline" {
> + # This matches and discards any other lines (including blank
> ones).
> + if { [string length $expect_out(buffer)] <= 2 } {
> + set output "blank line"
> + } else {
> + set output [string range $expect_out(buffer) 0 end-2]
> + }
> + verbose -log "DISCARDED $expect_out(spawn_id) : $output"
> + exp_continue
> }
> eof {
> - # unresolved "${executable} died prematurely"
> - # catch close
> - # return "${executable} died prematurely"
> + # This seems to be the only way that we can reliably know that the
> + # output is finished since there are cases where further output
> + # follows the dejagnu test harness totals.
> + verbose "saw eof" 2
> }
> timeout {
> warning "Timed out executing test case"
> @@ -259,19 +302,19 @@ proc fixed_host_execute {args} {
> return "Timed out executing test case"
> }
> }
> - -re "^$prefix\r\n" {
> - exp_continue
> - }
> }
>
> - # Use "wait" before "close": valgrind might not have finished
> - # writing the log out before we parse it, so we need to wait for
> - # the spawnee to finish.
> -
> - catch wait wres
> - verbose "wres: $wres" 2
> - verify_exit_status $executable $wres
> -
> + # Use "wait" to pick up the sub-process exit state. If the sub-process
> is
> + # writing to a file (perhaps under valgrind) then that also needs to be
> + # complete; only attempt this on a valid spawn.
> + if { $sub_proc_id > 0 } {
> + verbose "waiting for $sub_proc_id" 1
> + # Be explicit about what we are waiting for.
> + catch "wait -i $sub_proc_id" wres
> + verbose "wres: $wres" 2
> + verify_exit_status $executable $wres
> + }
> +
> if $run_under_valgrind {
> upvar 2 name name
> parse_valgrind_logfile $name $valgrind_logfile
> --
> 2.24.3 (Apple Git-128)
>
