chore(ci): add log for flaky meta backup test (#8109)

Add logs to troubleshoot flaky test in #7850

Approved-By: Li0k

src/meta/src/backup_restore/restore.rs

@@ -198,8 +198,8 @@ async fn restore_impl(
         tracing::info!(
             "snapshot {} after rewrite by snapshot {}:\n{}",
             target_id,
+            newest_id,
             target_snapshot,
-            newest_id
         );
     }
     if opts.dry_run {

src/storage/backup/integration_tests/common.sh

@@ -14,11 +14,11 @@ function clean_all_data {
 }
 
 function clean_etcd_data() {
-  cargo make clean-etcd-data
+  cargo make clean-etcd-data 1>/dev/null 2>&1
 }
 
 function start_cluster() {
-  cargo make d ci-meta-backup-test
+  cargo make d ci-meta-backup-test 1>/dev/null 2>&1
 }
 
 function wait_cluster_ready() {
@@ -27,18 +27,18 @@ function wait_cluster_ready() {
 }
 
 function full_gc_sst() {
-  ${BACKUP_TEST_RW_ALL_IN_ONE} risectl hummock trigger-full-gc -s 0
+  ${BACKUP_TEST_RW_ALL_IN_ONE} risectl hummock trigger-full-gc -s 0 1>/dev/null 2>&1
   # TODO #6482: wait full gc finish deterministically.
   # Currently have to wait long enough.
   sleep 30
 }
 
 function manual_compaction() {
-  ${BACKUP_TEST_RW_ALL_IN_ONE} risectl hummock trigger-manual-compaction "$@"
+  ${BACKUP_TEST_RW_ALL_IN_ONE} risectl hummock trigger-manual-compaction "$@" 1>/dev/null 2>&1
 }
 
 function start_etcd_minio() {
-  cargo make d ci-meta-backup-test-restore
+  cargo make d ci-meta-backup-test-restore 1>/dev/null 2>&1
 }
 
 function create_mvs() {
@@ -78,14 +78,28 @@ function restore() {
   --meta-snapshot-id "${job_id}" \
   --etcd-endpoints 127.0.0.1:2388 \
   --storage-directory backup \
-  --storage-url minio://hummockadmin:hummockadmin@127.0.0.1:9301/hummock001
+  --storage-url minio://hummockadmin:hummockadmin@127.0.0.1:9301/hummock001 \
+  1>/dev/null
 }
 
 function execute_sql() {
   local sql
   sql=$1
-  echo "execute sql ${sql}"
-  echo "SET QUERY_MODE=distributed;${sql}" | psql -h localhost -p 4566 -d dev -U root 2>&1
+  echo "${sql}" | psql -h localhost -p 4566 -d dev -U root 2>&1
+}
+
+function execute_sql_and_expect() {
+  local sql
+  sql=$1
+  local expected
+  expected=$2
+
+  echo "execute SQL ${sql}"
+  echo "expected string in result: ${expected}"
+  query_result=$(execute_sql "${sql}")
+  printf "actual result:\n%s\n" "${query_result}"
+  result=$(echo "${query_result}" | grep "${expected}")
+  [ -n "${result}" ]
 }
 
 function get_max_committed_epoch() {

src/storage/backup/integration_tests/run_all.sh

@@ -11,3 +11,5 @@ for t in "${tests[@]}"
 do
   bash "${DIR}/${t}"
 done
+
+echo "all tests succeeded"

src/storage/backup/integration_tests/test_query_backup.sh

@@ -69,48 +69,35 @@ done
 echo "safe epoch after compaction: ${safe_epoch}"
 
 echo "QUERY_EPOCH=safe_epoch. It should fail because it's not covered by any backup"
-result=$(
-execute_sql "
-SET QUERY_EPOCH TO ${safe_epoch};
-select * from t1;
-" | grep "Read backup error backup include epoch ${safe_epoch} not found"
-)
-[ -n "${result}" ]
+execute_sql_and_expect \
+"SET QUERY_EPOCH TO ${safe_epoch};
+select * from t1;" \
+"Read backup error backup include epoch ${safe_epoch} not found"
 
 echo "QUERY_EPOCH=0 aka disabling query backup"
-result=$(
-execute_sql "
-SET QUERY_EPOCH TO 0;
-select * from t1;
-" | grep "1 row"
-)
-[ -n "${result}" ]
+execute_sql_and_expect \
+"SET QUERY_EPOCH TO 0;
+select * from t1;" \
+"1 row"
 
 echo "QUERY_EPOCH=backup_safe_epoch + 1, it's < safe_epoch but covered by backup"
 [ $((backup_safe_epoch + 1)) -eq 1 ]
-result=$(
-execute_sql "
-SET QUERY_EPOCH TO $((backup_safe_epoch + 1));
-select * from t1;
-" | grep "0 row"
-)
-[ -n "${result}" ]
+execute_sql_and_expect \
+"SET QUERY_EPOCH TO $((backup_safe_epoch + 1));
+select * from t1;" \
+"0 row"
 
 echo "QUERY_EPOCH=backup_mce < safe_epoch, it's < safe_epoch but covered by backup"
-result=$(
-execute_sql "
-SET QUERY_EPOCH TO $((backup_mce));
-select * from t1;
-" | grep "3 row"
-)
-[ -n "${result}" ]
+execute_sql_and_expect \
+"SET QUERY_EPOCH TO ${backup_mce};
+select * from t1;" \
+"3 row"
 
 echo "QUERY_EPOCH=future epoch. It should fail because it's not covered by any backup"
 future_epoch=18446744073709551615
-result=$(
-execute_sql "
-SET QUERY_EPOCH TO ${future_epoch};
-select * from t1;
-" | grep "Read backup error backup include epoch ${future_epoch} not found"
-)
-[ -n "${result}" ]
+execute_sql_and_expect \
+"SET QUERY_EPOCH TO ${future_epoch};
+select * from t1;" \
+"Read backup error backup include epoch ${future_epoch} not found"
+
+echo "test succeeded"