Major performance improvements

.cargo/config.toml

@@ -0,0 +1,3 @@
+[profile.profiling]
+inherits = "release"
+debug = true

Cargo.lock

@@ -136,10 +136,60 @@ dependencies = [
 ]
 
 [[package]]
-name = "anyhow"
+name = "anstream"
-version = "1.0.102"
+version = "1.0.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "7f202df86484c868dbad7eaa557ef785d5c66295e41b460ef922eca0723b842c"
+checksum = "824a212faf96e9acacdbd09febd34438f8f711fb84e09a8916013cd7815ca28d"
+dependencies = [
+ "anstyle",
+ "anstyle-parse",
+ "anstyle-query",
+ "anstyle-wincon",
+ "colorchoice",
+ "is_terminal_polyfill",
+ "utf8parse",
+]
+
+[[package]]
+name = "anstyle"
+version = "1.0.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "940b3a0ca603d1eade50a4846a2afffd5ef57a9feac2c0e2ec2e14f9ead76000"
+
+[[package]]
+name = "anstyle-parse"
+version = "1.0.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "52ce7f38b242319f7cabaa6813055467063ecdc9d355bbb4ce0c68908cd8130e"
+dependencies = [
+ "utf8parse",
+]
+
+[[package]]
+name = "anstyle-query"
+version = "1.1.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "40c48f72fd53cd289104fc64099abca73db4166ad86ea0b4341abe65af83dadc"
+dependencies = [
+ "windows-sys 0.61.2",
+]
+
+[[package]]
+name = "anstyle-wincon"
+version = "3.0.11"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "291e6a250ff86cd4a820112fb8898808a366d8f9f58ce16d1f538353ad55747d"
+dependencies = [
+ "anstyle",
+ "once_cell_polyfill",
+ "windows-sys 0.61.2",
+]
+
+[[package]]
+name = "anyhow"
+version = "1.0.103"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2a4385e2e34eb35d6b3efe798b9eb88096925d87726c0798709bf56d9ed84af3"
 
 [[package]]
 name = "arbitrary"
@@ -624,6 +674,46 @@ dependencies = [
  "windows-link",
 ]
 
+[[package]]
+name = "clap"
+version = "4.6.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1ddb117e43bbf7dacf0a4190fef4d345b9bad68dfc649cb349e7d17d28428e51"
+dependencies = [
+ "clap_builder",
+ "clap_derive",
+]
+
+[[package]]
+name = "clap_builder"
+version = "4.6.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "714a53001bf66416adb0e2ef5ac857140e7dc3a0c48fb28b2f10762fc4b5069f"
+dependencies = [
+ "anstream",
+ "anstyle",
+ "clap_lex",
+ "strsim",
+]
+
+[[package]]
+name = "clap_derive"
+version = "4.6.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f2ce8604710f6733aa641a2b3731eaa1e8b3d9973d5e3565da11800813f997a9"
+dependencies = [
+ "heck 0.5.0",
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "clap_lex"
+version = "1.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "c8d4a3bb8b1e0c1050499d1815f5ab16d04f0959b233085fb31653fbfc9d98f9"
+
 [[package]]
 name = "clipboard-win"
 version = "5.4.1"
@@ -680,6 +770,12 @@ version = "1.1.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "3d7b894f5411737b7867f4827955924d7c254fc9f4d91a6aad6b097804b1018b"
 
+[[package]]
+name = "colorchoice"
+version = "1.0.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1d07550c9036bf2ae0c684c4297d503f838287c83c53686d05370d0e139ae570"
+
 [[package]]
 name = "combine"
 version = "4.6.7"
@@ -1865,6 +1961,12 @@ dependencies = [
  "syn",
 ]
 
+[[package]]
+name = "is_terminal_polyfill"
+version = "1.70.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "a6cb138bb79a146c1bd460005623e142ef0181e3d0219cb493e02f7d08a35695"
+
 [[package]]
 name = "itertools"
 version = "0.14.0"
@@ -2387,8 +2489,10 @@ dependencies = [
 name = "nes-emu"
 version = "0.1.0"
 dependencies = [
+ "anyhow",
  "bitfield",
  "bytes",
+ "clap",
  "console_error_panic_hook",
  "console_log",
  "cpal",
@@ -2930,6 +3034,12 @@ version = "1.21.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "9f7c3e4beb33f85d45ae3e3a1792185706c8e16d043238c593331cc7cd313b50"
 
+[[package]]
+name = "once_cell_polyfill"
+version = "1.70.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "384b8ab6d37215f3c5301a95a4accb5d64aa607f1fcb26a11b5303878451b4fe"
+
 [[package]]
 name = "orbclient"
 version = "0.3.51"
@@ -3900,6 +4010,12 @@ version = "0.1.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "6637bab7722d379c8b41ba849228d680cc12d0a45ba1fa2b48f2a30577a06731"
 
+[[package]]
+name = "strsim"
+version = "0.11.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7da8b5736845d9f2fcb837ea5d9e2628564b3b043a70948a3f0b778838c5fb4f"
+
 [[package]]
 name = "svg_fmt"
 version = "0.4.5"
@@ -4269,6 +4385,12 @@ version = "0.2.6"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "ebc1c04c71510c7f702b52b7c350734c9ff1295c464a03335b00bb84fc54f853"
 
+[[package]]
+name = "utf8parse"
+version = "0.2.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821"
+
 [[package]]
 name = "uuid"
 version = "1.23.0"

Cargo.toml

@@ -39,6 +39,8 @@ ringbuf = { version = "0.4.8", optional = true}
 rfd = { version = "0.17.2", optional = true }
 tokio = { version = "1.48.0", features = [], optional = true }
 log = "*"
+anyhow = "1.0.103"
+clap = { version = "4.6.1", features = ["derive"] }
 
 [dependencies.iced]
 git = "https://github.com/the10thWiz/iced"
@@ -57,3 +59,7 @@ required-features = ["iced", "rfd", "audio"]
 [[bin]]
 name = "wasm"
 required-features = ["web"]
+
+[[bin]]
+name = "bench"
+required-features = ["fs"]

profile.fish

@@ -0,0 +1,3 @@
+#!/usr/bin/fish
+
+cargo build --profile profiling --bin bench --features fs && samply record ./target/profiling/bench ../Downloads/Legend\ of\ Zelda,\ The\ \(USA\).nes --frames 10000

src/bin/bench/main.rs

@@ -0,0 +1,47 @@
+use std::{path::PathBuf, time::Instant};
+
+use nes_emu::{Break, NES};
+use tracing_subscriber::EnvFilter;
+use clap::Parser;
+
+extern crate nes_emu;
+
+#[derive(Parser)]
+#[command(version, about)]
+struct Args {
+    file: PathBuf,
+    #[arg(short, long)]
+    frames: Option<usize>,
+}
+
+fn main() -> Result<(), anyhow::Error> {
+    tracing_subscriber::fmt()
+        .with_env_filter(EnvFilter::from_default_env())
+        .init();
+    let args = Args::parse();
+
+    if let Some(frames) = args.frames {
+        println!("Running {frames} frames of {} as fast as possible", args.file.display());
+    } else {
+        println!("Running {} as fast as possible", args.file.display());
+    }
+    let mut n = NES::load_nes_file(args.file).unwrap();
+    n.reset();
+
+    let start = Instant::now();
+    let mut cur = 0;
+    loop {
+        while !n.halted() && !n.run_one_clock_cycle(&Break::default()).ppu_frame {
+        }
+        n.apu_mut().reset_frame_samples();
+        cur += 1;
+        if args.frames.is_some_and(|f| f < cur) {
+            let time = start.elapsed();
+            println!("Completed {} in {}s", cur, time.as_secs_f64());
+            println!("~= {} fps", cur as f64 / time.as_secs_f64());
+            break Ok(());
+        }
+        // TODO: update currently held button in controller
+    }
+    // Ok(())
+}

src/bin/native/audio.rs

@@ -25,6 +25,7 @@ pub struct Audio {
     last: usize,
     max: usize,
     paused: Arc<AtomicBool>,
+    kill: Arc<AtomicBool>,
 }
 
 impl Audio {
@@ -39,12 +40,14 @@ impl Audio {
         let (prod, mut cons) = SharedRb::new(BUFFER_SIZE * 1024 * 1024).split();
         let paused = Arc::new(AtomicBool::new(true));
         let paused_inner = Arc::clone(&paused);
+        let kill = Arc::new(AtomicBool::new(false));
+        let kill_inner = Arc::clone(&kill);
 
         let stream = device
             .build_output_stream(
                 &cpal::StreamConfig {
                     channels: 1,
-                    sample_rate: 60 * 3723,
+                    sample_rate: 60 * 3722,
                     buffer_size: cpal::BufferSize::Fixed(BUFFER_SIZE as FrameCount),
                 },
                 move |a: &mut [u8], _b| {
@@ -53,7 +56,12 @@ impl Audio {
                         a[taken..].fill(128);
                     }
                 },
-                |e| eprintln!("Audio: {e}"),
+                move |e| {
+                    eprintln!("Audio: {e}");
+                    if e == cpal::StreamError::BufferUnderrun {
+                        kill_inner.store(true, std::sync::atomic::Ordering::Release);
+                    }
+                },
                 None,
             )
             .unwrap();
@@ -64,6 +72,7 @@ impl Audio {
             _stream: stream,
             rb: prod,
             paused,
+            kill,
             last: 0,
             max: 0,
         }
@@ -74,6 +83,14 @@ impl Audio {
         let _ = self._stream.pause();
     }
 
+    pub fn killed(&self) -> bool {
+        self.kill.load(std::sync::atomic::Ordering::Acquire)
+    }
+
+    pub fn occupied(&self) -> usize {
+        self.rb.occupied_len()
+    }
+
     pub fn submit(&mut self, samples: &[u8]) {
         let start = self.rb.occupied_len();
         self.max = self.max.max(self.last - start);

src/bin/native/debugger.rs

@@ -233,7 +233,6 @@ impl DebuggerState {
                     column(
                         nes.debug_log()
                             .history()
-                            .into_iter()
                             .rev()
                             .map(|s| text(s).line_height(0.9).into())
                     )

src/bin/native/main.rs

@@ -5,17 +5,9 @@ use std::{
 };
 
 use iced::{
-    Element,
+    exit, keyboard::{self, key::Named, Key, Modifiers}, mouse, time, widget::{
-    Length::{Fill, Shrink},
+        self, button, canvas::{Frame, Program}, column, container, image, row, Canvas
-    Point, Rectangle, Renderer, Size, Subscription, Task, Theme,
+    }, window::{self, Id, Settings}, Element, Length::{Fill, Shrink}, Point, Rectangle, Renderer, Size, Subscription, Task, Theme
-    keyboard::{self, Key, Modifiers, key::Named},
-    mouse, time,
-    widget::{
-        self, Canvas, button,
-        canvas::{Frame, Program},
-        column, container, image, row,
-    },
-    window::{self, Id, Settings},
 };
 use nes_emu::{
     Break, NES,
@@ -313,6 +305,8 @@ impl Emulator {
                 } => {
                     if val == "t" {
                         self.nes.reset();
+                    } else if val == "q" {
+                        return exit();
                     }
                 }
                 keyboard::Event::KeyPressed {
@@ -377,6 +371,10 @@ impl Emulator {
             },
             Message::Periodic(_i) => {
                 if self.running {
+                    // Better idea: audio-controlled timing. Increase timing frequency, but we only run long enough
+                    // to keep the audio buffer full.
+                    // We'd likely need some kind of double-buffering for ppu output
+                    
                     // TODO: Smarter frame skip
                     if self.prev[0].elapsed() >= Duration::from_millis(2) {
                         self.nes.run_one_clock_cycle(&Break::default());
@@ -391,7 +389,8 @@ impl Emulator {
                             }
                         }
                         self.prev[0] = Instant::now();
-                        self.audio.submit(self.nes.apu().get_frame_samples());
+                        let samples = self.nes.apu().get_frame_samples();
+                        self.audio.submit(&samples[..samples.len().min(3722)]);
                         self.nes.apu_mut().reset_frame_samples();
                     }
                 } else {

src/cpu.rs

@@ -263,7 +263,9 @@ impl Cpu {
                 } else {
                     // debug!("Running 0x{:04X} {} :{:X} {:X?}", self.pc - (1 + params.len() as u16), $val, ins, params);
                     // debug!("Running 0x{:04X} {} :{:X} {:X?}", self.pc - (1 + params.len() as u16), $val, ins, params);
-                    self.last_instruction = format!("0x{:04X} {} :{:X} {:X?}", addr, $val, ins, params);
+                    if self.debug_log.enabled() {
+                        self.last_instruction = format!("0x{:04X} {} :{:X} {:X?}", addr, $val, ins, params);
+                    }
                     $(
                         let $name = params[0];
                         #[allow(unused_assignments)]

src/debug.rs

@@ -1,10 +1,13 @@
 // use std::num::NonZeroUsize;
 
+use std::collections::VecDeque;
+
 #[derive(Debug, Clone)]
 pub struct DebugLog {
     enabled: bool,
     current: String,
-    history: Vec<String>,
+    history: VecDeque<String>,
+    size: usize,
     // max_history: Option<NonZeroUsize>,
     // pos: usize,
 }
@@ -14,7 +17,8 @@ impl DebugLog {
         Self {
             enabled: false,
             current: String::new(),
-            history: vec![],
+            history: VecDeque::new(),
+            size: 0,
             // max_history: None,
             // pos: 0,
         }
@@ -24,30 +28,24 @@ impl DebugLog {
         // if self.current.len() > 500 {
         let mut rot = std::mem::take(&mut self.current);
         self.current = rot.split_off(rot.rfind('\n').unwrap_or(rot.len()));
-        // if let Some(max) = self.max_history {
+        self.size += rot.len();
-        //     if self.history.len() < max.into() {
-        //         self.history.extend(rot.lines().map(|s| s.to_owned()));
-        //     } else {
-        //         self.history[self.pos] = rot;
-        //         self.pos = (self.pos + 1) % max.get();
-        //     }
-        // } else {
-        // self.history.push(rot);
         self.history.extend(rot.lines().map(|s| s.to_owned()));
-        // }
+        while self.history.len() > 200 {
-        // }
+            self.size -= self.history.pop_front().map_or(0, |s| s.len());
+        }
     }
 
     // pub fn current(&self) -> &str {
     //     &self.current
     // }
 
-    pub fn history(&self) -> &[String] {
+    pub fn history(&self) -> impl Iterator<Item = &str> + DoubleEndedIterator {
-        &self.history[self.history.len().saturating_sub(100)..]
+        self.history.iter().map(|i| i.as_str())
+        // &self.history[self.history.len().saturating_sub(100)..]
     }
 
     pub fn pop(&mut self) -> Option<String> {
-        self.history.pop()
+        self.history.pop_back()
     }
 
     pub fn enable(&mut self) {

src/lib.rs

@@ -345,7 +345,7 @@ impl NES {
     }
 
     pub fn image(&self) -> &RenderBuffer<256, 240> {
-        &self.ppu.render_buffer
+        &self.ppu.render_buffer_b
     }
 
     pub fn cpu(&self) -> &Cpu {

src/ppu.rs

@@ -242,7 +242,8 @@ impl OAM {
                         } else {
                             0x0000
                         } + 16 * (self.sprite_output_units[run / 8].tile & !1) as u16
-                            + off as u16 + if off > 7 { 8 } else { 0 })
+                            + off as u16
+                            + if off > 7 { 8 } else { 0 })
                     } else {
                         let off = if self.sprite_output_units[run / 8].attrs.vflip() {
                             7 - off
@@ -704,7 +705,10 @@ pub struct PPU {
     pub palette: Palette,
     pub background: Background,
     pub oam: OAM,
-    pub render_buffer: RenderBuffer<256, 240>,
+    /// Current render buffer
+    pub render_buffer_a: RenderBuffer<256, 240>,
+    /// Output buffer (not rendering to)
+    pub render_buffer_b: RenderBuffer<256, 240>,
     pub dbg_int: bool,
     pub cycle: usize,
 }
@@ -761,7 +765,8 @@ impl PPU {
             even: false,
             scanline: 0,
             pixel: 25,
-            render_buffer: RenderBuffer::empty(),
+            render_buffer_a: RenderBuffer::empty(),
+            render_buffer_b: RenderBuffer::empty(),
             background: Background {
                 v: 0,
                 t: 0,
@@ -953,9 +958,15 @@ impl PPU {
                     self.background.v = (self.background.v & 0b0000_0100_0001_1111)
                         | (self.background.t & 0b0111_1011_1110_0000);
                 }
-                if self.scanline != 261 {
+                self.oam.ppu_cycle(
-                    self.oam.ppu_cycle(self.pixel, self.scanline, mem);
+                    self.pixel,
-                }
+                    if self.scanline == 261 {
+                        0
+                    } else {
+                        self.scanline - 1
+                    },
+                    mem,
+                );
                 if self.pixel == 0 {
                     if self.scanline == 1 {
                         // let h_scroll_offset = self.background.x as usize + ((self.background.t as usize & 0b11) << 3);
@@ -1004,7 +1015,7 @@ impl PPU {
                             bg_color
                         };
                         // Write to screen
-                        self.render_buffer.write(
+                        self.render_buffer_a.write(
                             self.scanline,
                             self.pixel - 1,
                             self.palette.color(color),
@@ -1112,6 +1123,7 @@ impl PPU {
         }
         if self.scanline == 241 && self.pixel == 1 {
             self.vblank = true;
+            std::mem::swap(&mut self.render_buffer_a, &mut self.render_buffer_b);
             return true;
         }
         return false;