-- Drive src/player/clockgate.s: measure the 68000's own FRAME CLOCK. -- ROADMAP P3. -- -- Two things are being measured and they need different instruments. -- -- THE RATE AND THE CADENCE are counted, not timed. The clock's tick is a -- V-DISP interrupt, and MAME's Lua sees the machine once per screen frame -- -- which is once per V-DISP. So the host's sampling granularity is exactly the -- clock's own granularity, and the cadence comes out as integers: how many -- refreshes each frame tick waited. There is no timing error to argue about -- in a count of 4s and 5s. -- -- THE COST IS TIMED BY THE 68000, because the host cannot. 1/55.46 s of host -- granularity is 18 ms and the interrupt costs microseconds. So the 68000 runs -- a one-instruction loop for a window of thousands of refreshes and the host -- reads the iteration count at both ends; the interrupt cost falls out of the -- difference between a run with the clock armed and one without. See the head -- of src/player/clockgate.s for the arithmetic. This script emits the raw -- counts; tools/bench/clock_cost.py does the subtraction, so that the two runs -- it needs can be separate MAME invocations. -- -- MEASUREMENT SCOPE. This is MAME 0.277's emulated X68000, not real hardware. -- What is being priced is the interrupt sequence of MAME's cycle-accurate -- M68000 core (src/devices/cpu/m68000, the `M68000` device x68k.cpp:1133 asks -- for) against zero-wait-state RAM. Real DRAM adds wait states to the six bus -- cycles of the exception and the four of the handler alike, so this is a LOWER -- BOUND in the same way every other 68000 figure in this project is. -- -- Env: -- DLX_CLK_ON 1 = arm the frame clock, 0 = leave it off (the calibration -- run). REQUIRED -- the two runs are not interchangeable and a -- default would let one be reported as the other. -- DLX_CLK_FPS frame rate to ask clk_init for (default 12) -- DLX_CLK_WIN measurement window, in raster frames (default 3000 = 54.1 s) -- DLX_CLK_OUT where to write the raw counts (default tmp/clock_run.txt) 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 CGFLAG, CGON, CGCNT = 0x18070, 0x18074, 0x18078 local CLK_PACE = 0x18034 local CLK_ACC, CLK_INCR = 0x18060, 0x18062 local CLK_VDISP, CLK_FPS = 0x18064, 0x18068 local CLK_ERR = 0x1806C local CPUHZ = 10000000 local ONS = os.getenv("DLX_CLK_ON") local FPS = tonumber(os.getenv("DLX_CLK_FPS") or "") or 12 local WIN = tonumber(os.getenv("DLX_CLK_WIN") or "") or 3000 local OUT = os.getenv("DLX_CLK_OUT") or "clock_run.txt" local function P(s) print("[CLK] "..s) end if ONS ~= "0" and ONS ~= "1" then P("DLX_CLK_ON must be 0 (calibration, clock off) or 1 (clock armed). The " .."cost figure is the DIFFERENCE between the two runs, so neither is " .."meaningful alone and neither gets to be the default.") M:exit() return end local ON = (ONS == "1") local code do local f=io.open("clockgate.bin","rb"); code=f:read("a"); f:close() end local function T() local t=M.time; return t.seconds + t.attoseconds/1e18 end -- Settling frames between the gate reporting `running` and the window opening. -- The CPU may still be inside clk_init when the host first sees CGFLAG=1, and -- the first V-DISP edge after arming lands wherever the raster happens to be. -- Two frames puts the window entirely inside the steady state. local SETTLE = 2 local st, n = "boot", 0 local f_ready, f0, f1 = nil, nil, nil local c0, c1, v0, v1, p0, p1, t0, t1 -- Cadence: refreshes between consecutive frame ticks. Recorded as a histogram -- and as the raw first few, because the interesting claim is not the mean (the -- divider makes that exact by construction) but that the SPREAD is only ever -- the two values either side of fps*VTOTAL/HFREQ. local last_pace, last_pace_f, cad, seen_tick = nil, nil, {}, false SUB = emu.add_machine_frame_notifier(function() local ok, err = pcall(function() n = n + 1 if st == "boot" then if T() < 3.0 then return end MODE.apply(SP) for i = 1, #code do SP:write_u8(0x10000+i-1, string.byte(code,i)) end SP:write_u32(CGFLAG, 0) SP:write_u32(CGON, ON and 1 or 0) SP:write_u32(CLK_FPS, FPS) local cpu = M.devices[":maincpu"] cpu.state["SR"].value = 0x2700 -- clk_init lowers it to $2500 itself cpu.state["SP"].value = 0x8000 cpu.state["PC"].value = 0x10000 P(string.format("clockgate.bin=%d B, clock %s, asking for %d fps, " .."window %d raster frames", #code, ON and "ARMED" or "OFF (calibration run)", FPS, WIN)) st = "wait"; return end if st == "wait" then local fl = SP:read_u32(CGFLAG) if fl == 0xEE then local e = SP:read_u32(CLK_ERR) P("clk_init REFUSED: CLK_ERR="..e..(e == 1 and " (CRTC is not in a 31.5 kHz mode, so HFREQ=31500 would be wrong)" or e == 2 and " (fps*VTOTAL does not fit the 16-bit accumulator)" or "")) M:exit(); return end if fl ~= 1 then if T() > 60 then P("TIMEOUT: the gate never started"); M:exit() end return end f_ready = n; st = "settle"; return end if st == "settle" then if n < f_ready + SETTLE then return end f0, t0 = n, T() c0 = SP:read_u32(CGCNT) v0 = SP:read_u32(CLK_VDISP) p0 = SP:read_u32(CLK_PACE) last_pace, last_pace_f = p0, n if ON then P(string.format("armed: incr=%d (fps*VTOTAL), acc=%d, first tick " .."pending", SP:read_u16(CLK_INCR), SP:read_u16(CLK_ACC))) end st = "run"; return end if st == "run" then if ON then local pc = SP:read_u32(CLK_PACE) if pc ~= last_pace then -- The FIRST change is dropped. Its interval runs from the window -- opening rather than from a tick, so it measures where the window -- happened to start and would show up as a spurious short bucket. if seen_tick then -- More than one tick in a single refresh would mean fps above the -- raster rate; give it its own bucket rather than averaging it in. local gap = n - last_pace_f if pc - last_pace > 1 then gap = 0 end cad[gap] = (cad[gap] or 0) + 1 end seen_tick = true last_pace, last_pace_f = pc, n end end if n < f0 + WIN then return end f1, t1 = n, T() c1 = SP:read_u32(CGCNT) v1 = SP:read_u32(CLK_VDISP) p1 = SP:read_u32(CLK_PACE) st = "done" local frames = f1 - f0 local secs = t1 - t0 local clocks = secs * CPUHZ local iters = c1 - c0 local ints = v1 - v0 local ticks = p1 - p0 P(string.format("window: %d raster frames, %.6f s emulated -> %.0f " .."68000 clocks", frames, secs, clocks)) -- THE INSTRUMENT IS 2.22% FAST AND IT IS WORTH SAYING SO EVERY RUN. -- The CRTC registers describe a 31,500 lines/s raster of VTOTAL lines. -- MAME does not run it at that rate: x68k_crtc.cpp refresh_mode() -- computes the frame period as (scr.max_x * scr.max_y) dots with -- scr.max_x = m_htotal - 8, one character cell short and an INCLUSIVE -- rectangle bound used as a count. So the emulated raster is fast by -- htotal/(htotal-8) -- 368/360 in this mode -- and every rate derived -- from it here is fast by the same factor. The divider under test is -- built on the registers, so its HARDWARE rate is the asked-for one and -- what this rig can check is that it tracks whatever raster it is given. local vtotal = SP:read_u16(0xE80008) + 1 local htotal = (SP:read_u16(0xE80000) + 1) * 8 local hw_hz = 31500 / vtotal local skew = htotal / (htotal - 8) P(string.format(" raster period %.4f ms = %.4f Hz", 1000*secs/frames, frames/secs)) P(string.format(" the CRTC registers describe 31500/%d = %.4f Hz; " .."MAME is fast by htotal/(htotal-8) = %d/%d = %.4f", vtotal, hw_hz, htotal, htotal-8, skew)) P(string.format(" loop iterations %d", iters)) if ON then P(string.format(" V-DISP interrupts %d, frame ticks %d", ints, ticks)) -- The self-check that makes the rest of it worth reading: the interrupt -- count and the host's screen-frame count are supposed to be the SAME -- clock seen from two sides. If they disagree by more than the one -- edge the window boundaries can straddle, the tick is not the raster. if math.abs(ints - frames) > 1 then P(string.format("FAIL: %d V-DISP interrupts over %d raster frames. " .."The tick is not coming from the raster.", ints, frames)) M:exit(); return end -- Two numbers, and confusing them is the whole trap. The measured rate -- is against MAME's fast raster; dividing the skew out gives the rate -- the same code produces on a machine whose raster matches its own -- registers, which is the number the player is judged on. local meas = ticks/secs P(string.format(" measured rate %.6f fps against MAME's raster " .."(%+.0f ppm vs the asked %d)", meas, 1e6*(meas/FPS - 1), FPS)) P(string.format(" de-skewed %.6f fps -> %+.1f ppm from %d, " .."which is the tick quantisation of %d ticks and not " .."drift", meas/skew, 1e6*(meas/skew/FPS - 1), FPS, ticks)) local ks = {} for k in pairs(cad) do ks[#ks+1] = k end table.sort(ks) local s = "" for _,k in ipairs(ks) do s = s .. string.format("%d:%d ", k, cad[k]) end P(" cadence, refreshes per frame tick: "..s) end local fh = io.open(OUT, "w") fh:write(string.format("on %d\nfps %d\nframes %d\nsecs %.15g\n" .."clocks %.15g\niters %d\nints %d\nticks %d\n" .."vtotal %d\nhtotal %d\nhw_hz %.15g\nskew %.15g\n", ON and 1 or 0, FPS, frames, secs, clocks, iters, ints, ticks, vtotal, htotal, hw_hz, skew)) for k, v in pairs(cad) do fh:write(string.format("cad %d %d\n", k, v)) end fh:close() P("counts -> "..OUT) P("done") M:exit(); return end end) if not ok then print("[CLK] LUA ERROR: "..tostring(err)); M:exit() end end)