feat(bench): synthetic load harness for flat-file backend (P1-P5)

End-to-end performance and correctness harness for the flat-file +
SQLite database backends. Lives in tests/bench/, built only on
demand (`make bench`); not part of `make check`.

Components

  gen_history (P1)
    Deterministic corpus generator. Knobs: lines, contacts, years,
    seed, stanza-id mode (uuid/libpurple/conversations/mixed), LMC
    rate, MAM-OOO rate, resources/contact, length profile
    (short/mixed/long/extreme). Emits the canonical
    flatlog/<account>/<contact>/history.log layout used by
    ff_verify_integrity. ~340 LOC.

  bench_runner (P1, P2.5)
    S1 cold tail-access via sparse index
    S2 warm tail-access (page cache hot)
    S3 deep pagination (1000 binary-search lookups)
    S4 first-time index build (cold file -> ff_state_ensure_fresh)
    S5 incremental extend (asserts no full rebuild path)
    S6 real ff_verify_integrity over the contact tree
    Reports total/err/warn/info issue counts in the CSV note.

  bench_long_messages (P2)
    L1-L14 long-message stress: 1KB up to 9.9MB bodies, plus
    oversized line rejection (10MB+1 -> ff_readline returns ""),
    embedded-newline / pipe / emoji body patterns, full parse on
    100x1MB, 1000x100KB sustained append.

  bench_failure_modes (P3)
    F1-F15 failure-injection: truncated last line, mid-file CRLF,
    mid-file BOM, LMC cycle, LMC depth>FF_MAX_LMC_DEPTH, manual
    ': ' in resource, RTL/ZWSP, Latin-1 byte, empty body,
    mtime/inode flip, empty file. Each test asserts expected issue
    levels and reports PASS/FAIL.

  bench_export_import (P5)
    Links real database_export.c + database_sqlite.c + database.c
    and drives log_database_export_to_flatfile /
    log_database_import_from_flatfile under load.
    Subcommands: seed, export, import, roundtrip, verify.
    S7a/b export, S8a/b import, S8e roundtrip with full byte-by-byte
    content diff of every row in (from_jid, to_jid, message,
    timestamp, type, stanza_id, archive_id, encryption, replace_id).

Make targets

  bench-quick / bench / bench-full
  bench-longmsg, bench-failure
  bench-multicontact, bench-lmc, bench-ooo
  bench-export, bench-import, bench-roundtrip
  bench-pipeline, bench-pipeline-max (1M rows)
  bench-compare, bench-update-baseline

Volume controls: BENCH_VOLUME (small/medium/max), BENCH_PIPE_ROWS,
BENCH_PIPE_ROWS_MAX, BENCH_DATA_DIR, BENCH_CSV.

Baseline + regression checking (P4)

  tests/bench/baseline.csv       51 rows: S1-S6 x {small,lmc,ooo}
                                 + L1-L14 + F1-F15 (11 of 15) +
                                 S7/S8 x {pipe100k, pipe1M}.
  compare_baseline.py            median over duplicate rows;
                                 exits 1 on any (scenario, volume)
                                 slowdown >= threshold (default 25%).

Verified at scale

  bench-pipeline-max: 1,000,000 rows, full content diff
    seed   17 s, export 304 s, import 31 s, idempotent re-import 10 s,
    diff 2.7 s -- mismatches=0.

Findings surfaced by the harness

  Export scales super-linearly: 4 s @ 100k -> 304 s @ 1M (76x for
    10x rows). Cause: g_slist_sort on the merged list + per-row
    ProfMessage/ff_parsed_line_t allocations. RSS peaks at 1.4 GB
    on 1M. Worth a follow-up.
  Export progress reporting only fires during the write phase --
    the merge+sort phase (~95% of wall time at 1M) is silent.
  /history export and /history import are blocking on the main
    UI thread; profanity is frozen for the duration (~5 min @ 1M).
  ff_readline sets *truncated=TRUE on partial-write tail but
    ff_verify_integrity does not surface this -- partial writes
    go unflagged (failure-injection F1).
  Parser silently truncates body at first unescaped ': ' if a
    resource was manually edited to contain it (F9).
  In gen_history (caught by the bench's own real-verify pass):
    g_strndup mid-codepoint truncation on UTF-8 bank strings -- fixed.

Linkage strategy

  database_flatfile.c + parser + verify + common.c are linked
  unconditionally. The export/import bench additionally links
  database.c + database_sqlite.c + database_export.c. bench_stubs.c
  provides minimal stubs for log_*, prefs_*, connection_get_jid,
  jid_create, files_*, message_*, ui hooks. integrity_issue_free
  is a weak symbol so it falls back to the real database.c
  implementation when that file is linked.
This commit is contained in:
2026-04-30 15:39:30 +03:00
parent 8868d58920
commit b1d820462a
15 changed files with 4241 additions and 0 deletions

537
tests/bench/bench_runner.c Normal file
View File

@@ -0,0 +1,537 @@
// SPDX-License-Identifier: GPL-3.0-or-later
//
// This file is part of CProof.
// See LICENSE for the full GPLv3 text and the special OpenSSL linking exception.
/*
* bench_runner.c
* vim: expandtab:ts=4:sts=4:sw=4
*
* Bench harness driver for the flat-file backend. Measures the underlying
* mechanics (state-build, sparse-index lookup, line throughput, verify).
*
* Pipeline:
* 1. Run gen_history first to populate $BENCH_DATA_DIR/contacts/<jid>/history.log.
* 2. ./bench_runner --data=DIR --csv=PATH [--scenarios=S1,S2,...]
* 3. Each scenario writes a row to the CSV.
*
* The harness does NOT invoke gen_history itself — that's the Makefile's
* job. This keeps the binary's deps minimal.
*
* Scenarios (S1S6 in P1):
* S1 cold tail-access open contact, drop cache, fetch last 100 lines
* S2 warm tail-access same as S1 but page-cache hot
* S3 deep pagination scroll back N=100 pages × 100 lines via index
* S4 first index build ff_state_new + ff_state_ensure_fresh on cold file
* S5 incremental extend append M lines, ensure_fresh -> measure (no rebuild)
* S6 verify integrity ff_verify_integrity over full file
*/
#include "config.h"
#include <errno.h>
#include <fcntl.h>
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/stat.h>
#include <time.h>
#include <unistd.h>
#include <glib.h>
#include <glib/gstdio.h>
#include "bench_common.h"
#include "bench_csv.h"
#include "database_flatfile.h"
// g_flatfile_account_jid is declared in database_flatfile.h. We assign to
// it directly (skip _flatfile_init which pulls in xmpp / connection deps).
// ---------------------------------------------------------------------------
// CLI
typedef struct
{
const char* data_dir;
const char* csv_path;
const char* scenarios; // comma-separated list, or "all"
const char* account_jid;
int extend_lines; // for S5
} cli_t;
static void
cli_default(cli_t* c)
{
c->data_dir = NULL;
c->csv_path = NULL;
c->scenarios = "all";
c->account_jid = "bench@bench.example";
c->extend_lines = 1000;
}
static int
parse_args(int argc, char** argv, cli_t* c)
{
cli_default(c);
for (int i = 1; i < argc; i++) {
const char* a = argv[i];
if (strncmp(a, "--data=", 7) == 0) c->data_dir = a + 7;
else if (strncmp(a, "--csv=", 6) == 0) c->csv_path = a + 6;
else if (strncmp(a, "--scenarios=", 12) == 0) c->scenarios = a + 12;
else if (strncmp(a, "--account=", 10) == 0) c->account_jid = a + 10;
else if (strncmp(a, "--extend-lines=", 15) == 0) c->extend_lines = atoi(a + 15);
else {
fprintf(stderr, "unknown option: %s\n", a);
return -1;
}
}
if (!c->data_dir) {
fprintf(stderr, "--data=DIR required\n");
return -1;
}
return 0;
}
static int
scenario_enabled(const char* list, const char* name)
{
if (!list || g_strcmp0(list, "all") == 0)
return 1;
auto_gcharv gchar** parts = g_strsplit(list, ",", -1);
for (int i = 0; parts[i]; i++) {
if (g_strcmp0(g_strstrip(parts[i]), name) == 0)
return 1;
}
return 0;
}
// ---------------------------------------------------------------------------
// Pick the largest history.log in the corpus — that's our "primary" contact.
typedef struct
{
char* path;
int64_t size;
int64_t lines; // best-effort
} corpus_pick_t;
static int64_t
count_lines(const char* path)
{
FILE* fp = fopen(path, "r");
if (!fp) return -1;
int64_t n = 0;
int c;
while ((c = fgetc(fp)) != EOF) {
if (c == '\n')
n++;
}
fclose(fp);
return n;
}
static gboolean
pick_primary(const char* data_dir, const char* account_dir, corpus_pick_t* out)
{
auto_gchar gchar* contacts_root = g_strdup_printf("%s/flatlog/%s",
data_dir, account_dir);
GDir* d = g_dir_open(contacts_root, 0, NULL);
if (!d) {
fprintf(stderr, "cannot open %s\n", contacts_root);
return FALSE;
}
char* best_path = NULL;
int64_t best_size = 0;
const char* name;
while ((name = g_dir_read_name(d)) != NULL) {
auto_gchar gchar* path = g_strdup_printf("%s/%s/history.log", contacts_root, name);
struct stat st;
if (stat(path, &st) == 0 && S_ISREG(st.st_mode) && st.st_size > best_size) {
best_size = st.st_size;
g_free(best_path);
best_path = g_strdup(path);
}
}
g_dir_close(d);
if (!best_path) {
fprintf(stderr, "no history.log under %s\n", contacts_root);
return FALSE;
}
out->path = best_path;
out->size = best_size;
fprintf(stderr, " primary contact: %s (%" PRId64 " bytes)\n", best_path, best_size);
out->lines = count_lines(best_path);
fprintf(stderr, " primary lines: %" PRId64 "\n", out->lines);
return TRUE;
}
// ---------------------------------------------------------------------------
// Scenario S1/S2: tail-access via state index
//
// Build state for the file (fresh first time, cached subsequent), then for
// the last 100 lines:
// - find the byte offset of the (n_entries-1)-th sparse-index entry
// - seek there, read forward to EOF with ff_readline + ff_parse_line,
// keep the last 100 in a ring buffer.
// This mirrors the read path used by _flatfile_get_previous_chat without
// pulling in xmpp/connection deps.
#define TAIL_PAGE 100
static double
run_tail_access(const char* path, int drop_cache, long* peak_rss_kb, int64_t* lines_read)
{
if (drop_cache)
bench_drop_page_cache(path);
double t0 = bench_now_ms();
ff_contact_state_t* state = ff_state_new(path);
if (!ff_state_ensure_fresh(state)) {
ff_state_free(state);
if (lines_read) *lines_read = 0;
return -1.0;
}
off_t start = 0;
if (state->n_entries > 1) {
start = state->entries[state->n_entries - 1].byte_offset;
} else {
start = state->bom_len; // tiny file
}
FILE* fp = fopen(path, "r");
if (!fp) {
ff_state_free(state);
return -1.0;
}
if (fseeko(fp, start, SEEK_SET) != 0) {
fclose(fp);
ff_state_free(state);
return -1.0;
}
char* ring[TAIL_PAGE];
memset(ring, 0, sizeof(ring));
int ring_pos = 0;
int64_t parsed = 0;
char* buf;
while ((buf = ff_readline(fp, NULL)) != NULL) {
if (buf[0] == '\0' || buf[0] == '#') {
free(buf);
continue;
}
ff_parsed_line_t* pl = ff_parse_line(buf);
free(buf);
if (!pl)
continue;
parsed++;
if (ring[ring_pos]) g_free(ring[ring_pos]);
ring[ring_pos] = g_strdup(pl->message ? pl->message : "");
ring_pos = (ring_pos + 1) % TAIL_PAGE;
ff_parsed_line_free(pl);
}
fclose(fp);
ff_state_free(state);
for (int i = 0; i < TAIL_PAGE; i++)
g_free(ring[i]);
double dt = bench_now_ms() - t0;
if (peak_rss_kb)
*peak_rss_kb = bench_peak_rss_kb();
if (lines_read)
*lines_read = parsed;
return dt;
}
// ---------------------------------------------------------------------------
// S3: deep pagination — for each of N pages, pick a synthetic ts hint and
// call ff_state_offset_for_time to locate the page start. Measures binary
// search throughput.
static double
run_deep_pagination(const char* path, int n_pages, long* peak_rss_kb)
{
ff_contact_state_t* state = ff_state_new(path);
if (!ff_state_ensure_fresh(state)) {
ff_state_free(state);
return -1.0;
}
if (state->n_entries < 2) {
ff_state_free(state);
return 0.0;
}
double t0 = bench_now_ms();
// Walk through index entries, calling ff_state_offset_for_time with their
// recorded epochs (cheaper than parsing, still exercises binary search).
for (int i = 0; i < n_pages; i++) {
size_t idx = (size_t)i % state->n_entries;
gint64 epoch = state->entries[idx].timestamp_epoch;
// Convert epoch to iso roughly — ff_state_offset_for_time parses ISO.
time_t t = (time_t)epoch;
GDateTime* dt = g_date_time_new_from_unix_utc((gint64)t);
auto_gchar gchar* iso = g_date_time_format_iso8601(dt);
g_date_time_unref(dt);
(void)ff_state_offset_for_time(state, iso);
}
double dt = bench_now_ms() - t0;
if (peak_rss_kb)
*peak_rss_kb = bench_peak_rss_kb();
ff_state_free(state);
return dt;
}
// ---------------------------------------------------------------------------
// S4: first-time build — drop cache, ff_state_new + ensure_fresh
static double
run_first_build(const char* path, long* peak_rss_kb, size_t* idx_entries)
{
bench_drop_page_cache(path);
double t0 = bench_now_ms();
ff_contact_state_t* state = ff_state_new(path);
int ok = ff_state_ensure_fresh(state);
double dt = bench_now_ms() - t0;
if (idx_entries) *idx_entries = ok ? state->n_entries : 0;
if (peak_rss_kb) *peak_rss_kb = bench_peak_rss_kb();
ff_state_free(state);
return ok ? dt : -1.0;
}
// ---------------------------------------------------------------------------
// S5: incremental extend — already-built state, then append N synthetic lines
// (writing them via ff_write_line directly) and call ensure_fresh to verify
// it takes the extend path, not full rebuild.
static double
run_incremental_extend(const char* path, int n_lines, long* peak_rss_kb,
int64_t* added_bytes)
{
ff_contact_state_t* state = ff_state_new(path);
if (!ff_state_ensure_fresh(state)) {
ff_state_free(state);
return -1.0;
}
size_t before_entries = state->n_entries;
size_t before_lines = state->total_lines;
(void)before_entries;
// Append n_lines lines directly to the file
FILE* fp = fopen(path, "a");
if (!fp) {
ff_state_free(state);
return -1.0;
}
int64_t before_size = -1;
{
struct stat st;
if (stat(path, &st) == 0) before_size = st.st_size;
}
GDateTime* now = g_date_time_new_now_utc();
for (int i = 0; i < n_lines; i++) {
GDateTime* t = g_date_time_add_seconds(now, i);
auto_gchar gchar* iso = g_date_time_format_iso8601(t);
g_date_time_unref(t);
auto_gchar gchar* sid = g_strdup_printf("ext-%d-%ld", i, (long)random());
ff_write_line(fp, iso, "chat", "none",
sid, NULL, NULL,
"buddy000@bench.example", "ext",
NULL, NULL, -1,
"extend payload");
}
g_date_time_unref(now);
fclose(fp);
// Now measure: ensure_fresh should hit the extend path.
double t0 = bench_now_ms();
int ok = ff_state_ensure_fresh(state);
double dt = bench_now_ms() - t0;
if (added_bytes) {
struct stat st;
if (stat(path, &st) == 0 && before_size >= 0)
*added_bytes = (int64_t)st.st_size - before_size;
else
*added_bytes = -1;
}
if (peak_rss_kb) *peak_rss_kb = bench_peak_rss_kb();
fprintf(stderr, " S5: lines before=%zu after=%zu (delta=%zu)\n",
before_lines, state->total_lines,
state->total_lines - before_lines);
ff_state_free(state);
return ok ? dt : -1.0;
}
// ---------------------------------------------------------------------------
// S6: verify integrity — calls the real ff_verify_integrity, walking the
// canonical $data/flatlog/$account/$contact/history.log layout that
// gen_history produces. We set g_flatfile_account_jid in main() and
// BENCH_DATA_DIR + the stubbed files_get_data_path() resolves the prefix.
static int
_count_level(GSList* issues, integrity_level_t level)
{
int n = 0;
for (GSList* l = issues; l; l = l->next) {
integrity_issue_t* i = (integrity_issue_t*)l->data;
if (i && i->level == level) n++;
}
return n;
}
static double
run_verify(long* peak_rss_kb, int64_t* total_issues, int* errors, int* warnings, int* infos)
{
// Drop cache for everything under the flatlog tree we'll walk. Cheap
// compared to the verify itself, and keeps the cold-start signal clean.
auto_gchar gchar* data_path = g_strdup_printf("%s/flatlog", getenv("BENCH_DATA_DIR"));
(void)data_path;
double t0 = bench_now_ms();
GSList* issues = ff_verify_integrity(NULL); // NULL = all contacts
double dt = bench_now_ms() - t0;
int e = _count_level(issues, INTEGRITY_ERROR);
int w = _count_level(issues, INTEGRITY_WARNING);
int i = _count_level(issues, INTEGRITY_INFO);
int total = g_slist_length(issues);
// Surface up to 5 errors / 3 warnings — helps debug bench-vs-real mismatches.
int shown_err = 0, shown_warn = 0;
for (GSList* l = issues; l; l = l->next) {
integrity_issue_t* iss = (integrity_issue_t*)l->data;
if (!iss) continue;
if (iss->level == INTEGRITY_ERROR && shown_err < 5) {
fprintf(stderr, " ERR %s:%d %s\n",
iss->file ? iss->file : "?", iss->line, iss->message ? iss->message : "");
shown_err++;
} else if (iss->level == INTEGRITY_WARNING && shown_warn < 3) {
fprintf(stderr, " WARN %s:%d %s\n",
iss->file ? iss->file : "?", iss->line, iss->message ? iss->message : "");
shown_warn++;
}
}
g_slist_free_full(issues, (GDestroyNotify)integrity_issue_free);
if (peak_rss_kb) *peak_rss_kb = bench_peak_rss_kb();
if (total_issues) *total_issues = total;
if (errors) *errors = e;
if (warnings) *warnings = w;
if (infos) *infos = i;
return dt;
}
// ---------------------------------------------------------------------------
// Driver
int
main(int argc, char** argv)
{
cli_t cli;
if (parse_args(argc, argv, &cli) != 0)
return 2;
g_flatfile_account_jid = g_strdup(cli.account_jid);
auto_gchar gchar* account_dir = ff_jid_to_dir(cli.account_jid);
// Sanity: data_dir/flatlog/<account_dir>/ must exist
auto_gchar gchar* contacts_root = g_strdup_printf("%s/flatlog/%s",
cli.data_dir, account_dir);
if (!g_file_test(contacts_root, G_FILE_TEST_IS_DIR)) {
fprintf(stderr, "ERROR: %s does not exist. Run gen_history first "
"(make sure --account matches).\n", contacts_root);
return 2;
}
corpus_pick_t pick = { 0 };
if (!pick_primary(cli.data_dir, account_dir, &pick))
return 2;
const char* volume_name = getenv("BENCH_VOLUME");
if (!volume_name) volume_name = "medium";
fprintf(stderr, "===== bench_runner: data=%s volume=%s =====\n", cli.data_dir, volume_name);
// ---- S1: cold tail access
if (scenario_enabled(cli.scenarios, "S1")) {
long rss = 0;
int64_t lr = 0;
double dt = run_tail_access(pick.path, /*drop=*/1, &rss, &lr);
fprintf(stderr, " S1 cold tail-access: %.2f ms (read %" PRId64 " lines)\n", dt, lr);
bench_csv_append(cli.csv_path, "S1_cold_tail", volume_name,
(uint64_t)pick.size, (uint64_t)pick.lines, dt, rss,
"tail page=100");
}
// ---- S2: warm tail access (run twice, take the warm)
if (scenario_enabled(cli.scenarios, "S2")) {
long rss = 0;
int64_t lr = 0;
run_tail_access(pick.path, /*drop=*/0, NULL, NULL);
double dt = run_tail_access(pick.path, /*drop=*/0, &rss, &lr);
fprintf(stderr, " S2 warm tail-access: %.2f ms (read %" PRId64 " lines)\n", dt, lr);
bench_csv_append(cli.csv_path, "S2_warm_tail", volume_name,
(uint64_t)pick.size, (uint64_t)pick.lines, dt, rss,
"tail page=100");
}
// ---- S3: deep pagination
if (scenario_enabled(cli.scenarios, "S3")) {
long rss = 0;
double dt = run_deep_pagination(pick.path, /*n_pages=*/1000, &rss);
fprintf(stderr, " S3 deep pagination (1000 lookups): %.2f ms\n", dt);
bench_csv_append(cli.csv_path, "S3_deep_pagination", volume_name,
(uint64_t)pick.size, (uint64_t)pick.lines, dt, rss,
"n_pages=1000");
}
// ---- S4: first-time index build
if (scenario_enabled(cli.scenarios, "S4")) {
long rss = 0;
size_t entries = 0;
double dt = run_first_build(pick.path, &rss, &entries);
fprintf(stderr, " S4 first build: %.2f ms (idx entries=%zu)\n", dt, entries);
auto_gchar gchar* note = g_strdup_printf("idx_entries=%zu", entries);
bench_csv_append(cli.csv_path, "S4_first_build", volume_name,
(uint64_t)pick.size, (uint64_t)pick.lines, dt, rss, note);
}
// ---- S5: incremental extend
if (scenario_enabled(cli.scenarios, "S5")) {
long rss = 0;
int64_t added = 0;
double dt = run_incremental_extend(pick.path, cli.extend_lines, &rss, &added);
fprintf(stderr, " S5 incremental extend (%d lines, %" PRId64 " bytes): %.2f ms\n",
cli.extend_lines, added, dt);
auto_gchar gchar* note = g_strdup_printf("appended=%d_lines", cli.extend_lines);
bench_csv_append(cli.csv_path, "S5_incremental_extend", volume_name,
(uint64_t)added, (uint64_t)cli.extend_lines, dt, rss, note);
}
// ---- S6: verify integrity (real ff_verify_integrity over the tree)
if (scenario_enabled(cli.scenarios, "S6")) {
long rss = 0;
int64_t total = 0;
int errors = 0, warnings = 0, infos = 0;
double dt = run_verify(&rss, &total, &errors, &warnings, &infos);
fprintf(stderr,
" S6 verify_integrity: %.2f ms (total=%" PRId64
" err=%d warn=%d info=%d)\n",
dt, total, errors, warnings, infos);
auto_gchar gchar* note = g_strdup_printf(
"total=%" PRId64 " err=%d warn=%d info=%d", total, errors, warnings, infos);
bench_csv_append(cli.csv_path, "S6_verify", volume_name,
(uint64_t)pick.size, (uint64_t)pick.lines, dt, rss, note);
}
g_free(pick.path);
g_free(g_flatfile_account_jid);
g_flatfile_account_jid = NULL;
return 0;
}