[Testsuite] Cleanup logs from gdb tests by adding newlines

Runs of the guality testsuite can sometimes end up with gcc.log containing
malformed lines like:

A debugging session is active.PASS: gcc.dg/guality/pr36728-1.c   -O2  line 18 arg4 == 4
A debugging session is active.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:ip == int *
	Inferior 1 [process 27054] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cicrp == const int * const restrict
	Inferior 1 [process 27160] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cvirp == int * const volatile restrict

This patch just makes sure the PASS/FAIL comes at the beginning of a line.  (At
the slight cost of adding some extra newlines not in the actual test output.)

I moved the remote_close target calls earlier, to avoid any possible race
condition of extra output being generated after the newline - this may not be
strictly necessary.

Tested on aarch64-none-linux-gnu and x86_64-none-linux-gnu.

I think this is reasonable for stage 3 - OK for trunk?

gcc/testsuite/ChangeLog:
	* lib/gcc-gdb-test.exp (gdb-test): call remote_close earlier, and send
	newline to log, before calling pass/fail/unsupported.
	* lib/gcc-simulate-thread.exp (simulate-thread): Likewise.
---
 gcc/testsuite/lib/gcc-gdb-test.exp        | 15 ++++++++++-----
 gcc/testsuite/lib/gcc-simulate-thread.exp | 10 +++++++---
 2 files changed, 17 insertions(+), 8 deletions(-)

Ping.

--Alan

On 10/12/15 10:31, Alan Lawrence wrote:
> Runs of the guality testsuite can sometimes end up with gcc.log containing
> malformed lines like:
>
> A debugging session is active.PASS: gcc.dg/guality/pr36728-1.c   -O2  line 18 arg4 == 4
> A debugging session is active.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:ip == int *
> 	Inferior 1 [process 27054] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cicrp == const int * const restrict
> 	Inferior 1 [process 27160] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cvirp == int * const volatile restrict
>
> This patch just makes sure the PASS/FAIL comes at the beginning of a line.  (At
> the slight cost of adding some extra newlines not in the actual test output.)
>
> I moved the remote_close target calls earlier, to avoid any possible race
> condition of extra output being generated after the newline - this may not be
> strictly necessary.
>
> Tested on aarch64-none-linux-gnu and x86_64-none-linux-gnu.
>
> I think this is reasonable for stage 3 - OK for trunk?
>
> gcc/testsuite/ChangeLog:
> 	* lib/gcc-gdb-test.exp (gdb-test): call remote_close earlier, and send
> 	newline to log, before calling pass/fail/unsupported.
> 	* lib/gcc-simulate-thread.exp (simulate-thread): Likewise.
> ---
>   gcc/testsuite/lib/gcc-gdb-test.exp        | 15 ++++++++++-----
>   gcc/testsuite/lib/gcc-simulate-thread.exp | 10 +++++++---
>   2 files changed, 17 insertions(+), 8 deletions(-)
>
> diff --git a/gcc/testsuite/lib/gcc-gdb-test.exp b/gcc/testsuite/lib/gcc-gdb-test.exp
> index d3ba6e4..f60cabf 100644
> --- a/gcc/testsuite/lib/gcc-gdb-test.exp
> +++ b/gcc/testsuite/lib/gcc-gdb-test.exp
> @@ -84,8 +84,9 @@ proc gdb-test { args } {
>       remote_expect target [timeout_value] {
>   	# Too old GDB
>   	-re "Unhandled dwarf expression|Error in sourced command file|<unknown type in " {
> -	    unsupported "$testname"
>   	    remote_close target
> +	    send_log "\n"
> +	    unsupported "$testname"
>   	    file delete $cmd_file
>   	    return
>   	}
> @@ -93,7 +94,9 @@ proc gdb-test { args } {
>   	-re {[\n\r]\$1 = ([^\n\r]*)[\n\r]+\$2 = ([^\n\r]*)[\n\r]} {
>   	    set first $expect_out(1,string)
>   	    set second $expect_out(2,string)
> +	    remote_close target
>   	    if { $first == $second } {
> +		send_log "\n"
>   		pass "$testname"
>   	    } else {
>   		# We need the -- to disambiguate $first from an option,
> @@ -101,7 +104,6 @@ proc gdb-test { args } {
>   		send_log -- "$first != $second\n"
>   		fail "$testname"
>   	    }
> -	    remote_close target
>   	    file delete $cmd_file
>   	    return
>   	}
> @@ -116,26 +118,29 @@ proc gdb-test { args } {
>   	    regsub -all {\mlong int\M} $type "long" type
>   	    regsub -all {\mshort int\M} $type "short" type
>   	    set expected [lindex $args 2]
> +	    remote_close target
>   	    if { $type == $expected } {
> +		send_log "\n"
>   		pass "$testname"
>   	    } else {
>   		send_log -- "$type != $expected\n"
>   		fail "$testname"
>   	    }
> -	    remote_close target
>   	    file delete $cmd_file
>   	    return
>   	}
>   	timeout {
> -	    unsupported "$testname"
>   	    remote_close target
> +	    send_log "\n"
> +	    unsupported "$testname"
>   	    file delete $cmd_file
>   	    return
>   	}
>       }
>
> -    unsupported "$testname"
>       remote_close target
> +    send_log "\n"
> +    unsupported "$testname"
>       file delete $cmd_file
>       return
>   }
> diff --git a/gcc/testsuite/lib/gcc-simulate-thread.exp b/gcc/testsuite/lib/gcc-simulate-thread.exp
> index f4275d7..6809636 100644
> --- a/gcc/testsuite/lib/gcc-simulate-thread.exp
> +++ b/gcc/testsuite/lib/gcc-simulate-thread.exp
> @@ -61,13 +61,15 @@ proc simulate-thread { args } {
>       remote_expect target [timeout_value] {
>   	# Too old GDB
>   	-re "Unhandled dwarf expression|Error in sourced command file" {
> -	    unsupported "$testcase $message"
>   	    remote_close target
> +	    send_log "\n"
> +	    unsupported "$testcase $message"
>   	    return
>   	}
>   	-re "FAIL:" {
> -	    fail "$testcase $message"
>   	    remote_close target
> +	    send_log "\n"
> +	    fail "$testcase $message"
>   	    return
>   	}
>   	# If the gdb output contained simulate_thread_done, assume
> @@ -78,13 +80,15 @@ proc simulate-thread { args } {
>   	    exp_continue
>   	}
>   	timeout {
> -	    fail "$testcase $message"
>   	    remote_close target
> +	    send_log "\n"
> +	    fail "$testcase $message"
>   	    return
>   	}
>       }
>
>       remote_close target
> +    send_log "\n"
>       if {$gdb_worked} {
>   	pass "$testcase $message"
>       } else {
>

So, I’d like for the guality people to chime in.  I only kick in, if they fail to do so for any reason.  :-)

Either, the stuff downstream _must_ arrange for newline ended content, or this code has to do it, if they don’t.  My take, I think they are signing up for newline terminated content:

binutils/gdb$ grep 'will be killed' *.c
top.c:                _("\tInferior %d [%s] will be killed.\n"), inf->num,

commit b8fa0bfa752bb672c66a1d6fdefcdf4cb308a712
Author: Pedro Alves <palves@redhat.com>
Date:   Fri Aug 14 14:28:15 2009 +0000

    2009-08-14  Pedro Alves  <pedro@codesourcery.com>
    
        gdb/
        * top.c (any_thread_of): Delete.
        (kill_or_detach): Use any_thread_of_process.
        * top.c (print_inferior_quit_action): New.
        (quit_confirm): Rewrite to print info about all inferiors.
        * target.c (dispose_inferior): New.
        (target_preopen): Use it.
    
    2009-08-14  Pedro Alves  <pedro@codesourcery.com>
    
        gdb/testsuite/
        * gdb.threads/killed.exp, gdb.threads/manythreads.exp,
        gdb.threads/staticthreads.exp: Adjust to "quit" output changes.


+                     _("\tInferior %d [%s] will be killed.\n"), inf->num,

So, the question is, what output this line, stripping that newline?  As far as I can tell, there is no gdb that won’t print it since 2009.

The other possible patch would be the routine that read that from gdb and printed it without the newline.  I’m not sure if that patch or your patch is better.

On Jan 4, 2016, at 4:16 AM, Alan Lawrence <alan.lawrence@foss.arm.com> wrote:
> On 10/12/15 10:31, Alan Lawrence wrote:
>> Runs of the guality testsuite can sometimes end up with gcc.log containing
>> malformed lines like:
>> 
>> A debugging session is active.PASS: gcc.dg/guality/pr36728-1.c   -O2  line 18 arg4 == 4
>> A debugging session is active.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:ip == int *
>> 	Inferior 1 [process 27054] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cicrp == const int * const restrict
>> 	Inferior 1 [process 27160] will be killed.PASS: gcc.dg/guality/restrict.c   -O2  line 30 type:cvirp == int * const volatile restrict
>> 
>> This patch just makes sure the PASS/FAIL comes at the beginning of a line.  (At
>> the slight cost of adding some extra newlines not in the actual test output.)
>> 
>> I moved the remote_close target calls earlier, to avoid any possible race
>> condition of extra output being generated after the newline - this may not be
>> strictly necessary.
>> 
>> Tested on aarch64-none-linux-gnu and x86_64-none-linux-gnu.
>> 
>> I think this is reasonable for stage 3 - OK for trunk?
>> 
>> gcc/testsuite/ChangeLog:
>> 	* lib/gcc-gdb-test.exp (gdb-test): call remote_close earlier, and send
>> 	newline to log, before calling pass/fail/unsupported.
>> 	* lib/gcc-simulate-thread.exp (simulate-thread): Likewise.
>> ---
>>  gcc/testsuite/lib/gcc-gdb-test.exp        | 15 ++++++++++-----
>>  gcc/testsuite/lib/gcc-simulate-thread.exp | 10 +++++++---
>>  2 files changed, 17 insertions(+), 8 deletions(-)
>> 
>> diff --git a/gcc/testsuite/lib/gcc-gdb-test.exp b/gcc/testsuite/lib/gcc-gdb-test.exp
>> index d3ba6e4..f60cabf 100644
>> --- a/gcc/testsuite/lib/gcc-gdb-test.exp
>> +++ b/gcc/testsuite/lib/gcc-gdb-test.exp
>> @@ -84,8 +84,9 @@ proc gdb-test { args } {
>>      remote_expect target [timeout_value] {
>>  	# Too old GDB
>>  	-re "Unhandled dwarf expression|Error in sourced command file|<unknown type in " {
>> -	    unsupported "$testname"
>>  	    remote_close target
>> +	    send_log "\n"
>> +	    unsupported "$testname"
>>  	    file delete $cmd_file
>>  	    return
>>  	}
>> @@ -93,7 +94,9 @@ proc gdb-test { args } {
>>  	-re {[\n\r]\$1 = ([^\n\r]*)[\n\r]+\$2 = ([^\n\r]*)[\n\r]} {
>>  	    set first $expect_out(1,string)
>>  	    set second $expect_out(2,string)
>> +	    remote_close target
>>  	    if { $first == $second } {
>> +		send_log "\n"
>>  		pass "$testname"
>>  	    } else {
>>  		# We need the -- to disambiguate $first from an option,
>> @@ -101,7 +104,6 @@ proc gdb-test { args } {
>>  		send_log -- "$first != $second\n"
>>  		fail "$testname"
>>  	    }
>> -	    remote_close target
>>  	    file delete $cmd_file
>>  	    return
>>  	}
>> @@ -116,26 +118,29 @@ proc gdb-test { args } {
>>  	    regsub -all {\mlong int\M} $type "long" type
>>  	    regsub -all {\mshort int\M} $type "short" type
>>  	    set expected [lindex $args 2]
>> +	    remote_close target
>>  	    if { $type == $expected } {
>> +		send_log "\n"
>>  		pass "$testname"
>>  	    } else {
>>  		send_log -- "$type != $expected\n"
>>  		fail "$testname"
>>  	    }
>> -	    remote_close target
>>  	    file delete $cmd_file
>>  	    return
>>  	}
>>  	timeout {
>> -	    unsupported "$testname"
>>  	    remote_close target
>> +	    send_log "\n"
>> +	    unsupported "$testname"
>>  	    file delete $cmd_file
>>  	    return
>>  	}
>>      }
>> 
>> -    unsupported "$testname"
>>      remote_close target
>> +    send_log "\n"
>> +    unsupported "$testname"
>>      file delete $cmd_file
>>      return
>>  }
>> diff --git a/gcc/testsuite/lib/gcc-simulate-thread.exp b/gcc/testsuite/lib/gcc-simulate-thread.exp
>> index f4275d7..6809636 100644
>> --- a/gcc/testsuite/lib/gcc-simulate-thread.exp
>> +++ b/gcc/testsuite/lib/gcc-simulate-thread.exp
>> @@ -61,13 +61,15 @@ proc simulate-thread { args } {
>>      remote_expect target [timeout_value] {
>>  	# Too old GDB
>>  	-re "Unhandled dwarf expression|Error in sourced command file" {
>> -	    unsupported "$testcase $message"
>>  	    remote_close target
>> +	    send_log "\n"
>> +	    unsupported "$testcase $message"
>>  	    return
>>  	}
>>  	-re "FAIL:" {
>> -	    fail "$testcase $message"
>>  	    remote_close target
>> +	    send_log "\n"
>> +	    fail "$testcase $message"
>>  	    return
>>  	}
>>  	# If the gdb output contained simulate_thread_done, assume
>> @@ -78,13 +80,15 @@ proc simulate-thread { args } {
>>  	    exp_continue
>>  	}
>>  	timeout {
>> -	    fail "$testcase $message"
>>  	    remote_close target
>> +	    send_log "\n"
>> +	    fail "$testcase $message"
>>  	    return
>>  	}
>>      }
>> 
>>      remote_close target
>> +    send_log "\n"
>>      if {$gdb_worked} {
>>  	pass "$testcase $message"
>>      } else {