refactor(cpu): account for timing in bus-access order

crates/gba-core/src/cpu.rs

@@ -257,6 +257,7 @@ impl Cpu {
         let result = self.execute_instruction(instruction, memory);
         memory.end_cpu_access(result.is_ok());
         if result.is_ok() {
+            memory.record_internal_cycles(summary.internal);
             if summary.refill {
                 self.refill_pipeline(memory);
             } else {

crates/gba-core/src/cpu/pipeline.rs

@@ -83,6 +83,12 @@ impl Cpu {
             memory.fetch_instruction(pc, instruction_set),
             memory.fetch_instruction(pc.wrapping_add(instruction_set.width()), instruction_set),
         ];
+        for (sample, kind) in fetches
+            .iter()
+            .zip([AccessKind::NonSequential, AccessKind::Sequential])
+        {
+            memory.record_code_access(sample.address(), instruction_set.access_width(), kind);
+        }
         memory.refill_cpu_bus_history(&fetches);
         self.pipeline = Some(Pipeline {
             pc,

crates/gba-core/src/cpu/timing.rs

@@ -5,14 +5,14 @@
 use super::{Cpu, CpuError, InstructionSet};
 use crate::{
     memory::Memory,
-    timing::{bus_cycles, refill_cycles, AccessKind, AccessWidth, StepTiming},
+    timing::{AccessKind, AccessWidth, StepTiming},
 };
 
 #[derive(Default)]
 pub(super) struct Summary {
     data: bool,
     pub(super) refill: bool,
-    internal: u32,
+    pub(super) internal: u32,
 }
 
 impl Summary {
@@ -43,7 +43,7 @@ impl Summary {
 }
 
 impl InstructionSet {
-    fn access_width(self) -> AccessWidth {
+    pub(super) fn access_width(self) -> AccessWidth {
         match self {
             Self::Arm => AccessWidth::Word,
             Self::Thumb => AccessWidth::Halfword,
@@ -57,27 +57,18 @@ impl Cpu {
     /// Failed instructions discard their timing trace and retain existing diagnostics.
     pub fn step_timed(&mut self, memory: &mut Memory) -> Result<StepTiming, CpuError> {
         let fetched = self.fetch(memory)?;
-        let instruction = fetched.instruction;
-        let summary = self.instruction_summary(instruction);
-        let fetch_address = fetched.lookahead.address();
-        let width = self.instruction_set.access_width();
-        // A WAITCNT store affects subsequent instructions, not this code access.
-        let waitcnt = memory.waitcnt();
         let code_kind = memory.cpu_code_kind(self.next_fetch_kind());
-        memory.begin_data_timing();
+        // Source timing precedes data accesses and their WAITCNT writes.
+        memory.begin_cpu_timing();
+        memory.record_code_access(
+            fetched.lookahead.address(),
+            self.instruction_set.access_width(),
+            code_kind,
+        );
         let result = self.execute_fetched(fetched, memory);
-        let data_cycles = memory.end_data_timing();
+        let timing = memory.end_cpu_timing(result.is_ok());
         result?;
-        let mut code_cycles = bus_cycles(waitcnt, fetch_address, width, code_kind);
+        Ok(timing)
-        if summary.refill {
-            code_cycles += refill_cycles(waitcnt, self.pc(), self.instruction_set.access_width());
-        }
-        Ok(StepTiming {
-            code_cycles,
-            data_cycles,
-            internal_cycles: summary.internal,
-            idle_cycles: 0,
-        })
     }
 
     /// Accept IRQ between instructions, discard the old-state fetch, then refill ARM.
@@ -89,15 +80,12 @@ impl Cpu {
         if !self.take_interrupt(memory.irq_pending(), false) {
             return None;
         }
-        let waitcnt = memory.waitcnt();
+        memory.begin_cpu_timing();
         let fetch = memory.fetch_instruction(address, state);
+        memory.record_code_access(fetch.address(), state.access_width(), kind);
         memory.discarded_cpu_fetch(&fetch);
         self.refill_pipeline(memory);
-        Some(StepTiming {
+        Some(memory.end_cpu_timing(true))
-            code_cycles: bus_cycles(waitcnt, fetch.address(), state.access_width(), kind)
-                + refill_cycles(waitcnt, self.pc(), self.instruction_set.access_width()),
-            ..StepTiming::default()
-        })
     }
 
     fn arm_summary(&self, instruction: u32) -> Summary {

crates/gba-core/src/memory.rs

@@ -8,6 +8,8 @@ mod irq_fetch_tests;
 mod iwram_bus;
 #[cfg(test)]
 mod iwram_history_tests;
+#[cfg(test)]
+mod timing_event_tests;
 pub(crate) use fetch::InstructionFetch;
 use iwram_bus::IwramBus;
 
@@ -17,7 +19,7 @@ use crate::{
     dma::{DmaError, DMA_BASE, DMA_END},
     input::Buttons,
     io::{Io, HALTCNT, KEYINPUT, POSTFLG},
-    timing::{bus_cycles, AccessKind, AccessWidth, DataTiming, StepTiming},
+    timing::{bus_cycles, AccessKind, AccessWidth, CpuTiming, StepTiming},
     video::{self, sprites::pipeline, Framebuffer, VideoError},
 };
 
@@ -89,7 +91,9 @@ pub struct Memory {
     bios: Option<Vec<u8>>,
     io: Io,
     cycles: u64,
-    data_timing: Cell<Option<DataTiming>>,
+    cpu_timing: Cell<Option<CpuTiming>>,
+    #[cfg(test)]
+    last_cpu_timing: Option<CpuTiming>,
     // A completed DMA unit breaks the CPU's next nominal code-access sequence.
     cpu_resume_nonsequential: bool,
     cpu_access: Option<CpuAccess>,
@@ -114,7 +118,9 @@ impl Memory {
             bios: None,
             io: Io::default(),
             cycles: 0,
-            data_timing: Cell::new(None),
+            cpu_timing: Cell::new(None),
+            #[cfg(test)]
+            last_cpu_timing: None,
             cpu_resume_nonsequential: false,
             cpu_access: None,
             bios_prefetch: None,
@@ -509,19 +515,47 @@ impl Memory {
         }
     }
 
-    pub(crate) fn begin_data_timing(&self) {
+    pub(crate) fn begin_cpu_timing(&self) {
-        debug_assert!(self.data_timing.get().is_none());
+        debug_assert!(self.cpu_timing.get().is_none());
-        self.data_timing.set(Some(DataTiming::default()));
+        self.cpu_timing.set(Some(CpuTiming::new(self.waitcnt())));
     }
 
-    pub(crate) fn end_data_timing(&self) -> u32 {
+    pub(crate) fn end_cpu_timing(&mut self, succeeded: bool) -> StepTiming {
-        self.data_timing.take().map_or(0, |trace| trace.cycles)
+        let trace = self
+            .cpu_timing
+            .take()
+            .expect("CPU timing transaction is active");
+        if !succeeded {
+            return StepTiming::default();
+        }
+        #[cfg(test)]
+        {
+            self.last_cpu_timing = Some(trace);
+        }
+        trace.total
+    }
+
+    pub(crate) fn record_code_access(&self, address: u32, width: AccessWidth, kind: AccessKind) {
+        if let Some(mut trace) = self.cpu_timing.get() {
+            trace.code(address, width, kind);
+            self.cpu_timing.set(Some(trace));
+        }
+    }
+
+    pub(crate) fn record_internal_cycles(&self, cycles: u32) {
+        if cycles == 0 {
+            return;
+        }
+        if let Some(mut trace) = self.cpu_timing.get() {
+            trace.internal(cycles);
+            self.cpu_timing.set(Some(trace));
+        }
     }
 
     fn record_access(&self, address: u32, width: AccessWidth) {
-        if let Some(mut trace) = self.data_timing.get() {
+        if let Some(mut trace) = self.cpu_timing.get() {
-            trace.access(self.waitcnt(), address, width);
+            trace.data(self.waitcnt(), address, width);
-            self.data_timing.set(Some(trace));
+            self.cpu_timing.set(Some(trace));
         }
     }
 

crates/gba-core/src/memory/fetch_tests.rs

@@ -142,10 +142,10 @@ fn sampling_has_no_timing_or_history_side_effects_and_never_uses_data_fallback()
     bios[8..12].copy_from_slice(&WORD.to_le_bytes());
     let mut memory = Memory::with_bios(vec![], bios).unwrap();
     memory.cpu_resume_nonsequential = true;
-    memory.begin_data_timing();
+    memory.begin_cpu_timing();
     let fetch = memory.fetch_instruction(8, InstructionSet::Arm);
     memory.fetch_instruction(0x0300_0000, InstructionSet::Thumb);
-    assert_eq!(memory.end_data_timing(), 0);
+    assert_eq!(memory.end_cpu_timing(true), StepTiming::default());
     assert_eq!(memory.bios_prefetch, None);
     assert!(memory.cpu_resume_nonsequential);
     assert_eq!(memory.cycles(), 0);

crates/gba-core/src/memory/timing_event_tests.rs

@@ -0,0 +1,321 @@
+//! Original checks of timing-event order, independent of aggregate cycle totals.
+use super::*;
+use crate::{
+    cpu::Cpu,
+    dma::DMA_STRIDE,
+    io::{IE, IME, TIMER_BASE, WAITCNT},
+    machine::{Machine, StepKind},
+    timing::TimingEvent,
+};
+
+const BASE: u32 = ROM_START + 0x100;
+const THUMB: u32 = ROM_START + 0x180;
+const DATA: u32 = 0x0300_1000;
+const ARM_NOP: u32 = 0xe1a0_0000;
+
+fn prepared(thumb: bool, instructions: &[u32], operands: &[(usize, u32)]) -> (Cpu, Memory) {
+    let mut operands = operands.to_vec();
+    if thumb {
+        operands.push((12, THUMB | 1));
+    }
+    let mut rom = ARM_NOP.to_le_bytes().repeat(256);
+    for (index, &(register, value)) in operands.iter().enumerate() {
+        let at = 0x100 + 4 * index;
+        let literal = 0x200 + 4 * index;
+        let ldr = 0xe59f_0000 | (register as u32) << 12 | (literal - at - 8) as u32;
+        rom[at..at + 4].copy_from_slice(&ldr.to_le_bytes());
+        rom[literal..literal + 4].copy_from_slice(&value.to_le_bytes());
+    }
+    // A NOP after operand setup establishes an incoming S kind.
+    let entry = 0x100 + 4 * (operands.len() + 1);
+    let (entry, width) = if thumb {
+        rom[entry..entry + 4].copy_from_slice(&0xe12f_ff1c_u32.to_le_bytes());
+        rom[0x180..0x1c0].copy_from_slice(&0x46c0_u16.to_le_bytes().repeat(32));
+        (0x180, 2)
+    } else {
+        (entry, 4)
+    };
+    for (index, instruction) in instructions.iter().enumerate() {
+        rom[entry + index * width..entry + (index + 1) * width]
+            .copy_from_slice(&instruction.to_le_bytes()[..width]);
+    }
+    let mut memory = Memory::with_bios(rom, ARM_NOP.to_le_bytes().repeat(BIOS_SIZE / 4)).unwrap();
+    let mut cpu = Cpu::new(BASE);
+    for _ in 0..operands.len() + 1 + usize::from(thumb) {
+        cpu.step(&mut memory).unwrap();
+    }
+    assert!(memory.last_cpu_timing.is_none()); // Untimed setup does not create a trace.
+    (cpu, memory)
+}
+
+fn code(address: u32, width: AccessWidth, kind: AccessKind, cycles: u32) -> TimingEvent {
+    TimingEvent::Code {
+        address,
+        width,
+        kind,
+        waitcnt: 0,
+        cycles,
+    }
+}
+
+fn data(address: u32, width: AccessWidth, kind: AccessKind, cycles: u32) -> TimingEvent {
+    TimingEvent::Data {
+        address,
+        width,
+        kind,
+        waitcnt: 0,
+        cycles,
+    }
+}
+
+fn events(memory: &Memory) -> Vec<TimingEvent> {
+    assert!(memory.cpu_timing.get().is_none());
+    memory.last_cpu_timing.unwrap().events()
+}
+
+#[test]
+fn pc_load_records_source_data_internal_and_target_pair_in_order() {
+    let target = 0x0200_0100;
+    let (mut cpu, mut memory) = prepared(false, &[0xe591_f000], &[(1, DATA)]);
+    memory.write32(DATA, target).unwrap();
+    let source = cpu.pc() + 8;
+    let timing = cpu.step_timed(&mut memory).unwrap();
+    assert_eq!(
+        events(&memory),
+        vec![
+            code(source, AccessWidth::Word, AccessKind::Sequential, 6),
+            data(DATA, AccessWidth::Word, AccessKind::NonSequential, 1),
+            TimingEvent::Internal { cycles: 1 },
+            code(target, AccessWidth::Word, AccessKind::NonSequential, 6),
+            code(target + 4, AccessWidth::Word, AccessKind::Sequential, 6),
+        ]
+    );
+    assert_eq!(
+        timing,
+        StepTiming {
+            code_cycles: 18,
+            data_cycles: 1,
+            internal_cycles: 1,
+            idle_cycles: 0
+        }
+    );
+    assert_eq!(memory.cycles(), 0);
+}
+
+#[test]
+fn largest_block_load_records_all_data_before_internal_and_refill_events() {
+    let target = 0x0200_0200;
+    let (mut cpu, mut memory) = prepared(false, &[0xe890_ffff], &[(0, DATA)]);
+    memory.write32(DATA + 60, target).unwrap();
+    let mut expected = vec![code(
+        cpu.pc() + 8,
+        AccessWidth::Word,
+        AccessKind::Sequential,
+        6,
+    )];
+    for index in 0..16 {
+        expected.push(data(
+            DATA + index * 4,
+            AccessWidth::Word,
+            if index == 0 {
+                AccessKind::NonSequential
+            } else {
+                AccessKind::Sequential
+            },
+            1,
+        ));
+    }
+    expected.extend([
+        TimingEvent::Internal { cycles: 1 },
+        code(target, AccessWidth::Word, AccessKind::NonSequential, 6),
+        code(target + 4, AccessWidth::Word, AccessKind::Sequential, 6),
+    ]);
+    let timing = cpu.step_timed(&mut memory).unwrap();
+    assert_eq!(events(&memory), expected);
+    assert_eq!(timing.total(), 35);
+}
+
+#[test]
+fn thumb_pop_records_word_data_then_halfword_targets_without_duplicate_fetch_costs() {
+    let target = 0x0300_2000;
+    let (mut cpu, mut memory) = prepared(true, &[0xbd03], &[(13, DATA)]);
+    memory.write32(DATA + 8, target).unwrap();
+    let timing = cpu.step_timed(&mut memory).unwrap();
+    assert_eq!(
+        events(&memory),
+        vec![
+            code(THUMB + 4, AccessWidth::Halfword, AccessKind::Sequential, 3),
+            data(DATA, AccessWidth::Word, AccessKind::NonSequential, 1),
+            data(DATA + 4, AccessWidth::Word, AccessKind::Sequential, 1),
+            data(DATA + 8, AccessWidth::Word, AccessKind::Sequential, 1),
+            TimingEvent::Internal { cycles: 1 },
+            code(target, AccessWidth::Halfword, AccessKind::NonSequential, 1),
+            code(target + 2, AccessWidth::Halfword, AccessKind::Sequential, 1),
+        ]
+    );
+    assert_eq!(timing.total(), 9);
+}
+
+#[test]
+fn state_change_and_taken_or_skipped_branches_have_only_the_required_code_events() {
+    let target = 0x0200_0100;
+    let (mut cpu, mut memory) = prepared(false, &[0xe12f_ff10], &[(0, target | 1)]);
+    let source = cpu.pc() + 8;
+    cpu.step_timed(&mut memory).unwrap();
+    assert_eq!(
+        events(&memory),
+        vec![
+            code(source, AccessWidth::Word, AccessKind::Sequential, 6),
+            code(target, AccessWidth::Halfword, AccessKind::NonSequential, 3),
+            code(target + 2, AccessWidth::Halfword, AccessKind::Sequential, 3),
+        ]
+    );
+    for (instruction, taken) in [(0xeaff_ffff, true), (0x0aff_ffff, false)] {
+        let (mut cpu, mut memory) = prepared(false, &[instruction], &[]);
+        let pc = cpu.pc();
+        let mut expected = vec![code(pc + 8, AccessWidth::Word, AccessKind::Sequential, 6)];
+        if taken {
+            expected.extend([
+                code(pc + 4, AccessWidth::Word, AccessKind::NonSequential, 8),
+                code(pc + 8, AccessWidth::Word, AccessKind::Sequential, 6),
+            ]);
+        }
+        cpu.step_timed(&mut memory).unwrap();
+        assert_eq!(events(&memory), expected);
+    }
+}
+
+#[test]
+fn swaps_and_register_shifts_place_internal_cycles_after_their_bus_work() {
+    for (instruction, swap) in [(0xe101_0092, true), (0xe1a0_0312, false)] {
+        let (mut cpu, mut memory) = prepared(false, &[instruction], &[(1, DATA)]);
+        let mut expected = vec![code(
+            cpu.pc() + 8,
+            AccessWidth::Word,
+            AccessKind::Sequential,
+            6,
+        )];
+        if swap {
+            expected.extend([
+                data(DATA, AccessWidth::Word, AccessKind::NonSequential, 1),
+                data(DATA, AccessWidth::Word, AccessKind::NonSequential, 1),
+            ]);
+        }
+        expected.push(TimingEvent::Internal { cycles: 1 });
+        cpu.step_timed(&mut memory).unwrap();
+        assert_eq!(events(&memory), expected);
+    }
+}
+
+#[test]
+fn waitcnt_store_records_old_source_settings_and_next_step_records_new_settings() {
+    for waitcnt in [0x18, 0x4018] {
+        // Prefetch enable is still stored only.
+        let (mut cpu, mut memory) = prepared(
+            false,
+            &[0xe581_0000, ARM_NOP],
+            &[(0, waitcnt), (1, WAITCNT)],
+        );
+        let pc = cpu.pc();
+        cpu.step_timed(&mut memory).unwrap();
+        assert_eq!(
+            events(&memory),
+            vec![
+                code(pc + 8, AccessWidth::Word, AccessKind::Sequential, 6),
+                data(WAITCNT, AccessWidth::Word, AccessKind::NonSequential, 1),
+            ]
+        );
+        cpu.step_timed(&mut memory).unwrap();
+        assert_eq!(
+            events(&memory),
+            vec![TimingEvent::Code {
+                address: pc + 12,
+                width: AccessWidth::Word,
+                kind: AccessKind::NonSequential,
+                waitcnt: waitcnt as u16,
+                cycles: 5,
+            }]
+        );
+    }
+}
+
+#[test]
+fn irq_entry_records_the_incoming_source_and_vector_pair_without_executing_code() {
+    let (mut cpu, mut memory) = prepared(true, &[0x6808], &[(1, DATA)]);
+    cpu.step_timed(&mut memory).unwrap(); // Load makes the next source N.
+    memory.write16(IE, 8).unwrap();
+    memory.write16(IME, 1).unwrap();
+    memory.write32(TIMER_BASE, 0x00c0_ffff).unwrap();
+    memory.advance_cycles(1);
+    let mut machine = Machine::new(cpu, memory);
+    let start = machine.cycles();
+    assert_eq!(machine.step().unwrap(), StepKind::IrqEntry);
+    assert_eq!(
+        events(machine.memory()),
+        vec![
+            code(
+                THUMB + 6,
+                AccessWidth::Halfword,
+                AccessKind::NonSequential,
+                5
+            ),
+            code(0x18, AccessWidth::Word, AccessKind::NonSequential, 1),
+            code(0x1c, AccessWidth::Word, AccessKind::Sequential, 1),
+        ]
+    );
+    assert_eq!(machine.cycles() - start, 7);
+}
+
+#[test]
+fn failed_instructions_discard_events_and_preserve_the_last_successful_trace() {
+    // The second LDR reads an unsupported data region; the first retains normal events.
+    let (mut cpu, mut memory) = prepared(false, &[0xe591_1000, 0xe591_0000], &[(1, DATA)]);
+    memory.write32(DATA, 0x0e00_0000).unwrap();
+    cpu.step_timed(&mut memory).unwrap();
+    let previous = events(&memory);
+    let before = cpu.clone();
+    for _ in 0..2 {
+        assert!(cpu.step_timed(&mut memory).is_err());
+        assert_eq!(cpu, before);
+        assert_eq!(events(&memory), previous);
+        assert_eq!(memory.cycles(), 0);
+    }
+    // A late block-load error must also discard already recorded data accesses.
+    {
+        let (mut cpu, mut memory) = prepared(false, &[ARM_NOP, 0xe8b1_0005], &[(1, IME)]);
+        cpu.step_timed(&mut memory).unwrap();
+        let previous = events(&memory);
+        let before = cpu.clone();
+        assert!(cpu.step_timed(&mut memory).is_err());
+        assert_eq!(cpu, before);
+        assert_eq!(events(&memory), previous);
+    }
+    // Host reads and untimed code neither join nor replace a completed trace.
+    memory.read32(DATA).unwrap();
+    let mut probe = Cpu::new(0x0300_0000);
+    probe.step(&mut memory).unwrap();
+    assert_eq!(events(&memory), previous);
+}
+
+#[test]
+fn deferred_source_errors_and_dma_steps_do_not_add_hidden_cpu_events() {
+    let mut memory = Memory::new(ARM_NOP.to_le_bytes().to_vec()).unwrap();
+    let mut cpu = Cpu::new(ROM_START);
+    cpu.step_timed(&mut memory).unwrap(); // Missing P+8 is deferred but still costs a fetch.
+    let previous = vec![code(
+        ROM_START + 8,
+        AccessWidth::Word,
+        AccessKind::Sequential,
+        6,
+    )];
+    assert_eq!(events(&memory), previous);
+    assert!(cpu.step_timed(&mut memory).is_err());
+    assert_eq!(events(&memory), previous);
+    let dma = DMA_BASE + 3 * DMA_STRIDE;
+    memory.write32(dma, DATA).unwrap();
+    memory.write32(dma + 4, DATA + 4).unwrap();
+    memory.write32(dma + 8, 0x8400_0001).unwrap();
+    memory.step_dma().unwrap().unwrap();
+    assert_eq!(events(&memory), previous);
+    assert_eq!(memory.cycles(), 4); // IWRAM read/write plus DMA startup, no CPU timing.
+}

crates/gba-core/src/timing.rs

@@ -89,33 +89,103 @@ pub fn bus_cycles(waitcnt: u16, address: u32, width: AccessWidth, kind: AccessKi
     }
 }
 
-/// Target/decode pair only. The caller separately charges the old-state source fetch.
+/// One speculative instruction/IRQ timing transaction. Events arrive in source,
-pub(crate) fn refill_cycles(waitcnt: u16, target: u32, width: AccessWidth) -> u32 {
+/// data, internal, then target-pair order. Device clocks still advance in bulk.
-    bus_cycles(waitcnt, target, width, AccessKind::NonSequential)
+/// Code uses the entry WAITCNT snapshot; data uses settings at each bus access.
-        + bus_cycles(
-            waitcnt,
-            target.wrapping_add(width.bytes()),
-            width,
-            AccessKind::Sequential,
-        )
-}
-
-/// A data-only trace. Instruction fetches and branch refills are charged by the
-/// CPU timing summary, not here. Actual CPU bus calls supply addresses and widths.
 #[derive(Debug, Default, Clone, Copy)]
-pub(crate) struct DataTiming {
+pub(crate) struct CpuTiming {
-    pub cycles: u32,
+    pub total: StepTiming,
-    next: Option<u32>,
+    code_waitcnt: u16,
+    next_data: Option<u32>,
+    // The largest supported step is LDM with PC: source + 16 data + I + 2 targets.
+    // Production builds keep only costs and sequencing state, not an event log.
+    #[cfg(test)]
+    events: [Option<TimingEvent>; 20],
+    #[cfg(test)]
+    event_count: usize,
 }
 
-impl DataTiming {
+impl CpuTiming {
-    pub fn access(&mut self, waitcnt: u16, address: u32, width: AccessWidth) {
+    pub fn new(code_waitcnt: u16) -> Self {
-        let kind = if self.next == Some(address) {
+        Self {
+            code_waitcnt,
+            ..Self::default()
+        }
+    }
+
+    pub fn code(&mut self, address: u32, width: AccessWidth, kind: AccessKind) {
+        let cycles = bus_cycles(self.code_waitcnt, address, width, kind);
+        self.total.code_cycles += cycles;
+        #[cfg(test)]
+        self.record(TimingEvent::Code {
+            address,
+            width,
+            kind,
+            waitcnt: self.code_waitcnt,
+            cycles,
+        });
+    }
+
+    pub fn data(&mut self, waitcnt: u16, address: u32, width: AccessWidth) {
+        let kind = if self.next_data == Some(address) {
             AccessKind::Sequential
         } else {
             AccessKind::NonSequential
         };
-        self.cycles += bus_cycles(waitcnt, address, width, kind);
+        let cycles = bus_cycles(waitcnt, address, width, kind);
-        self.next = Some(address.wrapping_add(width.bytes()));
+        self.total.data_cycles += cycles;
+        self.next_data = Some(address.wrapping_add(width.bytes()));
+        #[cfg(test)]
+        self.record(TimingEvent::Data {
+            address,
+            width,
+            kind,
+            waitcnt,
+            cycles,
+        });
+    }
+
+    pub fn internal(&mut self, cycles: u32) {
+        self.total.internal_cycles += cycles;
+        #[cfg(test)]
+        if cycles != 0 {
+            self.record(TimingEvent::Internal { cycles });
+        }
+    }
+
+    #[cfg(test)]
+    fn record(&mut self, event: TimingEvent) {
+        self.events[self.event_count] = Some(event);
+        self.event_count += 1;
+    }
+
+    #[cfg(test)]
+    pub fn events(&self) -> Vec<TimingEvent> {
+        self.events[..self.event_count]
+            .iter()
+            .map(|event| event.unwrap())
+            .collect()
     }
 }
+
+#[cfg(test)]
+#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+pub(crate) enum TimingEvent {
+    Code {
+        address: u32,
+        width: AccessWidth,
+        kind: AccessKind,
+        waitcnt: u16,
+        cycles: u32,
+    },
+    Data {
+        address: u32,
+        width: AccessWidth,
+        kind: AccessKind,
+        waitcnt: u16,
+        cycles: u32,
+    },
+    Internal {
+        cycles: u32,
+    },
+}

docs/architecture.md

@@ -51,15 +51,16 @@ The repository is a Cargo workspace with three crates:
 | `crates/gba-core/src/display.rs` | Display clock, scanline status, comparison edges, and display IRQ events |
 | `crates/gba-core/src/dma.rs` | DMA registers, internal pointers, retained channel data, trigger state, priority, and completion IRQs |
 | `crates/gba-core/src/machine.rs` | Timed CPU/DMA/device stepping and IRQ delivery |
-| `crates/gba-core/src/timing.rs` | Bus widths, wait-state costs, and timing breakdowns |
+| `crates/gba-core/src/timing.rs` | Bus widths, wait-state costs, ordered CPU timing transactions, and timing breakdowns |
 | `crates/gba-core/src/cpu/pipeline.rs` | CPU-owned ARM/Thumb instructions, PC/state tags, next fetch kind, deferred diagnostics, refills, and invalidation |
 | `crates/gba-core/src/cpu/arm_pipeline_tests.rs` | ARM self-modifying code, branches, target pairs, DMA isolation, exceptions, errors, and timing equivalence |
 | `crates/gba-core/src/cpu/thumb_pipeline_tests.rs` | Thumb retained halfwords, BL prefix/suffix, state-tagged refills, DMA isolation, rollback, and timing equivalence |
-| `crates/gba-core/src/cpu/timing.rs` | Source-fetch/target-pair costs, IRQ integration, next-fetch classification, and data accounting |
+| `crates/gba-core/src/cpu/timing.rs` | CPU timing transaction entry/exit, IRQ integration, and incoming instruction classification |
 | `crates/gba-core/src/cpu/fetch_timing_tests.rs` | Fetch-region/page/wait-window costs, DMA resume, WAITCNT stores, deferred errors, and timer/IRQ effects |
 | `crates/gba-core/src/cpu/refill_timing_tests.rs` | Refill source/target widths, wait settings, boundaries, DMA resume, and IRQ diagnostics |
 | `crates/gba-core/src/cpu/fetch_sequence_tests.rs` | Instruction-pair access kinds, transfer/internal-cycle breaks, refills, IRQ/DMA composition, and rollback |
 | `crates/gba-core/src/memory/irq_fetch_tests.rs` | Discarded IRQ fetch lanes, cold/retained entry, BIOS-history isolation, and deferred vector errors |
+| `crates/gba-core/src/memory/timing_event_tests.rs` | Ordered source/data/internal/refill events, WAITCNT snapshots, IRQ entry, rollback, and host/DMA isolation |
 | `crates/gba-core/src/cpu/dma_resume_tests.rs` | One-shot non-sequential DMA resume costs, wait settings, failures, idle, IRQs, and API isolation |
 | `crates/gba-core/src/cpu/timing_tests.rs` | Instruction timing and semantic-equivalence checks |
 | `crates/gba-demos/src/timer_demo.rs` | Original timer-configuration program and IRQ handler |

docs/hardware/cpu.md

@@ -356,6 +356,12 @@ The writable mask is `0x5fff`; the Game Pak type flag reads as GBA, and the uppe
 A CPU write to WAITCNT does not retroactively change that instruction's code-access cost.
 The new settings apply to subsequent code accesses.
 
+Timed CPU execution uses an ordered `CpuTiming` transaction: source fetch, actual data accesses, internal work, then target-pair fetches.
+A failed instruction discards the entire transaction. Target samples do not add duplicate fetch or data costs.
+IRQ entry records its source fetch and vector pair in the same path.
+Device clocks still advance once after the successful step; this is not per-cycle scheduling.
+See [Game Pak prefetch research](../research/gamepak-prefetch.md) for this prerequisite and unresolved queue behavior.
+
 ### Nominal CPU resume after DMA
 
 A successful DMA unit marks the next CPU instruction's nominal code access non-sequential.

docs/references.md

@@ -199,6 +199,16 @@ Persistent fetch access-kind research:
 See [persistent fetch access kinds](research/fetch-access-sequencing.md) for scope, cold-start policy, and regression-report changes.
 These are source comparisons, not hardware timing measurements or external-emulator test runs.
 
+Game Pak prefetch research:
+
+- [GBATEK GamePak Prefetch](https://www.problemkaputt.de/gbatek-gba-gamepak-prefetch.htm), for capacity, opcode-only service, and idle-bus progress.
+- [mGBA cycle counting and prefetch](https://mgba.io/2015/06/27/cycle-counting-prefetch/), for independent cartridge progress and original hardware-timing test leads.
+- The pinned NanoBoyAdvance bus timing above, for queued/in-progress/miss cases and completion-edge cancellation stalls.
+- [ares prefetch at 6f6786e0](https://github.com/ares-emulator/ares/blob/6f6786e04f0822a3475463df284f313ab8518d51/ares/gba/cpu/prefetch.cpp), compared with its pinned bus dispatcher above, for halfword ownership, full-buffer stopping, and page-boundary behavior.
+
+See [prefetch evidence and timing prerequisites](research/gamepak-prefetch.md).
+The source differences remain validation questions. No Game Pak prefetch implementation or hardware conformance result is claimed yet.
+
 Use [GBATEK](https://problemkaputt.de/gbatek.htm) and ARM7TDMI documentation for further hardware work.
 Only use game ROMs that you may lawfully use. Do not commit game ROMs, BIOS files, or game assets.
 The ignore file excludes `roms/`, common game ROM extensions, and save files.

docs/research/fetch-access-sequencing.md

@@ -126,4 +126,5 @@ The timer therefore runs two additional cycles before the handler stops it.
 - Game Pak prefetch, configurable EWRAM timing, display contention, and DMA during internal cycles remain unimplemented.
 - IRQ synchronization delays and complete BIOS/general-bus latch history remain incomplete.
 
-The next timing work is Game Pak prefetch, with explicit startup and invalidation rules and independent tests.
+The later [prefetch prerequisite](gamepak-prefetch.md) records source, data, internal, and refill costs in order without changing totals.
+The next timing work remains an active Game Pak queue, with verified startup and invalidation rules and independent tests.

docs/research/gamepak-prefetch.md

@@ -0,0 +1,115 @@
+# Game Pak prefetch: evidence and timing prerequisites
+
+## Current result
+
+Game Pak prefetch is **not enabled in the core yet**.
+WAITCNT bit 14 remains stored without accelerating instruction fetches.
+This change prepares ordered CPU timing transactions without changing cycle totals or instruction results.
+
+The previous timing path collected data costs during execution, then calculated source and refill costs afterward.
+That produced correct existing totals but could not directly advance a prefetch queue in bus-access order.
+A prefetch implementation needs to distinguish cartridge-bus occupation from time available for background fetching.
+An aggregate instruction cost cannot identify when to fill or invalidate a queue.
+
+## Sources reviewed
+
+- [GBATEK GamePak Prefetch](https://www.problemkaputt.de/gbatek-gba-gamepak-prefetch.htm) describes eight 16-bit entries, opcode-only service, and prefetch during internal or other-memory accesses.
+- [mGBA's cycle-counting article](https://mgba.io/2015/06/27/cycle-counting-prefetch/) explains independent cartridge-bus progress, partially completed fetches, and instruction-pair examples.
+  Its examples and linked timing suite provide leads for independent validation, not a local hardware-test pass.
+- [NanoBoyAdvance bus timing at 55b5cf0a](https://github.com/nba-emu/NanoBoyAdvance/blob/55b5cf0ae3d929582ac5bfd486558173502b8354/src/nba/src/bus/timing.cc) distinguishes queue hits, in-progress fetches, misses, and cancellation stalls.
+- [ares prefetch at 6f6786e0](https://github.com/ares-emulator/ares/blob/6f6786e04f0822a3475463df284f313ab8518d51/ares/gba/cpu/prefetch.cpp) provides an independent halfword-queue implementation.
+  Its [bus dispatcher](https://github.com/ares-emulator/ares/blob/6f6786e04f0822a3475463df284f313ab8518d51/ares/gba/cpu/bus.cpp) separates opcode requests, data requests, and other-region progress.
+
+No external implementation or ROM was added to the repository.
+No physical-hardware measurement or external-emulator differential run was performed.
+
+## Agreement and unresolved details
+
+The sources agree on the main model:
+
+- Prefetch is controlled by WAITCNT bit 14.
+- The buffer serves Game Pak opcodes, not arbitrary ROM data loads.
+- Internal CPU work and accesses to other memory can give the cartridge bus time to fetch ahead.
+- A matching ready entry avoids ordinary ROM waits.
+- A request for an in-progress fetch waits for the remaining work rather than restarting the full access.
+- Cartridge data traffic and nonmatching code requests interact with the active prefetch sequence.
+
+However, the implementation details are not interchangeable:
+
+| Area | Source observation | Required follow-up |
+| --- | --- | --- |
+| Entry granularity | NanoBoyAdvance groups ARM words; ares tracks halfwords | Verify partial ARM fetches and ARM/Thumb transitions |
+| Full buffer | ares stops production and restarts after draining; NanoBoyAdvance uses an instruction-sized countdown/count model | Establish capacity, pause, drain, and restart timing independently |
+| ROM page boundary | ares prevents background reads across the forced-N boundary; NanoBoyAdvance's queue step uses its retained duty | Verify 128 KiB boundaries without assuming a normal ready-entry hit |
+| Cancellation | Both contain completion-edge stall handling | Verify the exact halfword phase and which code/data requests trigger a stall |
+| DMA and idle | Prefetch shares cartridge time with other bus owners | Verify RAM-only DMA, cartridge DMA, HALT/STOP, and resume separately |
+| WAITCNT changes | Queue state and current transfer timing depend on register changes | Define enable, disable, and changed-wait behavior before integration |
+
+These differences do not establish that either implementation is wrong.
+They show why copying one queue policy is not sufficient evidence for the entire subsystem.
+The first implementation should state its supported cases and retain explicit limits for unresolved behavior.
+
+## Ordered CPU timing transactions
+
+`CpuTiming` replaces the data-only accumulator.
+A timed CPU instruction now records these events in order:
+
+1. Source instruction fetch, using the incoming access kind and instruction width.
+2. Actual data reads/writes, using their aligned bus addresses and widths.
+3. Internal CPU cycles from the incoming instruction classification.
+4. Refill target N and target+width S accesses, using the resulting instruction state.
+
+S means sequential access; N means non-sequential access.
+An instruction without data, internal work, or a refill omits those events.
+The two refill events occur in `Cpu::refill_pipeline`, alongside its existing mapped target samples.
+No separate refill-cost formula runs after execution.
+IRQ entry records its discarded incoming-state source fetch before its ARM vector pair, without a data or internal event.
+
+Code timing retains the entry WAITCNT snapshot.
+Data timing retains the settings observed at each actual bus access, including pre-write settings for a WAITCNT store.
+The next instruction uses the new WAITCNT settings.
+The existing data N/S rule and persistent CPU source-fetch kind are unchanged.
+
+The transaction returns the same `StepTiming` fields as before.
+A diagnostic discards the entire transaction, including any data events recorded before a late failure.
+Missing lookahead or target bytes retain their existing deferred diagnostic policy and nominal attempted-fetch cost.
+Device clocks still advance once after a successful machine step.
+This is ordered cost accounting, not a cycle-by-cycle bus scheduler.
+
+Untimed execution, host inspection, cold-fill sampling, and DMA do not join a CPU timing transaction.
+They retain their existing behavior and do not create extra code/data charges.
+Untimed CPU execution still updates instruction retention and the next fetch kind, but does not compute a timing transaction.
+A future active prefetch model must define timing-state progression for this API explicitly.
+
+## Original regression coverage
+
+Test builds retain events from the last successful CPU timing transaction.
+Production builds retain only totals, the code WAITCNT snapshot, and data-sequence state; they allocate no event log.
+The test log covers the maximum supported block load, including PC, without truncation.
+Tests inspect event order and metadata independently of total cycle assertions.
+
+Coverage includes:
+
+- Word PC loads and the full register-list LDM sequence.
+- Thumb POP with word data and halfword target fetches.
+- ARM-to-Thumb BX, taken branches to fallthrough, and skipped conditions.
+- Swaps, register-shift internal cycles, and absence of duplicate source/refill events.
+- WAITCNT stores with old source settings and new settings on the next fetch.
+- IRQ entry after a Thumb load, including the retained non-sequential source kind.
+- Failed data accesses, late block-load failure, missing current/lookahead slots, and retry isolation.
+- Host reads, untimed CPU execution, and DMA isolation from the CPU trace.
+
+## Validation
+
+Workspace and core/demo tests pass in debug and release on Darwin arm64.
+Formatting, clippy, rustdoc, Python preparation tests, native ROM windows, and all graphics smoke modes pass.
+The release executable is native Mach-O arm64.
+Public ARM, Thumb, memory, and BIOS reports match the preceding sequencing change exactly, including cycles and step counts.
+Debug and release reports also match. Original CPU and timer demo traces are unchanged.
+
+## Next implementation work
+
+Implement and test queue progress against these ordered timing events before enabling WAITCNT acceleration.
+Keep the cartridge queue separate from CPU instruction retention, BIOS protected-read history, and IWRAM local lanes.
+Resolve startup, capacity, page boundaries, partial ARM fetches, cancellation, and WAITCNT changes with independent expectations.
+DMA/idle progression and diagnostic rollback need separate tests before claiming those interactions are supported.

docs/status.md

@@ -45,6 +45,7 @@ Update this file when a feature lands or a limit is removed.
 - STOP freezes CPU/DMA/device clocks, retains device phases, and reports a stopped frame runner without spinning.
 - Machine execution to the next VBlank event, with a configurable step limit.
 - CPU/device stepping with nominal ARM7 instruction costs and memory wait states.
+- Ordered CPU timing transactions record source, data, internal, and refill costs, with whole-step diagnostic rollback.
 - Code costs use actual ARM PC+8/Thumb PC+4 source fetches and branch/exception target pairs, including region and ROM boundaries.
 - IRQ entry samples its discarded incoming-state fetch before the ARM vector pair, with local IWRAM history updates.
 - Persistent fetch access kinds follow CPU data/internal work, compose with DMA resume, and reset after target refills.
@@ -166,7 +167,9 @@ Writes to cartridge addresses return errors instead of modeling cartridge hardwa
    Keep unknown history diagnostic until fetch ordering and latch ownership have independent coverage.
    Validate BIOS snapshots with independent hardware tests before claiming exact refill or data-access history.
    The desktop runner still uses only the original BIOS. Keep protected reads image-derived for all supplied images.
-2. Add Game Pak prefetch with verified startup and invalidation rules.
+2. Add Game Pak prefetch using the ordered CPU timing path; bit 14 still does not accelerate execution.
+   Verify queue startup, full-buffer restart, page boundaries, partial ARM fetches, and invalidation before enabling it.
+   See [prefetch research and prerequisites](research/gamepak-prefetch.md).
    Validate cold-start costs, then extend per-access device updates, bus arbitration, and timer/IRQ delays.
 3. Validate keypad retrigger behavior with hardware tests and add remaining device registers; extend BIOS reset coverage as sound/serial support becomes available.
    Validate STOP entry/wake edges and add external wake sources and remaining DMA device modes.

docs/testing.md

@@ -265,6 +265,11 @@ They use independent N/S tables across every ROM window and wait setting, includ
 They check timed/untimed equivalence, clones, IRQ/DMA composition, repeated transfers, PC-load refills, failed steps, and cold-start policy.
 Page/wait-window crossings, masked IRQs, host/HALT isolation, and pre-write WAITCNT settings retain separate checks.
 See [persistent fetch access kinds](research/fetch-access-sequencing.md) for evidence and public-report changes.
+Timing-event tests inspect source/data/internal/refill order and metadata independently of aggregate cycle costs.
+They cover the full LDM register list, PC loads, Thumb POP, state changes, skipped branches, swaps, shifts, and IRQ entry.
+WAITCNT snapshots, late failure rollback, deferred fetch errors, and host/untimed/DMA isolation have separate checks.
+Test-only event logs do not add a production allocation or a public trace API.
+See [prefetch prerequisites](research/gamepak-prefetch.md); these tests do not establish an active Game Pak prefetch implementation.
 Instruction timing tests cover arithmetic, shifts, branches, transfers, block operations, multiply, and exception returns.
 Timed and untimed execution are compared across all 65,536 Thumb encodings with fixed initial registers.
 Timer/IRQ tests verify that changing WAITCNT changes when an interrupt is sampled.