-- Drive src/player/packed.s: THE DECODER-FREE PACKED PLAYER, END TO END, -- OFF A REAL VOLUME. ROADMAP K3. -- -- WHAT THIS SCRIPT DOES NOT DO IS THE POINT OF IT. tools/bench/stream.lua -- pushes expanded codebooks and a packed palette into RAM, plays a transport at -- a modelled byte rate, and writes the frame tick. This one pushes 2,898 bytes -- of 68000 code and eleven mailbox words, and then READS. It moves no picture -- byte, models no rate, sets no CRTC register and writes no palette entry: the -- machine brings up its own display, builds its own chain, keeps its own clock -- off V-DISP and fetches every record itself with READ(10) off a CZ-6BS1. -- -- SO THE GATE IS NOT THE ONE THE CODEC USES, AND IT HAD TO CHANGE. -- tools/bench/verify_decode.py checks ONE frame -- the last -- and that audits -- the whole run because the codec is temporally recursive: a SKIP block is a -- claim about the previous frame still being on screen, so the final frame is -- only right if all 120 were. A packed frame is a LITERAL. Frame 119 being -- pixel-exact says nothing whatever about frame 60. This script therefore -- snapshots EVERY frame and tools/bench/verify_packed.py compares all of them; -- the simplification that deleted the ring also deleted the gate's free lunch. -- -- WHEN A SNAPSHOT IS TAKEN, and why not on the frame it changed. PG_SHOWN is -- bumped by the 68000 after it clears R20 bit 11, so a change means "a complete -- frame is now displayable". But MAME's screen bitmap for the host frame in -- progress was drawn partly before that instant, so snapshotting immediately -- would sample the write window -- which BLANKS the graphics layer -- for part -- of the picture. A 12 fps frame lasts 4 or 5 host refreshes at 56.69 Hz, so -- waiting SNAP_DELAY whole host frames is safely inside the slot and safely -- after the window closed. -- -- Env: -- DLX_PK_HELD 1 = the channel HOLDS THE BUS (burst, max rate), 0 = it -- steals cycles. Not two speeds of one thing: 59.3 showed an -- auto-requested channel is charged by TIME, so held is the -- 68000 stopped for as long as the record takes to arrive. -- Default 1. -- DLX_PK_PACE 1 = the machine holds itself to the container's fps off -- V-DISP (default). 0 free-runs, which tests the CHAIN with -- the clock out of the way. -- DLX_PK_ITER passes over the scene (default 1). >1 exercises the seek, -- which for this container is arithmetic and nothing else. -- DLX_PK_NFR play only the first N frames (default: all of them) -- DLX_PK_FPS pace at this rate instead of the container's. NOT a -- cosmetic knob and not a way to make a number look better: -- under MAME the emulated transport takes about a whole 12 fps -- slot to deliver a 49,664 B record, and the write window has -- to be OPEN for all of it -- so at 12 fps there is no instant -- at which a complete frame is displayable and nothing can be -- snapshotted. Pacing slower opens a display interval without -- changing one byte of the transfer, which is what lets the -- PIXEL-EXACTNESS of all 120 frames be gated separately from -- the RATE the emulated transport happens to run at. The two -- are different questions and this is the knob that separates -- them. -- DLX_PK_CSV write the per-frame arrival series here 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 META = loadfile("packed_meta.lua")() -- src/player/packed.s. Inputs first, then outputs; the split is the file's. local PG_FLAG, PG_NFR, PG_FPS, PG_LBA0 = 0x18900, 0x18904, 0x18908, 0x1890C local PG_RECS, PG_PALL, PG_HELD = 0x18910, 0x18914, 0x18918 local PG_PACEON, PG_ITER = 0x1891C, 0x18920 local PG_CADF, PG_CADA = 0x18924, 0x18928 local PG_SHOWN, PG_ERR, PG_ERRAT = 0x18930, 0x18934, 0x18938 local PG_LATE, PG_LATE1, PG_LATEM = 0x1893C, 0x18940, 0x18944 local PG_VDISP, PG_VD0, PG_TSPIN = 0x18948, 0x1894C, 0x18950 local PG_GSPIN, PG_LOSTV, PG_ARRN = 0x18954, 0x18958, 0x1895C local PG_ARR = 0x1B000 -- src/player/clock.i and src/player/scsi.i, read for diagnosis only. local CLK_PACE, CLK_VDISP, CLK_ERR = 0x18034, 0x18064, 0x1806C local SC_ERR = 0x18200 local CRTC_R20 = 0xE80028 local HELD = (os.getenv("DLX_PK_HELD") or "1") == "1" local PACED = (os.getenv("DLX_PK_PACE") or "1") == "1" local ITERS = tonumber(os.getenv("DLX_PK_ITER") or "") or 1 local NFR = tonumber(os.getenv("DLX_PK_NFR") or "") or META.nframes local FPS = tonumber(os.getenv("DLX_PK_FPS") or "") or META.fps local CSV = os.getenv("DLX_PK_CSV") local SNAP_DELAY = 2 local SCERRNAME = {[0]="OK", "SELECTION TIMEOUT -- no target answered", "UNEXPECTED PHASE", "POLL TIMEOUT -- a phase never arrived", "NON-ZERO SCSI STATUS", "WINDOWED READ REFUSED -- a channel cannot drop bytes"} local code do local f=assert(io.open("packed.bin","rb")); code=f:read("a"); f:close() end local function T() local t=M.time; return t.seconds + t.attoseconds/1e18 end local function P(s) print("[PK] "..s) end local function setup() for i = 1, #code do SP:write_u8(0x10000+i-1, string.byte(code,i)) end SP:write_u32(PG_FLAG, 0) SP:write_u32(PG_NFR, NFR) SP:write_u32(PG_FPS, FPS) SP:write_u32(PG_LBA0, META.lba0) SP:write_u32(PG_RECS, META.rec_sectors) SP:write_u32(PG_PALL, META.palette_last) SP:write_u32(PG_HELD, HELD and 1 or 0) SP:write_u32(PG_PACEON, PACED and 1 or 0) SP:write_u32(PG_ITER, ITERS) -- DLXP2's cadence. Zero for a silent container, and the 68000 branches on the -- zero: a player told the wrong cadence does not fail, it reads an audio lump -- as a record and paints it. SP:write_u32(PG_CADF, META.cad_f or 0) SP:write_u32(PG_CADA, META.cad_a or 0) SP:write_u32(PG_SHOWN, 0) P(string.format("packed.bin=%d B, %dx%d %d fps, %d of %d frames, %d passes", #code, META.W, META.H, META.fps, NFR, META.nframes, ITERS)) local cad = "" if (META.cad_f or 0) > 0 then cad = string.format(" + (i//%d)*%d", META.cad_f, META.cad_a) end P(string.format("record %d B = %d sectors at LBA %d + i*%d%s, palette %s", META.rec_bytes, META.rec_sectors, META.lba0, META.rec_sectors, cad, META.palette_last == 1 and "LAST" or "FIRST")) if (META.cad_f or 0) > 0 then P(string.format("DLXP2: %d B of ADPCM at %d Hz rides in %d lumps of %d sectors, " .."one in front of every %d records -- the third term above is the " .."whole cost of it on the video path", META.aud_bytes, META.aud_hz, META.n_lumps, META.cad_a, META.cad_f)) end P(string.format("channel: %s, %s", HELD and "BUS HELD (burst, max rate)" or "CYCLE STEALING", PACED and ("SELF-PACED at "..FPS.." fps off V-DISP" ..(FPS ~= META.fps and (" -- NOT the container's " ..META.fps..", see DLX_PK_FPS") or "")) or "FREE-RUNNING (tests the chain, not the clock)")) P("this script writes NO picture byte, NO palette entry and NO CRTC register: " .."the machine brings up its own display and fetches its own records.") end local function launch() local cpu = M.devices[":maincpu"] cpu.state["SR"].value = 0x2700 -- supervisor, all interrupts masked; cpu.state["SP"].value = 0x8000 -- clk_init lowers it to $2500 itself cpu.state["PC"].value = 0x10000 end local st, t0 = "boot", nil local shown, pending, snaps = 0, nil, 0 local arrive, hostfr, missed = {}, 0, 0 -- WHICH FRAME EACH SNAPSHOT IS. MAME numbers snapshots 0000, 0001, ... in the -- order they were taken, and a frame that could not be sampled leaves no gap in -- that sequence -- so the file name is NOT the frame index and a verifier that -- assumed it was would compare frame 61 against record 60 and report a codec -- bug that is really a bookkeeping one. This is the map, written out for it. local snapfr = {} local r20seen = {} 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(); launch(); t0 = t; st = "running"; return end if st ~= "running" then return end hostfr = hostfr + 1 -- WHAT THE SCREEN MODE WAS, sampled every host frame. R20 bit 11 blanks -- the graphics layer, so this is the only way to see the shutter the player -- is running: the fraction of host frames that found the window OPEN is the -- fraction of the scene the display spent dark, and it is a MEASUREMENT of -- 47.4's cost under MAME rather than a restatement of the prior. local r20 = SP:read_u16(CRTC_R20) r20seen[#r20seen+1] = ((r20 >> 11) & 1) local s = SP:read_u32(PG_SHOWN) if s > shown then -- Only the LAST change matters if several landed in one host frame; that -- cannot happen at 12 fps on a 56.69 Hz raster, and if it ever does the -- gate below catches it as a missing snapshot rather than a wrong one. arrive[#arrive+1] = {n = s, t = t - t0} shown = s pending = SNAP_DELAY end if pending then pending = pending - 1 if pending <= 0 then pending = nil if (SP:read_u16(CRTC_R20) >> 11) & 1 == 0 then M.video:snapshot(); snaps = snaps + 1 snapfr[#snapfr+1] = shown - 1 else -- The window was open again when the delay expired: the frame we -- meant to sample is being overwritten. COUNTED, NOT PRINTED -- when -- the transfer is longer than the slot EVERY frame misses, and 119 -- identical lines bury the four numbers the run exists to report. -- The count is reported once at the end and the gate reads it there. missed = missed + 1 end end end local flag = SP:read_u32(PG_FLAG) if flag ~= 1 and pending then -- THE LAST FRAME IS STILL PENDING. packed.s spins in pg_hold with the -- window CLOSED once the scene is over, so the delay can simply run out; -- returning here rather than reporting is what stops the final frame -- being the one frame the gate never sees. return end if flag ~= 1 then st = "done" local wall = t - t0 P(string.format("FLAG=$%02X after %.3f s, %d frames shown, %d snapshots, " .."%d frames NOT SAMPLED (the write window had reopened " .."-- the transfer is longer than the display interval)", flag, wall, shown, snaps, missed)) local err = SP:read_u32(PG_ERR) if err ~= 0 then P(string.format("TRANSPORT FAILED on frame %d: %s", SP:read_u32(PG_ERRAT), SCERRNAME[err] or ("code "..err))) end P(string.format("array: the 68000 built %d entries (the container wants " .."%d)", SP:read_u32(PG_ARRN), META.entries)) -- The first entry, read back out of the machine's own RAM. It is the one -- place palette-first and palette-last are visible as a FACT rather than -- as a flag the rig passed in and the rig read back. P(string.format("chain[0] = MAR $%06X MTC %d ; chain[1] = MAR $%06X MTC %d", SP:read_u32(PG_ARR), SP:read_u16(PG_ARR+4), SP:read_u32(PG_ARR+6), SP:read_u16(PG_ARR+10))) if PACED then local vd = SP:read_u32(PG_VDISP) - SP:read_u32(PG_VD0) -- THE CLOCK, AGAINST THE RASTER THAT DROVE IT. CLK_VDISP counts the -- edges the 68000's ISR SAW. hostfr counts the frames MAME actually -- drew. A held channel halts the CPU, and the MFP's pending bit is one -- bit, so an edge that falls inside a transfer long enough to span two -- of them is an edge the machine can never count. Nothing in this -- project has ever run a transfer and a clock at once, so nothing could -- have seen this before. P(string.format("frame clock: PACE=%d ticks, V-DISP edges SEEN=%d, " .."host frames drawn=%d -> %d edges LOST (%.1f%%)", SP:read_u32(CLK_PACE), vd, hostfr, hostfr - vd, hostfr > 0 and (hostfr-vd)*100/hostfr or 0)) local nlate = SP:read_u32(PG_LATE) P(string.format("late frames (tick already past at the gate): %d%s", nlate, nlate > 0 and string.format(", first %d, worst " .."%d ticks", SP:read_u32(PG_LATE1), SP:read_u32(PG_LATEM)) or "")) -- AND WHY `late = 0` IS NOT `on time`. The gate compares the frame -- index against PACE, and PACE is advanced by the ISR that the held -- channel stops the CPU from running. A clock that loses edges loses -- them from BOTH sides of the comparison, so a player whose own clock -- has halved still reports every frame early. The LOST figure above is -- the only thing in this run that can contradict it, and it comes from -- the host's raster count rather than from the machine. if hostfr - vd > 0 then P(string.format(" ...and %d of those ticks were never " .."issued, so `late=%d` is measured against a clock " .."running at %.1f%% of the raster. The player " .."believes it is at %d fps and the screen is at " .."%.2f.", hostfr - vd, nlate, vd*100/hostfr, FPS, FPS * vd / hostfr)) end end P(string.format("CPU: %d trips round the TRANSFER wait in total, %d round " .."the PACE gate", SP:read_u32(PG_TSPIN), SP:read_u32(PG_GSPIN))) local open = 0 for _,v in ipairs(r20seen) do open = open + v end P(string.format("WRITE WINDOW OPEN on %d of %d host frames (%.1f%%) -- " .."buffer mode blanks the graphics layer, so that is the " .."share of the scene the display spent DARK under MAME", open, #r20seen, #r20seen > 0 and open*100/#r20seen or 0)) if #arrive >= 2 then local dts, first, last = {}, arrive[1].t, arrive[#arrive].t for i = 2, #arrive do dts[#dts+1] = arrive[i].t - arrive[i-1].t end table.sort(dts) -- CADENCE, AND THE GRANULARITY IT IS MEASURED AT. PG_SHOWN is sampled -- once per host frame, so a single inter-frame figure is quantised to -- 1/56.69 s = 17.6 ms and the min/median/max below are multiples of it. -- The MEAN over the whole run is not: the quantisation error is bounded -- by one host frame at each END, so over n-1 intervals it is 35 ms/(n-1) -- -- 0.30 ms a frame over 120. Read the mean; the spread is the -- sampler's, not the player's. local mean = (last-first)/(#arrive-1) P(string.format("cadence: %d frames in %.3f s = %.3f fps, mean " .."%.2f ms/frame (+/- %.2f ms, the sampler's); " .."inter-frame min %.1f median %.1f max %.1f ms", #arrive, last-first, (#arrive-1)/(last-first), mean*1000, 35.3/(#arrive-1), dts[1]*1000, dts[math.ceil(#dts/2)]*1000, dts[#dts]*1000)) -- THE TRANSPORT'S TIME IS ONLY READABLE OFF A FREE-RUNNING RUN. -- Paced, the mean inter-frame IS THE PACE PERIOD: the player waits for -- its tick and the record's delivery hides inside the slot, so dividing -- the record by that mean reports the clock rather than the transport -- and reports it as a rate. The first cut of this script printed -- "297.4 KB/s" off a 6 fps gate run, which is the pace and not the -- disc. Free-running there is no gate and the loop is transfer-bound, -- so the mean is the transfer. if not PACED then P(string.format(" -> FREE-RUNNING, so the mean IS the " .."transport: a %d B record lands in %.2f ms, i.e. " .."%.1f KB/s and %.1f%% of a %d fps slot. MAME's " .."device models carry no transfer timing " .."(docs/BENCHMARK.md, 42.5), so this is a property " .."of the APPARATUS -- it is not W and it is not a " .."measurement of any medium.", META.rec_bytes, mean*1000, META.rec_bytes/mean/1024, mean*META.fps*100, META.fps)) else -- What a paced run CAN say about the transfer, and it says it from -- the display rather than from the clock: the window is open for -- exactly as long as the record takes, so the open fraction times the -- slot is the transfer time, sampled at the host's frame rate. P(string.format(" -> PACED, so this mean is the PACE and " .."NOT the transport. What the run does bound is the " .."transfer: the window was open %.1f%% of a " .."%.2f ms slot = %.1f ms a record.", open*100/#r20seen, mean*1000, open/#r20seen*mean*1000)) end end if CSV then local f = io.open(CSV, "w") f:write("frame,t_s\n") for _,a in ipairs(arrive) do f:write(string.format("%d,%.6f\n", a.n-1, a.t)) end f:close() P("arrivals -> "..CSV) end do local f = assert(io.open("packed_snaps.csv", "w")) f:write("snapshot,frame\n") for i, fr in ipairs(snapfr) do f:write(string.format("%04d,%d\n", i-1, fr)) end f:close() P(string.format("%d snapshots -> tmp/packed_snaps.csv", #snapfr)) end P("done") M:exit() end end) if not ok then print("[PK] LUA ERROR: "..tostring(err)); M:exit() end end)