[PATCH v3 1/7] CI: wait for Xen to start before waiting for test to complete

[Marek Marczykowski-Górecki <marmarek@xxxxxxxxxxxxxxxxxxxxxx>]

Add additional stage in console output parsing - wait for first message
from Xen. The message is defined via BOOT_MSG variable. This has two
effects:
- distinguishes failing Xen to load at all from later test failures
- resets timeout when Xen starts loading

The latter is especially relevant for hardware tests where firmware +
network boot may take some time before Xen starts booting. The two-stage
timeout is more robust solution than increasing the overall timeout.
The issue has been observed on some dom0pvh-hvm jobs, at least on
runners hw3 and hw11. This patch is a first stage before qubes-x86-64.sh
is switched to use expect in the next stage.

While at it, consistently use 'expect -re' for all matches. This
especially allows matching newlines ("\n"), which will become relevant
in the next patch. And document variables used in console.exp.

Signed-off-by: Marek Marczykowski-Górecki <marmarek@xxxxxxxxxxxxxxxxxxxxxx>
---
Changes in v3:
- split off "CI: switch qubes runners to use console.exp"
- use BOOT_MSG in more tests (all using network boot)
---
 automation/scripts/console.exp                    | 27 +++++++++++++---
 automation/scripts/qemu-alpine-x86_64.sh          |  1 +-
 automation/scripts/qemu-smoke-dom0-arm32.sh       |  1 +-
 automation/scripts/qemu-smoke-dom0-arm64.sh       |  1 +-
 automation/scripts/qemu-smoke-dom0less-arm32.sh   |  1 +-
 automation/scripts/qemu-xtf-dom0less-arm64.sh     |  1 +-
 automation/scripts/xilinx-smoke-dom0-x86_64.sh    |  1 +-
 automation/scripts/xilinx-smoke-dom0less-arm64.sh |  1 +-
 8 files changed, 29 insertions(+), 5 deletions(-)

diff --git a/automation/scripts/console.exp b/automation/scripts/console.exp
index 31ce97b91b63..c27f893dfba7 100755
--- a/automation/scripts/console.exp
+++ b/automation/scripts/console.exp
@@ -1,4 +1,17 @@
 #!/usr/bin/env expect
+#
+# Variables used by this script:
+# - TEST_TIMEOUT: timeout between each *_MSG match
+# - TEST_TIMEOUT_OVERRIDE: when set, overrides TEST_TIMEOUT
+# - TEST_LOG: save console log to this file
+# - TEST_CMD: commands that prints test system console output to stdout - in
+#   qemu tests that's usually qemu itself (with -serial stdio), in hardware
+#   tests that's a command to read serial console
+# - UBOOT_CMD (optional): command to enter at u-boot prompt
+# - BOOT_MSG (optional): initial Xen message to wait for (aka sign-of-life)
+# - LOG_MSG (optional): final console message to wait for
+# - PASSED: message to look for to consider test a success; if LOG_MSG is set,
+#   both LOG_MSG and PASSED must appear (in any order) for test to succeed
 
 if {[info exists env(TEST_TIMEOUT_OVERRIDE)]} {
     set timeout $env(TEST_TIMEOUT_OVERRIDE)
@@ -28,21 +41,25 @@ if {[info exists env(UBOOT_CMD)]} {
     send "$env(UBOOT_CMD)\r"
 }
 
+if {[info exists env(BOOT_MSG)]} {
+    expect -re "$env(BOOT_MSG)"
+}
+
 if {[info exists env(LOG_MSG)]} {
     expect {
-        "$env(PASSED)" {
-            expect "$env(LOG_MSG)"
+        -re "$env(PASSED)" {
+            expect -re "$env(LOG_MSG)"
             exit 0
         }
-        "$env(LOG_MSG)" {
-            expect "$env(PASSED)"
+        -re "$env(LOG_MSG)" {
+            expect -re "$env(PASSED)"
             exit 0
         }
     }
 }
 
 expect {
-    "$env(PASSED)" {
+    -re "$env(PASSED)" {
         exit 0
     }
 }
diff --git a/automation/scripts/qemu-alpine-x86_64.sh 
b/automation/scripts/qemu-alpine-x86_64.sh
index 17e2141d625e..89bdb4df7dac 100755
--- a/automation/scripts/qemu-alpine-x86_64.sh
+++ b/automation/scripts/qemu-alpine-x86_64.sh
@@ -85,6 +85,7 @@ export TEST_CMD="qemu-system-x86_64 \
     -netdev user,id=n0,tftp=binaries,bootfile=/pxelinux.0"
 
 export TEST_LOG="smoke.serial"
+export BOOT_MSG="Latest ChangeSet: "
 export LOG_MSG="Domain-0"
 export PASSED="BusyBox"
 
diff --git a/automation/scripts/qemu-smoke-dom0-arm32.sh 
b/automation/scripts/qemu-smoke-dom0-arm32.sh
index 0c60a66e25e3..4f50eabdef53 100755
--- a/automation/scripts/qemu-smoke-dom0-arm32.sh
+++ b/automation/scripts/qemu-smoke-dom0-arm32.sh
@@ -92,6 +92,7 @@ export TEST_CMD="./qemu-system-arm \
 
 export UBOOT_CMD="virtio scan; dhcp; tftpb 0x40000000 boot.scr; source 
0x40000000"
 export TEST_LOG="${serial_log}"
+export BOOT_MSG="Latest ChangeSet: "
 export LOG_MSG="Domain-0"
 export PASSED="/ #"
 
diff --git a/automation/scripts/qemu-smoke-dom0-arm64.sh 
b/automation/scripts/qemu-smoke-dom0-arm64.sh
index 8774a8701232..51d037b0003e 100755
--- a/automation/scripts/qemu-smoke-dom0-arm64.sh
+++ b/automation/scripts/qemu-smoke-dom0-arm64.sh
@@ -104,6 +104,7 @@ export TEST_CMD="./binaries/qemu-system-aarch64 \
     -bios /usr/lib/u-boot/qemu_arm64/u-boot.bin"
 
 export UBOOT_CMD="virtio scan; dhcp; tftpb 0x40000000 boot.scr; source 
0x40000000"
+export BOOT_MSG="Latest ChangeSet: "
 export TEST_LOG="smoke.serial"
 export LOG_MSG="Domain-0"
 export PASSED="BusyBox"
diff --git a/automation/scripts/qemu-smoke-dom0less-arm32.sh 
b/automation/scripts/qemu-smoke-dom0less-arm32.sh
index 0c94e662aab9..0e2c5496db51 100755
--- a/automation/scripts/qemu-smoke-dom0less-arm32.sh
+++ b/automation/scripts/qemu-smoke-dom0less-arm32.sh
@@ -144,6 +144,7 @@ export TEST_CMD="./qemu-system-arm \
     -bios /usr/lib/u-boot/qemu_arm/u-boot.bin"
 
 export UBOOT_CMD="virtio scan; dhcp; tftpb 0x40000000 boot.scr; source 
0x40000000"
+export BOOT_MSG="Latest ChangeSet: "
 export TEST_LOG="${serial_log}"
 export LOG_MSG="${dom0_prompt}"
 export PASSED="${passed}"
diff --git a/automation/scripts/qemu-xtf-dom0less-arm64.sh 
b/automation/scripts/qemu-xtf-dom0less-arm64.sh
index 9608de6ec033..436f460c3cb6 100755
--- a/automation/scripts/qemu-xtf-dom0less-arm64.sh
+++ b/automation/scripts/qemu-xtf-dom0less-arm64.sh
@@ -61,6 +61,7 @@ export TEST_CMD="./binaries/qemu-system-aarch64 \
     -bios /usr/lib/u-boot/qemu_arm64/u-boot.bin"
 
 export UBOOT_CMD="virtio scan; dhcp; tftpb 0x40000000 boot.scr; source 
0x40000000"
+export BOOT_MSG="Latest ChangeSet: "
 export TEST_LOG="smoke.serial"
 export PASSED="${passed}"
 
diff --git a/automation/scripts/xilinx-smoke-dom0-x86_64.sh 
b/automation/scripts/xilinx-smoke-dom0-x86_64.sh
index 7834ffbe0593..69caabe2d8ed 100755
--- a/automation/scripts/xilinx-smoke-dom0-x86_64.sh
+++ b/automation/scripts/xilinx-smoke-dom0-x86_64.sh
@@ -159,6 +159,7 @@ stty -F ${SERIAL_DEV} 57600
 
 # Capture test result and power off board before exiting.
 export PASSED="${PASS_MSG}"
+export BOOT_MSG="Latest ChangeSet: "
 export TEST_CMD="cat ${SERIAL_DEV}"
 export TEST_LOG="smoke.serial"
 
diff --git a/automation/scripts/xilinx-smoke-dom0less-arm64.sh 
b/automation/scripts/xilinx-smoke-dom0less-arm64.sh
index b24ad11b8cac..3e1fcf6bf93c 100755
--- a/automation/scripts/xilinx-smoke-dom0less-arm64.sh
+++ b/automation/scripts/xilinx-smoke-dom0less-arm64.sh
@@ -140,6 +140,7 @@ stty -F ${SERIAL_DEV} 115200
 
 # Capture test result and power off board before exiting.
 export PASSED="${passed}"
+export BOOT_MSG="Latest ChangeSet: "
 export LOG_MSG="Welcome to Alpine Linux"
 export TEST_CMD="cat ${SERIAL_DEV}"
 export TEST_LOG="smoke.serial"
-- 
git-series 0.9.1