perf(functests): speedup — profrc pre-baking, pty-close shutdown, parallel port pools #103
@@ -12,6 +12,7 @@
|
||||
#include <fcntl.h>
|
||||
#include <sys/select.h>
|
||||
#include <regex.h>
|
||||
#include <signal.h>
|
||||
|
||||
#include <stabber.h>
|
||||
|
||||
@@ -20,11 +21,41 @@
|
||||
/* Number of parallel test groups for CI builds */
|
||||
#define TEST_GROUPS 4
|
||||
|
||||
/* Number of ports reserved per test group; allows skipping TIME_WAIT ports */
|
||||
#define PORTS_PER_GROUP 50
|
||||
|
||||
/* Base port and fallback scan range for stabber */
|
||||
#define BASE_PORT 5230
|
||||
#define FALLBACK_PORT_RANGE (TEST_GROUPS * PORTS_PER_GROUP)
|
||||
|
||||
/* Shutdown polling: interval and maximum attempts before escalating signals */
|
||||
#define MS_TO_US 1000
|
||||
#define SHUTDOWN_POLL_MS 50
|
||||
#define SHUTDOWN_POLL_MAX 100 /* 100 x 50ms = 5s */
|
||||
#define SIGTERM_POLL_MAX 20 /* 20 x 50ms = 1s */
|
||||
#define QUIT_GRACE_MS 100 /* grace for /quit to be read from pty */
|
||||
#define INIT_WAIT_MS 50 /* wait for child process to initialize */
|
||||
#define INPUT_DELAY_MS 10 /* let profanity process input */
|
||||
#define OUTPUT_POLL_MS 50 /* polling interval for output checks */
|
||||
#define READ_TIMEOUT_MS 100 /* select() timeout for pty reads */
|
||||
|
||||
/* Expect timeouts (seconds) */
|
||||
#define EXPECT_TIMEOUT_DEFAULT 30
|
||||
#define EXPECT_TIMEOUT_CONNECT 60
|
||||
|
||||
/* Terminal dimensions for forkpty */
|
||||
#define PTY_ROWS 24
|
||||
#define PTY_COLS 300
|
||||
|
||||
/* Preprocessor stringification (for setenv from numeric #define) */
|
||||
#define STRINGIFY_(x) #x
|
||||
#define STRINGIFY(x) STRINGIFY_(x)
|
||||
|
||||
char *config_orig;
|
||||
char *data_orig;
|
||||
|
||||
int fd = 0;
|
||||
int stub_port = 5230;
|
||||
int stub_port = BASE_PORT;
|
||||
pid_t child_pid = 0;
|
||||
|
||||
/*
|
||||
@@ -44,7 +75,7 @@ static char output_buffer[OUTPUT_BUF_SIZE];
|
||||
static size_t output_len = 0;
|
||||
|
||||
/* Timeout for expect operations in seconds */
|
||||
static int expect_timeout = 30;
|
||||
static int expect_timeout = EXPECT_TIMEOUT_DEFAULT;
|
||||
|
||||
gboolean
|
||||
_create_dir(const char *name)
|
||||
@@ -153,6 +184,12 @@ _cleanup_dirs(void)
|
||||
}
|
||||
}
|
||||
|
||||
static void
|
||||
sleep_ms(int ms)
|
||||
{
|
||||
usleep(ms * MS_TO_US);
|
||||
}
|
||||
|
||||
/*
|
||||
* Read available data from fd into output_buffer with timeout.
|
||||
* Returns number of bytes read, 0 on timeout, -1 on error.
|
||||
@@ -166,8 +203,8 @@ _read_output(int timeout_ms)
|
||||
FD_ZERO(&readfds);
|
||||
FD_SET(fd, &readfds);
|
||||
|
||||
tv.tv_sec = timeout_ms / 1000;
|
||||
tv.tv_usec = (timeout_ms % 1000) * 1000;
|
||||
tv.tv_sec = timeout_ms / MS_TO_US;
|
||||
tv.tv_usec = (timeout_ms % MS_TO_US) * MS_TO_US;
|
||||
|
||||
int ret = select(fd + 1, &readfds, NULL, NULL, &tv);
|
||||
if (ret <= 0) {
|
||||
@@ -198,8 +235,8 @@ void
|
||||
prof_start(void)
|
||||
{
|
||||
struct winsize ws;
|
||||
ws.ws_row = 24;
|
||||
ws.ws_col = 300; /* Match COLUMNS=300 from start_profanity.sh */
|
||||
ws.ws_row = PTY_ROWS;
|
||||
ws.ws_col = PTY_COLS;
|
||||
ws.ws_xpixel = 0;
|
||||
ws.ws_ypixel = 0;
|
||||
|
||||
@@ -216,7 +253,7 @@ prof_start(void)
|
||||
|
||||
if (child_pid == 0) {
|
||||
/* Child process */
|
||||
setenv("COLUMNS", "300", 1);
|
||||
setenv("COLUMNS", STRINGIFY(PTY_COLS), 1);
|
||||
setenv("TERM", "xterm", 1);
|
||||
|
||||
execl("./profanity", "./profanity", "-l", "DEBUG", NULL);
|
||||
@@ -232,7 +269,7 @@ prof_start(void)
|
||||
fcntl(fd, F_SETFL, flags | O_NONBLOCK);
|
||||
|
||||
/* Brief wait for process to initialize */
|
||||
usleep(50000); /* 50ms */
|
||||
sleep_ms(INIT_WAIT_MS);
|
||||
}
|
||||
|
||||
int
|
||||
@@ -246,38 +283,41 @@ init_prof_test(void **state)
|
||||
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 TEST_GROUPS ports.
|
||||
* Build 0 (local/default): 5230-5233, Full: 5230-5233, Minimal: 5234-5237, etc.
|
||||
* Build 0 and Full share the same range because build 0 is for local runs or sequential run (no parallel builds),
|
||||
|
jabber.developer marked this conversation as resolved
Outdated
|
||||
* while Full/Minimal/NoEncrypt/Default are used in CI where they run in parallel. */
|
||||
int port_base = 5230 + ((build_idx > 0 ? build_idx - 1 : 0) * TEST_GROUPS);
|
||||
/* Calculate port base: each build uses a different range of
|
||||
* TEST_GROUPS * PORTS_PER_GROUP ports.
|
||||
* Build 0 (local/default): 5230-5429, Full: 5230-5429, Minimal: 5430-5629, etc.
|
||||
* Build 0 and Full share the same range because build 0 is for local runs
|
||||
* or sequential run (no parallel builds), while Full/Minimal/NoEncrypt/Default
|
||||
* are used in CI where they run in parallel. */
|
||||
int port_base = BASE_PORT + ((build_idx > 0 ? build_idx - 1 : 0) * TEST_GROUPS * PORTS_PER_GROUP);
|
||||
|
||||
/* 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. */
|
||||
/* Each group gets a dedicated range of ports for parallel execution.
|
||||
* Group 1: port_base..port_base+PORTS_PER_GROUP-1
|
||||
* Group 2: port_base+PORTS_PER_GROUP..port_base+2*PORTS_PER_GROUP-1, etc.
|
||||
* Ports in TIME_WAIT from previous tests are skipped automatically. */
|
||||
gboolean started = FALSE;
|
||||
|
||||
|
||||
if (group >= 1 && group <= TEST_GROUPS) {
|
||||
/* Static allocation: each group gets a dedicated port */
|
||||
stub_port = port_base + group - 1;
|
||||
printf("[PROF_TEST] Build %d, Group %d: trying port %d\n", build_idx, group, stub_port);
|
||||
|
||||
if (stbbr_start(STBBR_LOGDEBUG, stub_port, 0) == 0) {
|
||||
started = TRUE;
|
||||
printf("[PROF_TEST] Started stabber on port %d\n", stub_port);
|
||||
} else {
|
||||
printf("[PROF_TEST] Failed to start stabber on port %d\n", stub_port);
|
||||
}
|
||||
}
|
||||
|
||||
/* Fallback to dynamic allocation if static failed or group=0 */
|
||||
if (!started) {
|
||||
printf("[PROF_TEST] Using dynamic port allocation\n");
|
||||
for (int p = port_base; p < port_base + 20; ++p) {
|
||||
int group_port_base = port_base + (group - 1) * PORTS_PER_GROUP;
|
||||
|
||||
for (int p = group_port_base; p < group_port_base + PORTS_PER_GROUP && !started; p++) {
|
||||
if (stbbr_start(STBBR_LOGDEBUG, p, 0) == 0) {
|
||||
stub_port = p;
|
||||
started = TRUE;
|
||||
}
|
||||
}
|
||||
if (!started) {
|
||||
fprintf(stderr, "[PROF_TEST] Failed to start stabber on ports %d-%d\n",
|
||||
group_port_base, group_port_base + PORTS_PER_GROUP - 1);
|
||||
}
|
||||
}
|
||||
|
||||
/* Fallback to dynamic allocation if static failed or group=0 */
|
||||
if (!started) {
|
||||
for (int p = port_base; p < port_base + FALLBACK_PORT_RANGE; ++p) {
|
||||
if (stbbr_start(STBBR_LOGDEBUG, p, 0) == 0) {
|
||||
stub_port = p;
|
||||
started = TRUE;
|
||||
|
jabber.developer marked this conversation as resolved
Outdated
jabber.developer
commented
Again comment reflects the change rather then adding the context to the code. It would make more sense to write why we setup this specific value prior to firing the tests (e.g., to ensure consistent output) Again comment reflects the change rather then adding the context to the code. It would make more sense to write why we setup this specific value prior to firing the tests (e.g., to ensure consistent output)
jabber.developer2
commented
Corrected Corrected
|
||||
printf("[PROF_TEST] Started stabber on port %d\n", stub_port);
|
||||
break;
|
||||
}
|
||||
}
|
||||
@@ -299,9 +339,6 @@ init_prof_test(void **state)
|
||||
printf("[PROF_TEST] Group %d using directories: config=%s, data=%s\n",
|
||||
group, xdg_config_home, xdg_data_home);
|
||||
|
||||
// Give stabber server thread time to start listening
|
||||
usleep(100000); // 100ms
|
||||
|
||||
config_orig = getenv("XDG_CONFIG_HOME");
|
||||
data_orig = getenv("XDG_DATA_HOME");
|
||||
|
||||
@@ -315,38 +352,37 @@ init_prof_test(void **state)
|
||||
_create_chatlogs_dir();
|
||||
_create_logs_dir();
|
||||
|
||||
/* Pre-write profrc with UI/notification defaults to ensure consistent,
|
||||
* deterministic output across tests (no timestamps, no roster/occupants
|
||||
* panels, low input-blocking delay for fast command processing). */
|
||||
char profrc_path[512];
|
||||
snprintf(profrc_path, sizeof(profrc_path),
|
||||
"%s/profanity/profrc", xdg_config_home);
|
||||
FILE* prc = fopen(profrc_path, "w");
|
||||
if (prc) {
|
||||
fprintf(prc,
|
||||
"[ui]\n"
|
||||
"inpblock=5\n"
|
||||
"inpblock.dynamic=false\n"
|
||||
"wrap=false\n"
|
||||
"roster=false\n"
|
||||
"occupants=false\n"
|
||||
"time.console=off\n"
|
||||
"time.chat=off\n"
|
||||
"time.muc=off\n"
|
||||
|
jabber.developer marked this conversation as resolved
Outdated
jabber.developer
commented
100 is a magic number; it should be defined as a constant where explanation could be provided 100 is a magic number; it should be defined as a constant where explanation could be provided
jabber.developer2
commented
Corrected Corrected
jabber.developer
commented
Not fixed actually ( Not fixed actually (`usleep(100000);`)
|
||||
"time.config=off\n"
|
||||
"time.private=off\n"
|
||||
"time.xmlconsole=off\n"
|
||||
"[notifications]\n"
|
||||
"message=false\n"
|
||||
|
jabber.developer marked this conversation as resolved
Outdated
jabber.developer
commented
here and later magic numbers here and later magic numbers
jabber.developer2
commented
Corrected Corrected
|
||||
"room=false\n");
|
||||
fclose(prc);
|
||||
}
|
||||
|
||||
prof_start();
|
||||
int prof_started = prof_output_regex("CProof\\. Type /help for help information\\.");
|
||||
assert_true(prof_started);
|
||||
|
||||
// set UI options to make expect assertions faster and more reliable
|
||||
prof_input("/inpblock timeout 5");
|
||||
assert_true(prof_output_regex("Input blocking set to 5 milliseconds"));
|
||||
prof_input("/inpblock dynamic off");
|
||||
assert_true(prof_output_regex("Dynamic input blocking disabled"));
|
||||
prof_input("/notify chat off");
|
||||
assert_true(prof_output_regex("Chat notifications disabled"));
|
||||
prof_input("/notify room off");
|
||||
assert_true(prof_output_regex("Room notifications disabled"));
|
||||
prof_input("/wrap off");
|
||||
assert_true(prof_output_regex("Word wrap disabled"));
|
||||
prof_input("/roster hide");
|
||||
assert_true(prof_output_regex("Roster disabled"));
|
||||
prof_input("/occupants default hide");
|
||||
assert_true(prof_output_regex("Occupant list disabled"));
|
||||
prof_input("/time console off");
|
||||
prof_input("/time console off");
|
||||
assert_true(prof_output_regex("Console time display disabled\\."));
|
||||
prof_input("/time chat off");
|
||||
assert_true(prof_output_regex("Chat time display disabled\\."));
|
||||
prof_input("/time muc off");
|
||||
assert_true(prof_output_regex("MUC time display disabled\\."));
|
||||
prof_input("/time config off");
|
||||
assert_true(prof_output_regex("Config time display disabled\\."));
|
||||
prof_input("/time private off");
|
||||
assert_true(prof_output_regex("Private chat time display disabled\\."));
|
||||
prof_input("/time xml off");
|
||||
assert_true(prof_output_regex("XML Console time display disabled\\."));
|
||||
return 0;
|
||||
}
|
||||
|
||||
@@ -355,11 +391,31 @@ close_prof_test(void **state)
|
||||
{
|
||||
if (fd > 0 && child_pid > 0) {
|
||||
prof_input("/quit");
|
||||
// Give profanity time to process quit command
|
||||
sleep(1);
|
||||
waitpid(child_pid, NULL, 0);
|
||||
/* Close pty master after brief grace — child gets SIGHUP which
|
||||
* accelerates shutdown instead of waiting for XMPP disconnect
|
||||
* timeout (~5s). */
|
||||
sleep_ms(QUIT_GRACE_MS);
|
||||
close(fd);
|
||||
fd = 0;
|
||||
int exited = 0;
|
||||
for (int i = 0; i < SHUTDOWN_POLL_MAX; i++) {
|
||||
|
jabber.developer marked this conversation as resolved
Outdated
jabber.developer
commented
The comment again reflects the change, though it also provides the context. However, I am not sure if it needs to stay. This context could be moved to the git commit message, which could later be checked via blame by anyone who plans to change this part. The comment again reflects the change, though it also provides the context. However, I am not sure if it needs to stay. This context could be moved to the git commit message, which could later be checked via blame by anyone who plans to change this part.
jabber.developer2
commented
Corrected Corrected
|
||||
if (waitpid(child_pid, NULL, WNOHANG) != 0) {
|
||||
exited = 1;
|
||||
break;
|
||||
}
|
||||
sleep_ms(SHUTDOWN_POLL_MS);
|
||||
}
|
||||
if (!exited) {
|
||||
kill(child_pid, SIGTERM);
|
||||
for (int i = 0; i < SIGTERM_POLL_MAX; i++) {
|
||||
if (waitpid(child_pid, NULL, WNOHANG) != 0) { exited = 1; break; }
|
||||
sleep_ms(SHUTDOWN_POLL_MS);
|
||||
}
|
||||
if (!exited) {
|
||||
kill(child_pid, SIGKILL);
|
||||
waitpid(child_pid, NULL, 0);
|
||||
}
|
||||
}
|
||||
child_pid = 0;
|
||||
}
|
||||
|
||||
@@ -371,13 +427,6 @@ close_prof_test(void **state)
|
||||
}
|
||||
|
||||
stbbr_stop();
|
||||
/*
|
||||
* TODO: Replace with proper synchronization.
|
||||
* stabber doesn't provide wait_stopped() API yet, so we use delay
|
||||
* to ensure the port is released before the next test starts.
|
||||
* See: https://git.jabber.space/devs/stabber/issues/3
|
||||
*/
|
||||
usleep(100000); // 100ms
|
||||
return 0;
|
||||
}
|
||||
|
||||
@@ -391,7 +440,7 @@ prof_input(const char *input)
|
||||
g_string_free(inp_str, TRUE);
|
||||
|
||||
/* Small delay to let profanity process input */
|
||||
usleep(10000);
|
||||
sleep_ms(INPUT_DELAY_MS);
|
||||
}
|
||||
|
||||
/*
|
||||
@@ -405,7 +454,7 @@ prof_output_exact(const char *text)
|
||||
|
||||
while (time(NULL) - start < expect_timeout) {
|
||||
/* Read any available output */
|
||||
while (_read_output(100) > 0) {
|
||||
while (_read_output(READ_TIMEOUT_MS) > 0) {
|
||||
/* Keep reading while data available */
|
||||
}
|
||||
|
||||
@@ -414,7 +463,7 @@ prof_output_exact(const char *text)
|
||||
return 1;
|
||||
}
|
||||
|
||||
usleep(50000); /* 50ms */
|
||||
sleep_ms(OUTPUT_POLL_MS);
|
||||
}
|
||||
|
||||
return 0;
|
||||
@@ -439,7 +488,7 @@ prof_output_regex(const char *pattern)
|
||||
|
||||
while (time(NULL) - start < expect_timeout) {
|
||||
/* Read any available output */
|
||||
while (_read_output(100) > 0) {
|
||||
while (_read_output(READ_TIMEOUT_MS) > 0) {
|
||||
/* Keep reading while data available */
|
||||
}
|
||||
|
||||
@@ -450,7 +499,7 @@ prof_output_regex(const char *pattern)
|
||||
return 1;
|
||||
}
|
||||
|
||||
usleep(50000); /* 50ms */
|
||||
sleep_ms(OUTPUT_POLL_MS);
|
||||
}
|
||||
|
||||
/* Timeout reached - log diagnostic info */
|
||||
@@ -492,12 +541,12 @@ prof_connect_with_roster(const char *roster)
|
||||
assert_true(prof_output_regex("password:"));
|
||||
prof_input("password");
|
||||
|
||||
expect_timeout = 60;
|
||||
expect_timeout = EXPECT_TIMEOUT_CONNECT;
|
||||
|
jabber.developer
commented
it feels like it could substituted with it feels like it could substituted with `prof_timeout_reset` to deduplicate code; it's out of scope though.
|
||||
assert_true(prof_output_regex("Connecting as stabber@localhost"));
|
||||
assert_true(prof_output_regex("logged in successfully"));
|
||||
assert_true(prof_output_regex(".+online.+ \\(priority 0\\)\\."));
|
||||
|
||||
expect_timeout = 60;
|
||||
expect_timeout = EXPECT_TIMEOUT_CONNECT;
|
||||
// Wait for presence stanza to be sent (content-based, not ID-based)
|
||||
// Match the actual attribute order from stanza_attach_caps
|
||||
assert_true(stbbr_received(
|
||||
@@ -516,7 +565,7 @@ prof_timeout(int timeout)
|
||||
void
|
||||
prof_timeout_reset(void)
|
||||
{
|
||||
expect_timeout = 60;
|
||||
expect_timeout = EXPECT_TIMEOUT_CONNECT;
|
||||
}
|
||||
|
||||
void
|
||||
|
||||
It was a useful explanation, I do not see a good reason to remove it.
Restored