diff --git a/runtime/stutter_map.c b/runtime/stutter_map.c index a7cb2493..8ad3709d 100644 --- a/runtime/stutter_map.c +++ b/runtime/stutter_map.c @@ -382,6 +382,41 @@ static int pipe_cmp(const void *x, const void *y) { return ka < kb ? 1 : ka > kb ? -1 : 0; } +// At the exit: the hitches in the run's last frames, which cand_decide and episode_close would have counted had the +// run gone on: the open episode, and the candidates still waiting for their next frames (the last two frames, three +// in a run of long ones). A waiting candidate counts as one that did not stand out unless it is over SM_HITCH_SURE_NS +// (a hitch whatever follows), and joins the episode of the frame before it as cand_decide joins it. Added to the +// exit's printed totals only, and only read: the exit's report runs on another thread (perf.c perf_summary_flush, from +// the window's close or the game's exit) while the presenting thread, which owns this state, may still be in +// stutter_frame; a race there miscounts these last frames at worst. Other reports leave them to the next one. +static void exit_tail(uint64_t *hitch, uint64_t *load, uint64_t *cause) { + int n = ep.open ? ep.n : 0, hit = ep.hitch, paced = pace_run, at_load = ep.first.load, why = ep.first.cause; + int nc = n_cand < SM_AFTER + 1 ? n_cand : SM_AFTER + 1; + uint64_t last = ep.open ? ep.last : pace_last; + for (int i = 0; i <= nc; i++) { + const Cand *c = i < nc ? &cand[i] : NULL; + int sure = c && c->d > SM_HITCH_SURE_NS; + if (c && c->frame == last + 1) { + last = c->frame; + if (n) { // it joins the episode + n++, hit |= sure; + if (!hit && n > SM_EPISODE_MAX) n = 0, paced = 1; // a change of pace + continue; + } + if (paced && !sure) continue; // the change of pace goes on + } + if (n && (hit || n >= 2)) { + if (at_load) ++*load; + else { + ++*hitch; + if (why >= 0 && why < SM_CAUSES) cause[why]++; + } + } + n = 0, paced = 0; + if (c) n = 1, hit = sure, at_load = c->load, why = c->cause, last = c->frame; + } +} + // The map as a report reads it: copied under sm_lock, then sorted and logged without it. The replay thread // (stutter_miss) and the pipeline workers (stutter_ready, inside vk_pipeline.c's P.lock, which the draw path takes too) // wait for sm_lock, and a report sorts up to SM_PIPES entries and logs about 85 lines. @@ -413,6 +448,7 @@ void stutter_report(const char *tag) { hitch += m->areas[i].hitch, load += m->areas[i].load_hitch, ns += m->areas[i].ns; for (int c = 0; c < SM_CAUSES; c++) cause[c] += m->areas[i].by_cause[c]; } + if (!strcmp(tag, "exit")) exit_tail(&hitch, &load, cause); char line[1400]; int o = snprintf(line, sizeof line, "stutter map (%s): %.1f min of play in %d areas; %llu hitches in play and %llu " "after area loads; %llu long frames were a change of pace (the frames after them as long), not " diff --git a/tests/stutter_hitch_check.c b/tests/stutter_hitch_check.c index b41d6d36..65f73bb2 100644 --- a/tests/stutter_hitch_check.c +++ b/tests/stutter_hitch_check.c @@ -12,9 +12,15 @@ uint64_t kern_now_ns(void) { return clock_ns; } void plat_mutex_lock(PlatMutex *m) { (void)m; } void plat_mutex_unlock(PlatMutex *m) { (void)m; } static int logged; +static char head[1400]; // the last report's first line void rt_log(const char *fmt, ...) { - (void)fmt; logged++; + char line[1400]; + va_list ap; + va_start(ap, fmt); + vsnprintf(line, sizeof line, fmt, ap); + va_end(ap); + if (!strncmp(line, "stutter map (", 13)) memcpy(head, line, sizeof head); } // perf.c's causes, in its order (FT_C_*); the frames below are charged to the last, unattributed @@ -39,6 +45,19 @@ static void expect(const char *what, uint64_t got, uint64_t want) { if (got != want) printf("FAIL %s: %llu, expected %llu\n", what, (unsigned long long)got, (unsigned long long)want), fails++; } +// The hitches in play the exit's report prints, and the ones the areas hold (what a report counts so far). +static uint64_t exit_hitches(void) { + head[0] = 0; + stutter_report("exit"); + const char *p = strstr(head, " areas; "); + return p ? strtoull(p + 8, NULL, 10) : UINT64_MAX; +} +static uint64_t counted(void) { + uint64_t n = 0; + for (int i = 0; i < n_areas; i++) n += areas[i].hitch; + return n; +} + int main(void) { stutter_map_init(); clock_ns = 10000000000ull; // well past any area load @@ -93,6 +112,26 @@ int main(void) { expect("five hitches at 30 fps", areas[3].hitch, 5); expect("five hitches at 30 fps (worst)", areas[3].worst_ns, 120000000ull); expect("five hitches at 30 fps (their time)", areas[3].cause_ns[OTHER], 600000000ull); + // The exit's report counts a hitch in the last frames, which only the next frames would have decided: a frame over + // the sure line followed by 0, 1 or 2 frames (a waiting candidate, then an open episode), two such frames in a row + // (one episode) and three long frames ending the run (one episode); each time what the run counts once it goes on + stutter_area("Death Mountain"); + clock_ns += 10000000000ull; + static const double tail[][3] = {{150.0, 0, 0}, {150.0, 7.0, 0}, {150.0, 7.0, 7.0}, {150.0, 150.0, 0}, + {150.0, 150.0, 7.0}, {87.0, 91.0, 96.0}}; + for (size_t t = 0; t < sizeof tail / sizeof *tail; t++) { + frames(100, 7.0); + uint64_t before = counted(); + for (int k = 0; k < 3 && tail[t][k] > 0; k++) frames(1, tail[t][k]); + char what[64]; + snprintf(what, sizeof what, "the exit right after case %zu", t); + expect(what, exit_hitches(), before + 1); + frames(60, 7.0); + snprintf(what, sizeof what, "case %zu once the run went on", t); + expect(what, counted(), before + 1); + } + frames(100, 7.0); + expect("the exit with nothing waiting", exit_hitches(), counted()); if (!logged) printf("FAIL nothing was logged\n"), fails++; if (fails) return 1; printf("stutter_hitch_check: all checks passed\n");