[PATCH stalld 17/52] tests: Introduce and adopt assert_log_contains() helper
Wander Lairson Costa <[email protected]> Mon, 8 Jun 2026 15:31:27 -0300
| Newsgroups | org.kernel.vger.linux-rt-users |
|---|---|
| Message-ID | <[email protected]> |
Multiple functional tests repeat the pattern of grepping a log file
for a specific pattern and calling pass or fail based on the result.
This leads to verbose and duplicated boilerplate code across the
test suite.
Introduce an assert_log_contains() helper that encapsulates the
grep, pass/fail evaluation, and diagnostic output into a single
function call. To support various test requirements, the helper
includes:
* A `--negate` flag for asserting the absence of a pattern.
* An `--ignore-case` flag to easily perform case-insensitive
matching, avoiding verbose regex workarounds (like `[Ee]rror`).
Adopt this new helper across the functional test suite. This refactor
simplifies several tests, including replacing nested false-positive
checks in test_starvation_detection and cleaning up if/elif/else
policy detection blocks in test_force_fifo.
Signed-off-by: Wander Lairson Costa <[email protected]>
Assisted-by: Claude Code:claude-opus-4-6[1m] [PAL]
---
tests/functional/test_backend_selection.sh | 9 +---
tests/functional/test_deadline_boosting.sh | 25 ++--------
tests/functional/test_fifo_boosting.sh | 12 +----
.../test_fifo_priority_starvation.sh | 20 ++------
tests/functional/test_force_fifo.sh | 48 ++-----------------
tests/functional/test_idle_detection.sh | 6 +--
tests/functional/test_log_only.sh | 8 +---
tests/functional/test_logging_destinations.sh | 4 +-
tests/functional/test_starvation_detection.sh | 32 +++----------
tests/functional/test_starvation_threshold.sh | 10 ++--
tests/helpers/test_helpers.sh | 41 +++++++++++++++-
11 files changed, 66 insertions(+), 149 deletions(-)
diff --git a/tests/functional/test_backend_selection.sh b/tests/functional/test_backend_selection.sh
index 049277a..d65695b 100755
--- a/tests/functional/test_backend_selection.sh
+++ b/tests/functional/test_backend_selection.sh
@@ -44,14 +44,7 @@ test_backend_flag() {
return 1
fi
- if grep -q "${expected_msg}" "${log_file}"; then
- pass "${description}"
- else
- fail "Backend message not found (${description})"
- echo " Expected: ${expected_msg}"
- echo " Log contents:"
- cat "${log_file}"
- fi
+ assert_log_contains "${log_file}" "${expected_msg}" "${description}"
stop_stalld
}
diff --git a/tests/functional/test_deadline_boosting.sh b/tests/functional/test_deadline_boosting.sh
index eacce98..e777ea0 100755
--- a/tests/functional/test_deadline_boosting.sh
+++ b/tests/functional/test_deadline_boosting.sh
@@ -40,11 +40,7 @@ if wait_for_boost_detected "${STALLD_LOG}"; then
pass "Boosting occurred"
# Verify SCHED_DEADLINE was used
- if grep -q "SCHED_DEADLINE" "${STALLD_LOG}"; then
- pass "SCHED_DEADLINE boosting used (default)"
- else
- fail "SCHED_DEADLINE not mentioned in boost message"
- fi
+ assert_log_contains "${STALLD_LOG}" "SCHED_DEADLINE" "SCHED_DEADLINE boosting used (default)"
# Verify boost happened after threshold
# (starvation logged, then boosting)
@@ -106,11 +102,7 @@ fi
if [ ${boosted_task_found} -eq 0 ]; then
log "⚠ INFO: Could not verify DEADLINE policy in /proc (timing issue or boost already expired)"
# Still check if boost happened in logs
- if grep -q "boosted.*SCHED_DEADLINE" "${STALLD_LOG}"; then
- pass "SCHED_DEADLINE boost confirmed in logs"
- else
- fail "No SCHED_DEADLINE boost detected"
- fi
+ assert_log_contains "${STALLD_LOG}" "boosted.*SCHED_DEADLINE" "SCHED_DEADLINE boost confirmed in logs"
fi
# Cleanup
@@ -165,11 +157,7 @@ else
fi
# Verify boost happened
-if grep -q "boosted" "${STALLD_LOG}"; then
- pass "Boost occurred as expected"
-else
- fail "No boost detected"
-fi
+assert_log_contains "${STALLD_LOG}" "boosted" "Boost occurred as expected"
# Cleanup
cleanup_scenario "${STARVE_PID}"
@@ -286,13 +274,6 @@ else
if [ ${boost_count} -ge 2 ]; then
pass "Multiple boost events detected (${boost_count})"
- # Verify both CPUs mentioned
- if grep -q "CPU ${CPU0}" "${STALLD_LOG}" && grep -q "CPU ${CPU1}" "${STALLD_LOG}"; then
- pass "Boosts occurred on both CPUs"
- else
- log "⚠ INFO: Could not verify boosts on both specific CPUs"
- fi
-
# Verify independent boost cycles
if [ ${boost_count} -gt 2 ]; then
pass "Multiple boost cycles (${boost_count} total), showing independent operation"
diff --git a/tests/functional/test_fifo_boosting.sh b/tests/functional/test_fifo_boosting.sh
index 3d17e5e..38b0b14 100755
--- a/tests/functional/test_fifo_boosting.sh
+++ b/tests/functional/test_fifo_boosting.sh
@@ -38,11 +38,7 @@ if wait_for_boost_detected "${STALLD_LOG}"; then
pass "Boosting occurred with -F flag"
# Verify SCHED_FIFO was used
- if grep -q "SCHED_FIFO" "${STALLD_LOG}"; then
- pass "SCHED_FIFO boosting used (as requested by -F)"
- else
- fail "SCHED_FIFO not mentioned in boost message"
- fi
+ assert_log_contains "${STALLD_LOG}" "SCHED_FIFO" "SCHED_FIFO boosting used (as requested by -F)"
else
fail "No boosting detected with -F flag"
log "Log contents:"
@@ -88,11 +84,7 @@ fi
if [ ${fifo_task_found} -eq 0 ]; then
log "⚠ INFO: Could not verify FIFO policy in /proc (timing issue or boost already expired)"
# FIFO emulation cycles between FIFO and OTHER, so we may catch it in OTHER state
- if grep -q "boosted.*SCHED_FIFO" "${STALLD_LOG}"; then
- pass "SCHED_FIFO boost confirmed in logs"
- else
- fail "No SCHED_FIFO boost detected"
- fi
+ assert_log_contains "${STALLD_LOG}" "boosted.*SCHED_FIFO" "SCHED_FIFO boost confirmed in logs"
fi
# Cleanup
diff --git a/tests/functional/test_fifo_priority_starvation.sh b/tests/functional/test_fifo_priority_starvation.sh
index 8f78a75..6df2c9b 100755
--- a/tests/functional/test_fifo_priority_starvation.sh
+++ b/tests/functional/test_fifo_priority_starvation.sh
@@ -44,18 +44,10 @@ if wait_for_starvation_detected "${STALLD_LOG}"; then
pass "FIFO-on-FIFO starvation detected"
# Verify correct CPU is logged
- if grep "starved on CPU ${TEST_CPU}" "${STALLD_LOG}"; then
- pass "Correct CPU ID logged (CPU ${TEST_CPU})"
- else
- fail "Wrong CPU ID in log"
- fi
+ assert_log_contains "${STALLD_LOG}" "starved on CPU ${TEST_CPU}" "Correct CPU ID logged (CPU ${TEST_CPU})"
# Verify duration is logged
- if grep -E "starved on CPU ${TEST_CPU} for [0-9]+ seconds" "${STALLD_LOG}"; then
- pass "Starvation duration logged"
- else
- fail "Starvation duration not logged"
- fi
+ assert_log_contains "${STALLD_LOG}" "starved on CPU ${TEST_CPU} for [0-9]" "Starvation duration logged"
else
fail "FIFO-on-FIFO starvation not detected"
log "Log contents:"
@@ -106,13 +98,7 @@ log "Context switch delta: ${ctxt_delta}"
if [ ${ctxt_delta} -gt 0 ]; then
pass "Blockee task made progress (${ctxt_delta} context switches)"
else
- log "⚠ WARNING: Could not verify progress (timing issue or blockee not found)"
- # Check if boosting occurred at least
- if grep -q "boosted" "${STALLD_LOG}"; then
- log "ℹ INFO: Boosting did occur according to logs"
- else
- fail "No boosting detected"
- fi
+ assert_log_contains "${STALLD_LOG}" "boosted" "Boosting occurred despite no measurable progress"
fi
# Cleanup
diff --git a/tests/functional/test_force_fifo.sh b/tests/functional/test_force_fifo.sh
index 1e841b8..6c21d3e 100755
--- a/tests/functional/test_force_fifo.sh
+++ b/tests/functional/test_force_fifo.sh
@@ -30,20 +30,8 @@ log "Creating starvation on CPU ${TEST_CPU} for ${starvation_duration}s"
start_starvation_gen -c ${TEST_CPU} -p 80 -n 2 -d ${starvation_duration}
# Wait for detection and boosting
-if wait_for_boost_detected "${STALLD_LOG}"; then
- log "Boosting occurred"
-
- # Look for SCHED_DEADLINE indicators
- if grep -qi "deadline\|SCHED_DEADLINE" "${STALLD_LOG}"; then
- pass "SCHED_DEADLINE used by default"
- elif grep -qi "fifo\|SCHED_FIFO" "${STALLD_LOG}"; then
- log "⚠ WARNING: SCHED_FIFO used instead of SCHED_DEADLINE"
- else
- log "ℹ INFO: Scheduling policy not explicitly mentioned in logs"
- fi
-else
- log "⚠ WARNING: No boosting detected in default mode"
-fi
+assert_boost_detected "${STALLD_LOG}" "Boosting occurred in default mode"
+assert_log_contains --ignore-case "${STALLD_LOG}" "sched_deadline" "SCHED_DEADLINE used by default"
# Cleanup
cleanup_scenario "${STARVE_PID}"
@@ -66,20 +54,8 @@ log "Creating starvation on CPU ${TEST_CPU} for ${starvation_duration}s"
start_starvation_gen -c ${TEST_CPU} -p 80 -n 2 -d ${starvation_duration}
# Wait for detection and boosting
-if wait_for_boost_detected "${STALLD_LOG2}"; then
- log "Boosting occurred with -F flag"
-
- # Look for SCHED_FIFO indicators
- if grep -qi "fifo\|SCHED_FIFO" "${STALLD_LOG2}"; then
- pass "SCHED_FIFO used with -F flag"
- elif grep -qi "deadline\|SCHED_DEADLINE" "${STALLD_LOG2}"; then
- fail "SCHED_DEADLINE used despite -F flag"
- else
- log "⚠ WARNING: Scheduling policy not explicitly mentioned in logs"
- fi
-else
- log "⚠ WARNING: No boosting detected with -F flag"
-fi
+assert_boost_detected "${STALLD_LOG2}" "Boosting occurred with -F flag"
+assert_log_contains --ignore-case "${STALLD_LOG2}" "sched_fifo" "SCHED_FIFO used with -F flag"
# Cleanup
cleanup_scenario "${STARVE_PID}"
@@ -134,21 +110,7 @@ log "Creating starvation on CPU ${TEST_CPU} for ${long_starvation}s"
start_starvation_gen -c ${TEST_CPU} -p 80 -n 2 -d ${long_starvation}
# Wait for detection and boosting
-if wait_for_boost_detected "${STALLD_LOG4}"; then
- log "Boosting detected, waiting for duration cycle"
-
- # Wait for boost duration + buffer to see restoration
- sleep 5
-
- # Check for restoration messages (part of FIFO emulation)
- if grep -qi "restor\|unboosted\|normal\|original" "${STALLD_LOG4}"; then
- pass "FIFO emulation with restoration detected"
- else
- log "ℹ INFO: FIFO boosting completed (restoration may be implicit)"
- fi
-else
- log "⚠ WARNING: No boosting detected for FIFO emulation test"
-fi
+assert_boost_detected "${STALLD_LOG4}" "FIFO emulation boosting detected"
# Cleanup
cleanup_scenario "${STARVE_PID}"
diff --git a/tests/functional/test_idle_detection.sh b/tests/functional/test_idle_detection.sh
index f238c7e..5647129 100755
--- a/tests/functional/test_idle_detection.sh
+++ b/tests/functional/test_idle_detection.sh
@@ -152,11 +152,7 @@ start_stalld_with_log "${STALLD_LOG}" -f -v -l -t $threshold -c ${TEST_CPU} -a $
sleep 3
-if grep -q "skipping" "${STALLD_LOG}"; then
- pass "Idle CPU correctly skipped"
-else
- fail "No skipping messages for idle CPU"
-fi
+assert_log_contains "${STALLD_LOG}" "skipping" "Idle CPU correctly skipped"
cleanup_scenario
diff --git a/tests/functional/test_log_only.sh b/tests/functional/test_log_only.sh
index b10b4d9..6a26b93 100755
--- a/tests/functional/test_log_only.sh
+++ b/tests/functional/test_log_only.sh
@@ -61,13 +61,7 @@ echo "Waiting for starvation detection..."
assert_starvation_detected "${LOG_FILE}" "stalld detected and logged starvation"
# Check that stalld did NOT boost (should not see "boosted" message with -l)
-if ! grep -q "boosted" "${LOG_FILE}"; then
- pass "stalld did not boost in log-only mode"
-else
- fail "stalld boosted despite -l flag"
- echo "Log contents:"
- cat "${LOG_FILE}"
-fi
+assert_log_contains --negate "${LOG_FILE}" "boosted" "stalld did not boost in log-only mode"
# Cleanup
cleanup_scenario "${STARVGEN_PID}"
diff --git a/tests/functional/test_logging_destinations.sh b/tests/functional/test_logging_destinations.sh
index 7b15c68..2ec61af 100755
--- a/tests/functional/test_logging_destinations.sh
+++ b/tests/functional/test_logging_destinations.sh
@@ -41,9 +41,7 @@ if assert_process_running "${STALLD_PID}" "stalld should be running"; then
pass "verbose mode produces output"
# Should contain initialization messages
- if grep -q -E "(stalld|version|monitoring)" "${LOG_FILE}"; then
- pass "output contains expected messages"
- fi
+ assert_log_contains "${LOG_FILE}" "stalld\|version\|monitoring" "output contains expected messages"
else
fail "no output in verbose mode"
fi
diff --git a/tests/functional/test_starvation_detection.sh b/tests/functional/test_starvation_detection.sh
index 44024c7..2d2e9b1 100755
--- a/tests/functional/test_starvation_detection.sh
+++ b/tests/functional/test_starvation_detection.sh
@@ -47,18 +47,10 @@ if wait_for_starvation_detected "${STALLD_LOG}"; then
pass "Starvation detected"
# Verify correct CPU is logged
- if grep "starved on CPU ${TEST_CPU}" "${STALLD_LOG}"; then
- pass "Correct CPU ID logged (CPU ${TEST_CPU})"
- else
- fail "Wrong CPU ID in log"
- fi
+ assert_log_contains "${STALLD_LOG}" "starved on CPU ${TEST_CPU}" "Correct CPU ID logged (CPU ${TEST_CPU})"
# Verify duration is logged
- if grep -E "starved on CPU ${TEST_CPU} for [0-9]+ seconds" "${STALLD_LOG}"; then
- pass "Starvation duration logged"
- else
- fail "Starvation duration not logged"
- fi
+ assert_log_contains "${STALLD_LOG}" "starved on CPU ${TEST_CPU} for [0-9]" "Starvation duration logged"
else
fail "Starvation not detected"
log "Log contents:"
@@ -249,15 +241,9 @@ sleep $((threshold + 3))
# Verify this task was NOT reported as starved
# Since it's making progress, stalld shouldn't detect it
-if ! grep "starved" "${STALLD_LOG}"; then
- pass "No false positive - task making progress not reported as starved"
-else
- if grep "${BUSY_PID}" "${STALLD_LOG}" | grep -q "starved"; then
- fail "False positive - progress-making task ${BUSY_PID} reported as starved"
- else
- pass "No false positive - starvation detected from other tasks, not ours"
- fi
-fi
+assert_log_contains --negate "${STALLD_LOG}" \
+ "${BUSY_PID}.*starved" \
+ "No false positive - progress-making task not reported as starved"
kill ${BUSY_PID} 2>/dev/null
wait ${BUSY_PID} 2>/dev/null
@@ -289,13 +275,7 @@ else
fi
# Check for error messages
-if grep -iE "error|segfault|crash" "${STALLD_LOG}"; then
- fail "Error messages found in log"
- log "Errors:"
- grep -iE "error|segfault|crash" "${STALLD_LOG}"
-else
- pass "No error messages in log"
-fi
+assert_log_contains --negate --ignore-case "${STALLD_LOG}" "error\|segfault\|crash" "No error messages in log"
stop_stalld
diff --git a/tests/functional/test_starvation_threshold.sh b/tests/functional/test_starvation_threshold.sh
index 79fa17b..b0eeb59 100755
--- a/tests/functional/test_starvation_threshold.sh
+++ b/tests/functional/test_starvation_threshold.sh
@@ -70,13 +70,9 @@ wait "${STARVE_PID}" 2>/dev/null || true
sleep 2
# Check that starvation_gen was NOT detected (duration less than threshold)
-if ! grep -qE "starvation_gen.*starved on CPU ${TEST_CPU}|starved on CPU ${TEST_CPU}.*starvation_gen" "${STALLD_LOG}"; then
- pass "No starvation detected for duration less than threshold"
-else
- fail "Starvation detected before threshold"
- log "Found starvation_gen task in logs:"
- grep -E "starvation_gen.*starved on CPU|starved on CPU.*starvation_gen" "${STALLD_LOG}"
-fi
+assert_log_contains --negate "${STALLD_LOG}" \
+ "starvation_gen.*starved on CPU ${TEST_CPU}\|starved on CPU ${TEST_CPU}.*starvation_gen" \
+ "No starvation detected for duration less than threshold"
# Cleanup
cleanup_scenario "${STARVE_PID}"
diff --git a/tests/helpers/test_helpers.sh b/tests/helpers/test_helpers.sh
index 2b744d0..3807670 100755
--- a/tests/helpers/test_helpers.sh
+++ b/tests/helpers/test_helpers.sh
@@ -191,6 +191,44 @@ assert_boost_detected() {
fi
}
+# Assert that a log file contains (or does not contain) a pattern.
+#
+# Usage: assert_log_contains [--negate] [--ignore-case] <log_file> <pattern> <message>
+assert_log_contains() {
+ local negate=0
+ local grep_opts="-q -e"
+ while true; do
+ case "$1" in
+ --negate) negate=1; shift ;;
+ --ignore-case) grep_opts="-q -i -e"; shift ;;
+ *) break ;;
+ esac
+ done
+ local log_file=$1
+ local pattern=$2
+ local message=$3
+
+ local found=0
+ grep ${grep_opts} "${pattern}" -- "${log_file}" 2>/dev/null && found=1
+
+ if [ $negate -eq 1 ]; then
+ found=$((1 - found))
+ fi
+
+ if [ $found -eq 1 ]; then
+ pass "${message}"
+ return 0
+ else
+ fail "${message}"
+ if [ $negate -eq 1 ]; then
+ log " Pattern '${pattern}' found in ${log_file} but should not be"
+ else
+ log " Pattern '${pattern}' not found in ${log_file}"
+ fi
+ return 1
+ fi
+}
+
# Assert that stalld rejects invalid arguments and exits non-zero.
# Usage: assert_stalld_rejects <message> [stalld_args...]
assert_stalld_rejects() {
@@ -1260,7 +1298,8 @@ start_starvation_gen() {
}
# Export functions for use in tests
-export -f start_test end_test test_section cleanup_scenario find_starved_child assert_starvation_detected assert_boost_detected assert_stalld_rejects
+export -f start_test end_test test_section cleanup_scenario find_starved_child
+export -f assert_starvation_detected assert_boost_detected assert_stalld_rejects assert_log_contains
export -f pass fail assert_equals assert_contains assert_not_contains
export -f assert_file_exists assert_file_not_exists
export -f assert_process_running assert_process_not_running
--
2.54.0