perf+harden(export): 25x faster export at 1M, mkstemp, full-body dedup
Some checks failed
CI Code / Check spelling (pull_request) Failing after 21s
CI Code / Linux (arch) (pull_request) Failing after 3m6s
CI Code / Check coding style (pull_request) Failing after 3m10s
CI Code / Code Coverage (pull_request) Successful in 2m49s
CI Code / Linux (debian) (pull_request) Successful in 4m26s
CI Code / Linux (ubuntu) (pull_request) Successful in 4m38s

Address 6 of 7 high/medium audit findings on database_export.c.
End-to-end migration of 1M rows: ~5 min -> ~1 min.

  H1  cache g_slist_length(merged) out of the write loop — was O(n²)
      via 2000 list walks at 500-row progress interval, now O(1).
        S7a_export_cold @ 1M:  309 s -> 11.2 s  (-96 %)

  L1  splice existing flatfile lines into merged via ownership
      transfer instead of 12-strdup deep-copy + g_date_time_ref;
      free list nodes only, NULL out existing.
        S7b_export_dedup @ 1M: 304 s -> 13.3 s  (-96 %)
        RSS @ S7b 1M: 2.4 GB -> 1.9 GB

  H2  mkstemp() with random suffix instead of fixed
      "{log_path}.export.tmp". Eliminates the unlink-and-retry race
      where two concurrent exports could clobber each other's
      in-flight tmp files.

  M4  SHA-256 over full body (incremental g_checksum_update) in
      the dedup-key fallback. Previous body[:256] hash collided
      on common preambles (signatures, code blocks) — second
      occurrence silently dropped on import.

  M2  Refuse _ff_read_all_lines on files > 2 GB. Each line expands
      ~10x in heap on parse; without a cap we OOM-kill prof on
      large flatfiles. Surface a clear error instead.

  M5  Break the outer import loop on system-level INSERT failure.
      Was cascading "Import of X failed" through every remaining
      contact when the real issue was disk-full / sqlite locked.

Verified on bench-pipeline-max: 1M rows, full content diff,
mismatches=0. baseline.csv updated.

Deferred: M3 O_TMPFILE (platform-conditional + linkat dance;
mkstemp covers most of the same window) and M6 SIGINT cancellation
(needs event-loop architecture changes).
This commit is contained in:
2026-04-30 17:10:39 +03:00
parent b1d820462a
commit 555faaa232
2 changed files with 127 additions and 92 deletions

View File

@@ -53,15 +53,23 @@
static char*
_make_dedup_key(const char* stanza_id, const char* timestamp, const char* from_jid, const char* body)
{
if (stanza_id && strlen(stanza_id) > 0)
if (stanza_id && stanza_id[0] != '\0')
return g_strdup(stanza_id);
// Fallback: composite key from timestamp + sender + body prefix
auto_gchar gchar* raw = g_strdup_printf("%s|%s|%.256s",
timestamp ? timestamp : "",
from_jid ? from_jid : "",
body ? body : "");
return g_compute_checksum_for_string(G_CHECKSUM_SHA256, raw, -1);
// Fallback for messages without stanza-id: SHA-256 over the FULL body,
// not the first 256 bytes. The previous prefix-only hash collided on
// legitimate near-identical templates (signatures, code blocks, paste-
// bombs) — second occurrence was silently dropped on import. Hashing
// whole body is microseconds of extra work per row.
GChecksum* sum = g_checksum_new(G_CHECKSUM_SHA256);
g_checksum_update(sum, (const guchar*)(timestamp ? timestamp : ""), -1);
g_checksum_update(sum, (const guchar*)"|", 1);
g_checksum_update(sum, (const guchar*)(from_jid ? from_jid : ""), -1);
g_checksum_update(sum, (const guchar*)"|", 1);
g_checksum_update(sum, (const guchar*)(body ? body : ""), -1);
char* key = g_strdup(g_checksum_get_string(sum));
g_checksum_free(sum);
return key;
}
// =========================================================================
@@ -126,6 +134,12 @@ _ff_list_contacts(void)
// Returns GSList<ff_parsed_line_t*>. Caller frees with g_slist_free_full(list, (GDestroyNotify)ff_parsed_line_free).
// =========================================================================
// Hard ceiling on the total size of a single contact's history.log that
// _ff_read_all_lines is willing to slurp into memory. Each line expands
// ~10x on parse (12 g_strdup'd fields + GDateTime), so 2 GB on disk
// becomes ~20 GB peak heap — well past any realistic working set.
#define FF_EXPORT_MAX_FILE_BYTES (2LL * 1024 * 1024 * 1024)
static GSList*
_ff_read_all_lines(const char* contact_barejid)
{
@@ -134,6 +148,20 @@ _ff_read_all_lines(const char* contact_barejid)
if (!log_path)
return NULL;
// Refuse upfront if the file is so large that parsing will OOM the
// process. We have no streaming-parse path; the whole file becomes
// a GSList of ff_parsed_line_t in memory. Surface a clear error so
// the user knows what hit them, rather than the kernel killing prof.
struct stat st;
if (stat(log_path, &st) == 0 && st.st_size > FF_EXPORT_MAX_FILE_BYTES) {
log_error("export: %s is %lld bytes (> %lld limit); refusing to load.",
log_path, (long long)st.st_size,
(long long)FF_EXPORT_MAX_FILE_BYTES);
cons_show_error("Flat-file for %s exceeds %lld MB load limit; cannot export.",
contact_barejid, (long long)(FF_EXPORT_MAX_FILE_BYTES / (1024 * 1024)));
return NULL;
}
FILE* fp = fopen(log_path, "r");
if (!fp)
return NULL;
@@ -234,25 +262,28 @@ _export_one_contact(const char* contact)
auto_gchar gchar* dir = g_path_get_dirname(log_path);
ff_ensure_dir(dir);
auto_gchar gchar* tmp_path = g_strdup_printf("%s.export.tmp", log_path);
// Use open() with O_NOFOLLOW|O_EXCL to prevent symlink attacks,
// and explicit 0600 permissions (chat history is private).
int tmp_fd = open(tmp_path, O_WRONLY | O_CREAT | O_EXCL | O_NOFOLLOW, S_IRUSR | S_IWUSR);
// Use mkstemp() to create a unique-named temp file. The previous fixed
// "{log_path}.export.tmp" name + unlink-retry was vulnerable to two
// concurrent exports clobbering each other's in-flight tmp files
// (process B unlinks A's mid-write tmp, both race to write, second
// rename wins). Random suffix eliminates that.
//
// mkstemp on glibc creates the file with mode 0600. We fchmod to be
// sure across libc implementations. mkstemp uses O_RDWR|O_CREAT|O_EXCL
// internally; symlink attacks aren't possible because the name was
// just generated and no other process knows it.
auto_gchar gchar* tmp_path = g_strdup_printf("%s.export.XXXXXX", log_path);
int tmp_fd = mkstemp(tmp_path);
if (tmp_fd < 0) {
if (errno == EEXIST) {
// Stale temp file from previous failed export — remove and retry
unlink(tmp_path);
tmp_fd = open(tmp_path, O_WRONLY | O_CREAT | O_EXCL | O_NOFOLLOW, S_IRUSR | S_IWUSR);
}
}
if (tmp_fd < 0) {
log_error("export: cannot create %s: %s", tmp_path, strerror(errno));
log_error("export: mkstemp(%s) failed: %s", tmp_path, strerror(errno));
g_hash_table_destroy(seen_keys);
g_slist_free_full(existing, (GDestroyNotify)ff_parsed_line_free);
g_slist_free_full(sqlite_lines, (GDestroyNotify)message_free);
return -1;
}
if (fchmod(tmp_fd, S_IRUSR | S_IWUSR) != 0) {
log_warning("export: fchmod(%s, 0600) failed: %s", tmp_path, strerror(errno));
}
FILE* fp = fdopen(tmp_fd, "w");
if (!fp) {
log_error("export: fdopen failed for %s: %s", tmp_path, strerror(errno));
@@ -275,29 +306,18 @@ _export_one_contact(const char* contact)
int contact_exported = 0;
int contact_skipped = 0;
// Collect ALL lines into a merged list for sorted output
// Collect ALL lines into a merged list for sorted output.
// Transfer ownership of every parsed line from `existing` directly into
// `merged` instead of deep-copying — saves ~12 g_strdup calls per row,
// which dominate wall time at 100k+ rows. After splicing we free the
// list nodes (not the data) and NULL out existing so the final cleanup
// doesn't double-free.
GSList* merged = NULL;
// Add existing flatfile lines (mark as already seen in dedup)
for (GSList* l = existing; l; l = l->next) {
ff_parsed_line_t* pl = l->data;
// Create a shallow copy for the merged list (originals freed separately)
ff_parsed_line_t* copy = g_malloc0(sizeof(ff_parsed_line_t));
copy->timestamp_str = g_strdup(pl->timestamp_str);
copy->timestamp = pl->timestamp ? g_date_time_ref(pl->timestamp) : NULL;
copy->type = g_strdup(pl->type);
copy->enc = g_strdup(pl->enc);
copy->stanza_id = g_strdup(pl->stanza_id);
copy->archive_id = g_strdup(pl->archive_id);
copy->replace_id = g_strdup(pl->replace_id);
copy->from_jid = g_strdup(pl->from_jid);
copy->from_resource = g_strdup(pl->from_resource);
copy->to_jid = g_strdup(pl->to_jid);
copy->to_resource = g_strdup(pl->to_resource);
copy->marked_read = pl->marked_read;
copy->message = g_strdup(pl->message);
merged = g_slist_prepend(merged, copy);
merged = g_slist_prepend(merged, l->data);
}
g_slist_free(existing);
existing = NULL;
// Add SQLite messages that aren't already in the flatfile
for (GSList* l = sqlite_lines; l; l = l->next) {
@@ -339,6 +359,11 @@ _export_one_contact(const char* contact)
// Sort merged list by timestamp (ISO8601 is lexicographically sortable)
merged = g_slist_sort(merged, _compare_parsed_lines_by_timestamp);
// Cache the total length once — calling g_slist_length() inside the
// write loop is O(n) per call, turning the loop into O(n²) wall time
// (catastrophic at >100k rows).
int merged_total = (int)g_slist_length(merged);
// Write all lines sorted
int written = 0;
for (GSList* l = merged; l; l = l->next) {
@@ -351,7 +376,7 @@ _export_one_contact(const char* contact)
pl->message);
written++;
if (written % EXPORT_PROGRESS_INTERVAL == 0) {
cons_show(" ... %s: %d/%d written so far", contact, written, (int)g_slist_length(merged));
cons_show(" ... %s: %d/%d written so far", contact, written, merged_total);
}
}
@@ -572,6 +597,16 @@ log_database_import_from_flatfile(const gchar* const contact_jid)
g_hash_table_destroy(seen_keys);
g_slist_free_full(ff_lines, (GDestroyNotify)ff_parsed_line_free);
// If the per-contact import bailed mid-stream (likely a system-level
// problem: disk full, sqlite locked, etc.) — don't blindly try the
// remaining contacts; they'll almost certainly hit the same error
// and produce a confusing wall of "Import of X failed" messages.
// Stop here so the user can investigate the root cause.
if (!import_ok) {
cons_show_error("Aborting import — system-level failure suspected. Fix the underlying issue and retry.");
break;
}
}
g_slist_free_full(contacts, g_free);

View File

@@ -1,51 +1,51 @@
scenario,volume,bytes,lines,wall_ms,peak_rss_kb,note
S1_cold_tail,small,39494716,10002,46.040,14408,tail page=100
S2_warm_tail,small,39494716,10002,33.878,14716,tail page=100
S3_deep_pagination,small,39494716,10002,1.024,14716,n_pages=1000
S4_first_build,small,39494716,10002,39.139,14716,idx_entries=20
S5_incremental_extend,small,104411,1000,0.859,14716,appended=1000_lines
S6_verify,small,39494716,10002,396.022,16424,total=1 err=0 warn=1 info=0
L1,longmsg,110586,100,1.486,9432,n=100 body=1024 write=0.8ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 1KB body x100
L2,longmsg,1032186,100,10.468,9432,n=100 body=10240 write=5.7ms read=4.8ms parsed=100 mismatch=0 parse_fail=0 10KB body x100
L3,longmsg,10248186,100,100.337,9816,n=100 body=102400 write=57.3ms read=43.1ms parsed=100 mismatch=0 parse_fail=0 100KB body x100
L4,longmsg,52432936,50,502.785,13608,n=50 body=1048576 write=264.5ms read=238.3ms parsed=50 mismatch=0 parse_fail=0 1MB body x50
L5,longmsg,52429696,10,518.558,27764,n=10 body=5242880 write=264.4ms read=254.2ms parsed=10 mismatch=0 parse_fail=0 5MB body x10
L6,longmsg,41435552,4,407.803,45852,n=4 body=10358784 write=211.3ms read=196.5ms parsed=4 mismatch=0 parse_fail=0 9.9MB body x4 (just under FF_MAX_LINE_LEN)
L7,longmsg,10485981,2,3.750,45852,oversize=10485761_rejected=yes read=3.8ms parsed=1
L8,longmsg,5175286,50,45.549,45852,n=50 body=102400 write=26.6ms read=18.9ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ \n every 100B
L9,longmsg,5124136,50,45.487,45852,n=50 body=102400 write=24.5ms read=21.0ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ pipes
L10,longmsg,5124136,50,43.254,45852,n=50 body=102400 write=18.9ms read=24.4ms parsed=50 mismatch=0 parse_fail=0 100KB body utf-8 emoji
L11,longmsg,110586,100,1.284,45852,n=100 body=1024 write=0.7ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 sanity baseline
L12,longmsg,5415366,1000,26.437,45852,5x1MB_in_last_100 parsed=1000
L13,longmsg,104865786,100,932.630,45852,n=100 body=1048576 write=485.7ms read=446.9ms parsed=100 mismatch=0 parse_fail=0 verify-equiv full parse on 100x1MB
L14,longmsg,102481986,1000,962.342,45852,n=1000 body=102400 write=510.4ms read=452.0ms parsed=1000 mismatch=0 parse_fail=0 rapid append 1000x100KB
F1,fail-pass,904,0,0.118,9540,issues total=1 err=0 warn=1 (partial-line tail; expect graceful handle)
F2,fail-pass,1119,0,0.113,9540,warnings=2 (expect CRLF warning) first_warn=File permissions are 644 expected 600 (sensitive data)
F3,fail-pass,341,0,0.072,9540,errors=1 warnings=1 (expect 1 unparsable line for mid-file BOM) first=Unparsable line
F7,fail-pass,527,0,0.082,9540,issues total=1 err=0 (cycle handled at read-time not verify)
F8,fail-pass,19044,0,0.981,9540,201 lines (1 orig + 200 corrections) errors=0 warns=1
F9,fail-pass,341,0,0.069,9540,errors=0 (parser splits at first ': ' — not flagged but body truncated)
F10,fail-pass,176,0,0.060,9540,errors=0 warnings=1 (RTL/ZWSP preserved literally)
F11,fail-pass,323,0,0.264,9540,errors=1 (Latin-1 byte: error or fallback OK)
F12,fail-pass,330,0,0.071,9540,errors=0 (empty body OK)
F14,fail-pass,23236,0,0.914,9540,v1_lines=100 v2_lines=250 (expect rebuild detected and 250 lines)
F15,fail-pass,0,0,0.121,9540,errors=0 infos=1 warnings=1 (empty file should yield INFO)
S1_cold_tail,lmc,389183687,100002,480.428,43456,tail page=100
S2_warm_tail,lmc,389183687,100002,477.482,43456,tail page=100
S3_deep_pagination,lmc,389183687,100002,1.066,43456,n_pages=1000
S4_first_build,lmc,389183687,100002,473.604,43456,idx_entries=200
S5_incremental_extend,lmc,104411,1000,0.902,43456,appended=1000_lines
S6_verify,lmc,389183687,100002,3892.137,43456,total=1 err=0 warn=1 info=0
S6_verify,ooo,397586720,100002,4037.058,33336,total=17573 err=0 warn=17573 info=0
S7a_export_cold,pipe100000,40714240,100000,3925.249,148432,exported=100000 db_rows=100000
S7b_export_dedup,pipe100000,40714240,100000,3884.913,252396,exported=0 db_rows=100000
S7_seed_export,pipe100000,40714240,100000,3894.644,148320,exported=100000 db_rows=100000
S8a_import_cold,pipe100000,40628224,100000,3162.988,123212,imported=100000 rows_before=0 rows_after=100000
S8b_import_idempotent,pipe100000,40628224,0,1178.929,194896,imported=0 rows_before=100000 rows_after=100000
S8e_roundtrip,pipe100000,40521728,100000,8905.553,148340,rows=100000 seed=1640ms export=3730ms import=3258ms diff=277ms exported=100000 imported=100000 rows_a=100000 rows_b=100000 mismatches=0 body=0 lmc=0
S7a_export_cold,pipe1000000,407732224,1000000,309245.302,1376872,exported=1000000 db_rows=1000000
S7b_export_dedup,pipe1000000,407732224,1000000,303526.638,2418088,exported=0 db_rows=1000000
S7_seed_export,pipe1000000,407732224,1000000,304160.043,1377084,exported=1000000 db_rows=1000000
S8a_import_cold,pipe1000000,406605824,1000000,31288.288,1124984,imported=1000000 rows_before=0 rows_after=1000000
S8b_import_idempotent,pipe1000000,406605824,0,10418.850,1841644,imported=0 rows_before=1000000 rows_after=1000000
S8e_roundtrip,pipe1000000,405757952,1000000,352840.026,1377148,rows=1000000 seed=17637ms export=301062ms import=31430ms diff=2711ms exported=1000000 imported=1000000 rows_a=1000000 rows_b=1000000 mismatches=0 body=0 lmc=0
scenario,volume,bytes,lines,wall_ms,peak_rss_kb,note
S1_cold_tail,small,39494716,10002,46.040,14408,tail page=100
S2_warm_tail,small,39494716,10002,33.878,14716,tail page=100
S3_deep_pagination,small,39494716,10002,1.024,14716,n_pages=1000
S4_first_build,small,39494716,10002,39.139,14716,idx_entries=20
S5_incremental_extend,small,104411,1000,0.859,14716,appended=1000_lines
S6_verify,small,39494716,10002,396.022,16424,total=1 err=0 warn=1 info=0
L1,longmsg,110586,100,1.486,9432,n=100 body=1024 write=0.8ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 1KB body x100
L2,longmsg,1032186,100,10.468,9432,n=100 body=10240 write=5.7ms read=4.8ms parsed=100 mismatch=0 parse_fail=0 10KB body x100
L3,longmsg,10248186,100,100.337,9816,n=100 body=102400 write=57.3ms read=43.1ms parsed=100 mismatch=0 parse_fail=0 100KB body x100
L4,longmsg,52432936,50,502.785,13608,n=50 body=1048576 write=264.5ms read=238.3ms parsed=50 mismatch=0 parse_fail=0 1MB body x50
L5,longmsg,52429696,10,518.558,27764,n=10 body=5242880 write=264.4ms read=254.2ms parsed=10 mismatch=0 parse_fail=0 5MB body x10
L6,longmsg,41435552,4,407.803,45852,n=4 body=10358784 write=211.3ms read=196.5ms parsed=4 mismatch=0 parse_fail=0 9.9MB body x4 (just under FF_MAX_LINE_LEN)
L7,longmsg,10485981,2,3.750,45852,oversize=10485761_rejected=yes read=3.8ms parsed=1
L8,longmsg,5175286,50,45.549,45852,n=50 body=102400 write=26.6ms read=18.9ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ \n every 100B
L9,longmsg,5124136,50,45.487,45852,n=50 body=102400 write=24.5ms read=21.0ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ pipes
L10,longmsg,5124136,50,43.254,45852,n=50 body=102400 write=18.9ms read=24.4ms parsed=50 mismatch=0 parse_fail=0 100KB body utf-8 emoji
L11,longmsg,110586,100,1.284,45852,n=100 body=1024 write=0.7ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 sanity baseline
L12,longmsg,5415366,1000,26.437,45852,5x1MB_in_last_100 parsed=1000
L13,longmsg,104865786,100,932.630,45852,n=100 body=1048576 write=485.7ms read=446.9ms parsed=100 mismatch=0 parse_fail=0 verify-equiv full parse on 100x1MB
L14,longmsg,102481986,1000,962.342,45852,n=1000 body=102400 write=510.4ms read=452.0ms parsed=1000 mismatch=0 parse_fail=0 rapid append 1000x100KB
F1,fail-pass,904,0,0.118,9540,issues total=1 err=0 warn=1 (partial-line tail; expect graceful handle)
F2,fail-pass,1119,0,0.113,9540,warnings=2 (expect CRLF warning) first_warn=File permissions are 644 expected 600 (sensitive data)
F3,fail-pass,341,0,0.072,9540,errors=1 warnings=1 (expect 1 unparsable line for mid-file BOM) first=Unparsable line
F7,fail-pass,527,0,0.082,9540,issues total=1 err=0 (cycle handled at read-time not verify)
F8,fail-pass,19044,0,0.981,9540,201 lines (1 orig + 200 corrections) errors=0 warns=1
F9,fail-pass,341,0,0.069,9540,errors=0 (parser splits at first ': ' — not flagged but body truncated)
F10,fail-pass,176,0,0.060,9540,errors=0 warnings=1 (RTL/ZWSP preserved literally)
F11,fail-pass,323,0,0.264,9540,errors=1 (Latin-1 byte: error or fallback OK)
F12,fail-pass,330,0,0.071,9540,errors=0 (empty body OK)
F14,fail-pass,23236,0,0.914,9540,v1_lines=100 v2_lines=250 (expect rebuild detected and 250 lines)
F15,fail-pass,0,0,0.121,9540,errors=0 infos=1 warnings=1 (empty file should yield INFO)
S1_cold_tail,lmc,389183687,100002,480.428,43456,tail page=100
S2_warm_tail,lmc,389183687,100002,477.482,43456,tail page=100
S3_deep_pagination,lmc,389183687,100002,1.066,43456,n_pages=1000
S4_first_build,lmc,389183687,100002,473.604,43456,idx_entries=200
S5_incremental_extend,lmc,104411,1000,0.902,43456,appended=1000_lines
S6_verify,lmc,389183687,100002,3892.137,43456,total=1 err=0 warn=1 info=0
S6_verify,ooo,397586720,100002,4037.058,33336,total=17573 err=0 warn=17573 info=0
S7a_export_cold,pipe100000,40714240,100000,1231.613,148128,exported=100000 db_rows=100000
S7b_export_dedup,pipe100000,40714240,100000,1484.406,199460,exported=0 db_rows=100000
S7_seed_export,pipe100000,40714240,100000,1238.138,148208,exported=100000 db_rows=100000
S8a_import_cold,pipe100000,40628224,100000,3237.481,123108,imported=100000 rows_before=0 rows_after=100000
S8b_import_idempotent,pipe100000,40628224,0,1047.286,194860,imported=0 rows_before=100000 rows_after=100000
S8e_roundtrip,pipe100000,40521728,100000,6520.475,148184,rows=100000 seed=1591ms export=1237ms import=3376ms diff=317ms exported=100000 imported=100000 rows_a=100000 rows_b=100000 mismatches=0 body=0 lmc=0
S7a_export_cold,pipe1000000,407732224,1000000,11247.107,1376772,exported=1000000 db_rows=1000000
S7b_export_dedup,pipe1000000,407732224,1000000,13262.643,1873220,exported=0 db_rows=1000000
S7_seed_export,pipe1000000,407732224,1000000,12125.624,1377076,exported=1000000 db_rows=1000000
S8a_import_cold,pipe1000000,406605824,1000000,36877.801,1124804,imported=1000000 rows_before=0 rows_after=1000000
S8b_import_idempotent,pipe1000000,406605824,0,11986.786,1841488,imported=0 rows_before=1000000 rows_after=1000000
S8e_roundtrip,pipe1000000,405757952,1000000,66449.762,1377084,rows=1000000 seed=20012ms export=11939ms import=31533ms diff=2966ms exported=1000000 imported=1000000 rows_a=1000000 rows_b=1000000 mismatches=0 body=0 lmc=0
1 scenario volume bytes lines wall_ms peak_rss_kb note
2 S1_cold_tail small 39494716 10002 46.040 14408 tail page=100
3 S2_warm_tail small 39494716 10002 33.878 14716 tail page=100
4 S3_deep_pagination small 39494716 10002 1.024 14716 n_pages=1000
5 S4_first_build small 39494716 10002 39.139 14716 idx_entries=20
6 S5_incremental_extend small 104411 1000 0.859 14716 appended=1000_lines
7 S6_verify small 39494716 10002 396.022 16424 total=1 err=0 warn=1 info=0
8 L1 longmsg 110586 100 1.486 9432 n=100 body=1024 write=0.8ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 1KB body x100
9 L2 longmsg 1032186 100 10.468 9432 n=100 body=10240 write=5.7ms read=4.8ms parsed=100 mismatch=0 parse_fail=0 10KB body x100
10 L3 longmsg 10248186 100 100.337 9816 n=100 body=102400 write=57.3ms read=43.1ms parsed=100 mismatch=0 parse_fail=0 100KB body x100
11 L4 longmsg 52432936 50 502.785 13608 n=50 body=1048576 write=264.5ms read=238.3ms parsed=50 mismatch=0 parse_fail=0 1MB body x50
12 L5 longmsg 52429696 10 518.558 27764 n=10 body=5242880 write=264.4ms read=254.2ms parsed=10 mismatch=0 parse_fail=0 5MB body x10
13 L6 longmsg 41435552 4 407.803 45852 n=4 body=10358784 write=211.3ms read=196.5ms parsed=4 mismatch=0 parse_fail=0 9.9MB body x4 (just under FF_MAX_LINE_LEN)
14 L7 longmsg 10485981 2 3.750 45852 oversize=10485761_rejected=yes read=3.8ms parsed=1
15 L8 longmsg 5175286 50 45.549 45852 n=50 body=102400 write=26.6ms read=18.9ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ \n every 100B
16 L9 longmsg 5124136 50 45.487 45852 n=50 body=102400 write=24.5ms read=21.0ms parsed=50 mismatch=0 parse_fail=0 100KB body w/ pipes
17 L10 longmsg 5124136 50 43.254 45852 n=50 body=102400 write=18.9ms read=24.4ms parsed=50 mismatch=0 parse_fail=0 100KB body utf-8 emoji
18 L11 longmsg 110586 100 1.284 45852 n=100 body=1024 write=0.7ms read=0.6ms parsed=100 mismatch=0 parse_fail=0 sanity baseline
19 L12 longmsg 5415366 1000 26.437 45852 5x1MB_in_last_100 parsed=1000
20 L13 longmsg 104865786 100 932.630 45852 n=100 body=1048576 write=485.7ms read=446.9ms parsed=100 mismatch=0 parse_fail=0 verify-equiv full parse on 100x1MB
21 L14 longmsg 102481986 1000 962.342 45852 n=1000 body=102400 write=510.4ms read=452.0ms parsed=1000 mismatch=0 parse_fail=0 rapid append 1000x100KB
22 F1 fail-pass 904 0 0.118 9540 issues total=1 err=0 warn=1 (partial-line tail; expect graceful handle)
23 F2 fail-pass 1119 0 0.113 9540 warnings=2 (expect CRLF warning) first_warn=File permissions are 644 expected 600 (sensitive data)
24 F3 fail-pass 341 0 0.072 9540 errors=1 warnings=1 (expect 1 unparsable line for mid-file BOM) first=Unparsable line
25 F7 fail-pass 527 0 0.082 9540 issues total=1 err=0 (cycle handled at read-time not verify)
26 F8 fail-pass 19044 0 0.981 9540 201 lines (1 orig + 200 corrections) errors=0 warns=1
27 F9 fail-pass 341 0 0.069 9540 errors=0 (parser splits at first ': ' — not flagged but body truncated)
28 F10 fail-pass 176 0 0.060 9540 errors=0 warnings=1 (RTL/ZWSP preserved literally)
29 F11 fail-pass 323 0 0.264 9540 errors=1 (Latin-1 byte: error or fallback OK)
30 F12 fail-pass 330 0 0.071 9540 errors=0 (empty body OK)
31 F14 fail-pass 23236 0 0.914 9540 v1_lines=100 v2_lines=250 (expect rebuild detected and 250 lines)
32 F15 fail-pass 0 0 0.121 9540 errors=0 infos=1 warnings=1 (empty file should yield INFO)
33 S1_cold_tail lmc 389183687 100002 480.428 43456 tail page=100
34 S2_warm_tail lmc 389183687 100002 477.482 43456 tail page=100
35 S3_deep_pagination lmc 389183687 100002 1.066 43456 n_pages=1000
36 S4_first_build lmc 389183687 100002 473.604 43456 idx_entries=200
37 S5_incremental_extend lmc 104411 1000 0.902 43456 appended=1000_lines
38 S6_verify lmc 389183687 100002 3892.137 43456 total=1 err=0 warn=1 info=0
39 S6_verify ooo 397586720 100002 4037.058 33336 total=17573 err=0 warn=17573 info=0
40 S7a_export_cold pipe100000 40714240 100000 3925.249 1231.613 148432 148128 exported=100000 db_rows=100000
41 S7b_export_dedup pipe100000 40714240 100000 3884.913 1484.406 252396 199460 exported=0 db_rows=100000
42 S7_seed_export pipe100000 40714240 100000 3894.644 1238.138 148320 148208 exported=100000 db_rows=100000
43 S8a_import_cold pipe100000 40628224 100000 3162.988 3237.481 123212 123108 imported=100000 rows_before=0 rows_after=100000
44 S8b_import_idempotent pipe100000 40628224 0 1178.929 1047.286 194896 194860 imported=0 rows_before=100000 rows_after=100000
45 S8e_roundtrip pipe100000 40521728 100000 8905.553 6520.475 148340 148184 rows=100000 seed=1640ms export=3730ms import=3258ms diff=277ms exported=100000 imported=100000 rows_a=100000 rows_b=100000 mismatches=0 body=0 lmc=0 rows=100000 seed=1591ms export=1237ms import=3376ms diff=317ms exported=100000 imported=100000 rows_a=100000 rows_b=100000 mismatches=0 body=0 lmc=0
46 S7a_export_cold pipe1000000 407732224 1000000 309245.302 11247.107 1376872 1376772 exported=1000000 db_rows=1000000
47 S7b_export_dedup pipe1000000 407732224 1000000 303526.638 13262.643 2418088 1873220 exported=0 db_rows=1000000
48 S7_seed_export pipe1000000 407732224 1000000 304160.043 12125.624 1377084 1377076 exported=1000000 db_rows=1000000
49 S8a_import_cold pipe1000000 406605824 1000000 31288.288 36877.801 1124984 1124804 imported=1000000 rows_before=0 rows_after=1000000
50 S8b_import_idempotent pipe1000000 406605824 0 10418.850 11986.786 1841644 1841488 imported=0 rows_before=1000000 rows_after=1000000
51 S8e_roundtrip pipe1000000 405757952 1000000 352840.026 66449.762 1377148 1377084 rows=1000000 seed=17637ms export=301062ms import=31430ms diff=2711ms exported=1000000 imported=1000000 rows_a=1000000 rows_b=1000000 mismatches=0 body=0 lmc=0 rows=1000000 seed=20012ms export=11939ms import=31533ms diff=2966ms exported=1000000 imported=1000000 rows_a=1000000 rows_b=1000000 mismatches=0 body=0 lmc=0