feat: Refactor Emulator to Accept ROM Parameter and Enhance Logging

- Updated Emulator::Run method to accept a Rom* parameter, improving flexibility in ROM handling.
- Refactored texture creation and ROM data initialization to utilize the new parameter.
- Enhanced logging in Snes class to provide detailed information during initialization, reset, and frame processing, aiding in debugging and performance monitoring.
- Introduced cycle tracking in Apu and Spc700 classes for accurate synchronization and debugging.
- Added unit tests for APU DSP functionality and IPL ROM handshake to ensure reliability and correctness of audio processing.
This commit is contained in:
scawful
2025-10-06 11:41:33 -04:00
parent e58bc3f007
commit a881c0f8e1
16 changed files with 922 additions and 79 deletions

View File

@@ -6,6 +6,7 @@
#include "app/emu/memory/dma.h"
#include "app/emu/memory/memory.h"
#include "app/emu/video/ppu.h"
#include "util/log.h"
namespace yaze {
namespace emu {
@@ -26,6 +27,8 @@ uint8_t input_read(Input* input) {
} // namespace
void Snes::Init(std::vector<uint8_t>& rom_data) {
LOG_INFO("SNES", "Initializing emulator with ROM size %zu bytes", rom_data.size());
// Initialize the CPU, PPU, and APU
ppu_.Init();
apu_.Init();
@@ -35,9 +38,11 @@ void Snes::Init(std::vector<uint8_t>& rom_data) {
Reset(true);
running_ = true;
LOG_INFO("SNES", "Emulator initialization complete");
}
void Snes::Reset(bool hard) {
LOG_INFO("SNES", "Reset called (hard=%d)", hard);
cpu_.Reset(hard);
apu_.Reset();
ppu_.Reset();
@@ -75,19 +80,47 @@ void Snes::Reset(bool hard) {
memory_.set_open_bus(0);
next_horiz_event = 16;
InitAccessTime(false);
LOG_INFO("SNES", "Reset complete - CPU will start at $%02X:%04X", cpu_.PB, cpu_.PC);
}
void Snes::RunFrame() {
// Debug: Log every 60th frame
static int frame_log_count = 0;
if (frame_log_count % 60 == 0) {
LOG_INFO("SNES", "Frame %d: CPU=$%02X:%04X vblank=%d frames_=%d",
frame_log_count, cpu_.PB, cpu_.PC, in_vblank_, frames_);
}
frame_log_count++;
// Debug: Log vblank loop entry
static int vblank_loop_count = 0;
if (in_vblank_ && vblank_loop_count++ < 10) {
LOG_INFO("SNES", "RunFrame: Entering vblank loop (in_vblank_=true)");
}
while (in_vblank_) {
cpu_.RunOpcode();
}
uint32_t frame = frames_;
// Debug: Log active frame loop entry
static int active_loop_count = 0;
if (!in_vblank_ && active_loop_count++ < 10) {
LOG_INFO("SNES", "RunFrame: Entering active frame loop (in_vblank_=false, frame=%d, frames_=%d)",
frame, frames_);
}
while (!in_vblank_ && frame == frames_) {
cpu_.RunOpcode();
}
}
void Snes::CatchUpApu() { apu_.RunCycles(cycles_); }
void Snes::CatchUpApu() {
// Bring APU up to the same master cycle count since last catch-up.
// cycles_ is monotonically increasing in RunCycle().
apu_.RunCycles(cycles_);
}
void Snes::HandleInput() {
memset(port_auto_read_, 0, sizeof(port_auto_read_));
@@ -180,6 +213,10 @@ void Snes::RunCycle() {
bool starting_vblank = false;
if (memory_.v_pos() == 0) {
// end of vblank
static int vblank_end_count = 0;
if (vblank_end_count++ < 10) {
LOG_INFO("SNES", "VBlank END - v_pos=0, setting in_vblank_=false at frame %d", frames_);
}
in_vblank_ = false;
in_nmi_ = false;
ppu_.HandleFrameStart();
@@ -203,6 +240,13 @@ void Snes::RunCycle() {
apu_.dsp().NewFrame();
// we are starting vblank
ppu_.HandleVblank();
static int vblank_start_count = 0;
if (vblank_start_count++ < 10) {
LOG_INFO("SNES", "VBlank START - v_pos=%d, setting in_vblank_=true at frame %d",
memory_.v_pos(), frames_);
}
in_vblank_ = true;
in_nmi_ = true;
if (auto_joy_read_) {
@@ -210,6 +254,11 @@ void Snes::RunCycle() {
auto_joy_timer_ = 4224;
HandleInput();
}
static int nmi_log_count = 0;
if (nmi_log_count++ < 10) {
LOG_INFO("SNES", "VBlank NMI check: nmi_enabled_=%d, calling Nmi()=%s",
nmi_enabled_, nmi_enabled_ ? "YES" : "NO");
}
if (nmi_enabled_) {
cpu_.Nmi();
}
@@ -248,7 +297,18 @@ uint8_t Snes::ReadBBus(uint8_t adr) {
}
if (adr < 0x80) {
CatchUpApu(); // catch up the apu before reading
return apu_.out_ports_[adr & 0x3];
uint8_t val = apu_.out_ports_[adr & 0x3];
// Log port reads when value changes or during critical phase
static int cpu_port_read_count = 0;
static uint8_t last_f4 = 0xFF, last_f5 = 0xFF;
bool value_changed = ((adr & 0x3) == 0 && val != last_f4) || ((adr & 0x3) == 1 && val != last_f5);
if (value_changed || cpu_port_read_count++ < 50) {
LOG_INFO("SNES", "CPU read APU port $21%02X (F%d) = $%02X at PC=$%02X:%04X [AFTER CatchUp: APU_cycles=%llu CPU_cycles=%llu]",
0x40 + (adr & 0x3), (adr & 0x3) + 4, val, cpu_.PB, cpu_.PC, apu_.GetCycles(), cycles_);
if ((adr & 0x3) == 0) last_f4 = val;
if ((adr & 0x3) == 1) last_f5 = val;
}
return val;
}
if (adr == 0x80) {
uint8_t ret = ram[ram_adr_++];
@@ -355,6 +415,11 @@ void Snes::WriteBBus(uint8_t adr, uint8_t val) {
if (adr < 0x80) {
CatchUpApu(); // catch up the apu before writing
apu_.in_ports_[adr & 0x3] = val;
static int cpu_port_write_count = 0;
if (cpu_port_write_count++ < 200) { // Increased to see full boot sequence
LOG_INFO("SNES", "CPU wrote APU port $21%02X (F%d) = $%02X at PC=$%02X:%04X",
0x40 + (adr & 0x3), (adr & 0x3) + 4, val, cpu_.PB, cpu_.PC);
}
return;
}
switch (adr) {
@@ -381,6 +446,14 @@ void Snes::WriteBBus(uint8_t adr, uint8_t val) {
void Snes::WriteReg(uint16_t adr, uint8_t val) {
switch (adr) {
case 0x4200: {
// Log ALL writes to $4200 unconditionally
static int write_4200_count = 0;
if (write_4200_count++ < 20) {
LOG_INFO("SNES", "Write $%02X to $4200 at PC=$%02X:%04X (NMI=%d IRQ_H=%d IRQ_V=%d JOY=%d)",
val, cpu_.PB, cpu_.PC, (val & 0x80) ? 1 : 0, (val & 0x10) ? 1 : 0,
(val & 0x20) ? 1 : 0, (val & 0x01) ? 1 : 0);
}
auto_joy_read_ = val & 0x1;
if (!auto_joy_read_) auto_joy_timer_ = 0;
h_irq_enabled_ = val & 0x10;
@@ -393,7 +466,12 @@ void Snes::WriteReg(uint16_t adr, uint8_t val) {
if (!nmi_enabled_ && (val & 0x80) && in_nmi_) {
cpu_.Nmi();
}
bool old_nmi = nmi_enabled_;
nmi_enabled_ = val & 0x80;
if (old_nmi != nmi_enabled_) {
LOG_INFO("SNES", ">>> NMI enabled CHANGED: %d -> %d <<<",
old_nmi, nmi_enabled_);
}
cpu_.set_int_delay(true);
break;
}