intermitant clock changes

[ethanpailes]

As I've been playing with this emulator I've noticed that the clock rate seems to jump around. Sometimes the game will slow the a crawl, and other times it runs so fast that it becomes hard to control. I think this may be because my machine isn't that powerful, and it may be missing frame timing (it was taking ~30ms a cpu cycle rather than the target 16 when I threw some prints in there).

I think the following diff might fix things:

diff --git a/src/cpu.rs b/src/cpu.rs
index bb07a5e..80f3556 100644
--- a/src/cpu.rs
+++ b/src/cpu.rs
@@ -1693,7 +1693,7 @@ impl Cpu {
 pub struct Rtc {
     pub cpu: Cpu,
     step_cycles: u32,
-    step_zero: time::SystemTime,
+    step_zero: time::Instant,
     step_flip: bool,
 }

@@ -1703,7 +1703,7 @@ impl Rtc {
         Self {
             cpu,
             step_cycles: 0,
-            step_zero: time::SystemTime::now(),
+            step_zero: time::Instant::now(),
             step_flip: false,
         }
     }
@@ -1713,14 +1713,20 @@ impl Rtc {
         if self.step_cycles > STEP_CYCLES {
             self.step_flip = true;
             self.step_cycles -= STEP_CYCLES;
-            let d = time::SystemTime::now().duration_since(self.step_zero).unwrap();
+            let now = time::Instant::now();
+            let d = now.duration_since(self.step_zero);
             let s = u64::from(STEP_TIME.saturating_sub(d.as_millis() as u32));
             rog::debugln!("CPU: sleep {} millis", s);
             thread::sleep(time::Duration::from_millis(s));
-            self.step_zero = self
-                .step_zero
+            self.step_zero = self.step_zero
                 .checked_add(time::Duration::from_millis(u64::from(STEP_TIME)))
                 .unwrap();
+
+            // If now is after the just updated target frame time, reset to
+            // avoid drift.
+            if now.checked_duration_since(self.step_zero).is_some() {
+                self.step_zero = now;
+            }
         }
         let cycles = self.cpu.next();
         self.step_cycles += cycles;

I don't think switching from SystemTime to monotonic time is actually that important, but I think it is probably the right thing to do here since we are just using this stuff for frame timing and it doesn't really have to relate to the real wallclock time.

But the bug can take a while to manifest, so I can't really confirm yet. I'm going to run an emulator with this patch for a while and update this thread.

[mohanson]

Did you using cargo run --release?

[ethanpailes]

No, I'm not. That's a good suggestion, I'll try it.

I think even if that does resolve my issue it is worth adding a fix to prevent the next target frame time from getting too far out of sync with reality. As things stand I think missing enough frames means that we become willing to "make up for lost time" and run the game at super-speed until we have caught back up with reality.

[ethanpailes]

I kept running my non-optim build for a while in an effort to miss some frames and verify the fix. I added a print to trigger when frames are missed, and I've been able to miss a bunch of frames without getting the speed-up behavior that I was observing before, so I think this patch does fix the issue. I noticed that I often missed frames when I went over to look at some other program, so I think the emulator got suspended for a bit.

Would you object to me turning this patch into a PR, and if not do you have a preference on switching to the monotonic clock?

I'm not really sure how to write an automated test for this fix, so if you have guidance there, that would be awesome! If you don't think this is really testable, I'll just open the PR as-is.

Thanks again for writing this emulator!

[mohanson]

Give me a PR plz. No unit tests are needed, which is difficult to write.

It does sleep for too long on poorly performing machines, I think we can manually add some delay in the CPU::next() to simulate this situation.

I will test this, but at first glance it looks like the right direction.