From c4997d25934e46a116e1640e4c1c8199413c063b Mon Sep 17 00:00:00 2001
From: Jan Dubois <jan.dubois@suse.com>
Date: Tue, 4 Jul 2023 08:50:17 -0700
Subject: [PATCH] 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       |  3 ++
 bats/tests/helpers/load.bash           |  5 +--
 bats/tests/helpers/utils.bash          | 12 +++++++
 bats/tests/helpers/vm.bash             | 43 +++++++++++++++++++++-----
 bats/tests/k8s/enable-disable-k8s.bats |  9 ++----
 5 files changed, 55 insertions(+), 17 deletions(-)

diff --git a/bats/tests/helpers/defaults.bash b/bats/tests/helpers/defaults.bash
index 75f04258b09..d5b225f94cd 100644
--- a/bats/tests/helpers/defaults.bash
+++ b/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
diff --git a/bats/tests/helpers/load.bash b/bats/tests/helpers/load.bash
index 99c409e01a8..76474a4688b 100644
--- a/bats/tests/helpers/load.bash
+++ b/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
diff --git a/bats/tests/helpers/utils.bash b/bats/tests/helpers/utils.bash
index c2c78d6b94a..141c6897873 100644
--- a/bats/tests/helpers/utils.bash
+++ b/bats/tests/helpers/utils.bash
@@ -49,6 +49,18 @@ get_setting() {
     jq_output "$@"
 }
 
+calling_function() {
+    caller 1 | awk '{print $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
diff --git a/bats/tests/helpers/vm.bash b/bats/tests/helpers/vm.bash
index c13f0ffc93b..ab8300075e1 100644
--- a/bats/tests/helpers/vm.bash
+++ b/bats/tests/helpers/vm.bash
@@ -160,20 +160,47 @@ docker_context_exists() {
     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 rdctl shell rc-service "$service_name" status
+    # Some services (e.g. k3s) report non-zero status when not running
+    if [[ $expect == started ]]; then
+        assert_success
+    fi
+    assert_output --partial "status: ${expect}"
+}
+
+wait_for_service_status() {
+    local service_name=$1
+    local expect=$2
+
+    local CALLER=$(calling_function)
+    trace "waiting for ${service_name} to be ${expect}"
+
+    try --max 30 --delay 5 assert_service_status "$service_name" "$expect"
 }
 
 wait_for_container_engine() {
-    try --max 12 --delay 10 container_engine_info
+    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 container_engine_info
 }
diff --git a/bats/tests/k8s/enable-disable-k8s.bats b/bats/tests/k8s/enable-disable-k8s.bats
index 86a1e522259..2de1443324f 100644
--- a/bats/tests/k8s/enable-disable-k8s.bats
+++ b/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' {