Files
NX2navi/runtime/stutter_map.c
chrg6 c040ca6c5f Write the frame-time summary and the stutter map at a fatal error too, the map only when its lock is free.
dispatch.c fatal_end wrote only the profiler's samples, so a run that ended in a FATAL had no "frametime" or
stutter-map lines for its last period: the numbers that would show what the game was doing before it failed.

perf.c perf_summary_flush_try (weak in dispatch.c for builds without perf.c) runs after fs_save_crash_wait: ft_stop,
then the running period's "frametime: at a fatal error" lines and the stutter map. The failing thread may hold any
lock, so stutter_map.c gains stutter_report_as(tag, try_only), which only tries sm_lock and writes nothing when it is
taken (stutter_report keeps the blocking take); the back end's exit lines (gfx_exit_log) and the trace's segments
(seg_close) are left out, as they read state the failure may have left half made. The crash report keeps no summary:
its state may be damaged.

Not reproduced before the change (a missing diagnostic). tests/fatal_exit_check.py now wants the summary at
rt_fatal and checks statically that perf_summary_flush_try only tries the map's lock and leaves the back end out;
tests/stutter_hitch_check.c gets the trylock stand-in it needs. fatal_exit_check, stutter_hitch_check,
stutter_map_check and the compile checks of every runtime file pass.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:43:23 -05:00

515 lines
27 KiB
C

// The stutter map (NX2NAVI_STUTTER_MAP=1): what a play session's hitches were, area by area, and which pipelines and
// shaders the draws met missing, so a long session says where the remaining stutters are and what the next pipeline
// list (tools/pipeline_list.py merge) and shader preparation must take in. Off by default; while it is off every hook
// returns at its first test.
//
// A hitch is a frame that stands out from the frames around it: its interval is over 2.5 times the median of the 32
// frames before it and at least 12 ms (or over 25 ms), and both of the next two frames are under two thirds of it
// (a frame over SM_HITCH_SURE_NS is one whatever follows). At 140 fps that is a frame over 17.5 ms followed by shorter
// ones. The look at the next two frames keeps a change of pace out: the game drawing its menus or a scene at a steady
// 60 or 30 fps after 140 is a slower rate, not a run of hitches, and the median takes the new rate within 16 frames.
// The decision waits two presents; the line and the counts carry what the frame itself waited for. Frames within
// SM_LOAD_NS of an area's load count apart, as the load's: an area load shows as a few long frames that are not a
// stutter in play. An area load is the game's (stutter_area) or the texture pool's (stutter_load: the pool makes an
// area's textures, vk_exec_draw.c pool_loading), which comes without the game's when it streams the next area in.
// Consecutive long frames are one episode, a hitch counted once with their summed time: a change of pace is a run of
// more than SM_EPISODE_MAX long frames none of which stands out from the ones after it, and an episode ends at its
// last frame that stood out once more than SM_EPISODE_MAX such frames follow that one. Three frames of 87, 91 and
// 96 ms after an area load (2026-11-13) each counted as a change of pace before, as each was followed by one as long.
//
// What a hitch went to comes from the frame-time summary's split (perf.c ft_frame: pipeline, translation, texture,
// fence, pacing, hand-off, replay, census, report, unattributed), with the draws that met a pipeline or a shader
// missing between the previous present and this one (stutter_miss, from the replay thread). Each hitch gets a
// "stutter:" line, at most SM_LINES_PER_S a second and SM_LINES_MAX in all; the counts go on past that. Every
// SM_REPORT_NS of play, when the window loses the focus in play (perf.c session_report) and at exit, "stutter map"
// lines rank the areas by their hitches and the pipelines by the time draws lost to them, each with whether this
// install had recorded it before (the pipeline list or an earlier run) and whether one of its shaders was translated
// in play rather than prepared.
//
// Threads: stutter_area runs on the game's loading threads, stutter_miss on the replay thread, stutter_ready on the
// pipeline workers (under vk_pipeline.c's P.lock; sm_lock is taken inside it and never takes it), stutter_frame and
// the periodic report on the present thread. The area table's play counts belong to the present thread; the rest is
// under sm_lock. A report copies the map under sm_lock and sorts and logs the copy without it.
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include "cfg.h"
#include "host.h"
#include "stutter_map.h"
#include "platform/platform.h"
int stutter_map_on;
#define SM_AREAS 128 // areas kept by name; later ones share the last slot
#define SM_CAUSES STUTTER_CAUSES // perf.c's FT_C_N, which perf.c asserts
#define SM_LOAD_NS 3000000000ull // after an area load, frames count as the load's for this long
#define SM_HITCH_MIN_NS 12000000.0 // a hitch is at least this long...
#define SM_HITCH_ANY_NS 25000000ull // ...and any frame over this is one
#define SM_HITCH_FACTOR 2.5 // times the median of the frames before it
#define SM_HITCH_SURE_NS 100000000ull // a frame this long is a hitch whatever follows it
#define SM_MEDIAN_N 32 // frames the median is taken over
#define SM_AFTER 2 // frames after a candidate that must be shorter...
#define SM_AFTER_RATIO 1.5 // ...by this factor
#define SM_EPISODE_MAX 8 // a run of long frames up to this long is an episode, longer a new pace
#define SM_PIPES 4096 // pipelines kept for the ranking (open addressing)
#define SM_RING 256 // draws that met something missing, between two presents
#define SM_LINES_MAX 4000
#define SM_LINES_PER_S 5
#define SM_REPORT_NS 300000000000ull // the map every 5 minutes of play
#define SM_TOP_AREAS 40
#define SM_TOP_PIPES 40
typedef struct {
char name[64];
uint64_t ns, frames, over25; // present thread
uint64_t hitch, load_hitch, by_cause[SM_CAUSES], cause_ns[SM_CAUSES], worst_ns, worst_frame;
uint64_t misses, shader_misses, miss_ns; // draws that met a pipeline / a shader missing
} Area;
typedef struct {
uint64_t key; // vertex (or mesh) and fragment input ids' first four bytes each; 0: not known
uint8_t used, mesh, recorded, fresh;
uint16_t area; // where draws first met it
uint64_t misses, shader_misses, wait_ns, ready_n;
double ready_max, ready_sum;
} Pipe;
typedef struct {
uint64_t key, ns;
uint8_t shader, mesh, skipped, has_v, has_f;
} Miss;
static PlatMutex sm_lock = PLAT_MUTEX_INIT;
static Area areas[SM_AREAS];
static int n_areas = 1; // areas[0]: from the start to the first area load
static volatile int cur_area;
static volatile uint64_t load_at; // kern_now_ns of the last area load
static Pipe pipes[SM_PIPES];
static uint32_t n_pipes, pipes_lost;
static Miss ring[SM_RING];
static volatile uint64_t ring_head; // sm_lock: draws noted so far
static uint64_t ring_tail; // present thread: draws taken so far
static uint64_t ring_lost;
// present thread
static uint64_t recent[SM_MEDIAN_N]; // the last frames' intervals, every frame (hitches too, so a new pace is learnt)
static uint64_t t_first, t_report, line_sec, lines_in_sec, lines, frames_seen, paced_out;
// A frame that may be a hitch, waiting for the SM_AFTER frames after it: its line (made when it happened, with the
// draws that met something missing then), its area and what it is charged to.
typedef struct {
char line[1400];
uint64_t frame, d, after_max, med;
double t_s; // seconds since the first frame
int area, load, cause, after;
int tail; // where the line's text after its head ("stutter: frame ... in <area>[, after its load]:") starts
} Cand;
static Cand cand[SM_AFTER + 1];
static int n_cand;
// The episode being gathered: decided candidates of consecutive frames, the first one's line and area (cand_decide).
static struct {
Cand first;
uint64_t last, total; // the last frame in it; the frames' summed intervals
int n, hitch, open; // frames in it; one of them stood out from the frames after it (or was over the sure line)
uint64_t hit_last, hit_total; // the episode up to its last frame that stood out: that frame, the summed intervals
int hit_n; // and the frames to it (0: none stood out)
} ep;
static int pace_run; // more than SM_EPISODE_MAX long frames, none standing out: a new pace, until it ends
static uint64_t pace_last;
void stutter_map_init(void) {
stutter_map_on = cfg_bool("NX2NAVI_STUTTER_MAP");
if (!stutter_map_on) return;
snprintf(areas[0].name, sizeof areas[0].name, "%s", "(before the first area)");
rt_log("stutter map: on (NX2NAVI_STUTTER_MAP): a hitch is a frame over %.1f times the median of the %d before it "
"and at least %.0f ms (or over %llu ms) whose next %d frames are under 1/%.1f of it (or one over %llu ms); "
"frames within %llu s of an area load count as the load's; the map every %llu minutes and at exit",
SM_HITCH_FACTOR, SM_MEDIAN_N, SM_HITCH_MIN_NS / 1e6, SM_HITCH_ANY_NS / 1000000ull, SM_AFTER, SM_AFTER_RATIO,
SM_HITCH_SURE_NS / 1000000ull, SM_LOAD_NS / 1000000000ull, SM_REPORT_NS / 60000000000ull);
}
static uint32_t id4(const uint8_t *id) {
return id ? (uint32_t)id[0] << 24 | (uint32_t)id[1] << 16 | (uint32_t)id[2] << 8 | id[3] : 0;
}
static uint64_t key_of(const uint8_t *vi, const uint8_t *fi) { return (uint64_t)id4(vi) << 32 | id4(fi); }
void stutter_load(void) {
if (stutter_map_on) __atomic_store_n(&load_at, kern_now_ns(), __ATOMIC_RELAXED);
}
void stutter_area(const char *name) {
if (!stutter_map_on || !name || !*name) return;
plat_mutex_lock(&sm_lock);
int i = 0;
while (i < n_areas && strcmp(areas[i].name, name)) i++;
if (i == n_areas) {
if (n_areas < SM_AREAS) snprintf(areas[n_areas++].name, sizeof areas[0].name, "%s", name);
else {
i = SM_AREAS - 1;
snprintf(areas[i].name, sizeof areas[i].name, "%s", "(more areas)");
}
}
__atomic_store_n(&cur_area, i, __ATOMIC_RELAXED);
__atomic_store_n(&load_at, kern_now_ns(), __ATOMIC_RELAXED);
plat_mutex_unlock(&sm_lock);
}
// sm_lock held. The entry for key (mesh apart), made on first use; NULL once the table is full.
static Pipe *pipe_at(uint64_t key, int mesh) {
uint64_t h = (key ^ (uint64_t)mesh) * 0x9E3779B97F4A7C15ull;
for (uint32_t k = 0; k < 64; k++) {
Pipe *p = &pipes[((h >> 52) + k) & (SM_PIPES - 1)];
if (p->used && p->key == key && p->mesh == mesh) return p;
if (!p->used) {
if (n_pipes >= SM_PIPES * 3 / 4) break;
memset(p, 0, sizeof *p);
p->used = 1, p->key = key, p->mesh = (uint8_t)mesh;
p->area = (uint16_t)__atomic_load_n(&cur_area, __ATOMIC_RELAXED);
n_pipes++;
return p;
}
}
pipes_lost++;
return NULL;
}
void stutter_miss(int shader, int mesh, const uint8_t *vi, const uint8_t *fi, uint64_t ns, int skipped) {
if (!stutter_map_on) return;
uint64_t key = key_of(vi, fi);
plat_mutex_lock(&sm_lock);
uint64_t h = ring_head;
if (h - ring_tail >= SM_RING) ring_lost++; // the present has not taken the oldest yet: it is overwritten
Miss *m = &ring[h % SM_RING];
m->key = key, m->ns = ns, m->shader = (uint8_t)(shader != 0), m->mesh = (uint8_t)(mesh != 0);
m->skipped = (uint8_t)(skipped != 0), m->has_v = vi != NULL, m->has_f = fi != NULL;
__atomic_store_n(&ring_head, h + 1, __ATOMIC_RELEASE);
Pipe *p = pipe_at(key, mesh != 0);
if (p) {
if (shader) p->shader_misses++;
else p->misses++;
p->wait_ns += ns;
}
plat_mutex_unlock(&sm_lock);
}
void stutter_ready(int mesh, const uint8_t *vi, const uint8_t *fi, double ms, int recorded, int fresh, int fast) {
(void)fast;
if (!stutter_map_on) return;
plat_mutex_lock(&sm_lock);
Pipe *p = pipe_at(key_of(vi, fi), mesh != 0);
if (p) {
p->ready_n++, p->ready_sum += ms;
if (ms > p->ready_max) p->ready_max = ms;
p->recorded |= (uint8_t)(recorded != 0), p->fresh |= (uint8_t)(fresh != 0);
}
plat_mutex_unlock(&sm_lock);
}
static void hex8(char *b, uint32_t v, int known) {
if (known) snprintf(b, 9, "%08x", v);
else snprintf(b, 9, "%s", "?");
}
// The draws noted since the previous present: counted for the area, and the first few named in line at *o.
static void take_misses(Area *a, char *line, int *o, size_t cap) {
uint64_t head = __atomic_load_n(&ring_head, __ATOMIC_ACQUIRE);
if (head == ring_tail) return;
plat_mutex_lock(&sm_lock);
head = ring_head;
if (head - ring_tail > SM_RING) ring_tail = head - SM_RING;
int named = 0;
uint64_t more = 0;
for (; ring_tail < head; ring_tail++) {
const Miss *m = &ring[ring_tail % SM_RING];
if (m->shader) a->shader_misses++;
else a->misses++;
a->miss_ns += m->ns;
if (!line) continue;
if (named >= 4 || *o >= (int)cap - 120) { more++; continue; }
char v[9], f[9];
hex8(v, (uint32_t)(m->key >> 32), m->has_v);
hex8(f, (uint32_t)m->key, m->has_f);
*o += snprintf(line + *o, cap - (size_t)*o, "%s %s %s %s/%s %.1f ms%s", named ? "," : "; draws that met",
m->shader ? "a shader missing:" : "a pipeline missing:", m->mesh ? "mesh" : "vertex", v,
m->has_f ? f : "none", m->ns / 1e6, m->skipped ? " (skipped)" : "");
named++;
}
if (more && line && *o < (int)cap - 32) *o += snprintf(line + *o, cap - (size_t)*o, " and %llu more", (unsigned long long)more);
plat_mutex_unlock(&sm_lock);
}
// The median of the last SM_MEDIAN_N frames' intervals (fewer at the start).
static uint64_t median_recent(void) {
uint64_t v[SM_MEDIAN_N], n = frames_seen < SM_MEDIAN_N ? frames_seen : SM_MEDIAN_N;
if (!n) return 0;
memcpy(v, recent, (size_t)n * sizeof v[0]);
for (uint64_t i = 1; i < n; i++)
for (uint64_t k = i; k > 0 && v[k - 1] > v[k]; k--) {
uint64_t t = v[k];
v[k] = v[k - 1], v[k - 1] = t;
}
return v[n / 2];
}
// The episode ends: a hitch with its frames' summed time, counted in its first frame's area and charged to that frame's
// cause, and its line logged; a single frame that did not stand out from the ones after it is a change of pace.
static void episode_close(uint64_t now) {
ep.open = 0;
const Cand *c = &ep.first;
if (!ep.hitch && ep.n < 2) {
paced_out++;
return;
}
Area *a = &areas[c->area];
if (c->load) a->load_hitch++;
else {
a->hitch++;
if (c->cause >= 0 && c->cause < SM_CAUSES) a->by_cause[c->cause]++, a->cause_ns[c->cause] += ep.total;
if (ep.total > a->worst_ns) a->worst_ns = ep.total, a->worst_frame = c->frame;
}
uint64_t sec = (now - t_first) / 1000000000ull;
if (sec != line_sec) line_sec = sec, lines_in_sec = 0;
if (lines >= SM_LINES_MAX || lines_in_sec >= SM_LINES_PER_S) return;
if (ep.n == 1) rt_log("%s", c->line);
else // the head with the episode's time; the parts and the draws are its first frame's
rt_log("stutter: frame %llu at %.1f s, %.1f ms (frames about %.1f ms) in %s%s:%s; an episode of %d frames to frame "
"%llu, %.1f ms the first, the parts above the first frame's", (unsigned long long)c->frame, c->t_s,
ep.total / 1e6, c->med / 1e6, areas[c->area].name, c->load ? ", after its load" : "", c->line + c->tail,
ep.n, (unsigned long long)ep.last, c->d / 1e6);
lines++, lines_in_sec++;
if (lines == SM_LINES_MAX) rt_log("stutter: the last such line of this run; the map's counts go on");
}
// A candidate the SM_AFTER frames after it have been seen for: it stands out (a hitch) or the frames after it are as
// long (paced). It joins the episode of the frame before it, or starts one. More than SM_EPISODE_MAX paced frames
// after the episode's last frame that stood out (or from its start, when none did) are a change of pace: they and the
// paced frames right after them are left out, and an episode with a frame that stood out ends at that frame and is
// counted. At 40 fps or less every frame is over SM_HITCH_ANY_NS and so a candidate: without the cut at the last frame
// that stood out, the first hitch took in every frame after it until the rate rose, and a 30 fps session counted one
// hitch seconds long in place of its five.
static void cand_decide(const Cand *c, uint64_t now) {
int paced = c->d <= SM_HITCH_SURE_NS && (double)c->after_max * SM_AFTER_RATIO >= (double)c->d;
if (pace_run) {
if (paced && c->frame == pace_last + 1) {
paced_out++, pace_last = c->frame;
return;
}
pace_run = 0;
}
if (ep.open && c->frame == ep.last + 1) {
ep.last = c->frame, ep.total += c->d, ep.n++;
if (!paced) ep.hitch = 1, ep.hit_n = ep.n, ep.hit_last = c->frame, ep.hit_total = ep.total;
if (ep.n - ep.hit_n > SM_EPISODE_MAX) {
paced_out += (uint64_t)(ep.n - ep.hit_n);
if (ep.hitch) ep.n = ep.hit_n, ep.last = ep.hit_last, ep.total = ep.hit_total, episode_close(now);
else ep.open = 0;
pace_run = 1, pace_last = c->frame;
}
return;
}
if (ep.open) episode_close(now);
ep.first = *c, ep.last = c->frame, ep.total = c->d, ep.n = 1, ep.hitch = !paced, ep.open = 1;
ep.hit_n = !paced, ep.hit_last = c->frame, ep.hit_total = paced ? 0 : c->d;
}
void stutter_frame(uint64_t frame, uint64_t now, uint64_t d, const uint64_t *part, const char *const *names, int n,
int cause) {
if (!stutter_map_on || !d) return;
if (!t_first) t_first = t_report = now;
int ai = __atomic_load_n(&cur_area, __ATOMIC_RELAXED);
Area *a = &areas[ai];
a->ns += d, a->frames++;
a->over25 += d > SM_HITCH_ANY_NS;
// this frame is one of the frames after each waiting candidate
for (int i = 0; i < n_cand;) {
Cand *c = &cand[i];
if (d > c->after_max) c->after_max = d;
if (++c->after < SM_AFTER) {
i++;
continue;
}
cand_decide(c, now);
memmove(&cand[i], &cand[i + 1], (size_t)(n_cand - i - 1) * sizeof cand[0]); // at most two others
n_cand--;
}
if (ep.open && frame > ep.last + SM_AFTER) episode_close(now); // the frame after its last was no candidate
uint64_t med = median_recent();
recent[frames_seen % SM_MEDIAN_N] = d;
frames_seen++;
double lim = (double)med * SM_HITCH_FACTOR;
if (lim < SM_HITCH_MIN_NS) lim = SM_HITCH_MIN_NS;
int maybe = (frames_seen > SM_MEDIAN_N && (double)d > lim) || d > SM_HITCH_ANY_NS;
if (!maybe || n_cand >= SM_AFTER + 1) {
take_misses(a, NULL, NULL, 0);
} else {
Cand *c = &cand[n_cand++];
c->frame = frame, c->d = d, c->after_max = 0, c->after = 0, c->area = ai, c->cause = cause;
c->load = now - __atomic_load_n(&load_at, __ATOMIC_RELAXED) < SM_LOAD_NS;
c->med = med, c->t_s = (now - t_first) / 1e9;
int o = snprintf(c->line, sizeof c->line, "stutter: frame %llu at %.1f s, %.1f ms (frames about %.1f ms) in %s%s:",
(unsigned long long)frame, c->t_s, d / 1e6, med / 1e6, a->name, c->load ? ", after its load" : "");
c->tail = o < (int)sizeof c->line ? o : (int)sizeof c->line - 1;
for (int k = 0; k < n && o < (int)sizeof c->line - 40; k++)
if (part[k] >= 500000) o += snprintf(c->line + o, sizeof c->line - (size_t)o, " %s %.1f", names[k], part[k] / 1e6);
if (cause >= 0 && cause < n && o < (int)sizeof c->line - 40)
o += snprintf(c->line + o, sizeof c->line - (size_t)o, " (charged to %s)", names[cause]);
take_misses(a, c->line, &o, sizeof c->line);
}
if (now - t_report >= SM_REPORT_NS) {
t_report = now;
char tag[32];
snprintf(tag, sizeof tag, "%.0f min", (now - t_first) / 6e10);
stutter_report(tag);
}
}
// In the order of perf.c's causes (FT_C_*); "hand-off" is the wait for the present thread to take the previous picture,
// "census" NX2NAVI_MEM_CENSUS's walk of the address space, "report" the memory report on the presenting thread.
static const char *const cause_short[SM_CAUSES] = {"pipeline", "translation", "texture", "fence", "pacing", "hand-off",
"replay", "census", "report", "unattributed"};
static int area_cmp(const void *x, const void *y) {
const Area *a = *(const Area *const *)x, *b = *(const Area *const *)y;
uint64_t ka = a->hitch + a->load_hitch, kb = b->hitch + b->load_hitch;
if (ka != kb) return ka < kb ? 1 : -1;
return a->ns < b->ns ? 1 : a->ns > b->ns ? -1 : 0;
}
static int pipe_cmp(const void *x, const void *y) {
const Pipe *a = *(const Pipe *const *)x, *b = *(const Pipe *const *)y;
double ka = a->wait_ns / 1e6 + a->ready_max, kb = b->wait_ns / 1e6 + b->ready_max;
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.
typedef struct {
Area areas[SM_AREAS];
Pipe pipes[SM_PIPES];
const Area *order[SM_AREAS];
const Pipe *list[SM_PIPES];
} MapCopy;
// try_only: sm_lock is only tried (a fatal error's summary, perf.c perf_summary_flush_try, on a thread that may
// hold it); 0 when it was held and nothing was written.
int stutter_report_as(const char *tag, int try_only) {
if (!stutter_map_on) return 1;
MapCopy *m = malloc(sizeof *m);
if (!m) {
rt_log("stutter map (%s): no memory for the report", tag);
return 1;
}
if (!try_only) plat_mutex_lock(&sm_lock);
else if (!plat_mutex_trylock(&sm_lock)) {
free(m);
return 0;
}
int na = n_areas;
memcpy(m->areas, areas, (size_t)na * sizeof *areas);
uint32_t np = 0, lost = pipes_lost;
for (uint32_t i = 0; i < SM_PIPES; i++)
if (pipes[i].used) m->pipes[np++] = pipes[i];
uint64_t rlost = ring_lost;
plat_mutex_unlock(&sm_lock);
uint64_t hitch = 0, load = 0, ns = 0, cause[SM_CAUSES] = {0};
for (int i = 0; i < na; i++) {
m->order[i] = &m->areas[i];
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 "
"hitches; in play by cause:", tag, ns / 6e10, na, (unsigned long long)hitch, (unsigned long long)load,
(unsigned long long)paced_out);
for (int c = 0; c < SM_CAUSES; c++)
if (cause[c]) o += snprintf(line + o, sizeof line - (size_t)o, " %s %llu", cause_short[c], (unsigned long long)cause[c]);
rt_log("%s", line);
qsort(m->order, (size_t)na, sizeof m->order[0], area_cmp);
for (int k = 0; k < na && k < SM_TOP_AREAS; k++) {
const Area *a = m->order[k];
if (!a->frames) continue;
o = snprintf(line, sizeof line, "stutter map: %s: %.1f min at %.0f fps; hitches %llu (%.2f a minute",
a->name, a->ns / 6e10, a->ns ? a->frames * 1e9 / a->ns : 0.0, (unsigned long long)a->hitch,
a->ns ? a->hitch * 6e10 / a->ns : 0.0);
for (int c = 0; c < SM_CAUSES; c++)
if (a->by_cause[c])
o += snprintf(line + o, sizeof line - (size_t)o, "; %s %llu, %.1f ms avg", cause_short[c],
(unsigned long long)a->by_cause[c], a->cause_ns[c] / 1e6 / a->by_cause[c]);
o += snprintf(line + o, sizeof line - (size_t)o, "), worst %.1f ms (frame %llu); over 25 ms %llu; after its "
"loads %llu; draws that met a pipeline missing %llu, a shader %llu, %.1f ms on the replay thread",
a->worst_ns / 1e6, (unsigned long long)a->worst_frame, (unsigned long long)a->over25,
(unsigned long long)a->load_hitch, (unsigned long long)a->misses,
(unsigned long long)a->shader_misses, a->miss_ns / 1e6);
rt_log("%s", line);
}
uint32_t nrec = 0, nnew = 0, nfresh = 0, nunknown = 0;
for (uint32_t i = 0; i < np; i++) {
const Pipe *p = m->list[i] = &m->pipes[i];
if (!p->key) nunknown++;
else if (p->ready_n) nrec += p->recorded, nnew += !p->recorded;
nfresh += p->fresh;
}
qsort(m->list, np, sizeof m->list[0], pipe_cmp);
rt_log("stutter map: %u pipelines draws met missing: %u that this install had recorded before (its prebuild had not "
"come to them), %u new to it, %u with a shader translated in play, %u still translating when met; %u not "
"kept (table full), %llu draws not seen by a present (ring full); the %d that cost the most:",
np, nrec, nnew, nfresh, nunknown, lost, (unsigned long long)rlost, SM_TOP_PIPES);
for (uint32_t k = 0; k < np && k < SM_TOP_PIPES; k++) {
const Pipe *p = m->list[k];
char v[9], f[9];
hex8(v, (uint32_t)(p->key >> 32), p->key >> 32 != 0);
hex8(f, (uint32_t)p->key, 1);
rt_log("stutter map: %s %s/%s first met in %s: %llu draws met it missing, %llu its shader, %.1f ms on the "
"replay thread; usable after %.0f ms at most (%llu times); %s%s",
p->mesh ? "mesh" : "vertex", v, (uint32_t)p->key ? f : "none", m->areas[p->area].name, // copied: area < na
(unsigned long long)p->misses, (unsigned long long)p->shader_misses, p->wait_ns / 1e6, p->ready_max,
(unsigned long long)p->ready_n,
!p->key ? "its shaders still translating" : !p->ready_n ? "not seen ready" : p->recorded ? "recorded before"
: "new to this install",
p->fresh ? ", a shader translated in play" : "");
}
free(m);
return 1;
}
void stutter_report(const char *tag) { stutter_report_as(tag, 0); }