Merge pull request #6223 from rgerhards/codex/analyze-and-fix-flaky-dynstats-test

tests: bound dynstats metric waits

tests/dynstats_overflow-vg.sh

@@ -4,6 +4,34 @@
 echo ===============================================================================
 echo \[dynstats_overflow-vg.sh\]: test for gathering stats when metrics exceed provisioned capacity
 . ${srcdir:=.}/diag.sh init
+
+wait_for_stats_metric() {
+  local pattern="$1"
+  local file="$2"
+  local timeout_ms="${3:-45000}"
+  local interval_ms=100
+  local waited_ms=0
+
+  while true; do
+    if [ -f "$file" ] && grep -q "$pattern" "$file"; then
+      return 0
+    fi
+
+    if [ $waited_ms -ge $timeout_ms ]; then
+      echo "stats metric pattern '$pattern' not found in '$file' within ${timeout_ms}ms"
+      if [ -f "$file" ]; then
+        echo "file contents:"
+        cat "$file"
+      else
+        echo "stats file '$file' does not exist"
+      fi
+      error_exit 1
+    fi
+
+    $TESTTOOL_DIR/msleep $interval_ms
+    waited_ms=$((waited_ms + interval_ms))
+  done
+}
 generate_conf
 add_conf '
 ruleset(name="stats") {
@@ -34,6 +62,10 @@ injectmsg_file $srcdir/testsuites/dynstats_input_more_1
 wait_queueempty
 . $srcdir/diag.sh allow-single-stats-flush-after-block-and-wait-for-it
 
+wait_for_stats_metric 'foo=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'bar=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'baz=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 first_column_sum_check 's/.*foo=\([0-9]*\)/\1/g' 'foo=' "${RSYSLOG_DYNNAME}.out.stats.log" 5
 first_column_sum_check 's/.*bar=\([0-9]*\)/\1/g' 'bar=' "${RSYSLOG_DYNNAME}.out.stats.log" 1
 first_column_sum_check 's/.*baz=\([0-9]*\)/\1/g' 'baz=' "${RSYSLOG_DYNNAME}.out.stats.log" 2
@@ -52,6 +84,8 @@ first_column_sum_check 's/.*no_metric=\([0-9]*\)/\1/g' 'no_metric=' "${RSYSLOG_D
 
 wait_for_stats_flush ${RSYSLOG_DYNNAME}.out.stats.log
 
+wait_for_stats_metric 'metrics_purged=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 first_column_sum_check 's/.*metrics_purged=\([0-9]*\)/\1/g' 'metrics_purged=' "${RSYSLOG_DYNNAME}.out.stats.log" 3
 
 rm ${RSYSLOG_DYNNAME}.out.stats.log
@@ -62,6 +96,10 @@ injectmsg_file $srcdir/testsuites/dynstats_input_more_2
 wait_queueempty
 . $srcdir/diag.sh allow-single-stats-flush-after-block-and-wait-for-it
 
+wait_for_stats_metric 'corge=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'grault=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'quux=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 content_check "foo 001 0"
 content_check "bar 002 0"
 content_check "baz 003 0"

tests/dynstats_overflow.sh

@@ -2,6 +2,34 @@
 # added 2015-11-13 by singh.janmejay
 # This file is part of the rsyslog project, released under ASL 2.0
 . ${srcdir:=.}/diag.sh init
+
+wait_for_stats_metric() {
+  local pattern="$1"
+  local file="$2"
+  local timeout_ms="${3:-30000}"
+  local interval_ms=100
+  local waited_ms=0
+
+  while true; do
+    if [ -f "$file" ] && grep -q "$pattern" "$file"; then
+      return 0
+    fi
+
+    if [ $waited_ms -ge $timeout_ms ]; then
+      echo "stats metric pattern '$pattern' not found in '$file' within ${timeout_ms}ms"
+      if [ -f "$file" ]; then
+        echo "file contents:"
+        cat "$file"
+      else
+        echo "stats file '$file' does not exist"
+      fi
+      error_exit 1
+    fi
+
+    $TESTTOOL_DIR/msleep $interval_ms
+    waited_ms=$((waited_ms + interval_ms))
+  done
+}
 generate_conf
 add_conf '
 ruleset(name="stats") {
@@ -32,6 +60,10 @@ injectmsg_file $srcdir/testsuites/dynstats_input_more_1
 wait_queueempty
 . $srcdir/diag.sh allow-single-stats-flush-after-block-and-wait-for-it
 
+wait_for_stats_metric 'foo=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'bar=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'baz=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 #first_column_sum_check 's/.*foo=\([0-9]*\)/\1/g' 'foo=' "${RSYSLOG_DYNNAME}.out.stats.log" 5
 first_column_sum_check 's/.*foo=//g' 'foo=' "${RSYSLOG_DYNNAME}.out.stats.log" 5
 first_column_sum_check 's/.*bar=//g' 'bar=' "${RSYSLOG_DYNNAME}.out.stats.log" 1
@@ -51,6 +83,8 @@ first_column_sum_check 's/.*no_metric=//g' 'no_metric=' "${RSYSLOG_DYNNAME}.out.
 
 wait_for_stats_flush ${RSYSLOG_DYNNAME}.out.stats.log
 
+wait_for_stats_metric 'metrics_purged=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 first_column_sum_check 's/.*metrics_purged=//g' 'metrics_purged=' "${RSYSLOG_DYNNAME}.out.stats.log" 3
 
 rm ${RSYSLOG_DYNNAME}.out.stats.log
@@ -61,6 +95,10 @@ injectmsg_file $srcdir/testsuites/dynstats_input_more_2
 wait_queueempty
 . $srcdir/diag.sh allow-single-stats-flush-after-block-and-wait-for-it
 
+wait_for_stats_metric 'corge=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'grault=' "${RSYSLOG_DYNNAME}.out.stats.log"
+wait_for_stats_metric 'quux=' "${RSYSLOG_DYNNAME}.out.stats.log"
+
 content_check "foo 001 0"
 content_check "bar 002 0"
 content_check "baz 003 0"