perf: make the benchmark able to answer the question, then ask it
PERF_PLAN phase 0, plus B1/B2 which turned out to cost seconds rather than the minutes budgeted for them. No library code is touched. The harness could not support the conclusions drawn from it. items_for() shrank the sample as work per item grew, so exactly the rows under investigation -- chain-16 and chain-32 -- ran 50 to 200 items and swung 4-8x between passes. Sample size now derives from a time budget with a floor, using work_us * stages / units as the per-item cost. The old ladder's error was treating depth as a throughput cost: past the core count it is, below it depth costs only latency. Rows now report median of N repetitions after a discarded warm-up, with IQR and range, so an unreliable row says so instead of being averaged into a table. The CSV header records nproc, governor and AC state, which immediately caught this laptop running on battery under powersave. A3 needed no experiment in the end: ru_nivcsw and ru_nvcsw are captured around every timed region and reported per item, so involuntary switches against depth is a column rather than a run. bench_dispatch answers B1 and B2 without instrumenting the scheduler. Sleeping is inferred from ru_nvcsw, since a thread blocking on a condition variable books a voluntary context switch. B1: a ThreadPool(1) dispatch is 291 ns null, 466 ns with a payload, against the ~290 ns the plan estimated -- so the abandon criterion is not met and workstream B stays alive. B2's answer is not the one the question expected. It is not whether workers sleep but which pool: on a private ThreadPool(1) the worker never sleeps, because it resubmits into its own queue and finds the work already there; on any pool of two or more it sleeps exactly once per task, because submit() round-robins to a different worker, which is asleep. That is the whole 466 ns to 1.7 us difference, and it inverts half the plan. B5 (bounded spin) buys nothing in the default configuration, and A5 must not make a shared pool the default until the wake cost is fixed, or every graph that already fits its cores gets 3-4x worse per dispatch. G1 lands as tests/soak_wedge.cpp, superseding benchmarks/repro_wedge.cpp, which was never wired into any build. Always compiled so it cannot rot; its CTest cases register only under -DKPN_ENABLE_SOAK_TESTS=ON, so the default test count is unchanged. A wedge is a hang, and a hang under CTest is an unattributable timeout, so it carries a watchdog that aborts naming the iteration and phase. Phase 0's gate is not yet cleared: the acceptance run belongs on the reference machine, not here. A 3-pass check lands every row within 0.7% against the 4-8x swings described above, which is encouraging and is not the same thing. Provisional, recorded so it can be checked: chain-16 came out 6% behind TBB rather than 28.5%. If that survives a proper run, the deep-chain deficit is substantially an artefact of the N=200 rows. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Claude Opus 5
@@ -0,0 +1,236 @@
|
||||
// Wedge soak test (PERF_PLAN G1).
|
||||
//
|
||||
// Runs a pipeline configuration end-to-end in a loop and fails if any single
|
||||
// iteration stops making progress. Its purpose is to keep performance work
|
||||
// from silently reintroducing one of the wedges fixed in August 2026 — the
|
||||
// scheduler and channel wake paths are where both perf workstreams operate.
|
||||
//
|
||||
// Originally the minimal reproducer for the shared-pool chain wedge at
|
||||
// (chain, depth=4, work_us=10, pool_threads=4); the pre-6802328 code wedged
|
||||
// 5/5 within 45 s, at iterations 149, 1249, 332, 1740 and 493.
|
||||
//
|
||||
// A wedge is a hang, so a plain loop would hang CTest until its timeout with
|
||||
// no indication of where. The watchdog turns that into a failure naming the
|
||||
// iteration and the phase it stalled in.
|
||||
//
|
||||
// Usage: ./kpn_soak_wedge [options]
|
||||
// --iters=5000 iterations to run
|
||||
// --mode=pool|priv shared ThreadPool(--threads), or one private pool/node
|
||||
// --depth=4 chain depth
|
||||
// --threads=4 shared pool size (--mode=pool only)
|
||||
// --items=1000 items pushed per iteration
|
||||
// --work-us=10 busy-work per node
|
||||
// --watchdog-sec=30 per-iteration progress deadline
|
||||
|
||||
#include <kpn/kpn.hpp>
|
||||
|
||||
#include <atomic>
|
||||
#include <chrono>
|
||||
#include <cstdio>
|
||||
#include <cstdlib>
|
||||
#include <cstring>
|
||||
#include <memory>
|
||||
#include <string>
|
||||
#include <thread>
|
||||
#include <vector>
|
||||
|
||||
#if defined(__linux__)
|
||||
#include <sys/prctl.h>
|
||||
#endif
|
||||
|
||||
using namespace kpn;
|
||||
using sclock = std::chrono::steady_clock;
|
||||
|
||||
static std::atomic<int> g_work_us{10};
|
||||
|
||||
static int chain_fn(int x) {
|
||||
int us = g_work_us.load(std::memory_order_relaxed);
|
||||
if (us > 0) {
|
||||
auto end = sclock::now() + std::chrono::microseconds(us);
|
||||
while (sclock::now() < end);
|
||||
}
|
||||
return x;
|
||||
}
|
||||
|
||||
using ChainNode = Node<chain_fn, in<>, out<>>;
|
||||
using PoolChainNode = PoolNode<chain_fn, in<>, out<>>;
|
||||
|
||||
static void push_retry(Channel<int>& ch, int val) {
|
||||
while (true) {
|
||||
try { ch.push(val); return; }
|
||||
catch (const ChannelOverflowError&) { std::this_thread::yield(); }
|
||||
catch (const ChannelClosedError&) { return; }
|
||||
}
|
||||
}
|
||||
|
||||
// ── watchdog ──────────────────────────────────────────────────────────────────
|
||||
//
|
||||
// The worker bumps g_progress at every phase boundary. The watchdog aborts if
|
||||
// it stops moving, so a wedge is reported as a failure at a known iteration
|
||||
// rather than as an unattributable CTest timeout.
|
||||
|
||||
static std::atomic<unsigned long> g_progress{0};
|
||||
static std::atomic<int> g_iter{0};
|
||||
static std::atomic<const char*> g_phase{"init"};
|
||||
static std::atomic<bool> g_done{false};
|
||||
|
||||
static void mark(const char* phase) {
|
||||
g_phase.store(phase, std::memory_order_relaxed);
|
||||
g_progress.fetch_add(1, std::memory_order_release);
|
||||
}
|
||||
|
||||
static void watchdog(double deadline_sec) {
|
||||
unsigned long last = g_progress.load(std::memory_order_acquire);
|
||||
auto last_move = sclock::now();
|
||||
while (!g_done.load(std::memory_order_acquire)) {
|
||||
std::this_thread::sleep_for(std::chrono::milliseconds(100));
|
||||
unsigned long now = g_progress.load(std::memory_order_acquire);
|
||||
if (now != last) { last = now; last_move = sclock::now(); continue; }
|
||||
double stalled = std::chrono::duration<double>(sclock::now() - last_move).count();
|
||||
if (stalled > deadline_sec) {
|
||||
std::fprintf(stderr,
|
||||
"\nWEDGE: no progress for %.0fs at iteration %d, phase '%s'\n",
|
||||
stalled, g_iter.load(std::memory_order_relaxed),
|
||||
g_phase.load(std::memory_order_relaxed));
|
||||
std::fflush(stderr);
|
||||
std::abort(); // core dump / stack trace at the point of the wedge
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// ── one iteration ─────────────────────────────────────────────────────────────
|
||||
|
||||
struct Opts {
|
||||
int iters = 5000;
|
||||
int depth = 4;
|
||||
int threads = 4;
|
||||
int items = 1000;
|
||||
int work_us = 10;
|
||||
bool shared_pool = true;
|
||||
double watchdog_sec = 30.0;
|
||||
};
|
||||
|
||||
static void one_round_pool(const Opts& o) {
|
||||
const std::size_t CAP = static_cast<std::size_t>(o.items);
|
||||
auto pool = std::make_shared<ThreadPool>(o.threads);
|
||||
|
||||
std::vector<std::shared_ptr<Channel<int>>> chs;
|
||||
for (int i = 0; i <= o.depth; ++i)
|
||||
chs.push_back(std::make_shared<Channel<int>>(CAP));
|
||||
|
||||
std::vector<std::unique_ptr<PoolChainNode>> nodes;
|
||||
for (int i = 0; i < o.depth; ++i) {
|
||||
nodes.push_back(std::make_unique<PoolChainNode>(pool, CAP));
|
||||
nodes.back()->set_input_channel<0>(chs[i]);
|
||||
nodes.back()->set_output_channel<0>(chs[i + 1].get());
|
||||
}
|
||||
|
||||
pool->start();
|
||||
for (auto& n : nodes) n->start();
|
||||
mark("started");
|
||||
|
||||
std::thread reader([&] {
|
||||
for (int i = 0; i < o.items; ++i) chs.back()->pop();
|
||||
});
|
||||
std::thread pusher([&] {
|
||||
for (int i = 0; i < o.items; ++i) push_retry(*chs[0], i);
|
||||
});
|
||||
|
||||
pusher.join(); mark("pushed");
|
||||
reader.join(); mark("drained");
|
||||
for (auto& n : nodes) n->stop();
|
||||
mark("nodes stopped");
|
||||
pool->stop();
|
||||
mark("pool stopped");
|
||||
}
|
||||
|
||||
static void one_round_private(const Opts& o) {
|
||||
const std::size_t CAP = static_cast<std::size_t>(o.items);
|
||||
|
||||
std::vector<std::shared_ptr<Channel<int>>> chs;
|
||||
for (int i = 0; i <= o.depth; ++i)
|
||||
chs.push_back(std::make_shared<Channel<int>>(CAP));
|
||||
|
||||
std::vector<std::unique_ptr<ChainNode>> nodes;
|
||||
for (int i = 0; i < o.depth; ++i) {
|
||||
nodes.push_back(std::make_unique<ChainNode>(CAP));
|
||||
nodes.back()->set_input_channel<0>(chs[i]);
|
||||
nodes.back()->set_output_channel<0>(chs[i + 1].get());
|
||||
}
|
||||
|
||||
for (auto& n : nodes) n->start();
|
||||
mark("started");
|
||||
|
||||
std::thread reader([&] {
|
||||
for (int i = 0; i < o.items; ++i) chs.back()->pop();
|
||||
});
|
||||
std::thread pusher([&] {
|
||||
for (int i = 0; i < o.items; ++i) push_retry(*chs[0], i);
|
||||
});
|
||||
|
||||
pusher.join(); mark("pushed");
|
||||
reader.join(); mark("drained");
|
||||
for (auto& n : nodes) n->stop();
|
||||
mark("nodes stopped");
|
||||
}
|
||||
|
||||
// ── main ──────────────────────────────────────────────────────────────────────
|
||||
|
||||
static void usage() {
|
||||
std::fprintf(stderr,
|
||||
"usage: kpn_soak_wedge [--iters=N] [--mode=pool|priv] [--depth=D]\n"
|
||||
" [--threads=T] [--items=N] [--work-us=U]\n"
|
||||
" [--watchdog-sec=S]\n");
|
||||
}
|
||||
|
||||
int main(int argc, char** argv) {
|
||||
#if defined(__linux__)
|
||||
// Allow gdb to attach under ptrace_scope=1 when a wedge is caught.
|
||||
prctl(PR_SET_PTRACER, PR_SET_PTRACER_ANY, 0, 0, 0);
|
||||
#endif
|
||||
|
||||
Opts o;
|
||||
for (int i = 1; i < argc; ++i) {
|
||||
std::string a = argv[i];
|
||||
auto eq = a.find('=');
|
||||
std::string key = a.substr(0, eq);
|
||||
std::string val = eq == std::string::npos ? "" : a.substr(eq + 1);
|
||||
|
||||
if (key == "--iters") o.iters = std::atoi(val.c_str());
|
||||
else if (key == "--depth") o.depth = std::atoi(val.c_str());
|
||||
else if (key == "--threads") o.threads = std::atoi(val.c_str());
|
||||
else if (key == "--items") o.items = std::atoi(val.c_str());
|
||||
else if (key == "--work-us") o.work_us = std::atoi(val.c_str());
|
||||
else if (key == "--watchdog-sec") o.watchdog_sec = std::atof(val.c_str());
|
||||
else if (key == "--mode") o.shared_pool = (val != "priv");
|
||||
else { usage(); return 2; }
|
||||
}
|
||||
g_work_us.store(o.work_us, std::memory_order_relaxed);
|
||||
|
||||
std::fprintf(stderr,
|
||||
"soak: mode=%s depth=%d threads=%d items=%d work_us=%d iters=%d watchdog=%.0fs\n",
|
||||
o.shared_pool ? "pool" : "priv", o.depth,
|
||||
o.shared_pool ? o.threads : o.depth, o.items, o.work_us,
|
||||
o.iters, o.watchdog_sec);
|
||||
|
||||
std::thread wd(watchdog, o.watchdog_sec);
|
||||
|
||||
const auto t0 = sclock::now();
|
||||
for (int i = 0; i < o.iters; ++i) {
|
||||
g_iter.store(i, std::memory_order_relaxed);
|
||||
if (o.shared_pool) one_round_pool(o);
|
||||
else one_round_private(o);
|
||||
if ((i + 1) % 100 == 0) {
|
||||
std::fprintf(stderr, "\r %d/%d", i + 1, o.iters);
|
||||
std::fflush(stderr);
|
||||
}
|
||||
}
|
||||
|
||||
g_done.store(true, std::memory_order_release);
|
||||
wd.join();
|
||||
|
||||
double secs = std::chrono::duration<double>(sclock::now() - t0).count();
|
||||
std::fprintf(stderr, "\ncompleted %d iterations in %.1fs with no wedge\n",
|
||||
o.iters, secs);
|
||||
return 0;
|
||||
}
|
||||
Reference in New Issue
Block a user