diff --git a/core/tests/test_session.cpp b/core/tests/test_session.cpp index 29cf892..1a5b74a 100644 --- a/core/tests/test_session.cpp +++ b/core/tests/test_session.cpp @@ -443,97 +443,110 @@ void testStallWatchdogTrace() } } -// TEMPORARY DEBUG -- remove before merge. The quiet sequence, run as N -// independent trials: a fresh steady_clock::now() per trial, plus trials -// with a synthetic fixed t0 and trials that compute `now` as an absolute -// offset from t0 instead of accumulating. Nothing is observed inside the -// loop; per-trial results are printed afterwards. If some trials pass and -// others fail in the same process, the absolute clock value -- not codegen -// -- is what the fault tracks. +// TEMPORARY DEBUG -- remove before merge. Five shapes of the same loop, +// each run twice. Nothing is printed until every trial is done. +// mode 0 accumulate `now += 30000ms`, pass `now` (known-bad) +// mode 1 absolute `t0 + milliseconds(offset)` (known-good) +// mode 2 accumulate, and sum the ns actually handed to poll +// mode 3 accumulate, pass a named copy of `now` +// mode 4 accumulate by a non-const step variable void testStallWatchdogQuiet() { struct Trial { - long long t0_ns; int mode; int early[6]; int fire[6]; + long long early_arg_sum_ms; + long long fire_arg_sum_ms; long long next_rel_ns; - long long backoff_ms; - int attempts_before_loop; int attempts_after; }; - const int kTrials = 12; + const int kTrials = 10; Trial trials[kTrials]; for (int t = 0; t < kTrials; ++t) { - // mode 0: now() as t0, accumulate. mode 1: now() as t0, absolute - // offsets. mode 2: synthetic t0 (epoch + a fixed odd nanosecond - // count), accumulate. - const int mode = t % 3; - std::chrono::steady_clock::time_point t0; - if (mode == 2) - t0 = std::chrono::steady_clock::time_point(std::chrono::nanoseconds(1234567891011LL)); - else - t0 = std::chrono::steady_clock::now(); - + const int mode = t % 5; + const auto t0 = std::chrono::steady_clock::now(); StallWatchdog w(std::chrono::milliseconds(2000), std::chrono::milliseconds(30000)); w.setExpectingFrames(true, t0); int early[6] = {0}; int fire[6] = {0}; - int attempts_before = 0; + long long esum = 0; + long long fsum = 0; - if (mode == 1) { - (void)w.poll(t0 + std::chrono::milliseconds(2000)); - (void)w.poll(t0 + std::chrono::milliseconds(4000)); - (void)w.poll(t0 + std::chrono::milliseconds(8000)); - (void)w.poll(t0 + std::chrono::milliseconds(16000)); - (void)w.poll(t0 + std::chrono::milliseconds(32000)); - attempts_before = w.attemptsThisStall(); + auto now = t0 + std::chrono::milliseconds(2000); + (void)w.poll(now); + now += std::chrono::milliseconds(2000); + (void)w.poll(now); + now += std::chrono::milliseconds(4000); + (void)w.poll(now); + now += std::chrono::milliseconds(8000); + (void)w.poll(now); + now += std::chrono::milliseconds(16000); + (void)w.poll(now); + + if (mode == 0) { + for (int i = 0; i < 6; ++i) { + early[i] = w.poll(now + std::chrono::milliseconds(29999)) ? 1 : 0; + now += std::chrono::milliseconds(30000); + fire[i] = w.poll(now) ? 1 : 0; + } + } else if (mode == 1) { long long at = 32000; for (int i = 0; i < 6; ++i) { early[i] = w.poll(t0 + std::chrono::milliseconds(at + 29999)) ? 1 : 0; at += 30000; fire[i] = w.poll(t0 + std::chrono::milliseconds(at)) ? 1 : 0; } - } else { - auto now = t0 + std::chrono::milliseconds(2000); - (void)w.poll(now); - now += std::chrono::milliseconds(2000); - (void)w.poll(now); - now += std::chrono::milliseconds(4000); - (void)w.poll(now); - now += std::chrono::milliseconds(8000); - (void)w.poll(now); - now += std::chrono::milliseconds(16000); - (void)w.poll(now); - attempts_before = w.attemptsThisStall(); + } else if (mode == 2) { + for (int i = 0; i < 6; ++i) { + const auto e = now + std::chrono::milliseconds(29999); + esum += std::chrono::duration_cast(e - t0).count(); + early[i] = w.poll(e) ? 1 : 0; + now += std::chrono::milliseconds(30000); + fsum += std::chrono::duration_cast(now - t0).count(); + fire[i] = w.poll(now) ? 1 : 0; + } + } else if (mode == 3) { for (int i = 0; i < 6; ++i) { early[i] = w.poll(now + std::chrono::milliseconds(29999)) ? 1 : 0; now += std::chrono::milliseconds(30000); + const auto fire_arg = now; + fire[i] = w.poll(fire_arg) ? 1 : 0; + } + } else { + std::chrono::milliseconds step(30000); + std::chrono::milliseconds probe(29999); + for (int i = 0; i < 6; ++i) { + early[i] = w.poll(now + probe) ? 1 : 0; + now += step; fire[i] = w.poll(now) ? 1 : 0; } } - trials[t].t0_ns = - (long long)std::chrono::duration_cast(t0.time_since_epoch()).count(); trials[t].mode = mode; for (int i = 0; i < 6; ++i) { trials[t].early[i] = early[i]; trials[t].fire[i] = fire[i]; } + trials[t].early_arg_sum_ms = esum; + trials[t].fire_arg_sum_ms = fsum; trials[t].next_rel_ns = (long long)std::chrono::duration_cast(w.dbgNextAllowed() - t0).count(); - trials[t].backoff_ms = w.dbgBackoffMs(); - trials[t].attempts_before_loop = attempts_before; trials[t].attempts_after = w.attemptsThisStall(); } + // Expected sums for mode 2: early args 61999..211999 step 30000, + // fire args 62000..212000 step 30000. + std::fprintf(stderr, "WDQUIET expect_early_sum=%lld expect_fire_sum=%lld\n", + (long long)(61999 + 91999 + 121999 + 151999 + 181999 + 211999), + (long long)(62000 + 92000 + 122000 + 152000 + 182000 + 212000)); for (int t = 0; t < kTrials; ++t) { std::fprintf(stderr, - "WDQUIET trial=%2d mode=%d t0_ns=%lld before=%d after=%d final_next_rel_ns=%lld backoff_ms=%lld early=%d%d%d%d%d%d fire=%d%d%d%d%d%d\n", - t, trials[t].mode, trials[t].t0_ns, trials[t].attempts_before_loop, - trials[t].attempts_after, trials[t].next_rel_ns, trials[t].backoff_ms, + "WDQUIET trial=%2d mode=%d after=%d final_next_rel_ns=%lld esum=%lld fsum=%lld early=%d%d%d%d%d%d fire=%d%d%d%d%d%d\n", + t, trials[t].mode, trials[t].attempts_after, trials[t].next_rel_ns, + trials[t].early_arg_sum_ms, trials[t].fire_arg_sum_ms, trials[t].early[0], trials[t].early[1], trials[t].early[2], trials[t].early[3], trials[t].early[4], trials[t].early[5], trials[t].fire[0], trials[t].fire[1], trials[t].fire[2],