mirror of
https://github.com/DeusData/codebase-memory-mcp.git
synced 2026-11-04 10:48:20 +00:00
feat(diagnostics): make superlinear passes visible from an ordinary run
Finding the 0.10.x indexing regression took an 11-corpus A/B across two
release binaries, a subset-scaling series, and a per-pass exponent fit.
None of that should have been necessary: the pass that carried it,
cross-file LSP, was already timed and already logged its def count. The
numbers were there, just never normalised into something a reader could
judge.
Three additions, all shipped without a flag except the detailed curve:
- parallel.resolve.cross_lsp_cost — cross-LSP cost NORMALISED per file,
next to defs_total. Wall time cannot separate "big repo" from
"superlinear pass"; us_per_file can. Measured on one Java tree:
files=3710 defs=102845 us_per_file=35129 us_per_file_per_kdef=341
files=14833 defs=339866 us_per_file=106722 us_per_file_per_kdef=314
Per-file cost tripled while per-kdef stayed flat — the fingerprint of
work proportional to the whole corpus (files x defs). One grep on two
differently sized repos now answers what previously took a two-binary
bench.
- parallel.resolve.scan_cost — candidates visited per tail-match lookup,
plus fallback_rows, which the code has counted since #1085 but exposed
only to a test. On the same tree the tail scan reached 242M candidate
visits (n^2.04), worth seeing even though it proved cheap in wall time.
- cbm_scale_probe (foundation/profile.h) — samples cumulative elapsed at
1/8, 1/4, 1/2 and 1 of a pass's items and fits k in T ~ n^k, warning
once k reaches 1.35 in shipped builds. Wired into parallel_extract and
parallel_resolve.
The probe's limits are documented rather than oversold: it catches growth
WITHIN a run, and would NOT have caught this bug, whose per-item cost is
constant-but-large within any single run (it reported 1.26 while the
cross-corpus exponent was 1.86). That is exactly why us_per_item and
us_per_file are emitted alongside it.
Tests are deterministic by construction: the exponent fit is a pure
function fed synthetic points, and the checkpoint bookkeeping is asserted
directly. A test that proved the detector by generating a real quadratic
workload would be asserting on the scheduler.
No product behaviour changes; diagnostics only.
Refs #1669.
Signed-off-by: Martin Vogel <martin.vogel.tech@gmail.com>
This commit is contained in:
1 parent
49d928be67
commit
f6e3af4325
5 files changed
+365
No files matched your search
@@ -5,6 +5,7 @@
|
||||
#include "foundation/log.h"
|
||||
#include "foundation/compat.h"
|
||||
|
||||
#include <math.h>
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <time.h>
|
||||
@@ -64,3 +65,121 @@ void cbm_profile_log_elapsed(const char *phase, const char *sub, const struct ti
|
||||
cbm_log_info("prof", "phase", phase, "sub", sub, "ms", ms_buf, "us", us_buf);
|
||||
}
|
||||
}
|
||||
|
||||
/* ── Scaling probe ──────────────────────────────────────────────────── */
|
||||
|
||||
enum {
|
||||
/* Below this, scheduling noise swamps the fit and every short pass would
|
||||
* cry wolf. A pass with fewer items than this is not where an O(n^2)
|
||||
* regression hurts anyone. */
|
||||
SCALE_MIN_ITEMS = 512,
|
||||
/* Likewise in time: a first checkpoint under a millisecond is measuring the
|
||||
* clock, not the workload. */
|
||||
SCALE_MIN_FIRST_US = 1000,
|
||||
};
|
||||
|
||||
static long scale_elapsed_us(const struct timespec *start) {
|
||||
struct timespec now;
|
||||
cbm_clock_gettime(CLOCK_MONOTONIC, &now);
|
||||
return ((long)(now.tv_sec - start->tv_sec) * PROF_US_PER_SEC) +
|
||||
((now.tv_nsec - start->tv_nsec) / PROF_NS_PER_US);
|
||||
}
|
||||
|
||||
void cbm_scale_begin(cbm_scale_probe_t *probe, const char *phase, long total) {
|
||||
if (!probe) {
|
||||
return;
|
||||
}
|
||||
probe->phase = phase;
|
||||
probe->total = total;
|
||||
atomic_init(&probe->next_cp, 0);
|
||||
for (int i = 0; i < CBM_SCALE_CHECKPOINTS; i++) {
|
||||
probe->cp_us[i] = 0;
|
||||
probe->cp_items[i] = 0;
|
||||
}
|
||||
cbm_clock_gettime(CLOCK_MONOTONIC, &probe->start);
|
||||
}
|
||||
|
||||
void cbm_scale_tick(cbm_scale_probe_t *probe, long done) {
|
||||
if (!probe || probe->total < SCALE_MIN_ITEMS) {
|
||||
return;
|
||||
}
|
||||
int cp = atomic_load_explicit(&probe->next_cp, memory_order_relaxed);
|
||||
if (cp >= CBM_SCALE_CHECKPOINTS) {
|
||||
return;
|
||||
}
|
||||
/* cp 0..3 -> total/8, total/4, total/2, total */
|
||||
long threshold = probe->total >> (CBM_SCALE_CHECKPOINTS - 1 - cp);
|
||||
if (done < threshold) {
|
||||
return;
|
||||
}
|
||||
/* Exactly one thread records each checkpoint; a loser simply moves on and
|
||||
* will re-evaluate against the next threshold on its following tick. */
|
||||
if (!atomic_compare_exchange_strong_explicit(&probe->next_cp, &cp, cp + 1, memory_order_relaxed,
|
||||
memory_order_relaxed)) {
|
||||
return;
|
||||
}
|
||||
probe->cp_us[cp] = scale_elapsed_us(&probe->start);
|
||||
probe->cp_items[cp] = done;
|
||||
}
|
||||
|
||||
double cbm_scale_fit_k(long first_n, long first_us, long last_n, long last_us) {
|
||||
if (first_n <= 0 || first_us <= 0 || last_us <= 0 || last_n <= first_n) {
|
||||
return -1.0;
|
||||
}
|
||||
/* k = log(T_last / T_first) / log(n_last / n_first) */
|
||||
return log((double)last_us / (double)first_us) / log((double)last_n / (double)first_n);
|
||||
}
|
||||
|
||||
void cbm_scale_end(cbm_scale_probe_t *probe) {
|
||||
if (!probe || probe->total < SCALE_MIN_ITEMS) {
|
||||
return;
|
||||
}
|
||||
int recorded = atomic_load_explicit(&probe->next_cp, memory_order_relaxed);
|
||||
if (recorded < 2) {
|
||||
return; /* need two points to speak about growth at all */
|
||||
}
|
||||
long first_us = probe->cp_us[0];
|
||||
long first_n = probe->cp_items[0];
|
||||
long last_us = probe->cp_us[recorded - 1];
|
||||
long last_n = probe->cp_items[recorded - 1];
|
||||
if (first_us < SCALE_MIN_FIRST_US || first_n <= 0 || last_n <= first_n || last_us <= 0) {
|
||||
return;
|
||||
}
|
||||
|
||||
double k = cbm_scale_fit_k(first_n, first_us, last_n, last_us);
|
||||
if (k < 0.0) {
|
||||
return;
|
||||
}
|
||||
long us_per_item = last_us / last_n;
|
||||
|
||||
char k_buf[PROF_BUF_LEN];
|
||||
char n_buf[PROF_BUF_LEN];
|
||||
char per_buf[PROF_BUF_LEN];
|
||||
char ms_buf[PROF_BUF_LEN];
|
||||
snprintf(k_buf, sizeof(k_buf), "%.2f", k);
|
||||
snprintf(n_buf, sizeof(n_buf), "%ld", last_n);
|
||||
snprintf(per_buf, sizeof(per_buf), "%ld", us_per_item);
|
||||
snprintf(ms_buf, sizeof(ms_buf), "%ld", last_us / PROF_US_PER_MS);
|
||||
|
||||
if (k >= CBM_SCALE_WARN_K) {
|
||||
/* Unflagged on purpose: this is the alarm the next accidental O(n^2)
|
||||
* should trip in an ordinary user's log. */
|
||||
cbm_log_warn("scaling.superlinear", "phase", probe->phase, "k", k_buf, "items", n_buf,
|
||||
"elapsed_ms", ms_buf, "us_per_item", per_buf);
|
||||
}
|
||||
if (!cbm_profile_active) {
|
||||
return;
|
||||
}
|
||||
char curve[PROF_BUF_LEN * CBM_SCALE_CHECKPOINTS];
|
||||
int used = 0;
|
||||
for (int i = 0; i < recorded && used < (int)sizeof(curve) - 1; i++) {
|
||||
int wrote = snprintf(curve + used, sizeof(curve) - (size_t)used, "%s%ld:%ld",
|
||||
i == 0 ? "" : ",", probe->cp_items[i], probe->cp_us[i] / PROF_US_PER_MS);
|
||||
if (wrote < 0) {
|
||||
break;
|
||||
}
|
||||
used += wrote;
|
||||
}
|
||||
cbm_log_info("scaling", "phase", probe->phase, "k", k_buf, "items", n_buf, "elapsed_ms", ms_buf,
|
||||
"us_per_item", per_buf, "curve_items_ms", curve);
|
||||
}
|
||||
@@ -15,12 +15,88 @@
|
||||
#ifndef CBM_PROFILE_H
|
||||
#define CBM_PROFILE_H
|
||||
|
||||
#include <stdatomic.h>
|
||||
#include <stdbool.h>
|
||||
#include <time.h>
|
||||
|
||||
/* Runtime-active flag. Set once by cbm_profile_init() from CBM_PROFILE env. */
|
||||
extern bool cbm_profile_active;
|
||||
|
||||
/* ── Scaling probe — single-run superlinearity detector ──────────────
|
||||
*
|
||||
* Per-pass elapsed time (pass.timing) tells you a pass is slow. It cannot tell
|
||||
* you WHY: big corpus, or O(n^2)? Establishing that for #1669 took an 11-corpus
|
||||
* A/B across two release binaries, where parallel_resolve turned out to be 87%
|
||||
* of a Java index.
|
||||
*
|
||||
* This makes the same question answerable from ONE run. A pass processing
|
||||
* `total` items records cumulative elapsed at 1/8, 1/4, 1/2 and 1 of them, then
|
||||
* fits the exponent k in T ~ n^k:
|
||||
*
|
||||
* k ~ 1.0 linear — cost per item is flat
|
||||
* k ~ 1.5 superlinear — e.g. a candidate set that grows with the corpus
|
||||
* k ~ 2.0 quadratic — every item compared against every other
|
||||
*
|
||||
* A pass whose k reaches CBM_SCALE_WARN_K logs `scaling.superlinear` at WARN in
|
||||
* SHIPPED builds with no flag — that is the point: the next accidental O(n^2)
|
||||
* should announce itself in an ordinary user's log rather than needing a
|
||||
* two-binary bench to find. The full checkpoint curve is emitted only under
|
||||
* CBM_PROFILE / --profile, so normal runs stay quiet.
|
||||
*
|
||||
* KNOW WHAT THIS DOES NOT CATCH. It measures growth WITHIN one run, so it sees
|
||||
* a pass whose per-item cost rises as the run proceeds. It does NOT see the
|
||||
* other quadratic shape — per-item work proportional to the WHOLE corpus, where
|
||||
* every item costs the same large amount and the in-run curve is therefore
|
||||
* flat. #1669 was exactly that shape: cross-file LSP rebuilt a registry from a
|
||||
* corpus-scaled def set for every file, measured k=1.86 across corpus SIZES
|
||||
* while this probe reported a harmless-looking 1.26 within a single run.
|
||||
*
|
||||
* For that shape the comparable number is `us_per_item`, which is emitted on
|
||||
* every line: it is a property of the corpus, not the machine, so the same
|
||||
* pass measured on a small and a large repo tells you immediately whether
|
||||
* per-item cost tracks repo size. Two runs, no rebuild, no A/B of binaries.
|
||||
*
|
||||
* Cost when nothing is wrong: four clock reads per pass, plus one relaxed
|
||||
* atomic load and an integer compare per tick. Tick from a site that is already
|
||||
* throttled (a progress-log point), never from the innermost loop. */
|
||||
|
||||
/* Checkpoints at total/8, total/4, total/2, total. */
|
||||
enum { CBM_SCALE_CHECKPOINTS = 4 };
|
||||
|
||||
/* k at or above this is reported. 1.35 sits clear of measured linear passes
|
||||
* (parallel_extract runs ~1.0-1.15 with normal scheduling jitter) while still
|
||||
* catching the mild-but-real 1.4-1.5 cases early. */
|
||||
#define CBM_SCALE_WARN_K 1.35
|
||||
|
||||
typedef struct {
|
||||
const char *phase;
|
||||
long total;
|
||||
struct timespec start;
|
||||
_Atomic int next_cp;
|
||||
long cp_us[CBM_SCALE_CHECKPOINTS];
|
||||
long cp_items[CBM_SCALE_CHECKPOINTS];
|
||||
} cbm_scale_probe_t;
|
||||
|
||||
/* Arm a probe for a pass that will process `total` items. Safe with total <= 0
|
||||
* (the probe then no-ops). */
|
||||
void cbm_scale_begin(cbm_scale_probe_t *probe, const char *phase, long total);
|
||||
|
||||
/* Record progress. Thread-safe and cheap: only the thread that crosses a
|
||||
* checkpoint boundary does any work, and only CBM_SCALE_CHECKPOINTS times. */
|
||||
void cbm_scale_tick(cbm_scale_probe_t *probe, long done);
|
||||
|
||||
/* Fit the exponent and report. Emits `scaling.superlinear` at WARN when
|
||||
* k >= CBM_SCALE_WARN_K (always), and `scaling` at INFO with the full curve
|
||||
* when profiling is active. */
|
||||
void cbm_scale_end(cbm_scale_probe_t *probe);
|
||||
|
||||
/* The fit itself, as a pure function of two (items, microseconds) points:
|
||||
* k such that T ~ n^k. Separated from the probe so the arithmetic is testable
|
||||
* without depending on wall-clock timing — a test that had to *produce* a
|
||||
* quadratic workload to check this would be measuring the scheduler.
|
||||
* Returns -1.0 for degenerate input (non-positive, or no growth in n). */
|
||||
double cbm_scale_fit_k(long first_n, long first_us, long last_n, long last_us);
|
||||
|
||||
/* Initialize profiling — reads CBM_PROFILE env var. Call once at startup. */
|
||||
void cbm_profile_init(void);
|
||||
|
||||
|
||||
@@ -28,6 +28,7 @@
|
||||
#include <ctype.h>
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <stdatomic.h>
|
||||
#include <string.h>
|
||||
|
||||
/* Confidence floor below which LSP-resolved calls are ignored and the
|
||||
@@ -856,6 +857,18 @@ static inline const CBMResolvedCall *cbm_pipeline_find_lsp_reference(
|
||||
* graph's file-shaped QN, accept one globally unique callable short name.
|
||||
*
|
||||
* Returns the matching node, or NULL if neither lookup hits. */
|
||||
/* Tail-match cost counters (#1669).
|
||||
*
|
||||
* The scan below is the one candidate loop in the resolve path with NO cap —
|
||||
* cbm_registry_resolve bails at REG_MAX_CANDIDATES=256, this does not. Its
|
||||
* candidate set is every node sharing a short name, which grows with the
|
||||
* corpus, so `candidates scanned` is the quantity that turns resolve from O(n)
|
||||
* into O(n^2). Counted always (two relaxed adds), surfaced by pass_parallel at
|
||||
* end of resolve: a candidates/lookup ratio that grows with corpus size IS the
|
||||
* regression, visible in one run. */
|
||||
extern _Atomic uint64_t g_lsp_tail_lookups;
|
||||
extern _Atomic uint64_t g_lsp_tail_candidates;
|
||||
|
||||
static inline const cbm_gbuf_node_t *cbm_pipeline_lsp_target_node_policy(
|
||||
const cbm_gbuf_t *gbuf, const char *project_name, const char *callee_qn, bool allow_tail_match,
|
||||
bool allow_unique_callable_fallback) {
|
||||
@@ -901,6 +914,8 @@ static inline const cbm_gbuf_node_t *cbm_pipeline_lsp_target_node_policy(
|
||||
if (cbm_gbuf_find_by_name(gbuf, short_name, &hits, &hit_count) != 0 || hit_count == 0) {
|
||||
return NULL;
|
||||
}
|
||||
atomic_fetch_add_explicit(&g_lsp_tail_lookups, 1, memory_order_relaxed);
|
||||
atomic_fetch_add_explicit(&g_lsp_tail_candidates, (uint64_t)hit_count, memory_order_relaxed);
|
||||
|
||||
const cbm_gbuf_node_t *match = NULL;
|
||||
const cbm_gbuf_node_t *unique_callable = NULL;
|
||||
|
||||
@@ -106,6 +106,10 @@ enum { PP_CSHARP_M_PREFIX_LEN = 2 };
|
||||
* memory (the resident floor, not in-flight transients, holds the budget). */
|
||||
static _Atomic long g_bp_nap_cycles = 0;
|
||||
static _Atomic uint64_t g_lsp_linear_fallback_rows = 0;
|
||||
/* Defined here, declared in lsp_resolve.h — the uncapped tail-match scan's
|
||||
* cost, surfaced at end of resolve (#1669). */
|
||||
_Atomic uint64_t g_lsp_tail_lookups = 0;
|
||||
_Atomic uint64_t g_lsp_tail_candidates = 0;
|
||||
|
||||
long cbm_pp_bp_nap_cycles(void) {
|
||||
return atomic_load_explicit(&g_bp_nap_cycles, memory_order_relaxed);
|
||||
@@ -121,6 +125,8 @@ uint64_t cbm_pp_lsp_linear_fallback_rows(void) {
|
||||
|
||||
void cbm_pp_lsp_linear_fallback_rows_reset(void) {
|
||||
atomic_store_explicit(&g_lsp_linear_fallback_rows, 0, memory_order_relaxed);
|
||||
atomic_store_explicit(&g_lsp_tail_lookups, 0, memory_order_relaxed);
|
||||
atomic_store_explicit(&g_lsp_tail_candidates, 0, memory_order_relaxed);
|
||||
}
|
||||
|
||||
/* Parse a positive MB-valued retention env knob (CBM_RETAIN_*_MB) into bytes.
|
||||
@@ -663,6 +669,9 @@ typedef struct {
|
||||
|
||||
const CBMMacroTable *macro_table; /* ObjectScript $$$macros (NULL if none) */
|
||||
const CBMReturnTypeTable *return_type_table; /* ObjectScript return types (NULL if none) */
|
||||
|
||||
/* Superlinearity probe — see profile.h. Ticked on each file claim below. */
|
||||
cbm_scale_probe_t scale;
|
||||
} extract_ctx_t;
|
||||
|
||||
/* Cap on the number of index.file_oversized WARN lines (the full list still goes
|
||||
@@ -728,6 +737,7 @@ static void extract_worker(int worker_id, void *ctx_ptr) {
|
||||
if (sort_pos >= ec->file_count) {
|
||||
break;
|
||||
}
|
||||
cbm_scale_tick(&ec->scale, sort_pos);
|
||||
if (atomic_load_explicit(ec->cancelled, memory_order_relaxed)) {
|
||||
break;
|
||||
}
|
||||
@@ -1120,7 +1130,9 @@ int cbm_parallel_extract_ex(cbm_pipeline_ctx_t *ctx, const cbm_file_info_t *file
|
||||
/* Sub-phase: Dispatch workers (parse + extract per file, PARALLEL) */
|
||||
CBM_PROF_START(t_dispatch);
|
||||
cbm_parallel_for_opts_t parallel_opts = {.max_workers = worker_count, .force_pthreads = false};
|
||||
cbm_scale_begin(&ec.scale, "parallel_extract", (long)file_count);
|
||||
cbm_parallel_for(worker_count, extract_worker, &ec, parallel_opts);
|
||||
cbm_scale_end(&ec.scale);
|
||||
CBM_PROF_END_N("parallel_extract", "3_dispatch_workers_parallel", t_dispatch, file_count);
|
||||
|
||||
/* Sub-phase: Merge all local gbufs into main gbuf (SEQUENTIAL, gbuf not thread-safe) */
|
||||
@@ -1432,6 +1444,11 @@ typedef struct {
|
||||
_Atomic uint64_t time_ns_rc_target; /* gbuf_find_by_qn for target */
|
||||
_Atomic uint64_t time_ns_rc_emit; /* emit_service_edge */
|
||||
_Atomic uint64_t time_ns_rc_source; /* find_source_node */
|
||||
|
||||
/* Superlinearity probe — see profile.h. This is the pass that made it
|
||||
* necessary (#1669: 87% of a Java index), so it is the one that must never
|
||||
* again grow superlinear without saying so. */
|
||||
cbm_scale_probe_t scale;
|
||||
} resolve_ctx_t;
|
||||
|
||||
/* Minimum buffer space needed per arg JSON object */
|
||||
@@ -2934,6 +2951,7 @@ static void resolve_worker(int worker_id, void *ctx_ptr) {
|
||||
if (file_idx >= rc->file_count) {
|
||||
break;
|
||||
}
|
||||
cbm_scale_tick(&rc->scale, file_idx);
|
||||
if (atomic_load_explicit(rc->cancelled, memory_order_relaxed)) {
|
||||
break;
|
||||
}
|
||||
@@ -3212,7 +3230,9 @@ int cbm_parallel_resolve(cbm_pipeline_ctx_t *ctx, const cbm_file_info_t *files,
|
||||
/* Sub-phase: Dispatch resolve workers (per-file call/usage resolution, PARALLEL) */
|
||||
CBM_PROF_START(t_resolve_dispatch);
|
||||
cbm_parallel_for_opts_t opts = {.max_workers = worker_count, .force_pthreads = false};
|
||||
cbm_scale_begin(&rc.scale, "parallel_resolve", (long)file_count);
|
||||
cbm_parallel_for(worker_count, resolve_worker, &rc, opts);
|
||||
cbm_scale_end(&rc.scale);
|
||||
CBM_PROF_END_N("parallel_resolve", "1_dispatch_workers_parallel", t_resolve_dispatch,
|
||||
file_count);
|
||||
/* Workers joined: the shared Rust registry (if built) is no longer read.
|
||||
@@ -3267,6 +3287,37 @@ int cbm_parallel_resolve(cbm_pipeline_ctx_t *ctx, const cbm_file_info_t *files,
|
||||
itoa_log(atomic_load_explicit(&rc.lsp_cross_skipped_no_source, memory_order_relaxed)),
|
||||
"defs_total", itoa_log(def_count));
|
||||
|
||||
/* Cross-LSP cost, NORMALISED (#1669). Wall time alone cannot distinguish
|
||||
* "big repo" from "superlinear pass"; us_per_file can. For a pass that is
|
||||
* linear in file count this number is roughly CONSTANT across repo sizes.
|
||||
* When cross-file LSP rebuilds its registry from a corpus-scaled def set,
|
||||
* per-file cost tracks defs_total instead — measured 35ms/file at 5.8k
|
||||
* files and 209ms/file at 46k on the same tree, which is the O(n^2) that
|
||||
* cost a 6x java regression and took an 11-corpus two-binary A/B to find.
|
||||
* Emitted next to defs_total so one grep on two differently sized repos
|
||||
* answers it. */
|
||||
int cross_files = atomic_load_explicit(&rc.lsp_cross_processed, memory_order_relaxed);
|
||||
uint64_t cross_us =
|
||||
atomic_load_explicit(&rc.time_ns_cross_lsp, memory_order_relaxed) / 1000ULL;
|
||||
if (cross_files > 0) {
|
||||
char cf_buf[CBM_SZ_32];
|
||||
char nf_buf[CBM_SZ_32];
|
||||
char cu_buf[CBM_SZ_32];
|
||||
char pk_buf[CBM_SZ_32];
|
||||
snprintf(cf_buf, sizeof(cf_buf), "%llu",
|
||||
(unsigned long long)(cross_us / (uint64_t)cross_files));
|
||||
snprintf(nf_buf, sizeof(nf_buf), "%d", cross_files);
|
||||
snprintf(cu_buf, sizeof(cu_buf), "%llu", (unsigned long long)(cross_us / 1000ULL));
|
||||
snprintf(pk_buf, sizeof(pk_buf), "%llu",
|
||||
(unsigned long long)(def_count > 0 ? (cross_us * 1000ULL) /
|
||||
((uint64_t)cross_files *
|
||||
(uint64_t)def_count)
|
||||
: 0ULL));
|
||||
cbm_log_info("parallel.resolve.cross_lsp_cost", "cross_lsp_ms", cu_buf, "files", nf_buf,
|
||||
"us_per_file", cf_buf, "defs_total", itoa_log(def_count),
|
||||
"us_per_file_per_kdef", pk_buf);
|
||||
}
|
||||
|
||||
cbm_log_info("parallel.resolve.done", "calls", itoa_log(total_calls), "usages",
|
||||
itoa_log(total_usages), "semantic", itoa_log(total_semantic + go_impl),
|
||||
"lsp_overrides", itoa_log(total_lsp_overrides));
|
||||
@@ -3344,5 +3395,27 @@ int cbm_parallel_resolve(cbm_pipeline_ctx_t *ctx, const cbm_file_info_t *files,
|
||||
"resolve", rsv_buf);
|
||||
cbm_log_info("parallel.resolve.calls_breakdown2", "field_hint", hnt_buf, "find_target", tgt_buf,
|
||||
"emit_edge", emt_buf);
|
||||
|
||||
/* Candidate-scan cost (#1669). `per_lookup` is the diagnostic that matters:
|
||||
* it is a property of the CORPUS, not of the machine, so it is comparable
|
||||
* across runs and versions. If it grows with repo size, the tail-match scan
|
||||
* is turning resolve superlinear — which is precisely what took an
|
||||
* 11-corpus two-binary A/B to establish the first time. `fallback_rows`
|
||||
* was already counted but, until now, readable only from a test. */
|
||||
uint64_t tail_lookups = atomic_load_explicit(&g_lsp_tail_lookups, memory_order_relaxed);
|
||||
uint64_t tail_cands = atomic_load_explicit(&g_lsp_tail_candidates, memory_order_relaxed);
|
||||
char tl_buf[CBM_SZ_32];
|
||||
char tc_buf[CBM_SZ_32];
|
||||
char tp_buf[CBM_SZ_32];
|
||||
char fb_buf[CBM_SZ_32];
|
||||
snprintf(tl_buf, sizeof(tl_buf), "%llu", (unsigned long long)tail_lookups);
|
||||
snprintf(tc_buf, sizeof(tc_buf), "%llu", (unsigned long long)tail_cands);
|
||||
snprintf(tp_buf, sizeof(tp_buf), "%llu",
|
||||
(unsigned long long)(tail_lookups ? tail_cands / tail_lookups : 0ULL));
|
||||
snprintf(fb_buf, sizeof(fb_buf), "%llu",
|
||||
(unsigned long long)atomic_load_explicit(&g_lsp_linear_fallback_rows,
|
||||
memory_order_relaxed));
|
||||
cbm_log_info("parallel.resolve.scan_cost", "tail_lookups", tl_buf, "tail_candidates", tc_buf,
|
||||
"per_lookup", tp_buf, "fallback_rows", fb_buf);
|
||||
return 0;
|
||||
}
|
||||
@@ -9,6 +9,7 @@
|
||||
#include "../src/foundation/diagnostics.h"
|
||||
#include "../src/foundation/log.h"
|
||||
#include "../src/foundation/platform.h"
|
||||
#include "../src/foundation/profile.h"
|
||||
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
@@ -568,7 +569,88 @@ TEST(diagnostics_outputs_are_owner_private_windows) {
|
||||
}
|
||||
#endif
|
||||
|
||||
|
||||
/* ── scaling probe (profile.h) ──────────────────────────────────────
|
||||
*
|
||||
* These pin the arithmetic and the checkpoint bookkeeping, deliberately WITHOUT
|
||||
* timing anything. A test that tried to prove the detector works by generating
|
||||
* a genuinely quadratic workload would be asserting on the scheduler, and would
|
||||
* go flaky on a loaded CI box — so the fit is a pure function and gets fed
|
||||
* synthetic points instead. */
|
||||
|
||||
TEST(scale_fit_k_recognises_linear_and_quadratic_growth) {
|
||||
/* 8x the items, 8x the time => k = 1 */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 8000, 8000) > 0.99);
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 8000, 8000) < 1.01);
|
||||
|
||||
/* 8x the items, 64x the time => k = 2 */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 8000, 64000) > 1.99);
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 8000, 64000) < 2.01);
|
||||
|
||||
/* n log n sits between, and must NOT be mistaken for quadratic */
|
||||
double k_nlogn = cbm_scale_fit_k(1000, 1000, 8000, 8000 * 13 / 10);
|
||||
ASSERT_TRUE(k_nlogn > 1.0);
|
||||
ASSERT_TRUE(k_nlogn < CBM_SCALE_WARN_K);
|
||||
PASS();
|
||||
}
|
||||
|
||||
TEST(scale_fit_k_rejects_degenerate_input) {
|
||||
ASSERT_TRUE(cbm_scale_fit_k(0, 1000, 8000, 8000) < 0.0); /* no first point */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 0, 8000, 8000) < 0.0); /* zero elapsed */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 1000, 8000) < 0.0); /* n did not grow */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 500, 8000) < 0.0); /* n went backwards */
|
||||
ASSERT_TRUE(cbm_scale_fit_k(1000, 1000, 8000, 0) < 0.0); /* zero total */
|
||||
PASS();
|
||||
}
|
||||
|
||||
TEST(scale_probe_records_checkpoints_at_eighths) {
|
||||
cbm_scale_probe_t p;
|
||||
cbm_scale_begin(&p, "unit", 1024);
|
||||
|
||||
/* Below the first threshold (1024/8 = 128), nothing is claimed. */
|
||||
for (long i = 0; i < 128; i++) {
|
||||
cbm_scale_tick(&p, i);
|
||||
}
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 0);
|
||||
|
||||
cbm_scale_tick(&p, 128); /* 1/8 */
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 1);
|
||||
cbm_scale_tick(&p, 200); /* still short of 1/4 */
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 1);
|
||||
cbm_scale_tick(&p, 256); /* 1/4 */
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 2);
|
||||
cbm_scale_tick(&p, 512); /* 1/2 */
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 3);
|
||||
cbm_scale_tick(&p, 1024); /* all */
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 4);
|
||||
|
||||
/* Saturates rather than overrunning the array. */
|
||||
cbm_scale_tick(&p, 2048);
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 4);
|
||||
ASSERT_EQ(p.cp_items[0], 128);
|
||||
ASSERT_EQ(p.cp_items[3], 1024);
|
||||
cbm_scale_end(&p);
|
||||
PASS();
|
||||
}
|
||||
|
||||
TEST(scale_probe_ignores_runs_too_small_to_judge) {
|
||||
/* Under SCALE_MIN_ITEMS a pass is not where an O(n^2) hurts anyone, and the
|
||||
* fit would be measuring noise — so the probe must stay silent. */
|
||||
cbm_scale_probe_t p;
|
||||
cbm_scale_begin(&p, "tiny", 64);
|
||||
for (long i = 0; i <= 64; i++) {
|
||||
cbm_scale_tick(&p, i);
|
||||
}
|
||||
ASSERT_EQ(atomic_load(&p.next_cp), 0);
|
||||
cbm_scale_end(&p); /* must not emit, must not crash */
|
||||
PASS();
|
||||
}
|
||||
|
||||
SUITE(diagnostics) {
|
||||
RUN_TEST(scale_fit_k_recognises_linear_and_quadratic_growth);
|
||||
RUN_TEST(scale_fit_k_rejects_degenerate_input);
|
||||
RUN_TEST(scale_probe_records_checkpoints_at_eighths);
|
||||
RUN_TEST(scale_probe_ignores_runs_too_small_to_judge);
|
||||
#ifndef _WIN32
|
||||
RUN_TEST(diagnostics_rejects_predictable_tmp_symlinks);
|
||||
#endif
|
||||
|
||||
Reference in new issue
Block a user