telemetry: split expert hits into pin-tier vs LRU ecache (#336)

The expert lookup counted a hit identically whether the pinned hot-store or the
LRU ecache served it — both Phase C branches bumped the single `m->hits`. With a
warm pin profile the pin tier absorbs most hot experts, so the ecache could be
serving anywhere from ~0% to most hits and the logs couldn't tell which. That
made every cache-policy question unanswerable, including #223's "at what cap
does the eviction policy start to win?" (a flat A/B can mean "pin absorbed
everything" or "genuine floor" and the lumped counter can't distinguish them).

Two counters `hit_pin`/`hit_ecache` bumped at the two lookup branches (the
existing `m->hits++` stays, so all existing math is unchanged), snapshotted in
ProfBase and reset alongside `hits`. Surfaced in the human-readable summaries:
  decode:  expert hit rate 31.3% (pin 22.1% + lru 9.2%)
  [PROF]:  hit 31.3% (X pin + Y lru / Z load)
  tiny:    hit rate 88.1% (0 pin + 74 lru / 10 miss)
The serve-mux STAT protocol line is untouched (openai_server.py parses it
positionally).

Invariant hit_pin + hit_ecache == hits holds by construction — exactly two
sites bump hits and each also bumps one split counter, nothing else mutates
hits. Verified numerically on the tiny oracle: 0 pin + 74 lru = 74 hits, 88.1%.
Zero cost: two increments on paths that already increment.

Reported-by: KingIcyCreamProjects <#336>

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
JustVugg
2026-07-18 01:43:50 +02:00
parent db09466d3d
commit 679c0742b2
+16 -10
View File
@@ -196,6 +196,7 @@ typedef struct {
uint64_t mtp_prop, mtp_acc; /* statistica acceptance */
int **eroute; int *enr; /* metodo C: routing dell'ULTIMO token per layer */
uint64_t eclock, hits, miss, ereq;
uint64_t hit_pin, hit_ecache; /* split di hits per tier (#336): pin vs LRU ecache */
uint64_t gpu_expert_calls; int gpu_expert_count; int64_t gpu_expert_bytes;
uint64_t n_fw, n_emit; /* metodo E: forward di decode / token emessi */
uint64_t route_slots, route_swaps; /* CACHE_ROUTE: slots chosen / substituted vs true top-K */
@@ -312,6 +313,7 @@ static void prof_lat(double s){ g_prof_lat[g_prof_nlat++ % PROF_LAT_CAP]=s; }
typedef struct {
double edisk,ewait,emm,ecpu,egpu,route,p2p,attn,head;
int64_t io,cpu_bytes; uint64_t hits,miss,ereq,n_fw,n_emit,nlat,n_p2p,cpu_rows;
uint64_t hit_pin,hit_ecache;
} ProfBase;
static void prof_base(Model *m, ProfBase *b){
b->edisk=edisk_s(); b->ewait=m->t_ewait; b->emm=m->t_emm;
@@ -319,6 +321,7 @@ static void prof_base(Model *m, ProfBase *b){
b->attn=m->t_attn; b->head=m->t_head;
b->io=atomic_load_explicit(&g_prof_io,memory_order_relaxed);
b->hits=m->hits; b->miss=m->miss; b->ereq=m->ereq;
b->hit_pin=m->hit_pin; b->hit_ecache=m->hit_ecache;
b->n_fw=m->n_fw; b->n_emit=m->n_emit; b->nlat=g_prof_nlat; b->n_p2p=m->n_p2p;
b->cpu_bytes=m->cpu_expert_bytes;b->cpu_rows=m->cpu_expert_rows;
}
@@ -3132,9 +3135,9 @@ static void moe(Model *m, Layer *l, int layer, float *x, int S, float *out, int
ESlot *use[64]; int missk[64]; int qof[64]; int nmiss=0;
for(int j=0;j<nb;j++){ int eid=uniq[base+j]; use[j]=NULL; qof[j]=-1;
ESlot *P=m->pin[layer];
for(int z=0;z<m->npin[layer];z++) if(P[z].eid==eid){ m->hits++; use[j]=&P[z]; break; }
for(int z=0;z<m->npin[layer];z++) if(P[z].eid==eid){ m->hits++; m->hit_pin++; use[j]=&P[z]; break; }
if(!use[j]){ ESlot *Sl=m->ecache[layer]; int nn=m->ecn[layer];
for(int z=0;z<nn;z++) if(Sl[z].eid==eid){ m->hits++; Sl[z].used=(uint64_t)__atomic_add_fetch(&m->eclock,1,__ATOMIC_RELAXED); use[j]=&Sl[z]; break; } }
for(int z=0;z<nn;z++) if(Sl[z].eid==eid){ m->hits++; m->hit_ecache++; Sl[z].used=(uint64_t)__atomic_add_fetch(&m->eclock,1,__ATOMIC_RELAXED); use[j]=&Sl[z]; break; } }
if(!use[j]){ qof[j]=nmiss; use[j]=&m->ws[nmiss]; missk[nmiss++]=j; m->miss++;
if(g_disk_split){ if(m->ld_ctx==1) m->miss_draft++; else if(m->ld_ctx==2) m->miss_absorb++; } }
}
@@ -4674,11 +4677,12 @@ static void prof_report(Model *m, const ProfBase *b, double elapsed, int tokens,
for(int i=0;i<=c->n_layers;i++){ if(m->npin)pinned+=m->npin[i]; if(m->ecn)lru+=m->ecn[i]; }
double io_w=m->t_ewait-b->ewait; /* stall the compute thread felt */
double io_svc=edisk_s()-b->edisk; /* read service on the loading threads (overlaps compute) */
uint64_t dhp=m->hit_pin-b->hit_pin, dhe=m->hit_ecache-b->hit_ecache; /* split #336 */
fprintf(f,"[PROF] expert I/O: %.3f GB fetched (%.1f MB/token, %.2f GB/s over the run%s) | "
"hit %.1f%% (%llu hit / %llu load) | %.1f loads/token | %.1fs read service / %.1fs felt wait\n",
"hit %.1f%% (%llu pin + %llu lru / %llu load) | %.1f loads/token | %.1fs read service / %.1fs felt wait\n",
io/1e9, tokens>0?io/1e6/tokens:0.0, io/1e9/elapsed,
g_mmap?"; COLI_MMAP=1: page cache may serve part":"",
hitp,(unsigned long long)dh,(unsigned long long)dm, tokens>0?(double)dq/tokens:0.0,
hitp,(unsigned long long)dhp,(unsigned long long)dhe,(unsigned long long)dm, tokens>0?(double)dq/tokens:0.0,
io_svc,io_w);
fprintf(f,"[PROF] resident experts: %d pinned (%.1f GB) + %d in LRU (%.1f GB, cap %d/layer)\n",
pinned,pinned*eb/1e9,lru,lru*eb/1e9,m->ecap);
@@ -4724,7 +4728,7 @@ static void run_replay(Model *m, const int *full, int nfull, int np){
if(np<2||nfull<=np){ fprintf(stderr,"REPLAY requires a non-empty prompt and continuation\n"); return; }
kv_alloc(m,nfull+2);
float *logit=step(m,full,np-1,0); free(logit);
m->hits=m->miss=m->ereq=m->gpu_expert_calls=0;
m->hits=m->miss=m->ereq=m->gpu_expert_calls=0; m->hit_pin=m->hit_ecache=0;
profile_reset(m);
ProfBase pb; prof_base(m,&pb);
double t0=now_s(); int steps=0;
@@ -4774,7 +4778,7 @@ static void run_text(Model *m, const char *snap, const char *prompt, int ngen){
}
prefill_t=now_s()-prefill_t;
printf("PROFILO PREFILL (%.2fs):\n",prefill_t); profile_print(m,prefill_t);
m->hits=m->miss=m->ereq=m->gpu_expert_calls=0;
m->hits=m->miss=m->ereq=m->gpu_expert_calls=0; m->hit_pin=m->hit_ecache=0;
m->n_emit=m->n_fw=0;
g_last_repin=0;
profile_reset(m);
@@ -4787,8 +4791,9 @@ static void run_text(Model *m, const char *snap, const char *prompt, int ngen){
double tot=m->hits+m->miss;
int nsp=0; for(int i=0;i<c->n_layers;i++) if(m->L[i].sparse) nsp++;
printf("\n---\nprefill %d tokens in %.2fs | decode %d tokens in %.2fs (%.2f tok/s) | "
"expert hit rate %.1f%% | RSS %.2f GB",
np,prefill_t,produced,dt,produced/dt,tot?100.0*m->hits/tot:0.0,rss_gb());
"expert hit rate %.1f%% (pin %.1f%% + lru %.1f%%) | RSS %.2f GB", /* split #336: quale tier serve gli hit */
np,prefill_t,produced,dt,produced/dt,tot?100.0*m->hits/tot:0.0,
tot?100.0*m->hit_pin/tot:0.0, tot?100.0*m->hit_ecache/tot:0.0, rss_gb());
if(g_cache_route && m->route_slots)
printf(" | swap %.1f%% (%llu/%llu)",
100.0*m->route_swaps/m->route_slots,
@@ -6535,8 +6540,9 @@ int main(int argc, char **argv){
double tot=m.hits+m.miss;
printf("N-gram speculation (DRAFT=%d): %.2f tokens/forward (%llu forwards per %llu tokens)\n",
g_draft, m.n_fw?(double)m.n_emit/m.n_fw:1.0, (unsigned long long)m.n_fw, (unsigned long long)m.n_emit);
printf("Expert cache hit rate: %.1f%% (hit=%llu miss=%llu) | RSS: %.2f GB | %.1f tok/s\n",
tot?100.0*m.hits/tot:0.0, (unsigned long long)m.hits, (unsigned long long)m.miss, rss_gb(), n_new/dt);
printf("Expert cache hit rate: %.1f%% (%llu pin + %llu lru / %llu miss) | RSS: %.2f GB | %.1f tok/s\n",
tot?100.0*m.hits/tot:0.0, (unsigned long long)m.hit_pin, (unsigned long long)m.hit_ecache,
(unsigned long long)m.miss, rss_gb(), n_new/dt);
profile_print(&m,dt);
if(g_prof) prof_report(&m,&pb,dt,n_new,stdout);
#ifdef COLI_CUDA