Improve Functional Test Stability and CI Reliability #79

Manually merged
jabber.developer merged 7 commits from fix/test-CI-stability into master 2026-02-02 16:47:30 +00:00
7 changed files with 289 additions and 56 deletions
Showing only changes of commit 9a2a7614a9 - Show all commits

6
.gitignore vendored
View File

@@ -62,6 +62,8 @@ tests/unittests/unittests
tests/unittests/unittests.log
tests/unittests/unittests.trs
test-suite.log
test-files/
test-logs/
# valgrind output
profval*
@@ -108,3 +110,7 @@ breaks
*.zip
*.log*
coverage/
*.gcno
*.gcda
*.gcov
coverage.info

View File

@@ -90,6 +90,15 @@ set -e
```
This will run the same tests that the CI runs and refuse the push if it fails.
The CI script runs 4 parallel builds with different configurations, each with Valgrind and functional tests.
Build 1 also collects code coverage (lines, functions, branches).
jabber.developer marked this conversation as resolved Outdated

Could you clarify that "build 1" is a standard build without flags?

Could you clarify that "build 1" is a standard build without flags?

Corrected

Corrected
Output shows test results per build:
```
✓ Build 1 passed (unit: 437/0, func: 69/0, cov: L:27.5% F:36.2% B:18.1%, 5m39s)
✓ Build 2 passed (unit: 398/0, func: 69/0, 5m00s)
```
Note that it will run on the actual content of the repository directory and not
what may have been staged/committed.

View File

@@ -313,7 +313,7 @@ FUNC_TEST_GROUPS = 1 2 3 4
check-functional-parallel: tests/functionaltests/functionaltests
@echo "Running functional tests in parallel ($(words $(FUNC_TEST_GROUPS)) groups)..."
@mkdir -p $(builddir)/test-logs
@mkdir -p $(builddir)/test-logs $(builddir)/test-files
@pids=""; \
for g in $(FUNC_TEST_GROUPS); do \
./tests/functionaltests/functionaltests $$g > $(builddir)/test-logs/group$$g.log 2>&1 & \
@@ -372,7 +372,10 @@ clean-local:
rm -f $(git_include) $(git_include).in
endif
.PHONY: my-prof.supp
clean-functional-tests:
rm -rf $(builddir)/test-files $(builddir)/test-logs
.PHONY: my-prof.supp clean-functional-tests
my-prof.supp:
@sed '/^# AUTO-GENERATED START/q' prof.supp > $@
@printf "\n\n# glib\n" >> $@
@@ -388,7 +391,7 @@ check-unit: tests/unittests/unittests
tests/unittests/unittests
@VALGRIND_CHECK_RULES@
VALGRIND_SUPPRESSIONS_FILES=prof.supp
VALGRIND_SUPPRESSIONS_FILES=$(srcdir)/prof.supp
# Code coverage targets (requires --enable-coverage)
coverage-clean:

View File

@@ -180,30 +180,13 @@ case "$ARCH" in
;;
esac
case "$ARCH" in
linux*)
echo
echo "--> Building with ./configure -C ${tests[0]} --enable-valgrind $*"
echo
# shellcheck disable=SC2086
./configure -C ${tests[0]} --enable-valgrind $*
$MAKE CC="${CC}"
if grep '^ID=' /etc/os-release | grep -q -e debian; then
$MAKE check-valgrind
else
$MAKE check-valgrind || log_content ./test-suite-memcheck.log
fi
$MAKE distclean
;;
esac
# Function to build and test a single configuration
build_and_test() {
local features="$1"
local extra_args="$2"
local idx="$3"
local run_valgrind="$4"
local run_coverage="$5"
local build_dir="build-$idx"
local log_file="build-$idx.log"
@@ -211,14 +194,101 @@ build_and_test() {
echo "=== Build $idx started at $(date) ==="
echo "--> Building in $build_dir with ./configure -C $features $extra_args"
local start_time=$SECONDS
mkdir -p "$build_dir"
cd "$build_dir"
# shellcheck disable=SC2086
../configure -C $features $extra_args
if ! ../configure -C $features $extra_args; then
echo "ERROR: configure failed"
exit 1
fi
$MAKE CC="${CC}"
$MAKE check-functional-parallel
if ! $MAKE CC="${CC}"; then
echo "ERROR: make failed"
exit 1
fi
# Run unit tests under Valgrind
local unit_passed=0 unit_failed=0
if [ "$run_valgrind" = "yes" ]; then
echo "--> Running unit tests under Valgrind..."
# Build unit tests first
$MAKE tests/unittests/unittests
# Run valgrind directly to capture cmocka output
valgrind --error-exitcode=1 --leak-check=full \
--suppressions=../prof.supp \
tests/unittests/unittests 2>&1 | tee unit-tests-output.log
valgrind_exit=${PIPESTATUS[0]}
if [ $valgrind_exit -ne 0 ]; then
echo "ERROR: Valgrind unit tests failed (exit code $valgrind_exit)"
exit 1
fi
# Extract unit test counts from cmocka output
unit_passed=$(grep -E "^\[ PASSED \] [0-9]+ test" unit-tests-output.log | grep -oE "[0-9]+" | head -1)
unit_failed=$(grep -E "^\[ FAILED \] [0-9]+ test" unit-tests-output.log | grep -oE "[0-9]+" | head -1)
[ -z "$unit_passed" ] && unit_passed=0
[ -z "$unit_failed" ] && unit_failed=0
echo "UNIT_TESTS: passed=$unit_passed failed=$unit_failed"
fi
# Set build index for port allocation: build 1 uses ports 5230-5233,
# build 2 uses 5234-5237, etc. This prevents port conflicts in parallel builds.
export PROF_BUILD_INDEX=$idx
local func_passed=0 func_failed=0
if ! $MAKE check-functional-parallel; then
echo "ERROR: functional tests failed"
exit 1
fi
# Extract functional test counts from group logs
echo "=== Functional test results ==="
for glog in ./test-logs/group*.log; do
if [ -f "$glog" ]; then
cnt=$(grep -E "^\[ PASSED \] [0-9]+ test" "$glog" | grep -oE "[0-9]+" | head -1)
[ -n "$cnt" ] && func_passed=$((func_passed + cnt))
cnt=$(grep -E "^\[ FAILED \] [0-9]+ test" "$glog" | grep -oE "[0-9]+" | head -1)
[ -n "$cnt" ] && func_failed=$((func_failed + cnt))
fi
done
echo "FUNC_TESTS: passed=$func_passed failed=$func_failed"
# Collect coverage data if enabled (lines, functions, branches)
# Must be done BEFORE make clean which removes .gcda files
local cov_lines="n/a" cov_funcs="n/a" cov_branches="n/a"
if [ "$run_coverage" = "yes" ]; then
echo "--> Collecting coverage data..."
if command -v lcov >/dev/null 2>&1; then
lcov --capture --directory . --output-file coverage.info \
--rc lcov_branch_coverage=1 --ignore-errors inconsistent 2>&1 || true
jabber.developer marked this conversation as resolved Outdated

Wouldn't it get caught in the error handler declared earlier?

Wouldn't it get caught in the error handler declared earlier?

It is done foe log readability.

It is done foe log readability.
# Remove test files, stubs, system headers - only keep src/ production code
lcov --remove coverage.info \
'/usr/*' \
'*/tests/*' \
'*test*.c' \
jabber.developer marked this conversation as resolved Outdated

(same as above) Wouldn't it get caught in the error handler declared earlier?

(same as above) Wouldn't it get caught in the error handler declared earlier?

It is done foe log readability.

It is done foe log readability.
'*stub*.c' \
'*/functionaltests/*' \
'*/unittests/*' \
--output-file coverage.info \
--rc lcov_branch_coverage=1 --ignore-errors inconsistent 2>&1 || true
if [ -f coverage.info ] && [ -s coverage.info ]; then
local summary
summary=$(lcov --summary coverage.info \
--rc lcov_branch_coverage=1 --ignore-errors inconsistent 2>&1 || true)
cov_lines=$(echo "$summary" | grep -E "lines\.*:" | grep -oE "[0-9]+\.[0-9]+%" | head -1)
cov_funcs=$(echo "$summary" | grep -E "functions\.*:" | grep -oE "[0-9]+\.[0-9]+%" | head -1)
cov_branches=$(echo "$summary" | grep -E "branches\.*:" | grep -oE "[0-9]+\.[0-9]+%" | head -1)
[ -z "$cov_lines" ] && cov_lines="n/a"
[ -z "$cov_funcs" ] && cov_funcs="n/a"
[ -z "$cov_branches" ] && cov_branches="n/a"
else
echo "WARNING: coverage.info is empty or not created"
fi
else
echo "WARNING: lcov not found"
fi
echo "COVERAGE: lines=$cov_lines funcs=$cov_funcs branches=$cov_branches"
fi
./profanity -v
$MAKE clean
@@ -226,46 +296,103 @@ build_and_test() {
cd ..
rm -rf "$build_dir"
local elapsed=$((SECONDS - start_time))
local mins=$((elapsed / 60))
local secs=$((elapsed % 60))
echo "=== Build $idx completed at $(date) ==="
echo "STATS: unit_passed=$unit_passed unit_failed=$unit_failed func_passed=$func_passed func_failed=$func_failed cov_lines=$cov_lines cov_funcs=$cov_funcs cov_branches=$cov_branches time=${mins}m${secs}s"
} > "$log_file" 2>&1
}
# Run all 4 configurations in parallel
echo "Starting parallel builds..."
# Coverage enabled only for build 1 (Full) - it has most code paths
echo
echo "=== Start build ==="
echo
echo "Starting 4 parallel build configurations..."
echo
pids=()
for idx in 1 2 3 4; do
if [ $idx -le ${#tests[@]} ]; then
build_and_test "${tests[$((idx-1))]}" "$*" "$idx" &
# All builds run Valgrind
if [ "$ARCH" = "linux" ]; then
run_valgrind="yes"
if [ $idx -eq 1 ]; then
extra_flags="--enable-valgrind --enable-coverage"
run_coverage="yes"
else
extra_flags="--enable-valgrind"
run_coverage="no"
fi
else
extra_flags=""
run_valgrind="no"
run_coverage="no"
fi
build_and_test "${tests[$((idx-1))]}" "$* $extra_flags" "$idx" "$run_valgrind" "$run_coverage" &
pids+=("$!")
echo "Started build $idx (PID: $!)"
flags_desc=""
[ "$run_valgrind" = "yes" ] && flags_desc="Valgrind"
[ "$run_coverage" = "yes" ] && flags_desc="${flags_desc:+$flags_desc+}Coverage"
[ -n "$flags_desc" ] && flags_desc=" [+$flags_desc]"
echo " → Build $idx: ${tests[$((idx-1))]}$flags_desc"
fi
done
echo
# Wait for all builds and check exit codes
failed=0
echo "Waiting for builds to complete..."
echo
failed_builds=()
for i in "${!pids[@]}"; do
idx=$((i + 1))
if wait "${pids[$i]}"; then
echo "✓ Build $idx passed"
if [ -f "build-$idx.log" ]; then
stats_line=$(grep "^STATS:" "build-$idx.log" | tail -1)
unit_p=$(echo "$stats_line" | grep -oE "unit_passed=[0-9]+" | cut -d= -f2)
unit_f=$(echo "$stats_line" | grep -oE "unit_failed=[0-9]+" | cut -d= -f2)
func_p=$(echo "$stats_line" | grep -oE "func_passed=[0-9]+" | cut -d= -f2)
func_f=$(echo "$stats_line" | grep -oE "func_failed=[0-9]+" | cut -d= -f2)
cov_lines=$(echo "$stats_line" | grep -oE "cov_lines=[0-9.]+%|cov_lines=n/a" | cut -d= -f2)
cov_funcs=$(echo "$stats_line" | grep -oE "cov_funcs=[0-9.]+%|cov_funcs=n/a" | cut -d= -f2)
cov_branches=$(echo "$stats_line" | grep -oE "cov_branches=[0-9.]+%|cov_branches=n/a" | cut -d= -f2)
jabber.developer marked this conversation as resolved Outdated

Wouldn't it create trash in non-CI (local) run?

Wouldn't it create trash in non-CI (local) run?

Added [ -n "$CI" ] check. Artifacts only created in CI environment now.

Added [ -n "$CI" ] check. Artifacts only created in CI environment now.
time=$(echo "$stats_line" | grep -oE "time=[0-9]+m[0-9]+s" | cut -d= -f2)
unit_p=${unit_p:-0}
unit_f=${unit_f:-0}
func_p=${func_p:-0}
func_f=${func_f:-0}
echo "✓ BUILD $idx PASSED"
echo " Unit tests: $unit_p passed, $unit_f failed"
echo " Functional tests: $func_p passed, $func_f failed"
if [ "$cov_lines" != "n/a" ] && [ -n "$cov_lines" ]; then
echo " Coverage: Lines: $cov_lines | Functions: $cov_funcs | Branches: $cov_branches"
fi
echo " Duration: ${time:-?}"
else
echo "✓ Build $idx passed (no stats available)"
fi
else
echo "✗ Build $idx failed"
echo "--- Log for build $idx ---"
echo "✗ BUILD $idx FAILED"
failed_builds+=("$idx")
fi
echo
done
# Show failed builds full logs
for idx in "${failed_builds[@]}"; do
if [ -f "build-$idx.log" ]; then
echo "=== BUILD $idx FAILURE LOG ==="
cat "build-$idx.log"
echo "--- End log ---"
failed=1
echo
fi
done
# Show all logs on success too
if [ $failed -eq 0 ]; then
echo
echo "All builds passed!"
for idx in 1 2 3 4; do
if [ -f "build-$idx.log" ]; then
echo "--- Log for build $idx ---"
cat "build-$idx.log"
fi
done
else
if [ ${#failed_builds[@]} -gt 0 ]; then
echo "RESULT: FAILED (builds ${failed_builds[*]})"
exit 1
else
echo "RESULT: ALL 4 BUILDS PASSED ✓"
fi

View File

@@ -8,6 +8,29 @@
# * python suppressions file from https://github.com/python/cpython/blob/main/Misc/valgrind-python.supp
#
# ============================================
# glibc AVX2 optimizations (false positives)
# See: https://sourceware.org/bugzilla/show_bug.cgi?id=19796
# ============================================
{
glibc_wcpncpy_avx2
Memcheck:Addr32
fun:__wcpncpy_avx2
fun:wcsxfrm_l
fun:g_utf8_collate_key
...
}
{
glibc_wcsxfrm_avx2
Memcheck:Addr32
...
fun:wcsxfrm_l
fun:g_utf8_collate_key
...
}
# ============================================
# Functional tests suppressions (stabber/pthread)
# ============================================

View File

@@ -69,6 +69,12 @@ main(int argc, char* argv[])
}
}
char group_env[16];
snprintf(group_env, sizeof(group_env), "%d", group);
setenv("PROF_TEST_GROUP", group_env, 1);
fprintf(stderr, "[PROF_TEST] Starting functional tests, group=%d\n", group);
/* ============================================================
* GROUP 1: Connect, Ping, Rooms, Software
* Basic XMPP session establishment and server queries

View File

@@ -136,8 +136,14 @@ _create_logs_dir(void)
void
_cleanup_dirs(void)
{
const char *group_env = getenv("PROF_TEST_GROUP");
int group = group_env ? atoi(group_env) : 0;
int dir_id = (group >= 1 && group <= 4) ? group : stub_port;
jabber.developer marked this conversation as resolved Outdated

IMPORTANT:
Here and everywhere else: can we avoid magic constant of "4"? Can we make "TEST_GROUPS" constant or something similar? This way it would be much easier to adjust in the future

IMPORTANT: Here and everywhere else: can we avoid magic constant of "4"? Can we make "TEST_GROUPS" constant or something similar? This way it would be much easier to adjust in the future

Added #define TEST_GROUPS 4 constant.

Added #define TEST_GROUPS 4 constant.
fprintf(stderr, "[PROF_TEST] Cleaning up directories for group %d (dir_id %d)\n", group, dir_id);
char cmd[512];
snprintf(cmd, sizeof(cmd), "rm -rf ./tests/functionaltests/files/%d", stub_port);
snprintf(cmd, sizeof(cmd), "rm -rf ./test-files/%d", dir_id);
int res = system(cmd);
if (res == -1) {
assert_true(FALSE);
@@ -221,30 +227,73 @@ prof_start(void)
/* Set non-blocking mode for reading */
int flags = fcntl(fd, F_GETFL, 0);
fcntl(fd, F_SETFL, flags | O_NONBLOCK);
/* Brief wait for process to initialize */
usleep(50000); /* 50ms */
}
int
init_prof_test(void **state)
{
/* Get test group from environment for static resource allocation */
const char *group_env = getenv("PROF_TEST_GROUP");
int group = group_env ? atoi(group_env) : 0;
/* Get build index for port offset (for parallel CI builds) */
const char *build_env = getenv("PROF_BUILD_INDEX");
int build_idx = build_env ? atoi(build_env) : 0;
/* Calculate port base: each build uses a different range of 4 ports
* Build 0/1: 5230-5233, Build 2: 5234-5237, Build 3: 5238-5241, Build 4: 5242-5245 */
int port_base = 5230 + ((build_idx > 0 ? build_idx - 1 : 0) * 4);
jabber.developer marked this conversation as resolved
Review

Why 2 builds (0 and 1) share the same ports range?

Why 2 builds (0 and 1) share the same ports range?

Added explanation: builds 0/1 share ports because they're mutually exclusive (sequential mode or parallel).

Added explanation: builds 0/1 share ports because they're mutually exclusive (sequential mode or parallel).
/* Static resource allocation to avoid conflicts in parallel execution.
* Group 1-4: use static port assignment.
* Group 0 (all groups): use dynamic allocation as fallback. */
jabber.developer marked this conversation as resolved Outdated

Can we do something with the magic number 4 in the comments as well? Here and elsewhere

Can we do something with the magic number 4 in the comments as well? Here and elsewhere

Config names added additional to predefined values.

Config names added additional to predefined values.
gboolean started = FALSE;
for (int p = 5230; p < 5250; ++p) {
int ret = stbbr_start(STBBR_LOGDEBUG, p, 0);
if (ret == 0) {
stub_port = p;
if (group >= 1 && group <= 4) {
/* Static allocation: each group gets a dedicated port */
stub_port = port_base + group - 1;
fprintf(stderr, "[PROF_TEST] Build %d, Group %d: trying port %d\n", build_idx, group, stub_port);
jabber.developer marked this conversation as resolved Outdated

It shouldn't be at the stderr. It would make more sense to put it in the stdout, since it's informational/debug data.

It shouldn't be at the `stderr`. It would make more sense to put it in the stdout, since it's informational/debug data.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.
if (stbbr_start(STBBR_LOGDEBUG, stub_port, 0) == 0) {
started = TRUE;
break;
fprintf(stderr, "[PROF_TEST] Started stabber on port %d\n", stub_port);
jabber.developer marked this conversation as resolved
Review

It shouldn't be at the stderr. It would make more sense to put it in the stdout, since it's informational/debug data.

It shouldn't be at the `stderr`. It would make more sense to put it in the stdout, since it's informational/debug data.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.
} else {
fprintf(stderr, "[PROF_TEST] Failed to start stabber on port %d\n", stub_port);
}
}
/* Fallback to dynamic allocation if static failed or group=0 */
if (!started) {
jabber.developer marked this conversation as resolved
Review

Should be in stderr. Please check analogous cases

Should be in stderr. Please check analogous cases

Corrected.

Corrected.
assert_true(FALSE); // could not start stabber on any port in range
fprintf(stderr, "[PROF_TEST] Using dynamic port allocation\n");
jabber.developer marked this conversation as resolved
Review

It shouldn't be at the stderr. It would make more sense to put it in the stdout, since it's informational/debug data.

It shouldn't be at the `stderr`. It would make more sense to put it in the stdout, since it's informational/debug data.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.
for (int p = port_base; p < port_base + 20; ++p) {
if (stbbr_start(STBBR_LOGDEBUG, p, 0) == 0) {
stub_port = p;
started = TRUE;
fprintf(stderr, "[PROF_TEST] Started stabber on port %d\n", stub_port);
jabber.developer marked this conversation as resolved Outdated

It shouldn't be at the stderr. It would make more sense to put it in the stdout, since it's informational/debug data.

It shouldn't be at the `stderr`. It would make more sense to put it in the stdout, since it's informational/debug data.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.

Fixed. Info messages now use printf() (stdout), stderr reserved for errors only.
break;
}
}
}
if (!started) {
fprintf(stderr, "[PROF_TEST] ERROR: could not start stabber on any port\n");
assert_true(FALSE);
jabber.developer marked this conversation as resolved Outdated

Why do we need to do this?

Why do we need to do this?

Removed.

Removed.
return -1;
}
// Generate unique XDG paths based on stub_port for parallel execution
// Generate unique XDG paths based on group for parallel execution
// Use ./test-files/ in current (build) directory for out-of-tree builds compatibility
int dir_id = (group >= 1 && group <= 4) ? group : stub_port;
snprintf(xdg_config_home, sizeof(xdg_config_home),
"./tests/functionaltests/files/%d/xdg_config_home", stub_port);
"./test-files/%d/xdg_config_home", dir_id);
snprintf(xdg_data_home, sizeof(xdg_data_home),
"./tests/functionaltests/files/%d/xdg_data_home", stub_port);
"./test-files/%d/xdg_data_home", dir_id);
fprintf(stderr, "[PROF_TEST] Group %d using directories: config=%s, data=%s\n",
jabber.developer marked this conversation as resolved
Review

same as above

same as above

Removed

Removed
group, xdg_config_home, xdg_data_home);
// Give stabber server thread time to start listening
usleep(100000); // 100ms
@@ -398,9 +447,19 @@ prof_output_regex(const char *pattern)
return 1;
}
usleep(50000); /* 50ms */
usleep(50000);

50 ms clarifying comment was on point. But it should be formatted in the same manner as other comments (for inline comment, use either /* or //, not both)

50 ms clarifying comment was on point. But it should be formatted in the same manner as other comments (for inline comment, use either `/*` or `//`, not both)

corrected

corrected
}
/* Timeout reached - log diagnostic info */
fprintf(stderr, "Timeout waiting for regex '%s' after %d seconds. Last output:\n", pattern, expect_timeout);
size_t len = strlen(output_buffer);
if (len > 500) {
fprintf(stderr, "...%s", output_buffer + len - 500);
} else {
fprintf(stderr, "%s", output_buffer);
}
fprintf(stderr, "\n");
regfree(&regex);
return 0;
}