[PATCH kvm-unit-tests v3 0/9] Improve the output of test runners

[PATCH kvm-unit-tests v3 0/9] Improve the output of test runners

[Radim Krčmář]

v2: http://www.spinics.net/lists/kvm/msg125429.html

mkstandalone is using generic code now, so v3 focuses on the output
again.  And the output looks like in v2.  Since v2, I've
* removed svm-disabled [3/7]
* reworked summary reporting [8/9] (it's a nice feature, but still ugly)
* turned all cases when QEMU won't run the test into SKIP [6/7]
* preserved check_param (it's not used, though)
* stopped returning 77 on all SKIPs [7/7] (a sacrifice to prevent
  another refactoring of our scripts)

I didn't manage to look at the comment from Lukáš's patches, but I don't
expect that v3 will be the last one ... a lot has changed since v2.


Radim Krčmář (9):
  lib/report: allow test skipping
  x86/*: report skipped tests
  x86/unittests: remove svm-disabled
  x86/pmu: expect failure with nmi_watchdog
  lib/report: don't print 0 failed tests
  scripts/runtime: skip tests that cannot run
  scripts/runtime: consolidate summary tags
  run_tests: print summary
  run_tests: log stderr

 lib/libcflat.h          |  1 +
 lib/report.c            | 49 ++++++++++++++++++++++++++++++++++---------------
 run_tests.sh            |  7 ++++---
 scripts/mkstandalone.sh |  4 ++++
 scripts/runtime.bash    | 32 +++++++++++++++++++++++++-------
 x86/apic.c              |  7 +++----
 x86/emulator.c          |  2 +-
 x86/hyperv_synic.c      |  2 +-
 x86/pku.c               |  2 +-
 x86/pmu.c               | 11 +++++++++--
 x86/smap.c              |  2 +-
 x86/svm.c               |  2 +-
 x86/tsc.c               |  2 +-
 x86/unittests.cfg       |  9 +--------
 14 files changed, 87 insertions(+), 45 deletions(-)

-- 
2.8.1

[PATCH v3 1/9] lib/report: allow test skipping

[Radim Krčmář]

We can now explicitly mark a unit-test as skipped.
If all unit-tests were skipped, the whole test is reported as skipped as
well.  This also includes the case where no tests were run, but still
ended with report_summary().

When the whole test is skipped, ./run_tests.sh prints yellow "SKIP"
instead of green "PASS".

Return value of 77 is used to please Autotools.  I also renamed few
things in reporting code and chose to refactor a logic while at it.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 lib/libcflat.h       |  1 +
 lib/report.c         | 45 +++++++++++++++++++++++++++++++--------------
 scripts/runtime.bash |  2 ++
 3 files changed, 34 insertions(+), 14 deletions(-)

diff --git a/lib/libcflat.h b/lib/libcflat.h
index df50615b4366..582e3fc60e28 100644
--- a/lib/libcflat.h
+++ b/lib/libcflat.h
@@ -79,6 +79,7 @@ extern void report_prefix_pop(void);
 extern void report(const char *msg_fmt, bool pass, ...);
 extern void report_xfail(const char *msg_fmt, bool xfail, bool pass, ...);
 extern void report_abort(const char *msg_fmt, ...);
+extern void report_skip(const char *msg_fmt, ...);
 extern int report_summary(void);
 
 extern void dump_stack(void);
diff --git a/lib/report.c b/lib/report.c
index 9e45781ee2ab..430b2aeaecbd 100644
--- a/lib/report.c
+++ b/lib/report.c
@@ -13,7 +13,7 @@
 #include "libcflat.h"
 #include "asm/spinlock.h"
 
-static unsigned int tests, failures, xfailures;
+static unsigned int tests, failures, xfailures, skipped;
 static char prefixes[256];
 static struct spinlock lock;
 
@@ -43,23 +43,25 @@ void report_prefix_pop(void)
 	spin_unlock(&lock);
 }
 
-void va_report_xfail(const char *msg_fmt, bool xfail, bool cond, va_list va)
+static void va_report(const char *msg_fmt,
+		bool pass, bool xfail, bool skip, va_list va)
 {
-	char *pass = xfail ? "XPASS" : "PASS";
-	char *fail = xfail ? "XFAIL" : "FAIL";
+	char *prefix = skip ? "SKIP"
+	                    : xfail ? (pass ? "XPASS" : "XFAIL")
+	                            : (pass ? "PASS"  : "FAIL");
 
 	spin_lock(&lock);
 
 	tests++;
-	printf("%s: ", cond ? pass : fail);
+	printf("%s: ", prefix);
 	puts(prefixes);
 	vprintf(msg_fmt, va);
 	puts("\n");
-	if (xfail && cond)
-		failures++;
-	else if (xfail)
+	if (skip)
+		skipped++;
+	else if (xfail && !pass)
 		xfailures++;
-	else if (!cond)
+	else if (xfail || !pass)
 		failures++;
 
 	spin_unlock(&lock);
@@ -69,7 +71,7 @@ void report(const char *msg_fmt, bool pass, ...)
 {
 	va_list va;
 	va_start(va, pass);
-	va_report_xfail(msg_fmt, false, pass, va);
+	va_report(msg_fmt, pass, false, false, va);
 	va_end(va);
 }
 
@@ -77,7 +79,15 @@ void report_xfail(const char *msg_fmt, bool xfail, bool pass, ...)
 {
 	va_list va;
 	va_start(va, pass);
-	va_report_xfail(msg_fmt, xfail, pass, va);
+	va_report(msg_fmt, pass, xfail, false, va);
+	va_end(va);
+}
+
+void report_skip(const char *msg_fmt, ...)
+{
+	va_list va;
+	va_start(va, msg_fmt);
+	va_report(msg_fmt, false, false, true, va);
 	va_end(va);
 }
 
@@ -87,9 +97,16 @@ int report_summary(void)
 
 	printf("\nSUMMARY: %d tests, %d unexpected failures", tests, failures);
 	if (xfailures)
-		printf(", %d expected failures\n", xfailures);
-	else
-		printf("\n");
+		printf(", %d expected failures", xfailures);
+	if (skipped)
+		printf(", %d skipped", skipped);
+	printf("\n");
+
+	if (tests == skipped)
+		/* Blame AUTOTOOLS for using 77 for skipped test and QEMU for
+		 * mangling error codes in a way that gets 77 if we ... */
+		return 77 >> 1;
+
 	return failures > 0 ? 1 : 0;
 
 	spin_unlock(&lock);
diff --git a/scripts/runtime.bash b/scripts/runtime.bash
index 0e055f0dddc2..ed073721216c 100644
--- a/scripts/runtime.bash
+++ b/scripts/runtime.bash
@@ -51,6 +51,8 @@ function run()
 
     if [ $ret -eq 0 ]; then
         echo -e "\e[32mPASS\e[0m $1"
+    elif [ $ret -eq 77 ]; then
+        echo -e "\e[33mSKIP\e[0m $1"
     elif [ $ret -eq 124 ]; then
         echo -e "\e[31mFAIL\e[0m $1 (timeout; duration=$timeout)"
     else
-- 
2.8.1

[PATCH v3 2/9] x86/*: report skipped tests

[Radim Krčmář]

No care to consistency or exhaustivity was given.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 x86/apic.c         | 7 +++----
 x86/emulator.c     | 2 +-
 x86/hyperv_synic.c | 2 +-
 x86/pku.c          | 2 +-
 x86/pmu.c          | 2 +-
 x86/smap.c         | 2 +-
 x86/svm.c          | 2 +-
 x86/tsc.c          | 2 +-
 8 files changed, 10 insertions(+), 11 deletions(-)

diff --git a/x86/apic.c b/x86/apic.c
index 61a0a7659805..8b08a950a0c7 100644
--- a/x86/apic.c
+++ b/x86/apic.c
@@ -27,7 +27,7 @@ static void tsc_deadline_timer_isr(isr_regs_t *regs)
     ++tdt_count;
 }
 
-static void start_tsc_deadline_timer(void)
+static void __test_tsc_deadline_timer(void)
 {
     handle_irq(TSC_DEADLINE_TIMER_VECTOR, tsc_deadline_timer_isr);
     irq_enable();
@@ -45,7 +45,6 @@ static int enable_tsc_deadline_timer(void)
     if (cpuid(1).c & (1 << 24)) {
         lvtt = TSC_DEADLINE_TIMER_MODE | TSC_DEADLINE_TIMER_VECTOR;
         apic_write(APIC_LVTT, lvtt);
-        start_tsc_deadline_timer();
         return 1;
     } else {
         return 0;
@@ -55,9 +54,9 @@ static int enable_tsc_deadline_timer(void)
 static void test_tsc_deadline_timer(void)
 {
     if(enable_tsc_deadline_timer()) {
-        printf("tsc deadline timer enabled\n");
+        __test_tsc_deadline_timer();
     } else {
-        printf("tsc deadline timer not detected\n");
+        report_skip("tsc deadline timer not detected");
     }
 }
 
diff --git a/x86/emulator.c b/x86/emulator.c
index 3730721258bc..8d262d832112 100644
--- a/x86/emulator.c
+++ b/x86/emulator.c
@@ -1082,7 +1082,7 @@ static void illegal_movbe_handler(struct ex_regs *regs)
 static void test_illegal_movbe(void)
 {
 	if (!(cpuid(1).c & (1 << 22))) {
-		printf("SKIP: illegal movbe\n");
+		report_skip("illegal movbe");
 		return;
 	}
 
diff --git a/x86/hyperv_synic.c b/x86/hyperv_synic.c
index 6e088944be1f..f5eb82bb7336 100644
--- a/x86/hyperv_synic.c
+++ b/x86/hyperv_synic.c
@@ -202,7 +202,7 @@ int main(int ac, char **av)
 
         report("Hyper-V SynIC test", ok);
     } else {
-        report("Hyper-V SynIC is not supported", true);
+        report_skip("Hyper-V SynIC is not supported");
     }
 
     return report_summary();
diff --git a/x86/pku.c b/x86/pku.c
index df51d1b59048..6214f0bc151f 100644
--- a/x86/pku.c
+++ b/x86/pku.c
@@ -68,7 +68,7 @@ int main(int ac, char **av)
 
     if (!(cpuid_indexed(7, 0).c & (1 << X86_FEATURE_PKU))) {
         printf("PKU not enabled, aborting\n");
-        abort();
+        return report_summary();
     }
 
     setup_vm();
diff --git a/x86/pmu.c b/x86/pmu.c
index 03f80190bb25..c68980044dee 100644
--- a/x86/pmu.c
+++ b/x86/pmu.c
@@ -387,7 +387,7 @@ int main(int ac, char **av)
 
 	if (!eax.split.version_id) {
 		printf("No pmu is detected!\n");
-		return 1;
+		return report_summary();
 	}
 	printf("PMU version:         %d\n", eax.split.version_id);
 	printf("GP counters:         %d\n", eax.split.num_counters);
diff --git a/x86/smap.c b/x86/smap.c
index 69e71864dc9b..c9de081a474b 100644
--- a/x86/smap.c
+++ b/x86/smap.c
@@ -93,7 +93,7 @@ int main(int ac, char **av)
 
 	if (!(cpuid_indexed(7, 0).b & (1 << X86_FEATURE_SMAP))) {
 		printf("SMAP not enabled, aborting\n");
-		abort();
+		return report_summary();
 	}
 
 	setup_vm();
diff --git a/x86/svm.c b/x86/svm.c
index 934b2ae91fa8..301cf8cb2d6b 100644
--- a/x86/svm.c
+++ b/x86/svm.c
@@ -1064,7 +1064,7 @@ int main(int ac, char **av)
 
     if (!(cpuid(0x80000001).c & 4)) {
         printf("SVM not availble\n");
-        return 0;
+        return report_summary();
     }
 
     setup_svm();
diff --git a/x86/tsc.c b/x86/tsc.c
index 6f89c911c2bc..62450e71725c 100644
--- a/x86/tsc.c
+++ b/x86/tsc.c
@@ -43,5 +43,5 @@ int main()
 		test_rdtscp(0x100);
 	} else
 		printf("rdtscp not supported\n");
-	return 0;
+	return report_summary();
 }
-- 
2.8.1

[PATCH v3 3/9] x86/unittests: remove svm-disabled

[Radim Krčmář]

svm-disabled says SKIP after the last patch.  It's better than the FAIL
it returned before (QEMU warns, so return 0 is treated as an error), but
I don't think that the test is useful enough to be fixed to return PASS.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 x86/unittests.cfg | 6 ------
 1 file changed, 6 deletions(-)

diff --git a/x86/unittests.cfg b/x86/unittests.cfg
index fcee6f98c598..60747cfca94e 100644
--- a/x86/unittests.cfg
+++ b/x86/unittests.cfg
@@ -159,12 +159,6 @@ smp = 2
 extra_params = -cpu qemu64,+svm
 arch = x86_64
 
-[svm-disabled]
-file = svm.flat
-smp = 2
-extra_params = -cpu qemu64,-svm
-arch = x86_64
-
 [taskswitch]
 file = taskswitch.flat
 arch = i386
-- 
2.8.1

[PATCH v3 4/9] x86/pmu: expect failure with nmi_watchdog

[Radim Krčmář]

Host's nmi_watchdog takes one slot, making the "all counters" unit-test
fail.  We know exactly what happens, mark it as expected failure.

PMU test is now executed regardless of host_nmi_watchdog.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 x86/pmu.c         | 9 ++++++++-
 x86/unittests.cfg | 3 +--
 2 files changed, 9 insertions(+), 3 deletions(-)

diff --git a/x86/pmu.c b/x86/pmu.c
index c68980044dee..70e9b3a41e96 100644
--- a/x86/pmu.c
+++ b/x86/pmu.c
@@ -92,6 +92,7 @@ struct pmu_event {
 };
 
 static int num_counters;
+static bool host_nmi_watchdog;
 
 char *buf;
 
@@ -291,7 +292,7 @@ static void check_counters_many(void)
 		if (!verify_counter(&cnt[i]))
 			break;
 
-	report("all counters", i == n);
+	report_xfail("all counters", host_nmi_watchdog, i == n);
 }
 
 static void check_counter_overflow(void)
@@ -374,6 +375,7 @@ static void check_rdpmc(void)
 
 int main(int ac, char **av)
 {
+	int i;
 	struct cpuid id = cpuid(10);
 
 	setup_vm();
@@ -385,6 +387,11 @@ int main(int ac, char **av)
 	ebx.full = id.b;
 	edx.full = id.d;
 
+	/* XXX: horrible command line parsing */
+	for (i = 1; i < ac; i++)
+		if (!strcmp(av[i], "host_nmi_watchdog=1"))
+			host_nmi_watchdog = true;
+
 	if (!eax.split.version_id) {
 		printf("No pmu is detected!\n");
 		return report_summary();
diff --git a/x86/unittests.cfg b/x86/unittests.cfg
index 60747cfca94e..3852b40a2927 100644
--- a/x86/unittests.cfg
+++ b/x86/unittests.cfg
@@ -121,8 +121,7 @@ file = msr.flat
 
 [pmu]
 file = pmu.flat
-extra_params = -cpu host
-check = /proc/sys/kernel/nmi_watchdog=0
+extra_params = -cpu host -append "host_nmi_watchdog=`cat /proc/sys/kernel/nmi_watchdog`"
 
 [port80]
 file = port80.flat
-- 
2.8.1

[PATCH v3 5/9] lib/report: don't print 0 failed tests

[Radim Krčmář]

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 lib/report.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/lib/report.c b/lib/report.c
index 430b2aeaecbd..4cd75534f978 100644
--- a/lib/report.c
+++ b/lib/report.c
@@ -95,7 +95,9 @@ int report_summary(void)
 {
 	spin_lock(&lock);
 
-	printf("\nSUMMARY: %d tests, %d unexpected failures", tests, failures);
+	printf("\nSUMMARY: %d tests", tests);
+	if (failures)
+		printf(", %d unexpected failures", failures);
 	if (xfailures)
 		printf(", %d expected failures", xfailures);
 	if (skipped)
-- 
2.8.1

[PATCH v3 6/9] scripts/runtime: skip tests that cannot run

[Radim Krčmář]

A case where QEMU won't run the kernel should be considered as skipped.
Hyper-V tests used to FAIL on old QEMUs.  The infamous QEMU=/dev/null
FAIL streak is covered too.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 scripts/runtime.bash | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/scripts/runtime.bash b/scripts/runtime.bash
index ed073721216c..4f29a59307f3 100644
--- a/scripts/runtime.bash
+++ b/scripts/runtime.bash
@@ -39,6 +39,12 @@ function run()
         fi
     done
 
+    cmdline="TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run /dev/null -smp $smp $opts"
+    eval $cmdline |& grep -q "could not load kernel" || {
+        echo "skip $1 (QEMU won't run)"
+        return 2
+    }
+
     cmdline="TESTNAME=$testname TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run $kernel -smp $smp $opts"
     if [ "$verbose" = "yes" ]; then
         echo $cmdline
-- 
2.8.1

[PATCH v3 7/9] scripts/runtime: consolidate summary tags

[Radim Krčmář]

Turn skip into yellow SKIP and add reusable definitions of all tags.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 scripts/runtime.bash | 18 +++++++++++-------
 1 file changed, 11 insertions(+), 7 deletions(-)

diff --git a/scripts/runtime.bash b/scripts/runtime.bash
index 4f29a59307f3..59f0df080988 100644
--- a/scripts/runtime.bash
+++ b/scripts/runtime.bash
@@ -2,6 +2,10 @@
 : ${MAX_SMP:=$(getconf _NPROCESSORS_CONF)}
 : ${TIMEOUT:=90s}
 
+PASS() { echo -ne "\e[32mPASS\e[0m"; }
+SKIP() { echo -ne "\e[33mSKIP\e[0m"; }
+FAIL() { echo -ne "\e[31mFAIL\e[0m"; }
+
 function run()
 {
     local testname="$1"
@@ -23,7 +27,7 @@ function run()
     fi
 
     if [ -n "$arch" ] && [ "$arch" != "$ARCH" ]; then
-        echo "skip $1 ($arch only)"
+        echo "`SKIP` $1 ($arch only)"
         return 2
     fi
 
@@ -34,14 +38,14 @@ function run()
         path=${check_param%%=*}
         value=${check_param#*=}
         if [ "$path" ] && [ "$(cat $path)" != "$value" ]; then
-            echo "skip $1 ($path not equal to $value)"
+            echo "`SKIP` $1 ($path not equal to $value)"
             return 2
         fi
     done
 
     cmdline="TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run /dev/null -smp $smp $opts"
     eval $cmdline |& grep -q "could not load kernel" || {
-        echo "skip $1 (QEMU won't run)"
+        echo "`SKIP` $1 (QEMU won't run)"
         return 2
     }
 
@@ -56,13 +60,13 @@ function run()
     ret=$?
 
     if [ $ret -eq 0 ]; then
-        echo -e "\e[32mPASS\e[0m $1"
+        echo "`PASS` $1"
     elif [ $ret -eq 77 ]; then
-        echo -e "\e[33mSKIP\e[0m $1"
+        echo "`SKIP` $1"
     elif [ $ret -eq 124 ]; then
-        echo -e "\e[31mFAIL\e[0m $1 (timeout; duration=$timeout)"
+        echo "`FAIL` $1 (timeout; duration=$timeout)"
     else
-        echo -e "\e[31mFAIL\e[0m $1"
+        echo "`FAIL` $1"
     fi
 
     return $ret
-- 
2.8.1

[PATCH v3 8/9] run_tests: print summary

[Radim Krčmář]

SUMMARY line is present if the test uses lib/report.  Summary contains
some interesting information, so duplicating the output isn't that big
of a cost.  Our log redirection got more complicated, though.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 run_tests.sh            |  6 +++---
 scripts/mkstandalone.sh |  3 +++
 scripts/runtime.bash    | 15 ++++++++++-----
 3 files changed, 16 insertions(+), 8 deletions(-)

diff --git a/run_tests.sh b/run_tests.sh
index 7e0237f3aa11..2a0082163423 100755
--- a/run_tests.sh
+++ b/run_tests.sh
@@ -25,6 +25,7 @@ specify the appropriate qemu binary for ARCH-run.
 EOF
 }
 
+RUNTIME_log_stdout="/dev/null"
 RUNTIME_arch_run="./$TEST_DIR/run"
 source scripts/runtime.bash
 
@@ -47,12 +48,11 @@ while getopts "g:hv" opt; do
 done
 
 if [ "$PRETTY_PRINT_STACKS" = "yes" ]; then
-	log_redir="> >(./scripts/pretty_print_stacks.py \$kernel >> test.log)"
+	RUNTIME_log_stdout='>(./scripts/pretty_print_stacks.py $kernel >> test.log)'
 else
-	log_redir=">> test.log"
+	RUNTIME_log_stdout='test.log'
 fi
 
-RUNTIME_arch_run="./$TEST_DIR/run $log_redir"
 config=$TEST_DIR/unittests.cfg
 rm -f test.log
 printf "BUILD_HEAD=$(cat build-head)\n\n" > test.log
diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
index ef15bc88a22a..ee01fe0c7777 100755
--- a/scripts/mkstandalone.sh
+++ b/scripts/mkstandalone.sh
@@ -68,6 +68,9 @@ generate_test ()
 	(echo "#!/bin/bash"
 	 cat scripts/arch-run.bash "$TEST_DIR/run") | temp_file RUNTIME_arch_run
 
+	echo "exec {stdout}>&1"
+	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
+
 	cat scripts/runtime.bash
 
 	echo "run ${args[@]}"
diff --git a/scripts/runtime.bash b/scripts/runtime.bash
index 59f0df080988..fc4be91d8727 100644
--- a/scripts/runtime.bash
+++ b/scripts/runtime.bash
@@ -6,6 +6,11 @@ PASS() { echo -ne "\e[32mPASS\e[0m"; }
 SKIP() { echo -ne "\e[33mSKIP\e[0m"; }
 FAIL() { echo -ne "\e[31mFAIL\e[0m"; }
 
+extract_summary()
+{
+    tail -1 | grep '^SUMMARY: ' | sed 's/^SUMMARY: /(/;s/$/)/'
+}
+
 function run()
 {
     local testname="$1"
@@ -55,18 +60,18 @@ function run()
     fi
 
     # extra_params in the config file may contain backticks that need to be
-    # expanded, so use eval to start qemu
-    eval $cmdline
+    # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
+    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
     ret=$?
 
     if [ $ret -eq 0 ]; then
-        echo "`PASS` $1"
+        echo "`PASS` $1 $summary"
     elif [ $ret -eq 77 ]; then
-        echo "`SKIP` $1"
+        echo "`SKIP` $1 $summary"
     elif [ $ret -eq 124 ]; then
         echo "`FAIL` $1 (timeout; duration=$timeout)"
     else
-        echo "`FAIL` $1"
+        echo "`FAIL` $1 $summary"
     fi
 
     return $ret
-- 
2.8.1

[PATCH v3 9/9] run_tests: log stderr

[Radim Krčmář]

After recent changes to logging, seeing it all the time doesn't help.
We could print one line in summary if stderr is missed.

Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
---
 run_tests.sh            | 1 +
 scripts/mkstandalone.sh | 1 +
 scripts/runtime.bash    | 3 ++-
 3 files changed, 4 insertions(+), 1 deletion(-)

diff --git a/run_tests.sh b/run_tests.sh
index 2a0082163423..3592db317897 100755
--- a/run_tests.sh
+++ b/run_tests.sh
@@ -47,6 +47,7 @@ while getopts "g:hv" opt; do
     esac
 done
 
+RUNTIME_log_stderr='test.log'
 if [ "$PRETTY_PRINT_STACKS" = "yes" ]; then
 	RUNTIME_log_stdout='>(./scripts/pretty_print_stacks.py $kernel >> test.log)'
 else
diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
index ee01fe0c7777..af2b8f43743c 100755
--- a/scripts/mkstandalone.sh
+++ b/scripts/mkstandalone.sh
@@ -70,6 +70,7 @@ generate_test ()
 
 	echo "exec {stdout}>&1"
 	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
+	echo "RUNTIME_log_stderr=>(cat >&2)"
 
 	cat scripts/runtime.bash
 
diff --git a/scripts/runtime.bash b/scripts/runtime.bash
index fc4be91d8727..ff2d98b547b5 100644
--- a/scripts/runtime.bash
+++ b/scripts/runtime.bash
@@ -61,7 +61,8 @@ function run()
 
     # extra_params in the config file may contain backticks that need to be
     # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
-    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
+    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary) \
+                            2>> $RUNTIME_log_stderr)
     ret=$?
 
     if [ $ret -eq 0 ]; then
-- 
2.8.1

Re: [PATCH v3 1/9] lib/report: allow test skipping

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:43PM +0200, Radim Krčmář wrote:
> We can now explicitly mark a unit-test as skipped.
> If all unit-tests were skipped, the whole test is reported as skipped as
> well.  This also includes the case where no tests were run, but still
> ended with report_summary().
> 
> When the whole test is skipped, ./run_tests.sh prints yellow "SKIP"
> instead of green "PASS".
> 
> Return value of 77 is used to please Autotools.  I also renamed few
> things in reporting code and chose to refactor a logic while at it.
> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  lib/libcflat.h       |  1 +
>  lib/report.c         | 45 +++++++++++++++++++++++++++++++--------------
>  scripts/runtime.bash |  2 ++
>  3 files changed, 34 insertions(+), 14 deletions(-)
> 
> diff --git a/lib/libcflat.h b/lib/libcflat.h
> index df50615b4366..582e3fc60e28 100644
> --- a/lib/libcflat.h
> +++ b/lib/libcflat.h
> @@ -79,6 +79,7 @@ extern void report_prefix_pop(void);
>  extern void report(const char *msg_fmt, bool pass, ...);
>  extern void report_xfail(const char *msg_fmt, bool xfail, bool pass, ...);
>  extern void report_abort(const char *msg_fmt, ...);
> +extern void report_skip(const char *msg_fmt, ...);
>  extern int report_summary(void);
>  
>  extern void dump_stack(void);
> diff --git a/lib/report.c b/lib/report.c
> index 9e45781ee2ab..430b2aeaecbd 100644
> --- a/lib/report.c
> +++ b/lib/report.c
> @@ -13,7 +13,7 @@
>  #include "libcflat.h"
>  #include "asm/spinlock.h"
>  
> -static unsigned int tests, failures, xfailures;
> +static unsigned int tests, failures, xfailures, skipped;
>  static char prefixes[256];
>  static struct spinlock lock;
>  
> @@ -43,23 +43,25 @@ void report_prefix_pop(void)
>  	spin_unlock(&lock);
>  }
>  
> -void va_report_xfail(const char *msg_fmt, bool xfail, bool cond, va_list va)
> +static void va_report(const char *msg_fmt,
> +		bool pass, bool xfail, bool skip, va_list va)
>  {
> -	char *pass = xfail ? "XPASS" : "PASS";
> -	char *fail = xfail ? "XFAIL" : "FAIL";
> +	char *prefix = skip ? "SKIP"
> +	                    : xfail ? (pass ? "XPASS" : "XFAIL")
> +	                            : (pass ? "PASS"  : "FAIL");
>  
>  	spin_lock(&lock);
>  
>  	tests++;
> -	printf("%s: ", cond ? pass : fail);
> +	printf("%s: ", prefix);
>  	puts(prefixes);
>  	vprintf(msg_fmt, va);
>  	puts("\n");
> -	if (xfail && cond)
> -		failures++;
> -	else if (xfail)
> +	if (skip)
> +		skipped++;
> +	else if (xfail && !pass)
>  		xfailures++;
> -	else if (!cond)
> +	else if (xfail || !pass)
>  		failures++;
>  
>  	spin_unlock(&lock);
> @@ -69,7 +71,7 @@ void report(const char *msg_fmt, bool pass, ...)
>  {
>  	va_list va;
>  	va_start(va, pass);
> -	va_report_xfail(msg_fmt, false, pass, va);
> +	va_report(msg_fmt, pass, false, false, va);
>  	va_end(va);
>  }
>  
> @@ -77,7 +79,15 @@ void report_xfail(const char *msg_fmt, bool xfail, bool pass, ...)
>  {
>  	va_list va;
>  	va_start(va, pass);
> -	va_report_xfail(msg_fmt, xfail, pass, va);
> +	va_report(msg_fmt, pass, xfail, false, va);
> +	va_end(va);
> +}
> +
> +void report_skip(const char *msg_fmt, ...)
> +{
> +	va_list va;
> +	va_start(va, msg_fmt);
> +	va_report(msg_fmt, false, false, true, va);
>  	va_end(va);
>  }
>  
> @@ -87,9 +97,16 @@ int report_summary(void)
>  
>  	printf("\nSUMMARY: %d tests, %d unexpected failures", tests, failures);
>  	if (xfailures)
> -		printf(", %d expected failures\n", xfailures);
> -	else
> -		printf("\n");
> +		printf(", %d expected failures", xfailures);
> +	if (skipped)
> +		printf(", %d skipped", skipped);
> +	printf("\n");
> +
> +	if (tests == skipped)
> +		/* Blame AUTOTOOLS for using 77 for skipped test and QEMU for
> +		 * mangling error codes in a way that gets 77 if we ... */
> +		return 77 >> 1;

Might be nicer to have something like '#define DEBUGEXIT_77 38', but this is
also fine by me.

> +
>  	return failures > 0 ? 1 : 0;
>  
>  	spin_unlock(&lock);
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index 0e055f0dddc2..ed073721216c 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -51,6 +51,8 @@ function run()
>  
>      if [ $ret -eq 0 ]; then
>          echo -e "\e[32mPASS\e[0m $1"
> +    elif [ $ret -eq 77 ]; then
> +        echo -e "\e[33mSKIP\e[0m $1"
>      elif [ $ret -eq 124 ]; then
>          echo -e "\e[31mFAIL\e[0m $1 (timeout; duration=$timeout)"
>      else
> -- 
> 2.8.1

Reviewed-by: Andrew Jones <drjones@redhat.com>

Re: [PATCH v3 2/9] x86/*: report skipped tests

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:44PM +0200, Radim Krčmář wrote:
> No care to consistency or exhaustivity was given.

Me neither, but I see that x86/tscdeadline_latency.c could use similar
updates too.

drew

> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  x86/apic.c         | 7 +++----
>  x86/emulator.c     | 2 +-
>  x86/hyperv_synic.c | 2 +-
>  x86/pku.c          | 2 +-
>  x86/pmu.c          | 2 +-
>  x86/smap.c         | 2 +-
>  x86/svm.c          | 2 +-
>  x86/tsc.c          | 2 +-
>  8 files changed, 10 insertions(+), 11 deletions(-)
> 
> diff --git a/x86/apic.c b/x86/apic.c
> index 61a0a7659805..8b08a950a0c7 100644
> --- a/x86/apic.c
> +++ b/x86/apic.c
> @@ -27,7 +27,7 @@ static void tsc_deadline_timer_isr(isr_regs_t *regs)
>      ++tdt_count;
>  }
>  
> -static void start_tsc_deadline_timer(void)
> +static void __test_tsc_deadline_timer(void)
>  {
>      handle_irq(TSC_DEADLINE_TIMER_VECTOR, tsc_deadline_timer_isr);
>      irq_enable();
> @@ -45,7 +45,6 @@ static int enable_tsc_deadline_timer(void)
>      if (cpuid(1).c & (1 << 24)) {
>          lvtt = TSC_DEADLINE_TIMER_MODE | TSC_DEADLINE_TIMER_VECTOR;
>          apic_write(APIC_LVTT, lvtt);
> -        start_tsc_deadline_timer();
>          return 1;
>      } else {
>          return 0;
> @@ -55,9 +54,9 @@ static int enable_tsc_deadline_timer(void)
>  static void test_tsc_deadline_timer(void)
>  {
>      if(enable_tsc_deadline_timer()) {
> -        printf("tsc deadline timer enabled\n");
> +        __test_tsc_deadline_timer();
>      } else {
> -        printf("tsc deadline timer not detected\n");
> +        report_skip("tsc deadline timer not detected");
>      }
>  }
>  
> diff --git a/x86/emulator.c b/x86/emulator.c
> index 3730721258bc..8d262d832112 100644
> --- a/x86/emulator.c
> +++ b/x86/emulator.c
> @@ -1082,7 +1082,7 @@ static void illegal_movbe_handler(struct ex_regs *regs)
>  static void test_illegal_movbe(void)
>  {
>  	if (!(cpuid(1).c & (1 << 22))) {
> -		printf("SKIP: illegal movbe\n");
> +		report_skip("illegal movbe");
>  		return;
>  	}
>  
> diff --git a/x86/hyperv_synic.c b/x86/hyperv_synic.c
> index 6e088944be1f..f5eb82bb7336 100644
> --- a/x86/hyperv_synic.c
> +++ b/x86/hyperv_synic.c
> @@ -202,7 +202,7 @@ int main(int ac, char **av)
>  
>          report("Hyper-V SynIC test", ok);
>      } else {
> -        report("Hyper-V SynIC is not supported", true);
> +        report_skip("Hyper-V SynIC is not supported");
>      }
>  
>      return report_summary();
> diff --git a/x86/pku.c b/x86/pku.c
> index df51d1b59048..6214f0bc151f 100644
> --- a/x86/pku.c
> +++ b/x86/pku.c
> @@ -68,7 +68,7 @@ int main(int ac, char **av)
>  
>      if (!(cpuid_indexed(7, 0).c & (1 << X86_FEATURE_PKU))) {
>          printf("PKU not enabled, aborting\n");
> -        abort();
> +        return report_summary();
>      }
>  
>      setup_vm();
> diff --git a/x86/pmu.c b/x86/pmu.c
> index 03f80190bb25..c68980044dee 100644
> --- a/x86/pmu.c
> +++ b/x86/pmu.c
> @@ -387,7 +387,7 @@ int main(int ac, char **av)
>  
>  	if (!eax.split.version_id) {
>  		printf("No pmu is detected!\n");
> -		return 1;
> +		return report_summary();
>  	}
>  	printf("PMU version:         %d\n", eax.split.version_id);
>  	printf("GP counters:         %d\n", eax.split.num_counters);
> diff --git a/x86/smap.c b/x86/smap.c
> index 69e71864dc9b..c9de081a474b 100644
> --- a/x86/smap.c
> +++ b/x86/smap.c
> @@ -93,7 +93,7 @@ int main(int ac, char **av)
>  
>  	if (!(cpuid_indexed(7, 0).b & (1 << X86_FEATURE_SMAP))) {
>  		printf("SMAP not enabled, aborting\n");
> -		abort();
> +		return report_summary();
>  	}
>  
>  	setup_vm();
> diff --git a/x86/svm.c b/x86/svm.c
> index 934b2ae91fa8..301cf8cb2d6b 100644
> --- a/x86/svm.c
> +++ b/x86/svm.c
> @@ -1064,7 +1064,7 @@ int main(int ac, char **av)
>  
>      if (!(cpuid(0x80000001).c & 4)) {
>          printf("SVM not availble\n");
> -        return 0;
> +        return report_summary();
>      }
>  
>      setup_svm();
> diff --git a/x86/tsc.c b/x86/tsc.c
> index 6f89c911c2bc..62450e71725c 100644
> --- a/x86/tsc.c
> +++ b/x86/tsc.c
> @@ -43,5 +43,5 @@ int main()
>  		test_rdtscp(0x100);
>  	} else
>  		printf("rdtscp not supported\n");
> -	return 0;
> +	return report_summary();
>  }
> -- 
> 2.8.1
> 
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH v3 4/9] x86/pmu: expect failure with nmi_watchdog

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:46PM +0200, Radim Krčmář wrote:
> Host's nmi_watchdog takes one slot, making the "all counters" unit-test
> fail.  We know exactly what happens, mark it as expected failure.
> 
> PMU test is now executed regardless of host_nmi_watchdog.
> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  x86/pmu.c         | 9 ++++++++-
>  x86/unittests.cfg | 3 +--
>  2 files changed, 9 insertions(+), 3 deletions(-)
> 
> diff --git a/x86/pmu.c b/x86/pmu.c
> index c68980044dee..70e9b3a41e96 100644
> --- a/x86/pmu.c
> +++ b/x86/pmu.c
> @@ -92,6 +92,7 @@ struct pmu_event {
>  };
>  
>  static int num_counters;
> +static bool host_nmi_watchdog;
>  
>  char *buf;
>  
> @@ -291,7 +292,7 @@ static void check_counters_many(void)
>  		if (!verify_counter(&cnt[i]))
>  			break;
>  
> -	report("all counters", i == n);
> +	report_xfail("all counters", host_nmi_watchdog, i == n);
>  }
>  
>  static void check_counter_overflow(void)
> @@ -374,6 +375,7 @@ static void check_rdpmc(void)
>  
>  int main(int ac, char **av)
>  {
> +	int i;
>  	struct cpuid id = cpuid(10);
>  
>  	setup_vm();
> @@ -385,6 +387,11 @@ int main(int ac, char **av)
>  	ebx.full = id.b;
>  	edx.full = id.d;
>  
> +	/* XXX: horrible command line parsing */
> +	for (i = 1; i < ac; i++)

This should be i = 0. Yes, I know, that's a crappy inconsistency we
have. I have somewhere low on the todo an item to try and find a way
for argv[0] to be the testname, but it's probably not worth it...
Hmm, an easy good 'nuff solution might be to always have argv[0] be
"TEST" or some such though.

> +		if (!strcmp(av[i], "host_nmi_watchdog=1"))
> +			host_nmi_watchdog = true;

You could use lib/util's parse_keyval here instead.

> +
>  	if (!eax.split.version_id) {
>  		printf("No pmu is detected!\n");
>  		return report_summary();
> diff --git a/x86/unittests.cfg b/x86/unittests.cfg
> index 60747cfca94e..3852b40a2927 100644
> --- a/x86/unittests.cfg
> +++ b/x86/unittests.cfg
> @@ -121,8 +121,7 @@ file = msr.flat
>  
>  [pmu]
>  file = pmu.flat
> -extra_params = -cpu host
> -check = /proc/sys/kernel/nmi_watchdog=0
> +extra_params = -cpu host -append "host_nmi_watchdog=`cat /proc/sys/kernel/nmi_watchdog`"
>  
>  [port80]
>  file = port80.flat
> -- 
> 2.8.1
> 
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH v3 5/9] lib/report: don't print 0 failed tests

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:47PM +0200, Radim Krčmář wrote:
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  lib/report.c | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/lib/report.c b/lib/report.c
> index 430b2aeaecbd..4cd75534f978 100644
> --- a/lib/report.c
> +++ b/lib/report.c
> @@ -95,7 +95,9 @@ int report_summary(void)
>  {
>  	spin_lock(&lock);
>  
> -	printf("\nSUMMARY: %d tests, %d unexpected failures", tests, failures);
> +	printf("\nSUMMARY: %d tests", tests);
> +	if (failures)
> +		printf(", %d unexpected failures", failures);
>  	if (xfailures)
>  		printf(", %d expected failures", xfailures);
>  	if (skipped)
> -- 
> 2.8.1
>

Reviewed-by: Andrew Jones <drjones@redhat.com> 

Re: [PATCH v3 6/9] scripts/runtime: skip tests that cannot run

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:48PM +0200, Radim Krčmář wrote:
> A case where QEMU won't run the kernel should be considered as skipped.
> Hyper-V tests used to FAIL on old QEMUs.  The infamous QEMU=/dev/null
> FAIL streak is covered too.
> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  scripts/runtime.bash | 6 ++++++
>  1 file changed, 6 insertions(+)
> 
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index ed073721216c..4f29a59307f3 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -39,6 +39,12 @@ function run()
>          fi
>      done
>  
> +    cmdline="TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run /dev/null -smp $smp $opts"
> +    eval $cmdline |& grep -q "could not load kernel" || {
> +        echo "skip $1 (QEMU won't run)"
> +        return 2
> +    }

This doesn't seem to work for arm; qemu just hangs with a /dev/null
kernel. Also, this will echo an extra command line per test to the
test.log.

$(TEST_DIR)/run scripts already do some qemu testing to make sure their
machine model and testdevs are available. If not, they return 2. Isn't
that good enough? Don't we just need to add a '$ret = 2' condition in
run()?

> +
>      cmdline="TESTNAME=$testname TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run $kernel -smp $smp $opts"
>      if [ "$verbose" = "yes" ]; then
>          echo $cmdline
> -- 
> 2.8.1
> 
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH v3 7/9] scripts/runtime: consolidate summary tags

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:49PM +0200, Radim Krčmář wrote:
> Turn skip into yellow SKIP and add reusable definitions of all tags.
> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  scripts/runtime.bash | 18 +++++++++++-------
>  1 file changed, 11 insertions(+), 7 deletions(-)
> 
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index 4f29a59307f3..59f0df080988 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -2,6 +2,10 @@
>  : ${MAX_SMP:=$(getconf _NPROCESSORS_CONF)}
>  : ${TIMEOUT:=90s}
>  
> +PASS() { echo -ne "\e[32mPASS\e[0m"; }
> +SKIP() { echo -ne "\e[33mSKIP\e[0m"; }
> +FAIL() { echo -ne "\e[31mFAIL\e[0m"; }
> +
>  function run()
>  {
>      local testname="$1"
> @@ -23,7 +27,7 @@ function run()
>      fi
>  
>      if [ -n "$arch" ] && [ "$arch" != "$ARCH" ]; then
> -        echo "skip $1 ($arch only)"
> +        echo "`SKIP` $1 ($arch only)"
>          return 2
>      fi
>  
> @@ -34,14 +38,14 @@ function run()
>          path=${check_param%%=*}
>          value=${check_param#*=}
>          if [ "$path" ] && [ "$(cat $path)" != "$value" ]; then
> -            echo "skip $1 ($path not equal to $value)"
> +            echo "`SKIP` $1 ($path not equal to $value)"
>              return 2
>          fi
>      done
>  
>      cmdline="TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run /dev/null -smp $smp $opts"
>      eval $cmdline |& grep -q "could not load kernel" || {
> -        echo "skip $1 (QEMU won't run)"
> +        echo "`SKIP` $1 (QEMU won't run)"
>          return 2
>      }
>  
> @@ -56,13 +60,13 @@ function run()
>      ret=$?
>  
>      if [ $ret -eq 0 ]; then
> -        echo -e "\e[32mPASS\e[0m $1"
> +        echo "`PASS` $1"
>      elif [ $ret -eq 77 ]; then
> -        echo -e "\e[33mSKIP\e[0m $1"
> +        echo "`SKIP` $1"
>      elif [ $ret -eq 124 ]; then
> -        echo -e "\e[31mFAIL\e[0m $1 (timeout; duration=$timeout)"
> +        echo "`FAIL` $1 (timeout; duration=$timeout)"
>      else
> -        echo -e "\e[31mFAIL\e[0m $1"
> +        echo "`FAIL` $1"
>      fi
>  
>      return $ret
> -- 
> 2.8.1
>

Reviewed-by: Andrew Jones <drjones@redhat.com> 

Re: [PATCH v3 8/9] run_tests: print summary

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:50PM +0200, Radim Krčmář wrote:
> SUMMARY line is present if the test uses lib/report.  Summary contains
> some interesting information, so duplicating the output isn't that big
> of a cost.  Our log redirection got more complicated, though.
> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  run_tests.sh            |  6 +++---
>  scripts/mkstandalone.sh |  3 +++
>  scripts/runtime.bash    | 15 ++++++++++-----
>  3 files changed, 16 insertions(+), 8 deletions(-)
> 
> diff --git a/run_tests.sh b/run_tests.sh
> index 7e0237f3aa11..2a0082163423 100755
> --- a/run_tests.sh
> +++ b/run_tests.sh
> @@ -25,6 +25,7 @@ specify the appropriate qemu binary for ARCH-run.
>  EOF
>  }
>  
> +RUNTIME_log_stdout="/dev/null"
>  RUNTIME_arch_run="./$TEST_DIR/run"
>  source scripts/runtime.bash
>  
> @@ -47,12 +48,11 @@ while getopts "g:hv" opt; do
>  done
>  
>  if [ "$PRETTY_PRINT_STACKS" = "yes" ]; then
> -	log_redir="> >(./scripts/pretty_print_stacks.py \$kernel >> test.log)"
> +	RUNTIME_log_stdout='>(./scripts/pretty_print_stacks.py $kernel >> test.log)'
>  else
> -	log_redir=">> test.log"
> +	RUNTIME_log_stdout='test.log'
>  fi
>  
> -RUNTIME_arch_run="./$TEST_DIR/run $log_redir"
>  config=$TEST_DIR/unittests.cfg
>  rm -f test.log
>  printf "BUILD_HEAD=$(cat build-head)\n\n" > test.log
> diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
> index ef15bc88a22a..ee01fe0c7777 100755
> --- a/scripts/mkstandalone.sh
> +++ b/scripts/mkstandalone.sh
> @@ -68,6 +68,9 @@ generate_test ()
>  	(echo "#!/bin/bash"
>  	 cat scripts/arch-run.bash "$TEST_DIR/run") | temp_file RUNTIME_arch_run
>  
> +	echo "exec {stdout}>&1"
> +	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
> +
>  	cat scripts/runtime.bash
>  
>  	echo "run ${args[@]}"
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index 59f0df080988..fc4be91d8727 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -6,6 +6,11 @@ PASS() { echo -ne "\e[32mPASS\e[0m"; }
>  SKIP() { echo -ne "\e[33mSKIP\e[0m"; }
>  FAIL() { echo -ne "\e[31mFAIL\e[0m"; }
>  
> +extract_summary()
> +{
> +    tail -1 | grep '^SUMMARY: ' | sed 's/^SUMMARY: /(/;s/$/)/'
> +}
> +
>  function run()
>  {
>      local testname="$1"
> @@ -55,18 +60,18 @@ function run()
>      fi
>  
>      # extra_params in the config file may contain backticks that need to be
> -    # expanded, so use eval to start qemu
> -    eval $cmdline
> +    # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))

The depth of our stdout resolution is getting insane. Oh well, let's see
how deep we can go before we throw our hands up and just rewrite all these
bash scripts in python.

>      ret=$?
>  
>      if [ $ret -eq 0 ]; then
> -        echo "`PASS` $1"
> +        echo "`PASS` $1 $summary"
>      elif [ $ret -eq 77 ]; then
> -        echo "`SKIP` $1"
> +        echo "`SKIP` $1 $summary"
>      elif [ $ret -eq 124 ]; then
>          echo "`FAIL` $1 (timeout; duration=$timeout)"
>      else
> -        echo "`FAIL` $1"
> +        echo "`FAIL` $1 $summary"
>      fi
>  
>      return $ret
> -- 
> 2.8.1
>

Reviewed-by: Andrew Jones <drjones@redhat.com>

Re: [PATCH v3 9/9] run_tests: log stderr

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:51PM +0200, Radim Krčmář wrote:
> After recent changes to logging, seeing it all the time doesn't help.
> We could print one line in summary if stderr is missed.

I miss it already :-)

I like stderr coming to the terminal from which run_tests.sh is run,
because it should be rare and probably important to see. I'd rather
this patch at least include the one summary line now, rather than
wait and see if we want it later. Or maybe just drop this patch?

One more comment below.

> 
> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> ---
>  run_tests.sh            | 1 +
>  scripts/mkstandalone.sh | 1 +
>  scripts/runtime.bash    | 3 ++-
>  3 files changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/run_tests.sh b/run_tests.sh
> index 2a0082163423..3592db317897 100755
> --- a/run_tests.sh
> +++ b/run_tests.sh
> @@ -47,6 +47,7 @@ while getopts "g:hv" opt; do
>      esac
>  done
>  
> +RUNTIME_log_stderr='test.log'
>  if [ "$PRETTY_PRINT_STACKS" = "yes" ]; then
>  	RUNTIME_log_stdout='>(./scripts/pretty_print_stacks.py $kernel >> test.log)'
>  else
> diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
> index ee01fe0c7777..af2b8f43743c 100755
> --- a/scripts/mkstandalone.sh
> +++ b/scripts/mkstandalone.sh
> @@ -70,6 +70,7 @@ generate_test ()
>  
>  	echo "exec {stdout}>&1"
>  	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
> +	echo "RUNTIME_log_stderr=>(cat >&2)"

No need for the single quotes like RUNTIME_log_stdout has? Or
does RUNTIME_log_stdout not need them?

>  
>  	cat scripts/runtime.bash
>  
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index fc4be91d8727..ff2d98b547b5 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -61,7 +61,8 @@ function run()
>  
>      # extra_params in the config file may contain backticks that need to be
>      # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
> -    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary) \
> +                            2>> $RUNTIME_log_stderr)
>      ret=$?
>  
>      if [ $ret -eq 0 ]; then
> -- 
> 2.8.1
>

Thanks,
drew 

Re: [PATCH kvm-unit-tests v3 0/9] Improve the output of test runners

[Andrew Jones]

On Fri, Apr 15, 2016 at 10:52:42PM +0200, Radim Krčmář wrote:
> v2: http://www.spinics.net/lists/kvm/msg125429.html
> 
> mkstandalone is using generic code now, so v3 focuses on the output
> again.  And the output looks like in v2.  Since v2, I've
> * removed svm-disabled [3/7]
> * reworked summary reporting [8/9] (it's a nice feature, but still ugly)
> * turned all cases when QEMU won't run the test into SKIP [6/7]
> * preserved check_param (it's not used, though)
> * stopped returning 77 on all SKIPs [7/7] (a sacrifice to prevent
>   another refactoring of our scripts)
> 
> I didn't manage to look at the comment from Lukáš's patches, but I don't
> expect that v3 will be the last one ... a lot has changed since v2.

Lukas' comment was that the skip due to a test needing KVM (i.e. not
possible to run with TCG) should get a more informative summary. He
wanted something along the lines of 'kvm test only, and this system
doesn't have kvm', rather than just 'kvm only'.

Oh, actually those summaries are arm and powerpc run script summaries,
not common runtime. They could still be improved with this series :-)

Thanks,
drew

> 
> 
> Radim Krčmář (9):
>   lib/report: allow test skipping
>   x86/*: report skipped tests
>   x86/unittests: remove svm-disabled
>   x86/pmu: expect failure with nmi_watchdog
>   lib/report: don't print 0 failed tests
>   scripts/runtime: skip tests that cannot run
>   scripts/runtime: consolidate summary tags
>   run_tests: print summary
>   run_tests: log stderr
> 
>  lib/libcflat.h          |  1 +
>  lib/report.c            | 49 ++++++++++++++++++++++++++++++++++---------------
>  run_tests.sh            |  7 ++++---
>  scripts/mkstandalone.sh |  4 ++++
>  scripts/runtime.bash    | 32 +++++++++++++++++++++++++-------
>  x86/apic.c              |  7 +++----
>  x86/emulator.c          |  2 +-
>  x86/hyperv_synic.c      |  2 +-
>  x86/pku.c               |  2 +-
>  x86/pmu.c               | 11 +++++++++--
>  x86/smap.c              |  2 +-
>  x86/svm.c               |  2 +-
>  x86/tsc.c               |  2 +-
>  x86/unittests.cfg       |  9 +--------
>  14 files changed, 87 insertions(+), 45 deletions(-)
> 
> -- 
> 2.8.1
> 
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH v3 2/9] x86/*: report skipped tests

[Radim Krčmář]

2016-04-19 08:34+0200, Andrew Jones:
> On Fri, Apr 15, 2016 at 10:52:44PM +0200, Radim Krčmář wrote:
>> No care to consistency or exhaustivity was given.
> 
> Me neither, but I see that x86/tscdeadline_latency.c could use similar
> updates too.

Thanks, I'll change it in v2.
(I missed it, because it's not a test that is run with ./run_tests.sh.)

Re: [PATCH v3 4/9] x86/pmu: expect failure with nmi_watchdog

[Radim Krčmář]

2016-04-19 08:44+0200, Andrew Jones:
> On Fri, Apr 15, 2016 at 10:52:46PM +0200, Radim Krčmář wrote:
> > Host's nmi_watchdog takes one slot, making the "all counters" unit-test
> > fail.  We know exactly what happens, mark it as expected failure.
> > 
> > PMU test is now executed regardless of host_nmi_watchdog.
> > 
> > Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> > ---
> >  x86/pmu.c         | 9 ++++++++-
> >  x86/unittests.cfg | 3 +--
> >  2 files changed, 9 insertions(+), 3 deletions(-)
> > 
> > diff --git a/x86/pmu.c b/x86/pmu.c
> > index c68980044dee..70e9b3a41e96 100644
> > --- a/x86/pmu.c
> > +++ b/x86/pmu.c
> > @@ -92,6 +92,7 @@ struct pmu_event {
> >  };
> >  
> >  static int num_counters;
> > +static bool host_nmi_watchdog;
> >  
> >  char *buf;
> >  
> > @@ -291,7 +292,7 @@ static void check_counters_many(void)
> >  		if (!verify_counter(&cnt[i]))
> >  			break;
> >  
> > -	report("all counters", i == n);
> > +	report_xfail("all counters", host_nmi_watchdog, i == n);
> >  }
> >  
> >  static void check_counter_overflow(void)
> > @@ -374,6 +375,7 @@ static void check_rdpmc(void)
> >  
> >  int main(int ac, char **av)
> >  {
> > +	int i;
> >  	struct cpuid id = cpuid(10);
> >  
> >  	setup_vm();
> > @@ -385,6 +387,11 @@ int main(int ac, char **av)
> >  	ebx.full = id.b;
> >  	edx.full = id.d;
> >  
> > +	/* XXX: horrible command line parsing */
> > +	for (i = 1; i < ac; i++)
> 
> This should be i = 0. Yes, I know, that's a crappy inconsistency we
> have. I have somewhere low on the todo an item to try and find a way
> for argv[0] to be the testname, but it's probably not worth it...
> Hmm, an easy good 'nuff solution might be to always have argv[0] be
> "TEST" or some such though.

argv[0] is the test name for me ... if I modify the loop to print them
all, then

  % /x86-run x86/pmu.flat -append "a b c"
  0: x86/pmu.flat
  1: a
  2: b
  3: c

>> +		if (!strcmp(av[i], "host_nmi_watchdog=1"))
>> +			host_nmi_watchdog = true;
> 
> You could use lib/util's parse_keyval here instead.

Wow, so it didn't have to be horrible ...

Re: [PATCH v3 6/9] scripts/runtime: skip tests that cannot run

[Radim Krčmář]

2016-04-19 09:01+0200, Andrew Jones:
> On Fri, Apr 15, 2016 at 10:52:48PM +0200, Radim Krčmář wrote:
> > A case where QEMU won't run the kernel should be considered as skipped.
> > Hyper-V tests used to FAIL on old QEMUs.  The infamous QEMU=/dev/null
> > FAIL streak is covered too.
> > 
> > Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> > ---
> >  scripts/runtime.bash | 6 ++++++
> >  1 file changed, 6 insertions(+)
> > 
> > diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> > index ed073721216c..4f29a59307f3 100644
> > --- a/scripts/runtime.bash
> > +++ b/scripts/runtime.bash
> > @@ -39,6 +39,12 @@ function run()
> >          fi
> >      done
> >  
> > +    cmdline="TIMEOUT=$timeout ACCEL=$accel $RUNTIME_arch_run /dev/null -smp $smp $opts"
> > +    eval $cmdline |& grep -q "could not load kernel" || {
> > +        echo "skip $1 (QEMU won't run)"
> > +        return 2
> > +    }
> 
> This doesn't seem to work for arm; qemu just hangs with a /dev/null
> kernel.

Thanks, I'll be using _NO_FILE_4Uhere_, like scripts/runtime does.

>         Also, this will echo an extra command line per test to the
> test.log.

Changing the logging mechanism in [8/9] got rid of it, but I forgot to
mention it.  Patches need a bit of reshufling to make it logical ...

> $(TEST_DIR)/run scripts already do some qemu testing to make sure their
> machine model and testdevs are available. If not, they return 2. Isn't
> that good enough?

QEMU can fail, because we appended something that isn't supported, like
hyperv tests do.  Then the test is a FAIL.

>                   Don't we just need to add a '$ret = 2' condition in
> run()?

What if we changed that return value to 77?  The test wasn't really run.

Re: [PATCH v3 9/9] run_tests: log stderr

[Radim Krčmář]

2016-04-19 09:26+0200, Andrew Jones:
> On Fri, Apr 15, 2016 at 10:52:51PM +0200, Radim Krčmář wrote:
>> After recent changes to logging, seeing it all the time doesn't help.
>> We could print one line in summary if stderr is missed.
> 
> I miss it already :-)
> 
> I like stderr coming to the terminal from which run_tests.sh is run,
> because it should be rare and probably important to see. I'd rather
> this patch at least include the one summary line now, rather than
> wait and see if we want it later.

Messages in stderr aren't rare, though ... we see several of them on
every batch:

warning: host doesn't support requested feature: CPUID.80000001H:ECX.svm [bit 2]
warning: host doesn't support requested feature: CPUID.80000001H:ECX.svm [bit 2]
warning: host doesn't support requested feature: CPUID.01H:ECX.vmx [bit 5]

(Warnings already screw up our FAIL heuristic, so we'd better do
 something with them ...)

>                                   Or maybe just drop this patch?

I'll drop this patch, it was borderline acceptable and making the
summary bearable would might be out of my league.

>> diff --git a/run_tests.sh b/run_tests.sh
>> @@ -47,6 +47,7 @@ while getopts "g:hv" opt; do
>> +RUNTIME_log_stderr='test.log'
>> diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
>> @@ -70,6 +70,7 @@ generate_test ()
>> +	echo "RUNTIME_log_stderr=>(cat >&2)"
> 
> No need for the single quotes like RUNTIME_log_stdout has? Or
> does RUNTIME_log_stdout not need them?

*evil laugh*, both of them need quotes just where they are.

RUNTIME_log_stdout is used in a subshell that wouldn't have access to
the fd if we evaluated it here.
RUNTIME_log_stderr has to be evaluated into the fd here, because it
wouldn't be evaluated in the future.

(Take a while to apprectiate this hellspawn.)

>> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
>> @@ -61,7 +61,8 @@ function run()
>> -    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
>> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary) \
>> +                            2>> $RUNTIME_log_stderr)

Re: [PATCH kvm-unit-tests v3 0/9] Improve the output of test runners

[Radim Krčmář]

2016-04-19 09:31+0200, Andrew Jones:
> On Fri, Apr 15, 2016 at 10:52:42PM +0200, Radim Krčmář wrote:
>> v2: http://www.spinics.net/lists/kvm/msg125429.html
>> 
>> mkstandalone is using generic code now, so v3 focuses on the output
>> again.  And the output looks like in v2.  Since v2, I've
>> * removed svm-disabled [3/7]
>> * reworked summary reporting [8/9] (it's a nice feature, but still ugly)
>> * turned all cases when QEMU won't run the test into SKIP [6/7]
>> * preserved check_param (it's not used, though)
>> * stopped returning 77 on all SKIPs [7/7] (a sacrifice to prevent
>>   another refactoring of our scripts)
>> 
>> I didn't manage to look at the comment from Lukáš's patches, but I don't
>> expect that v3 will be the last one ... a lot has changed since v2.
> 
> Lukas' comment was that the skip due to a test needing KVM (i.e. not
> possible to run with TCG) should get a more informative summary. He
> wanted something along the lines of 'kvm test only, and this system
> doesn't have kvm', rather than just 'kvm only'.
> 
> Oh, actually those summaries are arm and powerpc run script summaries,
> not common runtime. They could still be improved with this series :-)

Thanks for reviews ... I'll handle it.

Re: [PATCH v3 4/9] x86/pmu: expect failure with nmi_watchdog

[Andrew Jones]

On Tue, Apr 19, 2016 at 01:57:13PM +0200, Radim Krčmář wrote:
> 2016-04-19 08:44+0200, Andrew Jones:
> > On Fri, Apr 15, 2016 at 10:52:46PM +0200, Radim Krčmář wrote:
> > > Host's nmi_watchdog takes one slot, making the "all counters" unit-test
> > > fail.  We know exactly what happens, mark it as expected failure.
> > > 
> > > PMU test is now executed regardless of host_nmi_watchdog.
> > > 
> > > Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
> > > ---
> > >  x86/pmu.c         | 9 ++++++++-
> > >  x86/unittests.cfg | 3 +--
> > >  2 files changed, 9 insertions(+), 3 deletions(-)
> > > 
> > > diff --git a/x86/pmu.c b/x86/pmu.c
> > > index c68980044dee..70e9b3a41e96 100644
> > > --- a/x86/pmu.c
> > > +++ b/x86/pmu.c
> > > @@ -92,6 +92,7 @@ struct pmu_event {
> > >  };
> > >  
> > >  static int num_counters;
> > > +static bool host_nmi_watchdog;
> > >  
> > >  char *buf;
> > >  
> > > @@ -291,7 +292,7 @@ static void check_counters_many(void)
> > >  		if (!verify_counter(&cnt[i]))
> > >  			break;
> > >  
> > > -	report("all counters", i == n);
> > > +	report_xfail("all counters", host_nmi_watchdog, i == n);
> > >  }
> > >  
> > >  static void check_counter_overflow(void)
> > > @@ -374,6 +375,7 @@ static void check_rdpmc(void)
> > >  
> > >  int main(int ac, char **av)
> > >  {
> > > +	int i;
> > >  	struct cpuid id = cpuid(10);
> > >  
> > >  	setup_vm();
> > > @@ -385,6 +387,11 @@ int main(int ac, char **av)
> > >  	ebx.full = id.b;
> > >  	edx.full = id.d;
> > >  
> > > +	/* XXX: horrible command line parsing */
> > > +	for (i = 1; i < ac; i++)
> > 
> > This should be i = 0. Yes, I know, that's a crappy inconsistency we
> > have. I have somewhere low on the todo an item to try and find a way
> > for argv[0] to be the testname, but it's probably not worth it...
> > Hmm, an easy good 'nuff solution might be to always have argv[0] be
> > "TEST" or some such though.
> 
> argv[0] is the test name for me ... if I modify the loop to print them
> all, then
> 
>   % /x86-run x86/pmu.flat -append "a b c"
>   0: x86/pmu.flat
>   1: a
>   2: b
>   3: c

Ohhhh.... I thought for sure that all arches had this wrong. Looks like,
thanks to seabios, x86 is right. That now raises the priority of getting
arm and powerpc right too. I'll send patches soon.

> 
> >> +		if (!strcmp(av[i], "host_nmi_watchdog=1"))
> >> +			host_nmi_watchdog = true;
> > 
> > You could use lib/util's parse_keyval here instead.
> 
> Wow, so it didn't have to be horrible ...
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH v3 9/9] run_tests: log stderr

[Paolo Bonzini]

On 15/04/2016 22:52, Radim Krčmář wrote:
>  	echo "exec {stdout}>&1"
>  	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
> +	echo "RUNTIME_log_stderr=>(cat >&2)"
>  
>  	cat scripts/runtime.bash
>  
> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
> index fc4be91d8727..ff2d98b547b5 100644
> --- a/scripts/runtime.bash
> +++ b/scripts/runtime.bash
> @@ -61,7 +61,8 @@ function run()
>  
>      # extra_params in the config file may contain backticks that need to be
>      # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
> -    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary) \
> +                            2>> $RUNTIME_log_stderr)

Whoa, so this uses the outer eval?  Perhaps the 2>> should move before
the >.

Paolo

Re: [PATCH v3 8/9] run_tests: print summary

[Paolo Bonzini]

On 19/04/2016 09:19, Andrew Jones wrote:
> On Fri, Apr 15, 2016 at 10:52:50PM +0200, Radim Krčmář wrote:
>> SUMMARY line is present if the test uses lib/report.  Summary contains
>> some interesting information, so duplicating the output isn't that big
>> of a cost.  Our log redirection got more complicated, though.
>>
>> Signed-off-by: Radim Krčmář <rkrcmar@redhat.com>
>> ---
>>  run_tests.sh            |  6 +++---
>>  scripts/mkstandalone.sh |  3 +++
>>  scripts/runtime.bash    | 15 ++++++++++-----
>>  3 files changed, 16 insertions(+), 8 deletions(-)
>>
>> diff --git a/run_tests.sh b/run_tests.sh
>> index 7e0237f3aa11..2a0082163423 100755
>> --- a/run_tests.sh
>> +++ b/run_tests.sh
>> @@ -25,6 +25,7 @@ specify the appropriate qemu binary for ARCH-run.
>>  EOF
>>  }
>>  
>> +RUNTIME_log_stdout="/dev/null"
>>  RUNTIME_arch_run="./$TEST_DIR/run"
>>  source scripts/runtime.bash
>>  
>> @@ -47,12 +48,11 @@ while getopts "g:hv" opt; do
>>  done
>>  
>>  if [ "$PRETTY_PRINT_STACKS" = "yes" ]; then
>> -	log_redir="> >(./scripts/pretty_print_stacks.py \$kernel >> test.log)"
>> +	RUNTIME_log_stdout='>(./scripts/pretty_print_stacks.py $kernel >> test.log)'
>>  else
>> -	log_redir=">> test.log"
>> +	RUNTIME_log_stdout='test.log'
>>  fi
>>  
>> -RUNTIME_arch_run="./$TEST_DIR/run $log_redir"
>>  config=$TEST_DIR/unittests.cfg
>>  rm -f test.log
>>  printf "BUILD_HEAD=$(cat build-head)\n\n" > test.log
>> diff --git a/scripts/mkstandalone.sh b/scripts/mkstandalone.sh
>> index ef15bc88a22a..ee01fe0c7777 100755
>> --- a/scripts/mkstandalone.sh
>> +++ b/scripts/mkstandalone.sh
>> @@ -68,6 +68,9 @@ generate_test ()
>>  	(echo "#!/bin/bash"
>>  	 cat scripts/arch-run.bash "$TEST_DIR/run") | temp_file RUNTIME_arch_run
>>  
>> +	echo "exec {stdout}>&1"
>> +	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
>> +
>>  	cat scripts/runtime.bash
>>  
>>  	echo "run ${args[@]}"
>> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
>> index 59f0df080988..fc4be91d8727 100644
>> --- a/scripts/runtime.bash
>> +++ b/scripts/runtime.bash
>> @@ -6,6 +6,11 @@ PASS() { echo -ne "\e[32mPASS\e[0m"; }
>>  SKIP() { echo -ne "\e[33mSKIP\e[0m"; }
>>  FAIL() { echo -ne "\e[31mFAIL\e[0m"; }
>>  
>> +extract_summary()
>> +{
>> +    tail -1 | grep '^SUMMARY: ' | sed 's/^SUMMARY: /(/;s/$/)/'
>> +}
>> +
>>  function run()
>>  {
>>      local testname="$1"
>> @@ -55,18 +60,18 @@ function run()
>>      fi
>>  
>>      # extra_params in the config file may contain backticks that need to be
>> -    # expanded, so use eval to start qemu
>> -    eval $cmdline
>> +    # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
>> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
> 
> The depth of our stdout resolution is getting insane. Oh well, let's see
> how deep we can go before we throw our hands up and just rewrite all these
> bash scripts in python.

Why not just use a pipe here?

eval $cmdline 2>> $RUNTIME_log_stderr \
              | eval tee -a "$RUNTIME_log_stdout" | extract_summary

Anything I am missing?

Paolo

>>      ret=$?
>>  
>>      if [ $ret -eq 0 ]; then
>> -        echo "`PASS` $1"
>> +        echo "`PASS` $1 $summary"
>>      elif [ $ret -eq 77 ]; then
>> -        echo "`SKIP` $1"
>> +        echo "`SKIP` $1 $summary"
>>      elif [ $ret -eq 124 ]; then
>>          echo "`FAIL` $1 (timeout; duration=$timeout)"
>>      else
>> -        echo "`FAIL` $1"
>> +        echo "`FAIL` $1 $summary"
>>      fi
>>  
>>      return $ret
>> -- 
>> 2.8.1
>>
> 
> Reviewed-by: Andrew Jones <drjones@redhat.com>
> 

Re: [PATCH v3 8/9] run_tests: print summary

[Radim Krčmář]

2016-05-10 13:45+0200, Paolo Bonzini:
> On 19/04/2016 09:19, Andrew Jones wrote:
>> On Fri, Apr 15, 2016 at 10:52:50PM +0200, Radim Krčmář wrote:
>>>      # extra_params in the config file may contain backticks that need to be
>>> -    # expanded, so use eval to start qemu
>>> -    eval $cmdline
>>> +    # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
>>> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
>> 
>> The depth of our stdout resolution is getting insane. Oh well, let's see
>> how deep we can go before we throw our hands up and just rewrite all these
>> bash scripts in python.
> 
> Why not just use a pipe here?
> 
> eval $cmdline 2>> $RUNTIME_log_stderr \
>               | eval tee -a "$RUNTIME_log_stdout" | extract_summary
> 
> Anything I am missing?
> 
>>>      ret=$?

Simple pipeline would not return the return value of `eval $cmdline`, so
it seemed nicer with a redirection.

Re: [PATCH v3 9/9] run_tests: log stderr

[Radim Krčmář]

2016-05-10 13:41+0200, Paolo Bonzini:
> On 15/04/2016 22:52, Radim Krčmář wrote:
>>  	echo "exec {stdout}>&1"
>>  	echo "RUNTIME_log_stdout='>(cat >&\$stdout)'"
>> +	echo "RUNTIME_log_stderr=>(cat >&2)"
>>  
>>  	cat scripts/runtime.bash
>>  
>> diff --git a/scripts/runtime.bash b/scripts/runtime.bash
>> index fc4be91d8727..ff2d98b547b5 100644
>> --- a/scripts/runtime.bash
>> +++ b/scripts/runtime.bash
>> @@ -61,7 +61,8 @@ function run()
>>  
>>      # extra_params in the config file may contain backticks that need to be
>>      # expanded, so use eval to start qemu.  Same for $RUNTIME_log_stdout.
>> -    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary))
>> +    summary=$(eval $cmdline > >(eval "tee -a $RUNTIME_log_stdout" | extract_summary) \
>> +                            2>> $RUNTIME_log_stderr)
> 
> Whoa, so this uses the outer eval?

No, RUNTIME_log_stderr is evaluated only at the time of definition,
which makes it inconsistent with RUNTIME_log_stdout.

>                                     Perhaps the 2>> should move before
> the >.

I will drop this patch ... it's too insane and Drew liked stderr in
./run_tests.sh output.  Sorry.

Re: [PATCH v3 8/9] run_tests: print summary

[Paolo Bonzini]

On 10/05/2016 14:41, Radim Krčmář wrote:
>> > eval $cmdline 2>> $RUNTIME_log_stderr \
>> >               | eval tee -a "$RUNTIME_log_stdout" | extract_summary
>> > 
>> > Anything I am missing?
>> > 
>>>> >>>      ret=$?
> Simple pipeline would not return the return value of `eval $cmdline`, so
> it seemed nicer with a redirection.

Right...  Two more attempts:

    eval "$cmdline 2>> $RUNTIME_log_stderr
                   > >(tee -a $RUNTIME_log_stdout | extract_summary)"

    (eval $cmdline) 2> >($RUNTIME_cmd_stderr)
                     > >(tee >($RUNTIME_cmd_stdout) | extract_summary)"

(The latter requiring an extra useless uses of cat for test.log).

Would any of these work fine?

Paolo

Re: [PATCH v3 8/9] run_tests: print summary

[Radim Krčmář]

2016-05-10 16:32+0200, Paolo Bonzini:
> On 10/05/2016 14:41, Radim Krčmář wrote:
>>> > eval $cmdline 2>> $RUNTIME_log_stderr \
>>> >               | eval tee -a "$RUNTIME_log_stdout" | extract_summary
>>> > 
>>> > Anything I am missing?
>>> > 
>>>>> >>>      ret=$?
>> Simple pipeline would not return the return value of `eval $cmdline`, so
>> it seemed nicer with a redirection.
> 
> Right...  Two more attempts:
> 
>     eval "$cmdline 2>> $RUNTIME_log_stderr
>                    > >(tee -a $RUNTIME_log_stdout | extract_summary)"
> 
>     (eval $cmdline) 2> >($RUNTIME_cmd_stderr)
>                      > >(tee >($RUNTIME_cmd_stdout) | extract_summary)"
> 
> (The latter requiring an extra useless uses of cat for test.log).
> 
> Would any of these work fine?

The former one works.  The latter would work if $RUNTIME_cmd_stdout
accepted $kernel as an argument.

  summary=$(eval $cmdline
            > >(tee >(RUNTIME_log_stdout $kernel) | extract_summary))

Is that acceptable?
(I will gladly degrade performance to have less code in eval.)

Thanks.

Re: [PATCH v3 8/9] run_tests: print summary

[Paolo Bonzini]

On 10/05/2016 17:31, Radim Krčmář wrote:
> The former one works.  The latter would work if $RUNTIME_cmd_stdout
> accepted $kernel as an argument.
> 
>   summary=$(eval $cmdline
>             > >(tee >(RUNTIME_log_stdout $kernel) | extract_summary))
>
> Is that acceptable?
> (I will gladly degrade performance to have less code in eval.)

Yeah, same here.  Also "2> >(RUNTIME_log_stderr)"?

Thanks,

Paolo

Re: [PATCH v3 8/9] run_tests: print summary

[Radim Krčmář]

2016-05-10 17:46+0200, Paolo Bonzini:
> On 10/05/2016 17:31, Radim Krčmář wrote:
>> The former one works.  The latter would work if $RUNTIME_cmd_stdout
>> accepted $kernel as an argument.
>> 
>>   summary=$(eval $cmdline
>>             > >(tee >(RUNTIME_log_stdout $kernel) | extract_summary))
>>
>> Is that acceptable?
>> (I will gladly degrade performance to have less code in eval.)
> 
> Yeah, same here.  Also "2> >(RUNTIME_log_stderr)"?

Yes.  Time to rewrite it all!