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>
This commit is contained in:
Bobby Eshleman
2025-11-08 08:00:52 -08:00
committed by Jakub Kicinski
parent fc6aa0e470
commit d9cac93cd1
+30 -41
View File
@@ -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
if [[ "$#" -eq 0 ]]; then
__log_stdin | tee -a "${LOG}" > ${redirect}
else
__log_args "$@" | tee -a "${LOG}" > ${redirect}
fi
}
prefix="${LOG_PREFIX:-}"
log_setup() {
log "setup" "$@"
if [[ "$#" -eq 0 ]]; then
if [[ -n "${prefix}" ]]; then
awk -v prefix="${prefix}" '{printf "%s: %s\n", prefix, $0}'
else
cat
fi
else
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