wait_for_container_engine needs to check openresty status

The container engine will restart when the user enables/disabled allowed
images filtering. Sometimes check_for_container_engine executes so quickly
that it succeeds before the container engine is stopped.

This commit makes sure that the openresty service status matches the expected
value from the .containerEngine.allowedImages.enabled. That way we know that
the engine has been restarted.

This PR also adds some tracing statements (controlled via `RD_TRACE`), as I
got tired of adding/removing tracing every time I need to debug the helpers.

Signed-off-by: Jan Dubois <jan.dubois@suse.com>

bats/tests/helpers/defaults.bash

@@ -34,6 +34,9 @@ taking_screenshots() {
     is_true "$RD_TAKE_SCREENSHOTS"
 }
 
+########################################################################
+: "${RD_TRACE:=false}"
+
 ########################################################################
 # When RD_USE_GHCR_IMAGES is true, then all images will be pulled from
 # ghcr.io instead of docker.io, to avoid hitting the docker hub pull

bats/tests/helpers/kubernetes.bash

@@ -3,16 +3,18 @@ wait_for_apiserver() {
     local timeout="$(($(date +%s) + 10 * 60))"
     while true; do
         until kubectl get --raw /readyz &>/dev/null; do
-            assert [ "$(date +%s)" -lt "${timeout}" ]
+            assert [ "$(date +%s)" -lt "$timeout" ]
             sleep 1
         done
-        assert [ "$(date +%s)" -lt "${timeout}" ]
+        assert [ "$(date +%s)" -lt "$timeout" ]
         run kubectl get node -o jsonpath="{.items[0].status.nodeInfo.kubeletVersion}"
-        if [ "$status" -eq 0 ]; then
+        if ((status == 0)); then
             # Turn "v1.23.4+k3s1" into "1.23.4"
             local version=${output#v}
             version=${version%+*}
-            [ "$version" == "$desired_version" ] && return 0
+            if [ "$version" == "$desired_version" ]; then
+                return 0
+            fi
         fi
         sleep 1
     done

bats/tests/helpers/load.bash

@@ -47,7 +47,8 @@ source "$PATH_BATS_HELPERS/paths.bash"
 # and PATH_* variables from paths.bash
 source "$PATH_BATS_HELPERS/commands.bash"
 
-# vm.bash uses various PATH_* variables from paths.bash
+# vm.bash uses various PATH_* variables from paths.bash,
+# rdctl from commands.bash, and jq_output from utils.bash
 source "$PATH_BATS_HELPERS/vm.bash"
 
 # kubernetes.bash has no load-time dependencies
@@ -58,7 +59,7 @@ export PATH="$PATH_BATS_ROOT/bin/${OS/windows/linux}:$PATH"
 
 # If called from foo() this function will call local_foo() if it exist.
 call_local_function() {
-    local func="local_$(caller 0 | awk '{print $2}')"
+    local func="local_$(calling_function)"
     if [ "$(type -t "$func")" = "function" ]; then
         eval "$func"
     fi

bats/tests/helpers/os.bash

@@ -68,7 +68,7 @@ needs_port() {
         if [ "$(sysctl -n net.ipv4.ip_unprivileged_port_start)" -gt "$port" ]; then
             # Run sudo non-interactive, so don't prompt for password
             run sudo -n sysctl -w "net.ipv4.ip_unprivileged_port_start=$port"
-            if [ "$status" -ne 0 ]; then
+            if ((status > 0)); then
                 skip "net.ipv4.ip_unprivileged_port_start must be $port or less"
             fi
         fi

bats/tests/helpers/utils.bash

@@ -45,10 +45,26 @@ jq_output() {
 
 get_setting() {
     run rdctl api /settings
-    assert_success
+    assert_success || return
     jq_output "$@"
 }
 
+this_function() {
+    echo "${FUNCNAME[1]}"
+}
+
+calling_function() {
+    echo "${FUNCNAME[2]}"
+}
+
+# Write a comment to the TAP stream
+# Set CALLER to print a calling function higher up in the call stack.
+trace() {
+    if is_true "$RD_TRACE"; then
+        echo "# (${CALLER:-$(calling_function)}): $*" >&3
+    fi
+}
+
 try() {
     local max=24
     local delay=5
@@ -73,12 +89,14 @@ try() {
         esac
         shift
     done
-    local count=0
-    while [ "$count" -lt "$max" ]; do
+
+    local count
+    for ((count = 0; count < max; ++count)); do
         run "$@"
-        [ "$status" -eq 0 ] && return
+        if ((status == 0)); then
+            break
+        fi
         sleep "$delay"
-        count=$((count + 1))
     done
     echo "$output"
     return "$status"

bats/tests/helpers/vm.bash

@@ -9,6 +9,13 @@ wait_for_shell() {
     rdctl shell sync
 }
 
+pkill_by_path() {
+    local arg=$(readlink -f "$1")
+    if [[ -n $arg ]]; then
+        pkill -f "$arg"
+    fi
+}
+
 factory_reset() {
     if [ "$BATS_TEST_NUMBER" -gt 1 ]; then
         capture_logs
@@ -17,9 +24,9 @@ factory_reset() {
     if using_npm_run_dev; then
         if is_unix; then
             run rdctl shutdown
-            run pkill -f "$(readlink -f "$PATH_REPO_ROOT/node_modules")"
-            run pkill -f "$(readlink -f "$PATH_RESOURCES")"
-            run pkill -f "$(readlink -f "$LIMA_HOME")"
+            run pkill_by_path "$PATH_REPO_ROOT/node_modules"
+            run pkill_by_path "$PATH_RESOURCES"
+            run pkill_by_path "$LIMA_HOME"
         else
             # TODO: kill `npm run dev` instance on Windows
             true
@@ -148,32 +155,67 @@ start_application() {
     fi
 }
 
-container_engine_info() {
+get_container_engine_info() {
     run ctrctl info
-    assert_success
+    echo "$output"
+    assert_success || return
     assert_output --partial "Server Version:"
 }
 
 docker_context_exists() {
     run docker_exe context ls -q
-    assert_success
+    assert_success || return
     assert_line "$RD_DOCKER_CONTEXT"
 }
 
-buildkitd_is_running() {
-    run rdctl shell rc-service --nocolor buildkitd status
-    assert_success
-    assert_output --partial 'status: started'
+assert_service_status() {
+    local service_name=$1
+    local expect=$2
+
+    run rc_service "$service_name" status
+    # Some services (e.g. k3s) report non-zero status when not running
+    if [[ $expect == started ]]; then
+        assert_success || return
+    fi
+    assert_output --partial "status: ${expect}"
+}
+
+wait_for_service_status() {
+    local service_name=$1
+    local expect=$2
+
+    trace "waiting for ${service_name} to be ${expect}"
+    try --max 30 --delay 5 assert_service_status "$service_name" "$expect"
+}
+
+rdctl_api_settings() {
+    run rdctl api /settings
+    echo "$output"
+    assert_success || return
+    refute_output undefined
 }
 
 wait_for_container_engine() {
-    try --max 12 --delay 10 container_engine_info
+    local CALLER=$(this_function)
+
+    trace "waiting for api /settings to be callable"
+    try --max 30 --delay 5 rdctl_api_settings
+
+    run jq_output .containerEngine.allowedImages.enabled
     assert_success
+    if [[ $output == true ]]; then
+        wait_for_service_status openresty started
+    else
+        wait_for_service_status openresty stopped
+    fi
+
     if using_docker; then
+        trace "waiting for docker context to exist"
         try --max 30 --delay 5 docker_context_exists
-        assert_success
     else
-        try --max 30 --delay 5 buildkitd_is_running
-        assert_success
+        wait_for_service_status buildkitd started
     fi
+
+    trace "waiting for container engine info to be available"
+    try --max 12 --delay 10 get_container_engine_info
 }

bats/tests/k8s/enable-disable-k8s.bats

@@ -8,8 +8,7 @@ load '../helpers/load'
 
 verify_k8s_is_running() {
     wait_for_container_engine
-    run rc_service --nocolor k3s status
-    assert_line --partial "status: started"
+    wait_for_service_status k3s started
 }
 
 @test 'start rancher desktop with kubernetes enabled' {
@@ -21,11 +20,7 @@ verify_k8s_is_running() {
 @test 'disable kubernetes' {
     rdctl set --kubernetes-enabled=false
     wait_for_container_engine
-    echo "Sleeping for 60 seconds before testing to see if k3s is running..." 1>&3
-    sleep 60
-    # rc-service fails with exit code 3 when the service is not running
-    run rc_service --nocolor k3s status
-    assert_line --partial "status: stopped"
+    wait_for_service_status k3s stopped
 }
 
 @test 're-enable kubernetes' {