Pace the ring, then read the DMAC config out of the IPL ROM: audio is cheap and the disk is not

Two sessions that were never separated in the working tree, so they land as one
commit. check.sh ALL GREEN before and after both.

SESSION 19 -- the ring rig gets a frame clock (FINDINGS 51).

src/player/stream.s had no frame clock: it asked for record i the instant it
finished i-1, outran any finite pipe, and never let the ring back up. The 49.1
sweep passing at 48 KB was therefore a wrap-correctness result and nothing else.
PACE/PACEON ($18034/$18038) hold the decoder to 12 fps, so FR_HEAD-FR_TAIL
finally means what it reads as: whole frames the decoder could still draw with
delivery stopped dead. PACEON=0 free-runs and is what the wrap gate still uses,
so every figure in 49 is unmoved.

Paced, on the gate container: 64 KB holds 2 frames, 256 KB holds 7-8, 512 KB
holds 14-15, all pixel-exact. Tolerance is ceiling-1, measured by cutting the
pipe: 256 KB buys 500 ms of dead pipe, not 583.

SLACK IS ACCUMULATED, NOT OWNED. It is built out of pipe-wire and a seek spends
all of it. At 488 KB/s a 256 KB ring needs 4.83 s of play to reach its ceiling
from empty; 512 KB needs 8.42 s to reach 14. A bigger ring raises the ceiling
AND lengthens the climb, so a branch point does not ask "is the buffer big
enough" but "has there been enough play since the last one" -- and Dragon's
Lair's decision points are seconds apart. The rig now also says WHICH resource
is binding: at 460 KB/s every ring from 192 KB to 512 KB is rate-bound at
ceiling 4 and never fills, so larger rings are dead RAM in that scene.
20_seek_slack.py is the same model rewritten in Python from record sizes,
sharing no code with the Lua producer: 35/35 ceilings inside its bracket.

SESSION 20 -- the DMAC configuration was in the IPL ROM the whole time
(FINDINGS 52).

ROADMAP's "do this first" was to put the ADPCM stream on the bus. That needs a
clocks-per-byte figure for the audio channel, and 11_cpu_budget.py was charging
audio the DISK's rate -- 5 clk/B, its own help text calling it "single-address,
bus held". Audio was being charged the favourable end of B3, a 242 KB/s open
question.

It never had to be a guess. The IPL ROM programs all four HD63450 channels
itself and MAME boots the rig with it, so 21_iplrom_dmac.py reads the
configuration out of the image and decodes the MC68450 fields. Eight
(address, expected bytes, meaning) sites; a mismatch or an unknown revision
exits non-zero. In check.sh, no emulator, milliseconds.

ch3 DCR=$80, OCR=$32: dual address, 8-bit port, cycle steal WITHOUT hold,
REQG=10 external request. The DMAC arbitrates once per byte with no burst to
amortise the 5..8 + 2 over, so an audio byte is 16..19 clocks, not 5 -- the old
debit was 3.2x..3.8x small. And on the bus it is still nothing: 651 B/frame is
1.25%..1.48% of a frame, about 4% of what the decoder leaves. P6's bus risk
does not materialise. The unit worry was worth checking and nearly right: 15.6
kHz is 8 MHz/512 = 15,625 samples/s, two 4-bit samples to a byte = 7,812.5 B/s
exactly, and AUDIO_KBPS=7.8 is that in decimal kB while the tool multiplied by
1024.

THE DISK CHANNEL IS PROGRAMMED IDENTICALLY. ch1 (SASI) is DCR=$80 too, and so
is ch0. That is 16..19 clocks per delivered byte, where 42.4 brackets W at 5..12
and 42.5 has W=8 already missing 47/120 frames. The only worked example of a
disk DMA configuration on this machine sits above the entire bracket, and at
that price nothing fits at any container size. It is not scsiexrom.bin so B3
stays open -- what changed is that a cheap configuration is now the thing that
has to be SHOWN. W <= 12 is a requirement on the player's DMAC programming, not
a range the hardware hands us, and it is now the largest open number in the
project, ahead of the rate.

An unforced cross-check fell out: 15_bus_occupancy.py's new W sweep puts W=8 at
105.7% of the frame, agreeing with 42.5's 47/120, from mode histograms and bus
clocks respectively, two models sharing no code.

Also: ADPCM outranks the disk at the arbiter (CPR 1 against 2), so an audio byte
never waits and a video byte does -- relevant to 51's smooth-rate delivery model.

README MEDIA.

stream.lua gains DLX_SNAP_EVERY=1 (needs DLX_PACE, off by default, on no path
check.sh takes) and tools/media/make_readme_media.py turns the PNGs into
docs/img/. The stills and both clips are MAME's own screen pixels.

Building it turned up something worth recording. 116 of 119 captured frames are
pixel-exact against dlx.py; three are TORN -- frame n on top, frame n-1 below
the tear line -- because MAME captured the screen while the block loop was
partway down it. decode.s writes straight to the displayed page (one display
path, 28.1), so a real player tears the same way, and this is the first time
that consequence has been visible rather than argued. The script ASSERTS the
tear and refuses to build otherwise, rather than trimming three frames and
reporting "every frame I kept is exact". Second correction the capture forced:
the snapshot fires before frame n is decoded, so the obvious reading is that it
holds frame n-1 -- it does not, because MAME renders the screen at the end of
the machine frame, by which time the 68000 has finished frame n.

11_cpu_budget.py's "validated to within 1 pt" line is also corrected: the model
reads 2..10 pt HIGH and by more as the frame gets harder, which was already true
before either session.

src/player/decode.s is unchanged; decode.bin is still 1,296 B at the same MD5.

Claude-Session: https://claude.ai/code/session_01194oWYW8DQXK1SZ2DnChW6
This commit is contained in:
prosolis
2026-08-24 18:14:01 -07:00
parent b49bbdc939
commit 2f9f5cc995
49 changed files with 6276 additions and 375 deletions
+487
View File
@@ -0,0 +1,487 @@
-- Drive src/player/stream.s: decode a whole window through a BOUNDED RING,
-- with a modelled SCSI pipe as the producer. STATUS item 3, FINDINGS 49.
--
-- tools/bench/decode.lua preloads the entire container into emulated RAM and
-- lets the 68000 walk a0 through all of it. That gate is pixel-exact over 120
-- frames (FINDINGS 45) and tests nothing about delivery -- 45.4.1 says so in as
-- many words. It is also RAM-bound for a reason that has nothing to do with the
-- player: 5,261,814 B of stream needs a 6 MB machine.
--
-- Here the container lives in a HOST file (tools/bench/prep_stream.py's disk
-- image) and this script plays the part of the MB89352 plus a DMAC channel:
-- it delivers bytes at a modelled rate into a ring of DLX_RING_KB, and the
-- 68000 decodes out of that ring and nothing else. The emulated machine holds
-- ~256 KB of stream instead of 5 MB, so a STOCK 2 MB machine runs the whole
-- window -- the RAM ceiling of FINDINGS 44.6.4/45 is a property of the old rig
-- and this one does not have it.
--
-- WHAT IS BEING TESTED, precisely: that the block loop and the span chain --
-- which read with a monotonically increasing a0 and no bounds check anywhere --
-- stay pixel-exact when a0 is inside a ring one twentieth the size of the
-- stream, and when the address it is handed jumps backwards to the ring base
-- roughly every sixth frame. A green run is not "the decoder still works"; it
-- is "the wrap policy in src/player/stream.s does not corrupt a single pixel of
-- a temporally recursive 120-frame decode".
--
-- THE WRAP POLICY IS `aligned` (tools/analysis/19_ring_stream.py): never start a
-- record that will not fit before the end of the ring; leave the hole and
-- restart at the base. The alternative, letting records wrap and mirroring the
-- ring head into a shadow, costs 5.57% of the frame budget forever against this
-- one's 9.1% of a buffer, and the decoder is already at 91.1% of budget at p90.
-- (Those two are s14_d5_all1500's; the gate container this rig usually runs
-- makes it 3.64% of the budget against 5.7% of the ring. Per container.)
--
-- MEASUREMENT SCOPE, unchanged from decode.lua: MAME's gvram_w/gvram_r carry no
-- timing, so decode times here are pure 68000 instruction cycles against
-- zero-wait-state memory -- a LOWER BOUND. The pipe, likewise, is a MODEL: a
-- constant byte rate on the emulated clock, not a simulation of the MB89352.
-- What it is honest about is ARRIVAL ORDER and RESIDENCY, which is what the
-- ring exists to manage; it says nothing about the clocks the DMAC steals from
-- the 68000 while it does it. That debit is FINDINGS 43.2's and is not modelled
-- here -- so a zero-stall result from this rig means "the bytes were in time",
-- NOT "the frame fits".
--
-- Env:
-- DLX_RING_KB ring size in KB (default 256, FINDINGS 21's)
-- DLX_STREAM_KBPS modelled pipe, KB/s REQUIRED -- no default.
-- 0 = unlimited, which isolates the WRAP question from the
-- DELIVERY one and is what the green light uses.
-- There is deliberately no default rate: this project has
-- never measured the delivery pipe, and the figure that used
-- to be defaulted to here was a user-supplied "4 Mbps" with
-- no provenance that was never a bus measurement at all
-- (FINDINGS 42.1). A default is how a folklore number ends up
-- silently underneath a table nobody restates it in.
-- DLX_PREFILL_KB bytes to deliver before releasing the CPU (default 0)
-- DLX_PACE 1 = hold the decoder to META.fps (default 0 = free-run)
-- DLX_CUT_AT frame tick at which the pipe stops dead (a seek). Needs
-- DLX_PACE; unset = no cut.
-- DLX_CUT_FR how many frame times the cut lasts (default 1)
-- DLX_SLACK_CSV write the per-tick lookahead series to this path
-- DLX_SNAP_EVERY 1 = snapshot every frame tick (needs DLX_PACE). For
-- recording the player; not used by check.sh.
--
-- PACING, AND WHY THE UNPACED RIG COULD NOT ANSWER THE BUFFERING QUESTION
-- (FINDINGS 49.7.2). Free-running, src/player/stream.s asks for record i the
-- instant it finishes record i-1. It therefore outruns any finite pipe, the
-- ring never backs up, `overlaps` never refuses a placement, and every ring size
-- down to 48 KB passes while holding ONE record. That sweep tests wrap
-- correctness, which is real, and says nothing about buffering, which is what a
-- branch point needs. With DLX_PACE=1 the producer supplies a frame clock and
-- the decoder may not start frame i before tick i, so the ring fills to its own
-- capacity and FR_HEAD-FR_TAIL becomes the honest number: whole frames the
-- decoder could run on with delivery stopped dead. DLX_CUT_AT/DLX_CUT_FR then
-- stop it dead and check the answer against a real underrun.
M = manager.machine
SP = M.devices[":maincpu"].spaces["program"]
local function findfile(n)
for _,p in ipairs{"../tools/bench/"..n, "tools/bench/"..n, n} do
local f = io.open(p,"rb"); if f then f:close(); return p end
end
error(n.." not found")
end
local MODE = loadfile(findfile("crtc_mode.lua"))()
local META = loadfile("stream_meta.lua")()
local FLAG, ITER, NFR = 0x18000, 0x18008, 0x1800C
local RD_PTR, FR_HEAD, FR_TAIL = 0x18020, 0x18024, 0x18028
local STALLS, SPINS, DESC = 0x1802C, 0x18030, 0x18100
local PACE, PACEON = 0x18034, 0x18038
local DESCN = 64
local CB1, CB4 = 0x20000, 0x22000
local RING = 0x40000
local GVRAM, GPAL = 0xC00000, 0xE82000
local CPUHZ = 10000000
local FRAME12 = CPUHZ / META.fps
local AUDIO_KBPS = 7.8 -- ratectl.AUDIO_KBPS; the pipe carries it too
local RING_KB = tonumber(os.getenv("DLX_RING_KB") or "") or 256
local KBPS = tonumber(os.getenv("DLX_STREAM_KBPS") or "")
if KBPS == nil then
print("[STR] DLX_STREAM_KBPS is not set and has no default. Set it to the "
.."delivery rate you want to model, or to 0 for an unlimited pipe "
.."(which is what tools/bench/check.sh uses -- it gates the WRAP "
.."policy, and an unlimited pipe removes delivery as a variable).")
manager.machine:exit()
return
end
local PREFILL = (tonumber(os.getenv("DLX_PREFILL_KB") or "") or 0) * 1024
local PACED = (os.getenv("DLX_PACE") == "1")
local CUT_AT = tonumber(os.getenv("DLX_CUT_AT") or "")
local CUT_FR = tonumber(os.getenv("DLX_CUT_FR") or "") or 1
local SLACK_CSV = os.getenv("DLX_SLACK_CSV")
-- One snapshot per frame tick instead of one at the end of the run. This is a
-- DOCUMENTATION artefact -- 120 PNGs of a paced player, for a recording -- and
-- it is deliberately not on any path tools/bench/check.sh takes. Needs
-- DLX_PACE: snapshotting a free-running decoder would sample the screen at
-- whatever rate the 68000 happened to finish frames at, which is not a frame
-- rate and would misrepresent the player as faster than it is.
local SNAP_EVERY = (os.getenv("DLX_SNAP_EVERY") == "1")
local RINGSZ = RING_KB * 1024
-- Video's share of the pipe. Debiting audio is not optional bookkeeping: the
-- ADPCM stream comes off the same disk and out of the same budget (FINDINGS 33).
local BPS = (KBPS > 0) and (KBPS - AUDIO_KBPS) * 1024 or math.huge
local code do local f=io.open("stream.bin","rb"); code=f:read("a"); f:close() end
local cb do local f=io.open("stream_cb.bin","rb"); cb=f:read("a"); f:close() end
local DISK = assert(io.open("stream_disk.bin","rb"))
local YOFF = (MODE.height - META.H) // 2
local function T() local t=M.time; return t.seconds + t.attoseconds/1e18 end
local function P(s) print("[STR] "..s) end
local function push(addr, s, from, len)
local i, n = from, len
while n >= 4 do
SP:write_u32(addr, (string.unpack(">I4", s, i)))
addr, i, n = addr+4, i+4, n-4
end
while n > 0 do
SP:write_u8(addr, string.byte(s,i)); addr, i, n = addr+1, i+1, n-1
end
end
-- ------------------------------------------------------------ the producer
-- Ring occupancy is tracked as an explicit list of records still owned by the
-- decoder, rather than as a modular write-minus-read distance. Under `aligned`
-- the ring is not a simple modulus -- a wrap leaves a HOLE of arbitrary size --
-- so a distance would have to carry the holes as a correction term and would be
-- the easiest thing in this file to get quietly wrong. Six-ish live records is
-- a short list; an O(n) overlap test on it is exact and obviously exact.
-- arrival[i] = emulated time at which record i became RESIDENT. This, not the
-- decoder's spin counter, is what answers the delivery question. stream.s has
-- no frame clock: it asks for the next record the instant it finishes the last
-- one, so it outruns any finite pipe and "stalled" is what a decoder that is
-- merely EARLY looks like. A shipping player waits for vblank at 12 fps and
-- spends that same time idle. So the honest test is not "did the decoder ever
-- wait" but "was record i resident by its 12 fps deadline", which is a question
-- about arrival times alone and does not need the decoder paced.
local arrival = {}
local live, wcur, nsent = {}, 0, 0
local n_rate, n_ring = 0, 0
local holes, hole_bytes, credit = 0, 0, 0
local last_t, pf_t0, delivered = nil, nil, 0
local function overlaps(off, len)
for _,r in ipairs(live) do
if off < r.off + r.len and r.off < off + len then return true end
end
return false
end
local function reap()
local tail = SP:read_u32(FR_TAIL)
local i = 1
while i <= #live do
if live[i].idx < tail then
-- RD_PTR is the decoder's byte-granular release, and nothing here needs
-- it -- this producer has the index and works in whole records. Checking
-- it makes it a cross-check instead of a field nothing reads: a real
-- producer without an index (a DMAC chasing the CPU) has only this.
--
-- It holds for the LAST record retired in a pass and not for the others.
-- RD_PTR is a single released-to pointer, so it names the end of record
-- tail-1; if several records were consumed since the previous reap -- and
-- under a paced decoder with a stopped pipe, several is normal -- the
-- earlier ones are long overwritten by it. Asserting per record made the
-- check a test of how often reap happened to run.
if live[i].idx == tail - 1 then
local rp = SP:read_u32(RD_PTR)
local want = RING + live[i].off + live[i].len
if rp ~= want then
P(string.format("RD_PTR MISMATCH after frame %d: decoder released "
.."%08X, record ends %08X", live[i].idx, rp, want))
M:exit()
end
end
table.remove(live, i)
else
i = i + 1
end
end
end
-- Cut window: the pipe stops dead, as it does across a seek. Credit is FROZEN
-- rather than left to accumulate -- a drive that is repositioning is not
-- banking bytes it will burst on arrival, and letting credit build would hand
-- the ring back everything the cut took the moment it ended, which is the one
-- way to make a seek look free.
local cut_t0, cut_t1, cut_done = nil, nil, false
local function produce(now)
local dt = now - (last_t or now); last_t = now
local cut = (cut_t0 and now >= cut_t0 and now < cut_t1)
-- A seek stops DELIVERY. It does not stop the decoder, which goes on draining
-- the ring and releasing bytes behind itself, so reap() runs either way --
-- skipping it would have the ring look full for the whole cut and hide the
-- one thing the cut is for.
if not cut then credit = credit + dt * BPS end
reap()
if cut then return end
while nsent < META.nframes do
local rec = META.index[nsent + 1]
-- WHICH RESOURCE REFUSED, counted separately. A producer that stops
-- because it has no credit is RATE-bound and a bigger ring buys nothing; one
-- that stops because the decoder still owns the bytes is RING-bound and a
-- faster pipe buys nothing. The two look identical from the decoder's side
-- -- both are simply "no new record" -- and they have opposite fixes.
if credit < rec.len then n_rate = n_rate + 1; break end
-- `aligned`: refuse to start a record that will not finish inside the ring.
-- The hole is charged only once the record is actually PLACED. Charging it
-- at the point the wrap is decided counts one hole per retry while the
-- decoder still owns the ring base -- which is every tick of a fast pipe --
-- and reported 105 wraps over 120 records where there are 18.
local w, hole = wcur, 0
if w + rec.len > RINGSZ then w, hole = 0, RINGSZ - wcur end
if overlaps(w, rec.len) then n_ring = n_ring + 1; break end -- decoder owns them
if hole > 0 then holes = holes + 1; hole_bytes = hole_bytes + hole end
DISK:seek("set", rec.off)
push(RING + w, DISK:read(rec.len), 1, rec.len)
-- The descriptor MUST be visible before the count that advertises it. Here
-- the CPU is stopped while this runs so the order is academic; on hardware
-- it is not, and stream.s reads them in the opposite order for that reason.
SP:write_u32(DESC + (nsent % DESCN) * 4, RING + w)
live[#live+1] = {idx=nsent, off=w, len=rec.len}
wcur, nsent = w + rec.len, nsent + 1
credit, delivered = credit - rec.len, delivered + rec.len
SP:write_u32(FR_HEAD, nsent)
arrival[nsent] = now -- record nsent-1 is now resident
end
end
-- ------------------------------------------------------------------ setup
local function setup()
MODE.apply(SP)
push(CB1, cb, 1, META.cb1_len)
push(CB4, cb, 1 + META.cb1_len, META.cb4_len)
local palo = 1 + META.cb1_len + META.cb4_len
for c = 0, 255 do
SP:write_u16(GPAL + c*2, (string.unpack(">I2", cb, palo + c*2)))
end
for y = 0, MODE.height-1 do
local base, v = GVRAM + y*1024, 0
if y < YOFF or y >= YOFF+META.H then v = META.dark end
for x = 0, MODE.width-1 do SP:write_u16(base + x*2, v) end
end
for i = 1, #code do SP:write_u8(0x10000+i-1, string.byte(code,i)) end
SP:write_u32(FLAG, 0); SP:write_u32(FR_HEAD, 0); SP:write_u32(FR_TAIL, 0)
SP:write_u32(ITER, 1); SP:write_u32(NFR, META.nframes)
SP:write_u32(PACE, 0); SP:write_u32(PACEON, PACED and 1 or 0)
P(string.format("stream.bin=%d B, codebooks %d+%d B, disk %d B, %d frames",
#code, META.cb1_len, META.cb4_len, META.disk_len, META.nframes))
P(string.format("decoder %s%s", PACED and ("PACED at "..META.fps.." fps")
or "FREE-RUNNING (tests wrap, not buffering -- 49.7.2)",
CUT_AT and string.format(", pipe cut at tick %d for %.2f fr",
CUT_AT, CUT_FR) or ""))
P(string.format("ring %d KB at %06X, pipe %s, prefill %d KB, maxrec %d B",
RING_KB, RING, (KBPS > 0) and (KBPS.." KB/s") or "unlimited",
PREFILL // 1024, META.maxrec))
if META.maxrec > RINGSZ then
P("RING TOO SMALL: one record does not fit. stream.s needs a whole record "
.."contiguous."); M:exit()
end
end
local function launch()
local cpu = M.devices[":maincpu"]
cpu.state["SR"].value = 0x2700 -- supervisor, ALL interrupts masked
cpu.state["SP"].value = 0x8000
cpu.state["PC"].value = 0x10000
end
local st, t0, t_rel = "boot", nil, 0
local pace, min_ahead, min_at = -1, math.huge, -1
local sum_ahead, n_ahead = 0, 0
local slack_series = {}
SUB = emu.add_machine_frame_notifier(function()
local ok, err = pcall(function()
local t = T()
if st == "boot" then
if t < 3.0 then return end
setup(); last_t, pf_t0 = t, t; st = "prefill"; return
end
if st == "prefill" then
produce(t)
if delivered >= PREFILL then
P(string.format("prefill done: %.1f KB in %.3f s, releasing the CPU",
delivered/1024, t - pf_t0))
launch(); t_rel = t; st = "running"
end
return
end
if st == "running" then
if PACED then
local tick = math.floor((t - t_rel) * META.fps)
if tick > pace then
pace = tick
SP:write_u32(PACE, pace)
-- Taken BEFORE this tick's frame is decoded, so snapshot n is the
-- finished picture of frame n-1. tick 0 is skipped: nothing has been
-- drawn yet and it would record a black screen as a decoded frame.
if SNAP_EVERY and tick > 0 then M.video:snapshot() end
-- Sampled AT the tick, before this frame is decoded: FR_TAIL is the
-- count of frames already done, FR_HEAD the count resident, so the
-- difference is exactly how many further frames the decoder could
-- draw if the pipe went silent at this instant. Whole records, not
-- bytes -- the contiguity constraint of 49.2 means a partial record
-- buys nothing.
local ahead = SP:read_u32(FR_HEAD) - SP:read_u32(FR_TAIL)
-- Only sampled while the producer still HAS records to place. Once
-- it has sent the last one the lookahead drains to zero for reasons
-- that are about the window ending, not about the ring's capacity or
-- the pipe's rate -- and the minimum over the whole run would then
-- always be the drain tail, which is the one part of it that tells
-- you nothing.
if nsent < META.nframes then
if ahead < min_ahead then min_ahead, min_at = ahead, tick end
sum_ahead, n_ahead = sum_ahead + ahead, n_ahead + 1
slack_series[#slack_series+1] = {tick, ahead, n_ring, n_rate}
end
if CUT_AT and tick >= CUT_AT and not cut_t0 then
cut_t0, cut_t1 = t, t + CUT_FR / META.fps
P(string.format("PIPE CUT at tick %d for %.2f frame times "
.."(%.1f ms), with %d frames resident ahead",
tick, CUT_FR, 1000*CUT_FR/META.fps, ahead))
end
end
end
produce(t)
if cut_t0 and not cut_done and t >= cut_t1 then cut_done = true end
local fl = SP:read_u32(FLAG)
if fl == 1 and not t0 then t0 = t; return end
if fl == 0xEE then
P("BITSTREAM DESYNC -- the decoder consumed the wrong number of bytes.")
P(" Under a ring that is the whole point: it means a record was placed "
.."or described wrongly, not that the codec changed.")
M:exit(); return
end
if fl == 0xE1 then
P("PRODUCER STALLED OUT -- stream.s spun SPINMAX times with no new "
.."record. Delivered "..nsent.."/"..META.nframes..".")
M:exit(); return
end
if fl == 0xFF then
local dt = t - (t0 or t)
local stalls = SP:read_u32(STALLS)
local spins = SP:read_u32(SPINS)
if PACED then
-- Paced, the wall clock measures the PACE, not the decode: the loop
-- spends whatever is left of each slot spinning in `pacewait`. The
-- decode cost of this container is decode.lua's and FINDINGS 45's;
-- printing a cycles/frame here would just report 1/fps back.
P(string.format("decoded %d frames in %.4f s emulated at a %d fps "
.."pace (%.2f s nominal) -- the clock here measures "
.."the PACE, not the decode",
META.nframes, dt, META.fps, META.nframes/META.fps))
else
P(string.format("decoded %d frames in %.4f s emulated -> %.0f cycles/"
.."frame = %.1f%% of a %dfps frame",
META.nframes, dt, dt*CPUHZ/META.nframes,
100*(dt*CPUHZ/META.nframes)/FRAME12, META.fps))
end
P(string.format("ring: %d wraps, %d B of hole (mean %.1f KB, %.1f%% of "
.."the ring)", holes, hole_bytes,
holes > 0 and hole_bytes/holes/1024 or 0,
100*(holes > 0 and hole_bytes/holes or 0)/RINGSZ))
-- The decoder's own spin counter, kept for what it is: evidence that
-- stream.s outran the pipe, NOT evidence of an underrun. See the note
-- on `arrival` above.
if PACED then
-- Paced, a stall is an UNDERRUN: the frame's slot arrived and its
-- record had not. Free-running it is earliness (49.6) and means the
-- opposite thing, so the two are never printed in the same words.
P(string.format("UNDERRUNS: %d/%d frames waited past their %d fps slot "
.."(%d polls)", stalls, META.nframes, META.fps, spins))
-- WHAT THE MINIMUM OVER A RUN IS, AND IS NOT. At release the ring
-- holds only what the prefill put there, so the early ticks report a
-- buffer that has not been built yet, not a ring or a pipe that
-- cannot build it. A seek empties the ring the same way, so that
-- transient is the branch-point case rather than an artefact to be
-- trimmed -- but it has to be told apart from the CEILING, which is
-- what the ring is worth once it is full.
--
-- Which resource stopped the producer says which is which, and only
-- RING refusals count: a rate refusal fires on nearly every tick
-- (credit accrues continuously and records are placed whole), so it
-- marks nothing. A ring refusal means the ring actually filled.
local ceiling, ceil_at = 0, -1
for _,e in ipairs(slack_series) do
if e[2] > ceiling then ceiling, ceil_at = e[2], e[1] end
end
local ss_min, ss_at = math.huge, -1
for _,e in ipairs(slack_series) do
if e[3] > 0 and e[2] < ss_min then ss_min, ss_at = e[2], e[1] end
end
P(string.format("SEEK SLACK: ceiling %d frames (%.0f ms), first "
.."reached at tick %d; mean %.1f over the window",
ceiling, 1000*ceiling/META.fps, ceil_at,
sum_ahead/math.max(1,n_ahead)))
if n_ring > 0 then
P(string.format(" RING-BOUND: the ring filled (%d refusals). Once "
.."full it survives delivery stopped dead for %d "
.."frames = %.0f ms; min after first fill %d "
.."(tick %d)", n_ring, ceiling,
1000*ceiling/META.fps, ss_min, ss_at))
else
P(string.format(" RATE-BOUND: the ring NEVER filled in %d frames. "
.."A bigger ring buys nothing at this pipe; the "
.."buffer is still accumulating when the window "
.."ends.", META.nframes))
end
P(string.format(" BUILD TIME: %d ticks = %.2f s of play to reach the "
.."ceiling from empty -- which is what a branch point "
.."costs before the NEXT seek is affordable",
ceil_at, ceil_at/META.fps))
if SLACK_CSV then
local fh = io.open(SLACK_CSV, "w")
fh:write("tick,ahead,ring_refusals,rate_refusals\n")
for _,e in ipairs(slack_series) do
fh:write(string.format("%d,%d,%d,%d\n", e[1], e[2], e[3], e[4]))
end
fh:close()
P("slack series -> "..SLACK_CSV)
end
else
P(string.format("decoder waited on %d/%d frames (%d polls) -- it is "
.."free-running, so this is earliness, not underrun",
stalls, META.nframes, spins))
end
-- The delivery result. Deadline for record i is release + i/fps.
local misses, worst, prefill_s = 0, 0.0, 0.0
for i = 0, META.nframes-1 do
local a = arrival[i+1]
if a then
local late = a - (t_rel + i / META.fps)
if late > 0 then
misses = misses + 1
if late > worst then worst = late end
end
if late > prefill_s then prefill_s = late end
end
end
P(string.format("DEADLINE at %d fps: %d/%d records late, worst by "
.."%.1f ms (%.2f frame times)", META.fps, misses,
META.nframes, worst*1000, worst*META.fps))
-- The smallest start delay that makes every deadline: FINDINGS 21's
-- "required prefill", measured on the emulated clock through the real
-- ring rather than simulated from record sizes.
P(string.format("REQUIRED PREFILL: %.1f ms = %.2f frame times = %.1f KB "
.."at %s", prefill_s*1000, prefill_s*META.fps,
(KBPS > 0) and (prefill_s * BPS / 1024) or 0.0,
(KBPS > 0) and (KBPS.." KB/s") or "an unlimited pipe"))
M.video:snapshot()
P("snapshot taken after the sequential pass -- last frame, decoded "
.."entirely out of a "..RING_KB.." KB ring")
st = "snapped"; return
end
if t > 900 then P("TIMEOUT flag="..string.format("%08X",fl)); M:exit() end
return
end
if st == "snapped" then M:exit(); return end
end)
if not ok then print("[STR] LUA ERROR: "..tostring(err)); M:exit() end
end)