From 73199ca0e8b47110339d7110473d9e40c72738b3 Mon Sep 17 00:00:00 2001
From: Liam Fallon <35595825+liamfallon@users.noreply.github.com>
Date: Fri, 7 Jun 2024 22:15:23 +0100
Subject: [PATCH] Add logs for wait end times and porch package approval times
 to e2e tests (#267)

* Add logs for wait ends to e2e tests

* Added logging on porchctl approve
---
 e2e/lib/k8s.sh                       | 8 +++++++-
 e2e/lib/kpt.sh                       | 2 ++
 e2e/lib/porch.sh                     | 1 +
 e2e/tests/free5gc/001.sh             | 4 ++++
 e2e/tests/free5gc/003.sh             | 3 +++
 e2e/tests/free5gc/008.sh             | 5 ++++-
 e2e/tests/free5gc/009.sh             | 6 +++++-
 e2e/tests/oai/001b-infra-metal-lb.sh | 3 +++
 8 files changed, 29 insertions(+), 3 deletions(-)

diff --git a/e2e/lib/k8s.sh b/e2e/lib/k8s.sh
index 558cb718..99eeec46 100755
--- a/e2e/lib/k8s.sh
+++ b/e2e/lib/k8s.sh
@@ -40,6 +40,7 @@ function k8s_wait_exists {
     while [[ $lapse -gt 0 ]]; do
         found=$(kubectl --kubeconfig $kubeconfig -n $resource_namespace get $resource_type $resource_name -o jsonpath='{.metadata.name}' --ignore-not-found)
         if [[ $found ]]; then
+            info "found $resource_type $resource_namespace/$resource_name using $kubeconfig"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$resource_namespace/$resource_name $resource_type took $lapse seconds to exist"
             return
         fi
@@ -70,6 +71,7 @@ function k8s_wait_ready {
     while [[ $lapse -gt 0 ]]; do
         ready=$(kubectl --kubeconfig $kubeconfig -n $resource_namespace get $resource_type $resource_name -o jsonpath='{.status.conditions[?(@.type=="Ready")].status}' || echo)
         if [[ $ready == "True" ]]; then
+            info "status ready on $resource_type $resource_namespace/$resource_name using $kubeconfig"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$resource_namespace/$resource_name $resource_type took $lapse seconds to be ready"
             return
         fi
@@ -104,6 +106,7 @@ function k8s_wait_ready_replicas {
     while [[ $lapse -gt 0 ]]; do
         ready=$(kubectl --kubeconfig $kubeconfig -n $resource_namespace get $resource_type $resource_name -o jsonpath="{.status.$status_field}" || echo)
         if [[ $ready -ge $min_ready ]]; then
+            info "status ready on $resource_type $resource_namespace/$resource_name using $kubeconfig"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$resource_namespace/$resource_name $resource_type took $lapse seconds to have minimum number of replicas"
             return
         fi
@@ -136,7 +139,10 @@ function k8s_exec {
 
     info "executing command $command on $resource_name in namespace $resource_namespace using $kubeconfig"
     kubectl --kubeconfig $kubeconfig -n $resource_namespace exec $resource_name -- /bin/bash -c "$command"
-    return $?
+    result=$?
+    info "executed command $command on $resource_name in namespace $resource_namespace using $kubeconfig"
+
+    return $result
 }
 
 function _k8s_absolute_unit {
diff --git a/e2e/lib/kpt.sh b/e2e/lib/kpt.sh
index a98ccf21..163536db 100755
--- a/e2e/lib/kpt.sh
+++ b/e2e/lib/kpt.sh
@@ -32,6 +32,7 @@ function _wait_for_user_repo {
     while [[ $lapse -gt 0 ]]; do
         found=$(curl_gitea_api "repos/$user/$repo" 'import json; import sys; print("full_name" in json.loads(sys.stdin.read()))')
         if [[ $found == "True" ]]; then
+            info "found $repo repository of $user user"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$user user took $lapse seconds to exist in $repo repository"
             return
         fi
@@ -57,6 +58,7 @@ function kpt_wait_pkg {
     while [[ $lapse -gt 0 ]]; do
         found=$(curl_gitea_api "repos/$user/$repo/contents" "import json; import sys; print('$pkg' in [dir['path'] for dir in json.loads(sys.stdin.read()) if dir['type'] == 'dir' ])")
         if [[ $found == "True" ]]; then
+            info "found $pkg kpt package on $user/$repo repository"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$pkg kpt package took $lapse seconds to exist"
             return
         fi
diff --git a/e2e/lib/porch.sh b/e2e/lib/porch.sh
index 071ab6c7..47f6f008 100755
--- a/e2e/lib/porch.sh
+++ b/e2e/lib/porch.sh
@@ -29,6 +29,7 @@ function porch_wait_published_packagerev {
             fi
         done
         if [[ $found ]]; then
+            info "found package published revision on $pkg_name"
             [ $((timeout * 2 / 3)) -lt $lapse ] || warn "$pkg_name package took $lapse seconds to be published"
             break
         fi
diff --git a/e2e/tests/free5gc/001.sh b/e2e/tests/free5gc/001.sh
index f47bdc19..fd1b60f3 100755
--- a/e2e/tests/free5gc/001.sh
+++ b/e2e/tests/free5gc/001.sh
@@ -70,8 +70,12 @@ assert_commit_msg_in_branch "Intermediate commit" "proposed/regional/v1"
 assert_workload_resource_contains "proposed/regional/v1" "nephio.org/site-type: regional" "Workload cluster has not been transformed properly to proposed"
 
 # Approval
+info "approving package $regional_pkg_rev"
 porchctl rpkg approve -n default "$regional_pkg_rev"
+info "approved package $regional_pkg_rev"
 kubectl wait --for jsonpath='{.spec.lifecycle}'=Published packagerevisions "$regional_pkg_rev" --timeout="600s"
+info "published package $regional_pkg_rev"
+
 assert_workload_resource_contains "main" "nephio.org/site-type: regional" "Workload cluster has not been successfully merged into main branch"
 
 k8s_wait_exists "workloadcluster" "regional"
diff --git a/e2e/tests/free5gc/003.sh b/e2e/tests/free5gc/003.sh
index 14f5c568..5912dba5 100755
--- a/e2e/tests/free5gc/003.sh
+++ b/e2e/tests/free5gc/003.sh
@@ -45,8 +45,11 @@ kubectl wait --for jsonpath='{.spec.lifecycle}'=Proposed packagerevisions "$pkg_
 assert_branch_exists "proposed/free5gc-cp/v1" "nephio/regional"
 assert_commit_msg_in_branch "Intermediate commit" "proposed/free5gc-cp/v1" "nephio/regional"
 
+info "approving package $pkg_rev"
 porchctl rpkg approve -n default "$pkg_rev"
+info "approved package $pkg_rev"
 kubectl wait --for jsonpath='{.spec.lifecycle}'=Published packagerevisions "$pkg_rev" --timeout="600s"
+info "published package $pkg_rev"
 
 kpt_wait_pkg "regional" "free5gc-cp"
 k8s_wait_ready_replicas "statefulset" "mongodb" "$(k8s_get_capi_kubeconfig "regional")" "free5gc-cp"
diff --git a/e2e/tests/free5gc/008.sh b/e2e/tests/free5gc/008.sh
index c573fe95..90facefb 100755
--- a/e2e/tests/free5gc/008.sh
+++ b/e2e/tests/free5gc/008.sh
@@ -72,8 +72,11 @@ info "Proposing $upf_pkg_rev update"
 porchctl rpkg propose -n default "$upf_pkg_rev"
 k8s_wait_exists "packagerev" "$upf_pkg_rev"
 
-info "Approving $upf_pkg_rev update"
+info "approving package $upf_pkg_rev update"
 porchctl rpkg approve -n default "$upf_pkg_rev"
+info "approved package $upf_pkg_rev update"
+kubectl wait --for jsonpath='{.spec.lifecycle}'=Published packagerevisions "$upf_pkg_rev" --timeout="600s"
+info "published package $upf_pkg_rev update"
 
 # Get current UPF pod state after scaling
 k8s_wait_ready_replicas "deployment" "upf-edge01" "$cluster_kubeconfig" "free5gc-upf"
diff --git a/e2e/tests/free5gc/009.sh b/e2e/tests/free5gc/009.sh
index 1e1ae3f0..1441b3b9 100755
--- a/e2e/tests/free5gc/009.sh
+++ b/e2e/tests/free5gc/009.sh
@@ -100,8 +100,12 @@ while [[ $retries -gt 0 ]]; do
     fi
 
     if [[ $modified == false ]]; then
-        info "Approving update"
+        info "approving package $smf_pkg_rev update"
         output=$(porchctl rpkg approve -n default "$smf_pkg_rev" 2>&1)
+        info "approved package $smf_pkg_rev update"
+        kubectl wait --for jsonpath='{.spec.lifecycle}'=Published packagerevisions "$smf_pkg_rev" --timeout="600s"
+        info "published package $smf_pkg_rev update"
+
         if [[ $output =~ "modified" ]]; then
             modified=true
         fi
diff --git a/e2e/tests/oai/001b-infra-metal-lb.sh b/e2e/tests/oai/001b-infra-metal-lb.sh
index 312c71bc..f54c09c3 100755
--- a/e2e/tests/oai/001b-infra-metal-lb.sh
+++ b/e2e/tests/oai/001b-infra-metal-lb.sh
@@ -59,8 +59,11 @@ function _define_ip_address_pool {
     assert_commit_msg_in_branch "Intermediate commit" "proposed/$cluster-metallb-sandbox-config/v1" "nephio/mgmt-staging"
 
     # Approval
+    info "approving package $pkg_rev update"
     porchctl rpkg approve -n default "$pkg_rev"
+    info "approved package $pkg_rev update"
     kubectl wait --for jsonpath='{.spec.lifecycle}'=Published packagerevisions "$pkg_rev" --timeout="600s"
+    info "published package $pkg_rev update"
 }
 
 _define_ip_address_pool "core" "172.18.16.0/20"