genesis: Sonic 3 special-stage audio (S/H compositing fast path, I2S task priority, internal-RAM headroom)

components/box-emu/idf_component.yml

@@ -6,7 +6,9 @@ dependencies:
   espp/aw9523: '>=1.3.4'
   espp/button: '>=1.3.4'
   espp/drv2605: '>=1.3.4'
-  espp/esp-box: '>=1.3.4'
+  # >=1.3.8: the I2S feed task waits for a whole block instead of padding a
+  # partial one with silence (espp #845) -- needed for stutter-free Genesis audio
+  espp/esp-box: '>=1.3.8'
   espp/event_manager: '>=1.3.4'
   espp/max1704x: '>=1.3.4'
   espp/mcp23x17: '>=1.3.4'

components/box-emu/src/box-emu.cpp

@@ -44,7 +44,13 @@ bool BoxEmu::initialize_box() {
   logger_.info("Initializing underlying BSP");
   auto &box = Bsp::get();
   // initialize the sound
-  if (!box.initialize_sound()) {
+  // The I2S feed task does almost no work (hand one block to the DMA) but it
+  // must never be starved: it shares core 1 with the emulators' sound and
+  // video tasks (priority 20), and at the BSP's default priority 19 it only
+  // ran in the gaps between frames -- when core 1 was saturated (Sonic 3's
+  // special stages) the DMA underran and the audio queue overflowed, dropping
+  // ~7% of the audio. Above both emulator tasks it always runs promptly.
+  if (!box.initialize_sound(48000, {.name = "audio", .stack_size_bytes = 4096, .priority = 21, .core_id = 1})) {
     logger_.error("Failed to initialize sound!");
     return false;
   }

components/genesis/gwenesis/src/vdp/gwenesis_vdp.h

@@ -140,6 +140,18 @@ void gwenesis_vdp_set_buffers(unsigned char *screen_buffer, unsigned char *scale
 void gwenesis_vdp_set_buffer(unsigned char *ptr_screen_buffer);
 void gwenesis_vdp_render_line(int line);
 void gwenesis_vdp_skip_line(int line); /* ESP port: status bookkeeping for undrawn frames */
+/* ESP port diagnostics. GENESIS_PERF (default on) compiles in the per-frame
+ * time breakdown: the [genesis perf] report in genesis.cpp and these CPU-cycle
+ * counters per render stage (monotonic; see gwenesis_vdp_gfx.c). Defined here,
+ * in the header both files include, so GENESIS_PERF=0 removes all of it. */
+#ifndef GENESIS_PERF
+#define GENESIS_PERF 1
+#endif
+#if GENESIS_PERF
+extern uint32_t vdp_stat_planes_cycles;
+extern uint32_t vdp_stat_sprites_cycles;
+extern uint32_t vdp_stat_merge_cycles;
+#endif
 
 void gwenesis_vdp_render_config();
 

components/genesis/gwenesis/src/vdp/gwenesis_vdp_gfx.c

@@ -1025,6 +1025,21 @@ blit_4to5_line(uint16_t *in, uint16_t *out) {
   }
 }
 
+/* ESP port diagnostics: CPU cycles spent per render stage (monotonic; the
+ * driver reports per-window deltas in the [genesis perf] line). Compiled out
+ * with GENESIS_PERF=0 (gwenesis_vdp.h) along with the rest of the profiling. */
+#if GENESIS_PERF
+#include <esp_cpu.h>
+uint32_t vdp_stat_planes_cycles = 0;  /* draw_line_b + draw_line_aw */
+uint32_t vdp_stat_sprites_cycles = 0; /* draw_sprites(_over_planes) */
+uint32_t vdp_stat_merge_cycles = 0;   /* SHI merge or memcpy into the line buffer */
+#define VDP_STAT_MARK(t) uint32_t t = esp_cpu_get_cycle_count()
+#define VDP_STAT_ADD(acc, t_end, t_start) ((acc) += (t_end) - (t_start))
+#else
+#define VDP_STAT_MARK(t) ((void)0)
+#define VDP_STAT_ADD(acc, t_end, t_start) ((void)0)
+#endif
+
 /* ESP port: called instead of gwenesis_vdp_render_line() for the scanlines of
  * a frame whose pixels are not drawn (the display cannot show it). Keeps the
  * per-frame status bookkeeping the render would have done so the status
@@ -1083,44 +1098,61 @@ void gwenesis_vdp_render_line(int line)
   if (MODE_SHI)
     memset(ps, 0, 320);
 
+  VDP_STAT_MARK(t0);
   draw_line_b(line);
   draw_line_aw(line);
+  VDP_STAT_MARK(t1);
+  VDP_STAT_ADD(vdp_stat_planes_cycles, t1, t0);
 
   if (MODE_SHI)
     draw_sprites(line);
   else
     draw_sprites_over_planes(line);
+  VDP_STAT_MARK(t2);
+  VDP_STAT_ADD(vdp_stat_sprites_cycles, t2, t1);
 
   /* Mode Highlight/shadow is enabled */
   if (MODE_SHI) {
-    for (int x = 0; x < screen_width; x++) {
-      uint8_t plane = pb[x];
-      uint8_t sprite = ps[x];
-
-      if ((plane & 0xC0) < (sprite & 0xC0)) {
-        switch (sprite & 0x3F) {
-        // Palette=3, Sprite=14 :> draw plane, force highlight
-        case 0x3E:
-          screen_buffer_line[x] = plane; // 0x8410 | CRAM565[plane] >> 1;
-          break;
-        // Palette=3, Sprite=15 :> draw plane, force shadow
-        case 0x3F:
-          screen_buffer_line[x] = plane; // CRAM565[plane] >> 1;
-          break;
-        // draw sprite, normal
-        default:
-          screen_buffer_line[x] = sprite;
-          break;
-        }
-      } else {
-        screen_buffer_line[x] = plane;
+    /* Composite the sprite line over the plane line. The highlight/shadow
+     * colour math is not applied (it was already commented out below), so
+     * this is priority compositing only: a sprite pixel wins when its
+     * priority bits beat the plane's, except the two S/H operator sprites
+     * (palette 3, colours 14/15) which leave the plane as is.
+     *
+     * ESP port: the sprite buffer is cleared per line and only sprite pixels
+     * write it, so most of the line is zero there -- and a zero sprite byte
+     * can never win. Walk the line a word at a time and copy the plane word
+     * straight through unless one of its four sprite bytes is non-zero. (The
+     * per-pixel version of this loop was 7.5 ms of a 25 ms drawn frame in
+     * Sonic 3's special stages.) pb/ps/screen_buffer_line are 32-bit aligned
+     * (cache-line-aligned shared buffers) and screen_width is 256 or 320. */
+    const uint32_t *pb32 = (const uint32_t *)pb;
+    const uint32_t *ps32 = (const uint32_t *)ps;
+    uint32_t *out32 = (uint32_t *)screen_buffer_line;
+    const int words = screen_width >> 2;
+    for (int w = 0; w < words; w++) {
+      const uint32_t s4 = ps32[w];
+      if (s4 == 0) {
+        out32[w] = pb32[w];
+        continue;
+      }
+      uint32_t p4 = pb32[w];
+      uint32_t o4 = 0;
+      for (int b = 0; b < 32; b += 8) {
+        const uint32_t plane = (p4 >> b) & 0xFF;
+        const uint32_t sprite = (s4 >> b) & 0xFF;
+        const uint32_t take = ((plane & 0xC0) < (sprite & 0xC0)) && ((sprite & 0x3F) < 0x3E);
+        o4 |= (take ? sprite : plane) << b;
       }
+      out32[w] = o4;
     }
 
     /* Normal mode*/
   } else {
     memcpy(screen_buffer_line, pb, screen_width);
   }
+  VDP_STAT_MARK(t3);
+  VDP_STAT_ADD(vdp_stat_merge_cycles, t3, t2);
 }
 
 void gwenesis_vdp_gfx_save_state() {

components/genesis/include/genesis_shared_memory.hpp

@@ -9,9 +9,26 @@
 extern "C" {
 #endif
 
-// Initialize Genesis shared memory and hardware components
+// Internal RAM the Genesis must leave for the rest of the system. The core's
+// hot buffers prefer internal RAM in priority order (work RAM, YM2612 tables,
+// CPU/chip state, Z80 RAM, line buffers, audio) and spill to PSRAM once an
+// allocation would push free internal RAM below this. Measured: with no rule
+// the Genesis left 36 bytes in the main internal heap at launch, and drivers
+// that then could not get a few hundred bytes in the first frame hung the box.
+#define GENESIS_INTERNAL_RESERVE_BYTES (16 * 1024)
+
+// True if allocating `size` bytes of internal RAM would leave at least
+// GENESIS_INTERNAL_RESERVE_BYTES free.
+bool genesis_internal_has_headroom(size_t size);
+
+// Initialize Genesis shared memory and hardware components (everything except
+// VRAM, in internal-RAM priority order)
 void genesis_init_shared_memory(void);
 
+// Allocate VRAM. Called last, after the caller has placed its own hot buffers:
+// allocation order is internal-RAM priority, and VRAM is the buffer to spill.
+void genesis_init_shared_vram(void);
+
 // Free Genesis shared memory
 void genesis_free_shared_memory(void);
 

components/genesis/src/genesis.cpp

@@ -42,10 +42,8 @@ extern "C" {
 // serial capture of a play session doubles as a profile (tools/perf_report.py
 // summarises/diffs them). Cost is one CCOUNT read per section per scanline
 // (~2 cycles each), i.e. well under 0.1% of a frame; set GENESIS_PERF=0 to
-// compile it out entirely.
-#ifndef GENESIS_PERF
-#define GENESIS_PERF 1
-#endif
+// compile it out entirely. The flag is defined in gwenesis_vdp.h so the VDP's
+// own render-stage counters (vdp_stat_*) follow it too.
 #if GENESIS_PERF
 static constexpr uint32_t GENESIS_PERF_REPORT_FRAMES = 300;
 struct GenesisPerf {
@@ -73,6 +71,10 @@ struct GenesisPerf {
   uint32_t z80_halted_at_start{0};
   uint32_t z80_wto_at_start{0};
   uint32_t z80_ymw_at_start{0};
+  // VDP render stage cycles (gwenesis_vdp_gfx.c counters) at the start of the window
+  uint32_t vdp_planes_at_start{0};
+  uint32_t vdp_sprites_at_start{0};
+  uint32_t vdp_merge_at_start{0};
 };
 static GenesisPerf perf;
 #define PERF_NOW() esp_cpu_get_cycle_count()
@@ -108,9 +110,14 @@ static void genesis_perf_report() {
   const uint32_t blit_cycles_now = box.blit_cycles();
   const uint32_t blitted = blitted_now - perf.blitted_at_start;
   const uint32_t blit_us = blitted ? (blit_cycles_now - perf.blit_cycles_at_start) / ticks_per_us / blitted : 0;
+  // VDP render stages, per DRAWN frame (the vdp bucket above is per frame
+  // including skipped ones)
+  const uint32_t drawn = perf.frames > perf.skipped ? perf.frames - perf.skipped : 1;
+  auto us_drawn = [&](uint32_t cycles) { return cycles / ticks_per_us / drawn; };
   fmt::print("[genesis perf] fps={:.1f} frame={}us 68k={}us vdp={}us convert={}us barrier={}us present={}us other={}us"
              " sleep={}us late={}/{} skipped={}/{} dropped={}/{} blit={}us | core1 snd={}us leash={}us | q_dropped={}"
              " | z80 irq={} busreq={} halted={} wto={} ymw={}"
+             " | drawn planes={}us sprites={}us merge={}us"
              " | int_free={} int_largest={}\n",
              fps, frame_us, m68k, vdp, convert, barrier, present, other,
              (uint32_t)(perf.sleep_us / n), perf.late, perf.frames, perf.skipped, perf.frames,
@@ -119,9 +126,15 @@ static void genesis_perf_report() {
              z80_stat_irq_taken - perf.z80_irq_at_start, z80_stat_busreq - perf.z80_busreq_at_start,
              z80_stat_halted_slices - perf.z80_halted_at_start, z80_stat_wait_timeout - perf.z80_wto_at_start,
              z80_stat_ym_writes - perf.z80_ymw_at_start,
+             us_drawn(vdp_stat_planes_cycles - perf.vdp_planes_at_start),
+             us_drawn(vdp_stat_sprites_cycles - perf.vdp_sprites_at_start),
+             us_drawn(vdp_stat_merge_cycles - perf.vdp_merge_at_start),
              heap_caps_get_free_size(MALLOC_CAP_INTERNAL),
              heap_caps_get_largest_free_block(MALLOC_CAP_INTERNAL));
   perf = GenesisPerf{};
+  perf.vdp_planes_at_start = vdp_stat_planes_cycles;
+  perf.vdp_sprites_at_start = vdp_stat_sprites_cycles;
+  perf.vdp_merge_at_start = vdp_stat_merge_cycles;
   perf.dropped_at_start = dropped_now;
   perf.blitted_at_start = blitted_now;
   perf.blit_cycles_at_start = blit_cycles_now;
@@ -447,7 +460,9 @@ static void reset_genesis_runtime_state() {
 }
 
 static void *allocate_hot_memory(size_t size, const char *name = "hot") {
-  void *ptr = heap_caps_malloc(size, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT);
+  // internal only while the system keeps its headroom (GENESIS_INTERNAL_RESERVE_BYTES)
+  void *ptr = genesis_internal_has_headroom(size)
+    ? heap_caps_malloc(size, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT) : nullptr;
   const bool internal = (ptr != nullptr);
   if (!ptr) {
     ptr = heap_caps_malloc(size, MALLOC_CAP_8BIT | MALLOC_CAP_SPIRAM);
@@ -463,7 +478,7 @@ static void *allocate_shared_hot_memory(size_t size, shared_mem_region_t region
     .region = region,
     .storage = SHARED_MEM_INTERNAL,
   };
-  void *ptr = shared_mem_allocate(&request);
+  void *ptr = genesis_internal_has_headroom(size) ? shared_mem_allocate(&request) : nullptr;
   if (!ptr) {
     // degrade to PSRAM rather than fail init (see genesis_shared_memory.cpp)
     request.storage = SHARED_MEM_PSRAM;
@@ -563,9 +578,9 @@ static IRAM_ATTR void cpu_vdp_run_frame(int screen_height, int lines_per_frame)
     m68k_run(system_clock);
     // Release this line to the sound core: its 68k->sound writes are now queued.
     core0_line.store(scan_line, std::memory_order_release);
-    uint32_t t1 = PERF_NOW();
     PERF_ACC(m68k, t0);
     if (render_frame) {
+      uint32_t t1 = PERF_NOW();
       gwenesis_vdp_render_line(scan_line);
       uint32_t t2 = PERF_NOW();
       PERF_ACC(vdp, t1);
@@ -779,8 +794,9 @@ static void init(uint8_t *romdata, size_t rom_data_size) {
   // The YM2612 LFO table is next: like tl_tab/sin_tab (allocated first in
   // genesis_init_shared_memory()) it is read per sample on core 1, and in PSRAM
   // its random reads thrash the data cache both cores share. VRAM is allocated
-  // last and spills to PSRAM when the block is too small for everything --
-  // moving it internal measured no VDP speed-up. See genesis_shared_memory.cpp.
+  // last (genesis_init_shared_vram(), below) and spills to PSRAM when the block
+  // is too small for everything -- moving it internal measured no VDP speed-up.
+  // See genesis_shared_memory.cpp.
   M68K_RAM = (uint8_t*)allocate_hot_memory(MAX_RAM_SIZE, "M68K_RAM");
   lfo_pm_table = (int16_t*)allocate_hot_memory(128*8*16 * sizeof(int16_t), "lfo_pm_table");
 
@@ -796,13 +812,9 @@ static void init(uint8_t *romdata, size_t rom_data_size) {
   // the live CRAM565 immediately afterward. Because only one line is ever live it
   // is a tiny INTERNAL-RAM buffer instead of a ~77KB PSRAM full-frame buffer, so
   // both the VDP's per-line writes and the converter's reads hit fast internal
-  // RAM. (Try internal; in the unlikely event it can't be had, fall back to PSRAM.)
-  genesis_index_buffer = (uint8_t*)heap_caps_malloc(
-      GENESIS_SCREEN_WIDTH, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT);
-  if (!genesis_index_buffer) {
-    genesis_index_buffer = (uint8_t*)heap_caps_malloc(
-        GENESIS_SCREEN_WIDTH, MALLOC_CAP_8BIT | MALLOC_CAP_SPIRAM);
-  }
+  // RAM. (Same headroom rule as every other internal allocation; falls back to
+  // PSRAM rather than eat into the system's reserve.)
+  genesis_index_buffer = (uint8_t*)allocate_hot_memory(GENESIS_SCREEN_WIDTH, "index_buffer");
 
 #if GENESIS_DUAL_CORE
   sound_q = (uint32_t*)allocate_hot_memory(SOUND_Q_SIZE * sizeof(uint32_t), "sound_q");
@@ -814,6 +826,11 @@ static void init(uint8_t *romdata, size_t rom_data_size) {
   }
 #endif
 
+  // VRAM last of all: every allocation above is hotter, and with the headroom
+  // rule allocation order is priority -- whatever no longer fits spills to
+  // PSRAM, and 64 kB of VRAM is the buffer measured to lose nothing there.
+  genesis_init_shared_vram();
+
   if (!gwenesis_sn76489_buffer || !gwenesis_ym2612_buffer || !M68K_RAM || !lfo_pm_table ||
       !VRAM || !ZRAM || !ym2612 || !OPNREGS || !sin_tab || !render_buffer || !sprite_buffer ||
       !CRAM || !SAT_CACHE || !gwenesis_vdp_regs || !fifo || !CRAM565 || !VSRAM || !tl_tab ||
@@ -879,6 +896,9 @@ static void init(uint8_t *romdata, size_t rom_data_size) {
   perf.z80_halted_at_start = z80_stat_halted_slices;
   perf.z80_wto_at_start = z80_stat_wait_timeout;
   perf.z80_ymw_at_start = z80_stat_ym_writes;
+  perf.vdp_planes_at_start = vdp_stat_planes_cycles;
+  perf.vdp_sprites_at_start = vdp_stat_sprites_cycles;
+  perf.vdp_merge_at_start = vdp_stat_merge_cycles;
 #endif
   genesis_initialized = true;
 }
@@ -1002,12 +1022,12 @@ void IRAM_ATTR run_genesis_rom() {
         ym2612_run(system_clock);
       }
       // (single-core path: the Z80/sound share the "m68k" bucket)
-      uint32_t t1 = PERF_NOW();
       PERF_ACC(m68k, t0);
 
       /* Video */
       if (scan_line < screen_height) {
         if (render_frame) {
+          uint32_t t1 = PERF_NOW();
           gwenesis_vdp_render_line(scan_line); /* render scan_line */
           uint32_t t2 = PERF_NOW();
           PERF_ACC(vdp, t1);
@@ -1138,7 +1158,6 @@ void IRAM_ATTR run_genesis_rom() {
   // overruns the audio buffer and stutters. Pace each region at its own rate.
   const uint64_t max_frame_time =
     1000000 / (REG1_PAL ? GWENESIS_REFRESH_RATE_PAL : GWENESIS_REFRESH_RATE_NTSC);
-  const bool late = elapsed >= max_frame_time; // this frame overran its period
   //
   // Pace against a running deadline rather than per frame. Since the display-
   // aware frame skip, frames alternate between rendered (~19 ms, overrunning)
@@ -1173,7 +1192,7 @@ void IRAM_ATTR run_genesis_rom() {
 #if GENESIS_PERF
   perf.frame_us += elapsed;
   perf.sleep_us += esp_timer_get_time() - end;
-  perf.late += late;
+  perf.late += (elapsed >= max_frame_time); // this frame overran its period
   if (++perf.frames == GENESIS_PERF_REPORT_FRAMES) {
     genesis_perf_report();
   }