joeylib2/scripts/bench-iigs.sh

252 lines
10 KiB
Bash
Executable file

#!/usr/bin/env bash
# bench-iigs.sh - Headless UBER perf capture for the IIgs (the reference
# port). Until this script existed, PERF.md's IIgs column was carried over
# from old captures because nothing could get joeylog.txt off the emulated
# disk; every "hashes identical x4" gate needs this.
#
# Boots GS/OS under headless MAME with a WORK COPY of joey.2mg, drives the
# Finder to launch UBER (same keystroke timeline as verify-iigs.sh), then
# polls the Super Hi-Res framebuffer for UBER's solid-green "done" screen
# (jlSurfaceClear color 2 -> SHR bytes 0x22). When seen, MAME exits and
# cadius extracts JOEYLOG.TXT from the work image into build/iigs/bin/
# joeylog.txt, where tools/uber-perf-table and diff-uber-hashes expect it.
#
# Usage: scripts/bench-iigs.sh
# MAME_ROMPATH override ROM dir (default ~/.mame/roms)
# BENCH_MAX_FRAMES hard frame cap before giving up (default 36000)
#
# Requires: toolchains/env.sh sourced; build/iigs/bin/joey.2mg with UBER on
# it (run 'make iigs-disk', ensure UBER was not skipped for space).
set -euo pipefail
repo=$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)
: "${LLVM816_ROOT:?bench-iigs.sh: source toolchains/env.sh first}"
CADIUS="${CADIUS:-$LLVM816_ROOT/tools/cadius/cadius}"
sys_disk=$repo/toolchains/emulators/support/gsos-system.po
data_disk=$repo/build/iigs/bin/joey.2mg
out_log=$repo/build/iigs/bin/joeylog.txt
rompath="${MAME_ROMPATH:-$HOME/.mame/roms}"
maxFrames="${BENCH_MAX_FRAMES:-36000}"
[ -x "$CADIUS" ] || { echo "bench-iigs: cadius not found at $CADIUS" >&2; exit 2; }
for f in "$sys_disk" "$data_disk"; do
[ -f "$f" ] || { echo "bench-iigs: missing $f (run 'make iigs-disk')" >&2; exit 2; }
done
if ! "$CADIUS" CATALOG "$data_disk" 2>/dev/null | grep -qE '^ UBER +S16'; then
echo "bench-iigs: UBER not on joey.2mg (800KB floppy full? JOEY_DISK_EXAMPLES=\"UBER\" scripts/make-iigs-disk.sh)" >&2
exit 2
fi
work=$(mktemp -d -t joeylib-bench.XXXXXX)
trap 'rm -rf "$work"' EXIT
cp "$sys_disk" "$work/boot.po"
cp "$data_disk" "$work/joey.2mg"
# Finder keystroke timeline is verify-iigs.sh's, launching UBER. From frame
# 4500 on, sample the SHR framebuffer every 60 frames: UBER ends on a solid
# color-2 clear + present, so nearly every byte reads 0x22. The red "running"
# bar and the showcase can never look like that. On green, exit; the log was
# already flushed (uber.c calls jlLogFlush before the key wait).
cat > "$work/bench.lua" <<LUA
local cpu = manager.machine.devices[":maincpu"]
local mem = cpu.spaces["program"]
local nat = manager.machine.natkeyboard
local frame = 0
local idx = 1
local function field(port, name)
local p = manager.machine.ioport.ports[port]
if p == nil then return nil end
return p.fields[name]
end
local key_cmd = field(":macadb:KEY3", "Command / Open Apple")
local function press(f) if f then f:set_value(1) end end
local function release(f) if f then f:set_value(0) end end
local function greenDone()
-- 64 samples spread across the 32000-byte SHR buffer; solid color-2
-- fill means byte 0x22 everywhere.
local hits = 0
for i = 0, 63 do
if mem:read_u8(0xE12000 + i * 500) == 0x22 then hits = hits + 1 end
end
return hits >= 60
end
-- UBER's progress mailbox in the unused SCB bytes (see uber.c):
-- 9DC8 opIndex, 9DC9 phase, 9DCA-B heartbeat, 9DCC-D last-seen tick,
-- 9DD8-B log-ring base address, 9DDC-F log-ring head-counter address.
local function mailbox()
local op = mem:read_u8(0xE19DC8)
local phase = mem:read_u8(0xE19DC9)
local hb = mem:read_u8(0xE19DCA) | (mem:read_u8(0xE19DCB) << 8)
local tick = mem:read_u8(0xE19DCC) | (mem:read_u8(0xE19DCD) << 8)
return string.format("op=%d phase=%d heartbeat=%d tick=%d", op, phase, hb, tick)
end
local function rd32(addr)
return mem:read_u8(addr) | (mem:read_u8(addr+1) << 8) | (mem:read_u8(addr+2) << 16) | (mem:read_u8(addr+3) << 24)
end
-- Live drain of the IIgs RAM log ring (src/core/debug.c): the app pokes
-- the ring base and head-counter addresses into the mailbox at startup;
-- we read new bytes each frame and emit whole lines as UBERLOG events.
-- The head is a free-running 16-bit total; ring size 8192 must match
-- JOEY_LOG_RING_BYTES.
local RING_SIZE = 8192
local logRingBase = 0
local logHeadAddr = 0
local logRead = 0
local logPartial = ""
local function drainLog()
if logRingBase == 0 then
-- Latch only after the app's magic word appears: the SCB region
-- holds 0x80 fill before uberMbLayout() runs, and a garbage
-- latch reads noise forever.
local magic = mem:read_u8(0xE19DCE) | (mem:read_u8(0xE19DCF) << 8)
if magic ~= 0x4A4C then
return
end
logRingBase = rd32(0xE19DD8) & 0xFFFFFF
logHeadAddr = rd32(0xE19DDC) & 0xFFFFFF
if logRingBase ~= 0 then
io.write(string.format("BENCH-IIGS logring base=%06X head=%06X\n", logRingBase, logHeadAddr))
io.flush()
end
return
end
local head = mem:read_u8(logHeadAddr) | (mem:read_u8(logHeadAddr + 1) << 8)
while logRead ~= head do
local b = mem:read_u8(logRingBase + (logRead % RING_SIZE))
logRead = (logRead + 1) & 0xFFFF
if b == 10 then
io.write("UBERLOG " .. logPartial .. "\n")
logPartial = ""
elseif b >= 32 and b < 127 then
logPartial = logPartial .. string.char(b)
end
end
io.flush()
end
local steps = {
{3000, function() nat:post("J") end},
{3120, function() press(key_cmd) end},
{3126, function() nat:post("o") end},
{3180, function() release(key_cmd) end},
{3540, function() nat:post("UBER") end},
{3660, function() press(key_cmd) end},
{3666, function() nat:post("o") end},
{3720, function() release(key_cmd) end},
}
local pcs = {}
emu.register_frame_done(function()
frame = frame + 1
while idx <= #steps and frame >= steps[idx][1] do
steps[idx][2]()
idx = idx + 1
end
if frame >= 4200 and frame % 20 == 0 then
drainLog()
end
if frame >= 4500 and frame % 2000 == 0 then
io.write(string.format("BENCH-IIGS progress frame=%d %s\n", frame, mailbox()))
-- TEMP #84: sprite-geometry diagnostics from sprite.c pokes.
io.write(string.format("BENCH-IIGS spritediag drawW=%d drawH=%d tiles=%04X saveW=%d saveH=%d\n",
mem:read_u8(0xE19DE0) | (mem:read_u8(0xE19DE1) << 8),
mem:read_u8(0xE19DE2) | (mem:read_u8(0xE19DE3) << 8),
mem:read_u8(0xE19DE4) | (mem:read_u8(0xE19DE5) << 8),
mem:read_u8(0xE19DE6) | (mem:read_u8(0xE19DE7) << 8),
mem:read_u8(0xE19DE8) | (mem:read_u8(0xE19DE9) << 8)))
-- TEMP #84: watch the sprite struct bytes in place (16 bytes at
-- the pointer setupSprite poked; printable ASCII shown).
local sptr = rd32(0xE19DEA) & 0xFFFFFF
if sptr ~= 0 then
local bytes = {}
local text = {}
for i = 0, 15 do
local b = mem:read_u8(sptr + i)
bytes[#bytes + 1] = string.format("%02X", b)
if b >= 32 and b < 127 then
text[#text + 1] = string.char(b)
else
text[#text + 1] = "."
end
end
io.write(string.format("BENCH-IIGS spritemem ptr=%06X %s |%s| stagePtr=%08X\n",
sptr, table.concat(bytes, " "), table.concat(text), rd32(0xE19DD0)))
end
io.flush()
end
if frame >= 4500 and frame % 60 == 0 and greenDone() then
io.write(string.format("BENCH-IIGS done frame=%d %s\n", frame, mailbox()))
io.flush()
manager.machine:exit()
end
-- On timeout, sample the PC across 40 frames first so a hang site
-- can be resolved against the link map (ALIGN=0x10000 means the
-- bank-local offset equals the link offset within its segment).
if frame >= $maxFrames and frame < $maxFrames + 40 then
local pc = cpu.state["PC"].value
pcs[string.format("%06X", pc)] = (pcs[string.format("%06X", pc)] or 0) + 1
end
if frame >= $maxFrames + 40 then
io.write(string.format("BENCH-IIGS timeout frame=%d %s\n", frame, mailbox()))
for k, v in pairs(pcs) do
io.write(string.format("BENCH-IIGS pc %s count=%d\n", k, v))
end
io.flush()
manager.machine:exit()
end
end)
LUA
echo "bench-iigs: running UBER headless under MAME (cap $maxFrames frames)..." >&2
cd "$work"
out=$(QT_QPA_PLATFORM=offscreen SDL_VIDEODRIVER=dummy SDL_AUDIODRIVER=dummy \
timeout 1200 mame apple2gs \
-rompath "$rompath" \
-flop3 "$work/boot.po" -flop4 "$work/joey.2mg" \
-video none -sound none -nothrottle \
-autoboot_script "$work/bench.lua" </dev/null 2>&1) || true
echo "$out" | grep -E '^BENCH-IIGS (progress|pc|spritediag|spritemem|logring)' | sed 's/^/bench-iigs: /' >&2
marker=$(echo "$out" | grep -E '^BENCH-IIGS (done|timeout)' | tail -1)
echo "bench-iigs: $marker" >&2
if echo "$marker" | grep -q timeout; then
echo "bench-iigs: WARNING -- frame cap hit before the green done screen (partial capture likely)" >&2
fi
if [ -z "$marker" ]; then
echo "bench-iigs: FAIL -- MAME produced no marker (boot/launch failed)" >&2
echo "$out" | tail -15 >&2
exit 1
fi
# Primary log source: the RAM-ring drain (UBERLOG lines emitted live by
# the Lua probe -- immune to the FST non-persistence and floppy-write
# stalls of findings #80/#82). Falls back to cadius extraction of the
# on-disk joeylog.txt only if the ring never produced anything.
echo "$out" | grep -E '^UBERLOG ' | sed 's/^UBERLOG //' > "$out_log"
if [ ! -s "$out_log" ]; then
echo "bench-iigs: no ring log captured; falling back to on-disk extraction" >&2
"$CADIUS" EXTRACTFILE "$work/joey.2mg" "/JOEYLIB/JOEYLOG.TXT" "$work/" >/dev/null 2>&1 || true
extracted=$(find "$work" -maxdepth 1 -iname 'joeylog.txt*' | head -1)
if [ -z "$extracted" ]; then
echo "bench-iigs: FAIL -- no ring log AND no JOEYLOG.TXT on the work image" >&2
"$CADIUS" CATALOG "$work/joey.2mg" >&2 || true
exit 1
fi
# cadius may suffix the ProDOS type (#04xxxx); normalize and strip CRs.
tr -d '\r' < "$extracted" > "$out_log"
fi
ops=$(grep -c "ops/sec" "$out_log" || true)
chks=$(grep -c "UBER-CHK" "$out_log" || true)
done_marker=$(grep -c "press any key to exit" "$out_log" || true)
echo "bench-iigs: captured $ops op lines, $chks check lines (complete=$done_marker)" >&2
echo " -> $out_log" >&2
grep "UBER" "$out_log" | sed 's/ | hash=.*//' || true