Frame timing

[Ian]

I think it's only daytona on the edge which will crash, but it's not easy making it crash unfortunately for a save state

Wouldn't it be easier debugging something like the scud test menu with just the car as an absolute minimal example? Trying to plough through the main game loop in assembly must be, an uphill struggle.

[Bart]

The likelihood of a crash could probably be increased by decreasing the PowerPC frequency (resulting in less time to build a complete frame).

Re: the test menu, that's a good idea. I was under the impression that it might still be hooked into the main game loop. For example, even the 2D cinematic sequence in Scud Race Plus appears to be driven by the main loop. I guess I'll have to see.

[Ian]

speaking of the test menu, how do we get it back with the current rom loading code ?

[HarryTuttle]

speaking of the test menu, how do we get it back with the current rom loading code ?

Code: Select all

  <game name="scud">
.
.
.
    <roms>
      <patches>
        <!-- Secret debug menu -->
        <patch region="crom" bits="32" offset="0x199DE8" value="0x00050208" />
      </patches>
.
.
.


[Ian]

thanks Harry

[Ian]

Bart,
I did a bit of poking around with frame timing (again). Looking this time only at the 2D rolling start bug. The rolling start bug exists as far as I can tell because we draw the frame at the wrong time The scroll values should apply to the next frame, instead they apply to the current one.

Anyway,
I put a bit of code in there to see where in the frame time the memory updates happen as a % of the frame time.

Code: Select all

UINT64 fStart = 0;
UINT64 fEnd = 0;

void CModel3::RunMainBoardFrame(void) {
  fStart = ppc_total_cycles();
  fEnd = ppc_total_cycles() + frameCycles;

void CTileGen::WriteRAM32(unsigned addr, UINT32 data) {
   double timeP = (double)(ppc_total_cycles() - fStart) / (fEnd - fStart) * 100;
   printf("addr %x %lf\n", addr, timeP);


addr f88a8 0.111960
**truncated**
addr f84c4 0.620400
regs 60 80000000 0.624960
regs 64 80008000 0.625800
regs 68 80000000 0.626640
regs 6c 80000000 0.627480
regs 10 2 0.697920
regs c 3 0.702120
regs 10 4 2.651041
regs 10 8 2.654281 <- swap buffers should happen here before the scroll values are updated
addr f6580 5.467364
**truncated**
addr f65e0 5.478884
swap buffers

So the scroll values are written at 5.4% of the frame time .. Hmm that looks like the status change value.
Okay so I'll change the status change value and reboot the game

I changed the status change value to
statusCycles = (unsigned)((float)frameCycles * 10.5f/100.0f);

Now I get ..

addr f88a8 0.111960
**truncated**
addr f84c4 0.620400
regs 60 80000000 0.624960
regs 64 80008000 0.625800
regs 68 80000000 0.626640
regs 6c 80000000 0.627480
regs 10 2 0.697920
regs c 3 0.702120
regs 10 4 2.651041
regs 10 8 2.654281 <- swap buffers should happen here before the scroll values are updated
addr f6580 10.467364
**truncated**
addr f65e0 10.478884
swap buffers

Okay one last time, let's change it to
statusCycles = (unsigned)((float)frameCycles * 20.5f/100.0f);

Now the results are

addr f88a8 0.111960
**truncated**
addr f84c4 0.620400
regs 60 80000000 0.624960
regs 64 80008000 0.625800
regs 68 80000000 0.626640
regs 6c 80000000 0.627480
regs 10 2 0.697920
regs c 3 0.702120
regs 10 4 2.651041
regs 10 8 2.654281 <- swap buffers should happen here before the scroll values are updated
addr f6580 20.467364
**truncated**
addr f65e0 20.478884
swap buffers

The timing of the memory writes seem to be directly related to the status change bit, and if I was to guess it is probably simply the v-blank interval.

Mame uses this

Code: Select all

READ64_MEMBER(model3_state::real3d_status_r)
{
   m_real3d_status ^= 0xffffffffffffffffU;
   if (offset == 0)
   {
      /* pretty sure this is VBLANK */
      m_real3d_status &= ~0x0000000200000000U;
      if (m_screen->vblank())
         m_real3d_status |= 0x0000000200000000U;
      return m_real3d_status;
   }
   return m_real3d_status;
}

I am pretty sure that must be correct ...

[Bart]

Good find. I think this is indeed correct. It does not make sense at all for the tile generator VRAM area to be touched during the active frame. Doing so was commonly done for various special effects on 16-bit and earlier consoles but it's clearly not correct on Model 3.

I took a look at what we are currently doing and realized these are hacks designed to make the games run at the correct speed. Fighting Vipers 2 in particular was a weird one. Right now, our VBL period is way too short. 2.5% of frame time makes no sense. It should be much larger (an order of magnitude I would think). There were also some issues with Daytona 2 not transferring completed scene graphs if the VBL period was too long.

The question is: when is the Real3D chip doing its rendering? My guess is that it needs more time to prepare a frame than the VBL period alone. If the games are syncing to VBL, I would guess that they compute game logic during the active part of the frame and then transfer over the updated scene graph after VBL starts. But if the GPU takes longer than VBL to render a frame, it is already busy rendering the next frame. I'm guessing that when the next frame starts, the Real3D swaps the ping pong buffers and gets busy rendering a new frame, while it displays the frame buffer from the last update.

When I ran code on the actual board, I noticed that numerous IRQs were firing once per frame but I wasn't able to determine whether they were firing at the same time in the frame. From what I've seen of the game code, it doesn't seem like it matters much because most logic is driven off a single IRQ which I take to be the VBL IRQ.

[Ian]

If you look closer at what I posted, you'll see most of the tile gen data is written right at the start of a frame
But only the scroll values are delayed with regards to v-blank. No idea why it's like that but I assume the scroll values we are using in the wrong frame

[Bart]

Correct me if I am wrong but if you look at RunMainBoardFrame(), we actually run the VBL first. Would be more logical (for anyone reading the code) to have it at the end but the effect is the same. The VBL IRQ is generated immediately at what you are marking as "beginning of frame". My guess is that the VBL IRQ is happening, and that the code to transfer data to the tile gen is synced to this. The code to write the scroll RAM, for whatever reason, is using the VBL status bit to detect VBL, but we flip this much later.

In your testing, the VBL status bit is tripped 5% into the frame, counting from beginning of VBL actually because of how I laid out the code. But with a few hard-coded exceptions, VBL is only 2.5% of the frame, so indeed, we've already drawn the frame by the time scroll is updated...

We should lengthen VBL as well as synchronize it to the status bit. But I predict that this will break timing in many games, namely Fighting Vipers 2.

[Ian]

I see we are running VBL first and I agree it shouldn't matter if it's at the start or at the end.
But what triggers 'vbl'? The IRQ that gets called? Because calling it after 'VBL' doesn't seem to make any difference

It would be interesting to find out what the correct VBL time actually is. Maybe the guys that did the model2 project would know, I am sure the value is similar for that, given they both use the crazy 57.5 fps.