Re: [PATCH] Implement timestamp'ed output on "make check"

[Pedro Alves <palves@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 1588 bytes --]

On 12/06/2018 03:29 PM, Pedro Alves wrote:
> On 12/05/2018 08:26 PM, Sergio Durigan Junior wrote:
> 
>> Unfortunately they haven't reached the commit which introduces the
>> timestamp feature, so we still don't know exactly where they're hanging.
> 
> Actually we could know even without the timestamp feature -- all the
> testsuite/*/gdb.log files have something like:
> 
>   Test run by pedro on Tue Dec  4 18:15:17 2018
> 
> at the top, and ...
> 
>   runtest completed at Tue Dec  4 18:15:18 2018
> 
> ... at the bottom.
> 
> So a simple script could extract that info and present it
> in a convenient way.

Here's a quick bash POC.

Make sure to test in parallel mode (make check-parallel),
so that each testcase gets its own gdb.log file
and then run the script, like:

 $ cd gdb
 $ make -j8 check-parallel
 $ extract-times testsuite/outputs/ | sort -n | tail -n 10
 33 seconds for testsuite/outputs/gdb.base/whatis-ptype-typedefs/gdb.log
 35 seconds for testsuite/outputs/gdb.base/quit-live/gdb.log
 35 seconds for testsuite/outputs/gdb.base/structs/gdb.log
 37 seconds for testsuite/outputs/gdb.base/gdb-sigterm/gdb.log
 39 seconds for testsuite/outputs/gdb.threads/attach-many-short-lived-threads/gdb.log
 43 seconds for testsuite/outputs/gdb.base/multi-forks/gdb.log
 48 seconds for testsuite/outputs/gdb.linespec/cpls-ops/gdb.log
 64 seconds for testsuite/outputs/gdb.linespec/cpcompletion/gdb.log
 78 seconds for testsuite/outputs/gdb.base/break-interp/gdb.log
 149 seconds for testsuite/outputs/gdb.base/sigstep/gdb.log

(that was run against an older test dir I had handy.)

[-- Attachment #2: extract-times --]
[-- Type: text/plain, Size: 393 bytes --]

#!/bin/bash

find $1 -name "gdb.log" | \
    while read line;
    do
	#echo $line
	start=$(head -n1 $line | sed 's/Test run by .* on //g')
	end=$(tail -n1 $line | sed 's/.*completed at //g')
	#echo start=$start
	#echo end=$end
	start_sec=$(date --date="$start" '+%s')
	end_sec=$(date --date="$end" '+%s')
	duration_sec=$((end_sec - start_sec))
	echo "$duration_sec seconds for $line"
    done