-- 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, with the HOST writing -- the tick (default 0 = free-run) -- 2 = hold it to META.fps with the 68000 writing its own -- tick, off the CRTC's V-DISP (src/player/clock.i, ROADMAP -- P3). Same gate, same ring, same deadlines; what changes -- is that nothing outside the machine decides when a frame -- may start. Deadlines are then taken from the ticks the -- machine actually emitted rather than from a host model of -- 12 fps -- which matters, because MAME's raster runs 2.22% -- fast (see tools/bench/clock.lua) and a host model would -- quietly grade every arrival against the wrong clock. -- 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, CLKON = 0x18034, 0x18038, 0x1803C local CLK_VDISP, CLK_FPS, CLK_ERR = 0x18064, 0x18068, 0x1806C local LATEFR, LATEMAX, LATE1ST = 0x18080, 0x18084, 0x18088 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 SELFCLK = (os.getenv("DLX_PACE") == "2") local PACED = (os.getenv("DLX_PACE") == "1") or SELFCLK 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) SP:write_u32(CLKON, SELFCLK and 1 or 0) SP:write_u32(CLK_FPS, META.fps) 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", SELFCLK and ("SELF-PACED at "..META.fps.." fps off V-DISP") or PACED and ("PACED at "..META.fps.." fps by the host") 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 -- tick_t[i+1] = emulated time of frame tick i, filled in as they are observed. -- Under a self-clock this replaces the host's `t_rel + i/fps` as the deadline: -- the machine's clock is the one the player is actually held to, and MAME's -- raster is 2.22% fast, so grading arrivals against a host model of 12 fps -- would flatter every record by that much. local tick_t = {} 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 -- WHO WRITES THE TICK. Host-paced, the tick is a host model of -- META.fps and this script advances it. Self-paced, the 68000 has -- already advanced it off the raster and this script only READS it -- -- the frame gate in src/player/stream.s cannot tell the two apart, -- which is the point: the same bytes are gated either way. local tick = SELFCLK and SP:read_u32(PACE) or math.floor((t - t_rel) * META.fps) if tick > pace then pace = tick if not SELFCLK then SP:write_u32(PACE, pace) end -- The emulated time this tick actually happened, which is what a -- record's deadline is measured against under a self-clock. Ticks -- can arrive more than one apart if the host misses a frame, so the -- whole run is filled rather than just the newest. for k = #tick_t, tick do tick_t[k+1] = t end -- 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 == 0xE2 then local e = SP:read_u32(CLK_ERR) P("FRAME CLOCK REFUSED: CLK_ERR="..e..(e == 1 and " (the CRTC is not in a 31.5 kHz mode, so the divider's 31500 " .."lines/s would be wrong)" or e == 2 and " (fps*VTOTAL does not fit the 16-bit accumulator)" or "")) 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 if SELFCLK then -- The clock's own report, in the run where it actually paced a -- decoder rather than a busy loop. The rate is against MAME's fast -- raster; tools/bench/clock_run.sh is where it gets de-skewed. local vd = SP:read_u32(CLK_VDISP) local vt = SP:read_u16(0xE80008) + 1 -- VTOTAL, as clk_init read it -- DELIBERATELY NOT A RATE. 120 ticks is far too short a window to -- quote fps from: the run's start and end each straddle a tick, so -- +/-1 on 119 intervals is +/-8000 ppm and would read as drift the -- clock does not have. What IS exact here is a count of refreshes -- against a count of ticks. The rate figure comes from -- tools/bench/clock_run.sh, over thousands of them. P(string.format("FRAME CLOCK: %d V-DISP interrupts drove %d ticks " .."(%.4f refreshes/frame; the divider's own ratio is " .."31500/(%d*%d) = %.4f), %.0f clocks/frame of " .."interrupt at FINDINGS 54's 181.35 each", vd, pace + 1, vd/(pace + 1), META.fps, vt, 31500/(META.fps*vt), 181.35*vd/(pace+1))) 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)) -- The other way a paced frame can go wrong, and it is not the same -- failure. An UNDERRUN is the pipe: the record was not there. This -- is the CPU: the record was there, the slot was already open, and -- the decoder had no idle left in the frame before. Under a -- host-written tick every slot is 83.33 ms; under the machine's own -- clock they alternate 72.13 and 90.16 ms, 37.9% of them short, and -- this is what the short ones cost (FINDINGS 54). local late, latemax = SP:read_u32(LATEFR), SP:read_u32(LATEMAX) local late1 = SP:read_u32(LATE1ST) P(string.format("NO IDLE: %d/%d frames found their slot already open " .."-- the frame before used all of it; worst overrun " .."%d whole tick%s, first at frame %d", late, META.nframes, latemax, latemax == 1 and "" or "s", late1 == 0xFFFFFFFF and -1 or late1)) -- 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 due = SELFCLK and tick_t[i+1] or (t_rel + i / META.fps) if not due then due = t_rel + i / META.fps end local late = a - due 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)