diff mbox series

[v2,27/28] tests/qemu-iotests: re-format output to for make check-block

Message ID 20190523102532.10486-28-alex.bennee@linaro.org
State Superseded
Headers show
Series current testing/next queue | expand

Commit Message

Alex Bennée May 23, 2019, 10:25 a.m. UTC
This attempts to clean-up the output to better match the output of the
rest of the QEMU check system when called with -makecheck. This includes:

  - formatting as "  TEST    iotest-FMT: nnn"
  - only dumping config on failure (when -makecheck enabled)

The non-make check output has been cleaned up as well:

  - line re-displayed (\r) at the end
  - fancy colours for pass/fail/skip
  - timestamps always printed (option removed)

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>
Tested-by: Thomas Huth <thuth@redhat.com>


---
v3
  - revert echo to printf
  - add _report_test_start
v4
  - -pretty -> -makecheck
  - keep all output together for makecheck
v5
  - merged in kwolf's pretty printing
  - timestamps always printed in non-makecheck mode
---
 tests/qemu-iotests/check | 179 +++++++++++++++++++++++++--------------
 1 file changed, 116 insertions(+), 63 deletions(-)

-- 
2.20.1

Comments

Max Reitz May 27, 2019, 1:43 p.m. UTC | #1
On 23.05.19 12:25, Alex Bennée wrote:
> This attempts to clean-up the output to better match the output of the

> rest of the QEMU check system when called with -makecheck. This includes:

> 

>   - formatting as "  TEST    iotest-FMT: nnn"

>   - only dumping config on failure (when -makecheck enabled)

> 

> The non-make check output has been cleaned up as well:

> 

>   - line re-displayed (\r) at the end

>   - fancy colours for pass/fail/skip

>   - timestamps always printed (option removed)

> 

> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

> Tested-by: Thomas Huth <thuth@redhat.com>

> 

> ---

> v3

>   - revert echo to printf

>   - add _report_test_start

> v4

>   - -pretty -> -makecheck

>   - keep all output together for makecheck

> v5

>   - merged in kwolf's pretty printing

>   - timestamps always printed in non-makecheck mode

> ---

>  tests/qemu-iotests/check | 179 +++++++++++++++++++++++++--------------

>  1 file changed, 116 insertions(+), 63 deletions(-)


Unless I missed something, this breaks ./check:

$ ./check -T -qcow2
000 - unknown test, ignored
QEMU          -- "build/x86_64-softmmu/qemu-system-x86_64" -nodefaults
-machine accel=qtest
QEMU_IMG      -- "build/qemu-img"
QEMU_IO       -- "build/qemu-io"  --cache writeback -f qcow2
QEMU_NBD      -- "build/qemu-nbd"
IMGFMT        -- qcow2 (compat=1.1)
IMGPROTO      -- file
PLATFORM      -- Linux/x86_64 dresden 5.0.14-300.fc30.x86_64
TEST_DIR      -- build/tests/qemu-iotests/scratch
SOCKET_SCM_HELPER -- build/tests/qemu-iotests/socket_scm_helper

Passed all 0 tests


Max
Alex Bennée May 27, 2019, 4:20 p.m. UTC | #2
Max Reitz <mreitz@redhat.com> writes:

> On 23.05.19 12:25, Alex Bennée wrote:

>> This attempts to clean-up the output to better match the output of the

>> rest of the QEMU check system when called with -makecheck. This includes:

>>

>>   - formatting as "  TEST    iotest-FMT: nnn"

>>   - only dumping config on failure (when -makecheck enabled)

>>

>> The non-make check output has been cleaned up as well:

>>

>>   - line re-displayed (\r) at the end

>>   - fancy colours for pass/fail/skip

>>   - timestamps always printed (option removed)

>>

>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

>> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

>> Tested-by: Thomas Huth <thuth@redhat.com>

>>

>> ---

>> v3

>>   - revert echo to printf

>>   - add _report_test_start

>> v4

>>   - -pretty -> -makecheck

>>   - keep all output together for makecheck

>> v5

>>   - merged in kwolf's pretty printing

>>   - timestamps always printed in non-makecheck mode

>> ---

>>  tests/qemu-iotests/check | 179 +++++++++++++++++++++++++--------------

>>  1 file changed, 116 insertions(+), 63 deletions(-)

>

> Unless I missed something, this breaks ./check:

>

> $ ./check -T -qcow2

> 000 - unknown test, ignored


Because -T has been dropped (timestamps are always shown). Of course
removing from the opts passing falls through. Should I just do:

modified   tests/qemu-iotests/check
@@ -433,6 +433,11 @@ testlist options
             cachemode=true
             xpand=false
             ;;
+        -T)
+            echo "-T no longer needed"
+            exit -1
+            ;;
+
         -v)
             verbose=true


> QEMU          -- "build/x86_64-softmmu/qemu-system-x86_64" -nodefaults

> -machine accel=qtest

> QEMU_IMG      -- "build/qemu-img"

> QEMU_IO       -- "build/qemu-io"  --cache writeback -f qcow2

> QEMU_NBD      -- "build/qemu-nbd"

> IMGFMT        -- qcow2 (compat=1.1)

> IMGPROTO      -- file

> PLATFORM      -- Linux/x86_64 dresden 5.0.14-300.fc30.x86_64

> TEST_DIR      -- build/tests/qemu-iotests/scratch

> SOCKET_SCM_HELPER -- build/tests/qemu-iotests/socket_scm_helper

>

> Passed all 0 tests

>

>

> Max



--
Alex Bennée
Max Reitz May 27, 2019, 4:53 p.m. UTC | #3
On 27.05.19 18:20, Alex Bennée wrote:
> 

> Max Reitz <mreitz@redhat.com> writes:

> 

>> On 23.05.19 12:25, Alex Bennée wrote:

>>> This attempts to clean-up the output to better match the output of the

>>> rest of the QEMU check system when called with -makecheck. This includes:

>>>

>>>   - formatting as "  TEST    iotest-FMT: nnn"

>>>   - only dumping config on failure (when -makecheck enabled)

>>>

>>> The non-make check output has been cleaned up as well:

>>>

>>>   - line re-displayed (\r) at the end

>>>   - fancy colours for pass/fail/skip

>>>   - timestamps always printed (option removed)

>>>

>>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

>>> Message-Id: <20190503143904.31211-1-alex.bennee@linaro.org>

>>> Tested-by: Thomas Huth <thuth@redhat.com>

>>>

>>> ---

>>> v3

>>>   - revert echo to printf

>>>   - add _report_test_start

>>> v4

>>>   - -pretty -> -makecheck

>>>   - keep all output together for makecheck

>>> v5

>>>   - merged in kwolf's pretty printing

>>>   - timestamps always printed in non-makecheck mode

>>> ---

>>>  tests/qemu-iotests/check | 179 +++++++++++++++++++++++++--------------

>>>  1 file changed, 116 insertions(+), 63 deletions(-)

>>

>> Unless I missed something, this breaks ./check:

>>

>> $ ./check -T -qcow2

>> 000 - unknown test, ignored

> 

> Because -T has been dropped (timestamps are always shown). Of course

> removing from the opts passing falls through. Should I just do:


Ah, OK.

> modified   tests/qemu-iotests/check

> @@ -433,6 +433,11 @@ testlist options

>              cachemode=true

>              xpand=false

>              ;;

> +        -T)

> +            echo "-T no longer needed"

> +            exit -1

> +            ;;

> +

>          -v)

>              verbose=true


Hm, why not just ignore it?

Max
diff mbox series

Patch

diff --git a/tests/qemu-iotests/check b/tests/qemu-iotests/check
index 922c5d1d3d3..f46b90dbbf4 100755
--- a/tests/qemu-iotests/check
+++ b/tests/qemu-iotests/check
@@ -27,9 +27,7 @@  bad=""
 notrun=""
 casenotrun=""
 interrupt=true
-
-# by default don't output timestamps
-timestamp=${TIMESTAMP:=false}
+makecheck=false
 
 _init_error()
 {
@@ -88,6 +86,22 @@  _full_platform_details()
     echo "$os/$platform $host $kernel"
 }
 
+_full_env_details()
+{
+    cat <<EOF
+QEMU          -- "$QEMU_PROG" $QEMU_OPTIONS
+QEMU_IMG      -- "$QEMU_IMG_PROG" $QEMU_IMG_OPTIONS
+QEMU_IO       -- "$QEMU_IO_PROG" $QEMU_IO_OPTIONS
+QEMU_NBD      -- "$QEMU_NBD_PROG" $QEMU_NBD_OPTIONS
+IMGFMT        -- $FULL_IMGFMT_DETAILS
+IMGPROTO      -- $IMGPROTO
+PLATFORM      -- $FULL_HOST_DETAILS
+TEST_DIR      -- $TEST_DIR
+SOCKET_SCM_HELPER -- $SOCKET_SCM_HELPER
+
+EOF
+}
+
 # $1 = prog to look for
 set_prog_path()
 {
@@ -254,8 +268,8 @@  other options
     -misalign           misalign memory allocations
     -n                  show me, do not run tests
     -o options          -o options to pass to qemu-img create/convert
-    -T                  output timestamps
     -c mode             cache mode
+    -makecheck          pretty print output for make check
 
 testlist options
     -g group[,group...]        include tests from these groups
@@ -403,7 +417,10 @@  testlist options
                 command -v xxdiff >/dev/null 2>&1 && diff=xxdiff
             fi
             ;;
-
+        -makecheck)   # makecheck friendly output
+            makecheck=true
+            xpand=false
+            ;;
         -n)        # show me, don't do it
             showme=true
             xpand=false
@@ -416,11 +433,6 @@  testlist options
             cachemode=true
             xpand=false
             ;;
-        -T)        # turn on timestamp output
-            timestamp=true
-            xpand=false
-            ;;
-
         -v)
             verbose=true
             xpand=false
@@ -633,12 +645,6 @@  _wallclock()
     date "+%H %M %S" | awk '{ print $1*3600 + $2*60 + $3 }'
 }
 
-_timestamp()
-{
-    now=$(date "+%T")
-    printf %s " [$now]"
-}
-
 _wrapup()
 {
     if $showme
@@ -704,23 +710,54 @@  END        { if (NR > 0) {
 
 trap "_wrapup; exit \$status" 0 1 2 3 15
 
+# Report the test start and results. For makecheck we want to pretty
+# print the whole report at the end of the execution.
+# args: $seq, $starttime, $lasttime
+_report_test_start()
+{
+    if ! $makecheck; then
+        if [ -n "$3" ]; then
+            local lasttime=" (last: $3s)"
+        fi
+        printf "%-8s %-10s [%s]            %4s%-14s\r" "$1" "..." "$2" "..." "$lasttime"
+    fi
+}
+# args:$seq $status $starttime $lasttime $thistime $details
+_report_test_result()
+{
+    local status lasttime thistime
+    if $makecheck; then
+        if [ -n "$2" ] && [ "$2" != "pass" ]; then
+            status=" [$2]"
+        fi
+        printf "  TEST    iotest-$IMGFMT: %s%s\n" "$1" "$status"
+        return
+    fi
+
+    if [ -n "$4" ]; then
+        lasttime=" (last: $4s)"
+    fi
+    if [ -n "$5" ]; then
+        thistime=" $5s"
+    fi
+    case "$2" in
+        "pass")     status=$(printf "\e[32m%-10s\e[0m" "$2") ;;
+        "fail")     status=$(printf "\e[1m\e[31m%-10s\e[0m" "$2") ;;
+        "not run")  status=$(printf "\e[33m%-10s\e[0m" "$2") ;;
+        *)          status=$(printf "%-10s" "$2") ;;
+    esac
+
+    printf "%-8s %s [%s] [%s] %4s%-14s %s\n" "$1" "$status" "$3" "$(date '+%T')" "$thistime" "$lasttime" "$6"
+}
+
 [ -f $TIMESTAMP_FILE ] || touch $TIMESTAMP_FILE
 
 FULL_IMGFMT_DETAILS=$(_full_imgfmt_details)
 FULL_HOST_DETAILS=$(_full_platform_details)
 
-cat <<EOF
-QEMU          -- "$QEMU_PROG" $QEMU_OPTIONS
-QEMU_IMG      -- "$QEMU_IMG_PROG" $QEMU_IMG_OPTIONS
-QEMU_IO       -- "$QEMU_IO_PROG" $QEMU_IO_OPTIONS
-QEMU_NBD      -- "$QEMU_NBD_PROG" $QEMU_NBD_OPTIONS
-IMGFMT        -- $FULL_IMGFMT_DETAILS
-IMGPROTO      -- $IMGPROTO
-PLATFORM      -- $FULL_HOST_DETAILS
-TEST_DIR      -- $TEST_DIR
-SOCKET_SCM_HELPER -- $SOCKET_SCM_HELPER
-
-EOF
+if ! $makecheck; then
+    _full_env_details
+fi
 
 seq="check"
 
@@ -728,42 +765,43 @@  seq="check"
 
 for seq in $list
 do
-    err=false
-    printf %s "$seq"
+    err=false       # error flag
+    printdiff=false # show diff to reference output?
+    status=""       # test result summary
+    results=""      # test result details
+
     if [ -n "$TESTS_REMAINING_LOG" ] ; then
         sed -e "s/$seq//" -e 's/  / /' -e 's/^ *//' $TESTS_REMAINING_LOG > $TESTS_REMAINING_LOG.tmp
         mv $TESTS_REMAINING_LOG.tmp $TESTS_REMAINING_LOG
         sync
     fi
 
+    lasttime=$(sed -n -e "/^$seq /s/.* //p" <$TIMESTAMP_FILE)
+    starttime=$(date "+%T")
+    _report_test_start $seq $starttime $lasttime
+
     if $showme
     then
-        echo
-        continue
+        status="not run"
     elif [ -f expunged ] && $expunge && egrep "^$seq([         ]|\$)" expunged >/dev/null
     then
-        echo " - expunged"
+        status="not run"
+        results="expunged"
         rm -f $seq.out.bad
         echo "/^$seq\$/d" >>$tmp.expunged
     elif [ ! -f "$source_iotests/$seq" ]
     then
-        echo " - no such test?"
+        status="not run"
+        results="no such test?"
         echo "/^$seq\$/d" >>$tmp.expunged
     else
         # really going to try and run this one
         #
         rm -f $seq.out.bad
-        lasttime=$(sed -n -e "/^$seq /s/.* //p" <$TIMESTAMP_FILE)
-        if [ "X$lasttime" != X ]; then
-                printf %s " ${lasttime}s ..."
-        else
-                printf "        "        # prettier output with timestamps.
-        fi
         rm -f core $seq.notrun
         rm -f $seq.casenotrun
 
         start=$(_wallclock)
-        $timestamp && printf %s "        [$(date "+%T")]"
 
         if [ "$(head -n 1 "$source_iotests/$seq")" == "#!/usr/bin/env python" ]; then
             run_command="$PYTHON $seq"
@@ -781,26 +819,26 @@  do
                     $run_command >$tmp.out 2>&1)
         fi
         sts=$?
-        $timestamp && _timestamp
         stop=$(_wallclock)
 
         if [ -f core ]
         then
-            printf " [dumped core]"
             mv core $seq.core
+            status="fail"
+            results="[dumped core] $seq.core"
             err=true
         fi
 
         if [ -f $seq.notrun ]
         then
-            $timestamp || printf " [not run] "
-            $timestamp && echo " [not run]" && printf %s "        $seq -- "
-            cat $seq.notrun
-            notrun="$notrun $seq"
+            # overwrites timestamp output
+            status="not run"
+            results="$(cat $seq.notrun)"
         else
             if [ $sts -ne 0 ]
             then
-                printf %s " [failed, exit status $sts]"
+                status="fail"
+                results=$(printf %s "[failed, exit status $sts]")
                 err=true
             fi
 
@@ -821,22 +859,23 @@  do
 
             if [ ! -f "$reference" ]
             then
-                echo " - no qualified output"
+                status="fail"
+                reason="no qualified output"
                 err=true
             else
                 if diff -w "$reference" $tmp.out >/dev/null 2>&1
                 then
-                    echo ""
-                    if $err
-                    then
-                        :
-                    else
-                        echo "$seq $(expr $stop - $start)" >>$tmp.time
+                    if ! $err; then
+                        status="pass"
+                        thistime=$(expr $stop - $start)
+                        echo "$seq $thistime" >>$tmp.time
                     fi
                 else
-                    echo " - output mismatch (see $seq.out.bad)"
                     mv $tmp.out $seq.out.bad
                     $diff -w "$reference" "$PWD"/$seq.out.bad
+                    status="fail"
+                    results="output mismatch (see $seq.out.bad)"
+                    printdiff=true
                     err=true
                 fi
             fi
@@ -850,13 +889,27 @@  do
 
     # come here for each test, except when $showme is true
     #
-    if $err
-    then
-        bad="$bad $seq"
-        n_bad=$(expr $n_bad + 1)
-        quick=false
-    fi
-    [ -f $seq.notrun ] || try=$(expr $try + 1)
+    _report_test_result $seq "$status" "$starttime" "$lasttime" "$thistime" "$results"
+    case "$status" in
+        "pass")
+            try=$(expr $try + 1)
+            ;;
+        "fail")
+            try=$(expr $try + 1)
+            if $makecheck; then
+                _full_env_details
+            fi
+            if $printdiff; then
+                $diff -w "$reference" "$PWD"/$seq.out.bad
+            fi
+            bad="$bad $seq"
+            n_bad=$(expr $n_bad + 1)
+            quick=false
+            ;;
+        "not run")
+            notrun="$notrun $seq"
+            ;;
+    esac
 
     seq="after_$seq"
 done