Add logs for wait end times and porch package approval times to e2e t…

…ests (#267)

* Add logs for wait ends to e2e tests

* Added logging on porchctl approve

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 {

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

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

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"

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"

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"

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

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"