Merge pull request #86 from agbrs/mgba-test-runner-cycles

Mgba test runner cycles

.github/workflows/rust.yml

@@ -28,7 +28,7 @@ jobs:
         key: ${{ runner.os }}-cargo-${{ hashFiles('**/Cargo.lock') }}
 
     - name: install mgba-test-runner
-      run: cargo install --path mgba-test-runner
+      run: cargo install --path mgba-test-runner --verbose
     - name: Build agb library
       working-directory: agb
       run: cargo build --verbose
@@ -38,7 +38,10 @@ jobs:
     - name: Run Clippy on agb image converter
       working-directory: agb-image-converter
       run: cargo clippy --verbose
-    - name: Run Tests for agb
+    - name: Run Tests for agb in debug mode
       working-directory: agb
       run: cargo test --verbose
+    - name: Run Tests for agb in release mode
+      working-directory: agb
+      run: cargo test --verbose --release
       

agb/Cargo.toml

@@ -7,11 +7,10 @@ description = "Library for Game Boy Advance Development"
 license = "MPL-2.0"
 
 [profile.dev]
-opt-level = 0
+opt-level = 3
 debug = true
 
 [profile.release]
-panic = "abort"
 lto = true
 
 

agb/src/lib.rs

@@ -89,7 +89,9 @@ where
             mgba::DebugLevel::Info,
         )
         .unwrap();
+        mgba::number_of_cycles_tagged(785);
         self(gba);
+        mgba::number_of_cycles_tagged(785);
         mgba.print(format_args!("[ok]"), mgba::DebugLevel::Info)
             .unwrap();
     }
@@ -138,6 +140,8 @@ pub extern "C" fn main() -> ! {
 
 #[cfg(test)]
 fn assert_image_output(image: &str) {
+    display::busy_wait_for_VBlank();
+    display::busy_wait_for_VBlank();
     let mut mgba = crate::mgba::Mgba::new().unwrap();
     mgba.print(
         format_args!("image:{}", image),

agb/src/mgba.rs

@@ -26,6 +26,12 @@ fn is_running_in_mgba() -> bool {
     DEBUG_ENABLE.get() == ENABLE_HANDSHAKE_OUT
 }
 
+const NUMBER_OF_CYCLES: MemoryMapped<u16> = unsafe { MemoryMapped::new(0x04FF_F800) };
+
+pub fn number_of_cycles_tagged(tag: u16) {
+    NUMBER_OF_CYCLES.set(tag)
+}
+
 pub struct Mgba {
     bytes_written: usize,
 }

mgba-test-runner/Cargo.toml

@@ -6,6 +6,9 @@ edition = "2018"
 
 # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
 
+[profile.release]
+debug = true
+
 [dependencies]
 regex = "1"
 anyhow = "1.0"

mgba-test-runner/add_cycles_register.patch

@@ -0,0 +1,40 @@
+diff --git a/include/mgba/internal/gba/io.h b/include/mgba/internal/gba/io.h
+index 9875061f3..bdeafdcd3 100644
+--- a/include/mgba/internal/gba/io.h
++++ b/include/mgba/internal/gba/io.h
+@@ -157,6 +157,7 @@ enum GBAIORegisters {
+ 	REG_DEBUG_STRING = 0xFFF600,
+ 	REG_DEBUG_FLAGS = 0xFFF700,
+ 	REG_DEBUG_ENABLE = 0xFFF780,
++	REG_DEBUG_CYCLES = 0xFFF800,
+ };
+ 
+ mLOG_DECLARE_CATEGORY(GBA_IO);
+diff --git a/src/gba/io.c b/src/gba/io.c
+index cc39e1192..d34dcb4b4 100644
+--- a/src/gba/io.c
++++ b/src/gba/io.c
+@@ -573,6 +573,11 @@ void GBAIOWrite(struct GBA* gba, uint32_t address, uint16_t value) {
+ 	case REG_DEBUG_ENABLE:
+ 		gba->debug = value == 0xC0DE;
+ 		return;
++	case REG_DEBUG_CYCLES: {
++		int32_t number_of_cycles = mTimingCurrentTime(&gba->timing);
++		mLOG(GBA_DEBUG, INFO, "Cycles: %d Tag: %d", number_of_cycles, value);
++		return;
++	}
+ 	case REG_DEBUG_FLAGS:
+ 		if (gba->debug) {
+ 			GBADebug(gba, value);
+@@ -936,6 +941,11 @@ uint16_t GBAIORead(struct GBA* gba, uint32_t address) {
+ 			return 0x1DEA;
+ 		}
+ 		// Fall through
++	case REG_DEBUG_CYCLES: {
++		int32_t number_of_cycles = mTimingCurrentTime(&gba->timing);
++		mLOG(GBA_DEBUG, INFO, "Cycles: %d", number_of_cycles);
++		return number_of_cycles;
++	}
+ 	default:
+ 		mLOG(GBA_IO, GAME_ERROR, "Read from unused I/O register: %03X", address);
+ 		return GBALoadBad(gba->cpu);

mgba-test-runner/build-mgba.sh

@@ -2,12 +2,14 @@
 
 MGBA_VERSION=$1
 OUT_DIRECTORY=$2
+CURRENT_DIRECTORY=$(pwd)
 
 cd ${OUT_DIRECTORY}
 curl -L https://github.com/mgba-emu/mgba/archive/refs/tags/${MGBA_VERSION}.tar.gz -o mgba-${MGBA_VERSION}.tar.gz
 tar -xvf mgba-${MGBA_VERSION}.tar.gz
 cd mgba-${MGBA_VERSION}
 rm -rf build
+patch --strip=1 < ${CURRENT_DIRECTORY}/add_cycles_register.patch
 mkdir -p build
 cd build
 cmake .. \
@@ -29,6 +31,7 @@ cmake .. \
 	-DUSE_LZMA=OFF \
 	-DUSE_DISCORD_RPC=OFF \
 	-DENABLE_SCRIPTING=OFF \
+	-DCMAKE_BUILD_TYPE=Debug \
     -DUSE_EPOXY=OFF
 make
 

mgba-test-runner/build.rs

@@ -19,6 +19,7 @@ fn main() {
         .file("c/test-runner.c")
         .include(&mgba_directory.join("include"))
         .static_flag(true)
+        .debug(true)
         .compile("test-runner");
 
     let bindings = bindgen::Builder::default()
@@ -29,4 +30,9 @@ fn main() {
     bindings
         .write_to_file(&out_path.join("runner-bindings.rs"))
         .expect("Couldn't write bindings!");
+
+    println!("cargo:rerun-if-changed=c/test-runner.c");
+    println!("cargo:rerun-if-changed=c/test-runner.h");
+    println!("cargo:rerun-if-changed=build-mgba.sh");
+    println!("cargo:rerun-if-changed=add_cycles_register.patch");
 }

mgba-test-runner/c/test-runner.c

@@ -19,7 +19,7 @@ struct MGBA {
 };
 
 struct MGBA* new_runner(char* filename) {
-    struct MGBA* mgba = malloc(sizeof(struct MGBA));
+    struct MGBA* mgba = calloc(1, sizeof(struct MGBA));
     mgba->mlogger.log = log_output;
     mgba->callback.callback = NULL;
 

mgba-test-runner/src/main.rs

@@ -16,12 +16,22 @@ enum Status {
     Sucess,
 }
 
+enum Timing {
+    None,
+    WaitFor(i32),
+    Difference(i32),
+}
+
+const TEST_RUNNER_TAG: u16 = 785;
+
 fn test_file(file_to_run: &str) -> Status {
     let mut finished = Status::Running;
     let debug_reader_mutex = Regex::new(r"(?s)^\[(.*)\] GBA Debug: (.*)$").unwrap();
+    let tagged_cycles_reader = Regex::new(r"Cycles: (\d*) Tag: (\d*)").unwrap();
 
     let mut mgba = runner::MGBA::new(file_to_run).unwrap();
     let video_buffer = mgba.get_video_buffer();
+    let mut number_of_cycles = Timing::None;
 
     mgba.set_logger(|message| {
         if let Some(captures) = debug_reader_mutex.captures(message) {
@@ -41,6 +51,29 @@ fn test_file(file_to_run: &str) -> Status {
             } else if out.ends_with("...") {
                 print!("{}", out);
                 io::stdout().flush().expect("can't flush stdout");
+            } else if out.starts_with("Cycles: ") {
+                if let Some(captures) = tagged_cycles_reader.captures(out) {
+                    let num_cycles: i32 = captures[1].parse().unwrap();
+                    let tag: u16 = captures[2].parse().unwrap();
+
+                    if tag == TEST_RUNNER_TAG {
+                        number_of_cycles = match number_of_cycles {
+                            Timing::WaitFor(n) => Timing::Difference(num_cycles - n),
+                            Timing::None => Timing::WaitFor(num_cycles),
+                            Timing::Difference(_) => Timing::WaitFor(num_cycles),
+                        };
+                    }
+                }
+            } else if out == "[ok]" {
+                if let Timing::Difference(cycles) = number_of_cycles {
+                    println!(
+                        "[ok: {} c ≈ {} s]",
+                        cycles,
+                        ((cycles as f64 / (16.78 * 1_000_000.0)) * 100.0).round() / 100.0
+                    );
+                } else {
+                    println!("{}", out);
+                }
             } else {
                 println!("{}", out);
             }