selftests/vsock: improve logging in vmtest.sh

Improve usability of logging functions. Remove the test name prefix from
logging functions so that logging calls can be made deeper into the call
stack without passing down the test name or setting some global. Teach
log function to accept a LOG_PREFIX variable to avoid unnecessary
argument shifting.

Remove log_setup() and instead use log_host(). The host/guest prefixes
are useful to show whether a failure happened on the guest or host side,
but "setup" doesn't really give additional useful information. Since all
log_setup() calls happen on the host, lets just use log_host() instead.

Signed-off-by: Bobby Eshleman <bobbyeshleman@meta.com>
Reviewed-by: Stefano Garzarella <sgarzare@redhat.com>
Link: https://patch.msgid.link/20251108-vsock-selftests-fixes-and-improvements-v4-1-d5e8d6c87289@meta.com
Signed-off-by: Jakub Kicinski <kuba@kernel.org>

diff --git a/tools/testing/selftests/vsock/vmtest.sh b/tools/testing/selftests/vsock/vmtest.sh
index 8ceeb8a7894f5be52b60da36d4ebc64b68c97819..bc16b13cdbe3442fbeed35d5afedf053b279b718 100755 (executable)
--- a/tools/testing/selftests/vsock/vmtest.sh
+++ b/tools/testing/selftests/vsock/vmtest.sh
@@ -271,60 +271,51 @@ EOF
 
 host_wait_for_listener() {
        wait_for_listener "${TEST_HOST_PORT_LISTENER}" "${WAIT_PERIOD}" "${WAIT_PERIOD_MAX}"
-}
-
-__log_stdin() {
-       cat | awk '{ printf "%s:\t%s\n","'"${prefix}"'", $0 }'
-}
 
-__log_args() {
-       echo "$*" | awk '{ printf "%s:\t%s\n","'"${prefix}"'", $0 }'
 }
 
 log() {
-       local prefix="$1"
+       local redirect
+       local prefix
 
-       shift
-       local redirect=
        if [[ ${VERBOSE} -eq 0 ]]; then
                redirect=/dev/null
        else
                redirect=/dev/stdout
        fi
 
+       prefix="${LOG_PREFIX:-}"
+
        if [[ "$#" -eq 0 ]]; then
-               __log_stdin | tee -a "${LOG}" > ${redirect}
+               if [[ -n "${prefix}" ]]; then
+                       awk -v prefix="${prefix}" '{printf "%s: %s\n", prefix, $0}'
+               else
+                       cat
+               fi
        else
-               __log_args "$@" | tee -a "${LOG}" > ${redirect}
-       fi
-}
-
-log_setup() {
-       log "setup" "$@"
+               if [[ -n "${prefix}" ]]; then
+                       echo "${prefix}: " "$@"
+               else
+                       echo "$@"
+               fi
+       fi | tee -a "${LOG}" > "${redirect}"
 }
 
 log_host() {
-       local testname=$1
-
-       shift
-       log "test:${testname}:host" "$@"
+       LOG_PREFIX=host log "$@"
 }
 
 log_guest() {
-       local testname=$1
-
-       shift
-       log "test:${testname}:guest" "$@"
+       LOG_PREFIX=guest log "$@"
 }
 
 test_vm_server_host_client() {
-       local testname="${FUNCNAME[0]#test_}"
 
        vm_ssh -- "${VSOCK_TEST}" \
                --mode=server \
                --control-port="${TEST_GUEST_PORT}" \
                --peer-cid=2 \
-               2>&1 | log_guest "${testname}" &
+               2>&1 | log_guest &
 
        vm_wait_for_listener "${TEST_GUEST_PORT}"
 
@@ -332,18 +323,17 @@ test_vm_server_host_client() {
                --mode=client \
                --control-host=127.0.0.1 \
                --peer-cid="${VSOCK_CID}" \
-               --control-port="${TEST_HOST_PORT}" 2>&1 | log_host "${testname}"
+               --control-port="${TEST_HOST_PORT}" 2>&1 | log_host
 
        return $?
 }
 
 test_vm_client_host_server() {
-       local testname="${FUNCNAME[0]#test_}"
 
        ${VSOCK_TEST} \
                --mode "server" \
                --control-port "${TEST_HOST_PORT_LISTENER}" \
-               --peer-cid "${VSOCK_CID}" 2>&1 | log_host "${testname}" &
+               --peer-cid "${VSOCK_CID}" 2>&1 | log_host &
 
        host_wait_for_listener
 
@@ -351,19 +341,18 @@ test_vm_client_host_server() {
                --mode=client \
                --control-host=10.0.2.2 \
                --peer-cid=2 \
-               --control-port="${TEST_HOST_PORT_LISTENER}" 2>&1 | log_guest "${testname}"
+               --control-port="${TEST_HOST_PORT_LISTENER}" 2>&1 | log_guest
 
        return $?
 }
 
 test_vm_loopback() {
-       local testname="${FUNCNAME[0]#test_}"
        local port=60000 # non-forwarded local port
 
        vm_ssh -- "${VSOCK_TEST}" \
                --mode=server \
                --control-port="${port}" \
-               --peer-cid=1 2>&1 | log_guest "${testname}" &
+               --peer-cid=1 2>&1 | log_guest &
 
        vm_wait_for_listener "${port}"
 
@@ -371,7 +360,7 @@ test_vm_loopback() {
                --mode=client \
                --control-host="127.0.0.1" \
                --control-port="${port}" \
-               --peer-cid=1 2>&1 | log_guest "${testname}"
+               --peer-cid=1 2>&1 | log_guest
 
        return $?
 }
@@ -399,25 +388,25 @@ run_test() {
 
        host_oops_cnt_after=$(dmesg | grep -i 'Oops' | wc -l)
        if [[ ${host_oops_cnt_after} -gt ${host_oops_cnt_before} ]]; then
-               echo "FAIL: kernel oops detected on host" | log_host "${name}"
+               echo "FAIL: kernel oops detected on host" | log_host
                rc=$KSFT_FAIL
        fi
 
        host_warn_cnt_after=$(dmesg --level=warn | grep -c -i 'vsock')
        if [[ ${host_warn_cnt_after} -gt ${host_warn_cnt_before} ]]; then
-               echo "FAIL: kernel warning detected on host" | log_host "${name}"
+               echo "FAIL: kernel warning detected on host" | log_host
                rc=$KSFT_FAIL
        fi
 
        vm_oops_cnt_after=$(vm_ssh -- dmesg | grep -i 'Oops' | wc -l)
        if [[ ${vm_oops_cnt_after} -gt ${vm_oops_cnt_before} ]]; then
-               echo "FAIL: kernel oops detected on vm" | log_host "${name}"
+               echo "FAIL: kernel oops detected on vm" | log_host
                rc=$KSFT_FAIL
        fi
 
        vm_warn_cnt_after=$(vm_ssh -- dmesg --level=warn | grep -c -i 'vsock')
        if [[ ${vm_warn_cnt_after} -gt ${vm_warn_cnt_before} ]]; then
-               echo "FAIL: kernel warning detected on vm" | log_host "${name}"
+               echo "FAIL: kernel warning detected on vm" | log_host
                rc=$KSFT_FAIL
        fi
 
@@ -452,10 +441,10 @@ handle_build
 
 echo "1..${#ARGS[@]}"
 
-log_setup "Booting up VM"
+log_host "Booting up VM"
 vm_start
 vm_wait_for_ssh
-log_setup "VM booted up"
+log_host "VM booted up"
 
 cnt_pass=0
 cnt_fail=0