Measuring lag, spare cycles in Mesen

Discuss technical or other issues relating to programming the Nintendo Entertainment System, Famicom, or compatible systems. See the NESdev wiki for more information.

Moderator: Moderators

Post Reply
samwise970
Posts: 24
Joined: Tue Oct 17, 2017 12:13 am

Measuring lag, spare cycles in Mesen

Post by samwise970 »

I was testing a poorly implemented sprite flicker routine on my laptop today, and I noticed FCEUX dropped down to 55fps, so I loaded up SMB3 and it was at 60.

When I got home, I ran my rom on my desktop in Mesen, and it showed a solid 60. I turned the lag counter on and it didn't seem to be missing any inputs.

This leads me to wondering, when building a game, how do you guys know when you're pushing against the limits of the system? Are you just turning on the lag counter and making your code more efficient once you start missing inputs? Is there a better way to measure how many CPU cycles I have "left" between the end of my loop and NMI? The sprite flicker routine comes after my controller reading so I wonder if that's causing me to miss something, maybe I should read the controller at the end of my main loop?

I'm new to using Mesen in general, and don't have any Lua experience. Is there a script anyone uses to determine how many cycles you have to work with? Not trying to get others to do my work, just wondering if there's a rough outline of how to do this.

Thanks kindly!
User avatar
tokumaru
Posts: 12427
Joined: Sat Feb 12, 2005 9:43 pm
Location: Rio de Janeiro - Brazil

Re: Measuring lag, spare cycles in Mesen

Post by tokumaru »

I'm pretty sure that the number of frames per second reported by emulators doesn't have anything to do with the logic frames in the emulated program... it merely informs you how close the emulator is to the ideal 60 fps that a real console always outputs, regardless of what the games themselves are doing.

Lag frames are purely a software issue: your game logic is trying to keep up with the hardware's constant frame rate of 60Hz by updating the PPU every single frame, but it's possible that your game logic takes too long to finish and the program isn't ready to update the graphics by the time a new hardware frame starts. Emulators are completely unaware of this though, and will simply render a new frame, even if it looks the same as the previous one, just as the real console would.

If the emulator is reporting frame rate drops, that's probably a performance issue with your PC, not a problem in your NES program.

If you want to count lag frames, you'll have to do it from within your NES program. You can simply count the number of NMIs (i.e. increment a counter somewhere in your NMI handler) and also count the number of times when the NMI handler DOESN'T interrupt the game logic (increment another counter). When the NMI counter reaches 60, the other counter will tell you how many frames your game engine actually processed in a second. You can copy that final value to another variable that you can watch as your frame rate indicator while the program is running. Don't forget to reset both counters when the NMI counter reaches 60.

As for keeping track of how many cycles you have left after your're finished with the game logic, I believe that some emulators have special registers to help you with that, but the old-school way to do this is to set the monochrome and/or emphasis bits of the PPU as soon as the frame calculations are over, and you'll have a clear visual indication of how much time you have to spare.
Sour
Posts: 890
Joined: Sun Feb 07, 2016 6:16 pm

Re: Measuring lag, spare cycles in Mesen

Post by Sour »

This is pretty much exactly what this tool in Mesen allows you to do: http://mesen.ca/docs/debugging/debugger ... ce-tracker
Right-click on a line of code (in the debugger) that runs at the very end of your game logic for a frame and enable the "performance tracker" on it to see a graph of how much of the CPU time per frame that you're using (everything after the instruction you enable the tracker on until the next NMI will be considered to be "idle" cycles and not count towards CPU usage)

Also in general, the profiler can be used to find bottlenecks in your code: http://mesen.ca/docs/debugging/performanceprofiler.html
User avatar
tokumaru
Posts: 12427
Joined: Sat Feb 12, 2005 9:43 pm
Location: Rio de Janeiro - Brazil

Re: Measuring lag, spare cycles in Mesen

Post by tokumaru »

Cool, I didn't know Mesen had a specific tool for this! Do you have to select the end of the game logic every time you reassemble your programs, due to the code moving around?
psycopathicteen
Posts: 3140
Joined: Wed May 19, 2010 6:12 pm

Re: Measuring lag, spare cycles in Mesen

Post by psycopathicteen »

The confusion between the emulator causing the PC to lag, vs emulated hardware lag is one of the reasons why the SNES's CPU has such a bad reputation.
User avatar
tokumaru
Posts: 12427
Joined: Sat Feb 12, 2005 9:43 pm
Location: Rio de Janeiro - Brazil

Re: Measuring lag, spare cycles in Mesen

Post by tokumaru »

Another misconception regarding processing power is when people associate the speed of game characters with the speed of the CPU. I think this started with Sonic on the Genesis, when SEGA suggested that only "blast processing" could move things that fast, while in reality moving an object by 16 pixels is not at all more complex than moving it by only 1 pixel.
tepples
Posts: 22705
Joined: Sun Sep 19, 2004 11:12 pm
Location: NE Indiana, USA (NTSC)
Contact:

Re: Measuring lag, spare cycles in Mesen

Post by tepples »

But if the camera happens to be following the fast-moving object, the engine code has to keep up with dumping a bunch of scroll seam updates into the nametables. The Genesis VDP has a few hardware features to help with that compared to the NES: DMA from work RAM to VRAM, longer vblank, no attribute table with a different memory layout, and a 4-word VRAM write FIFO that can commit up to about 8 words per scanline outside of vertical or forced blanking. I don't seem to remember a lot of NES games that scrolled diagonally at 16 horizontal pixels and 16 vertical pixels per frame, which can be most easily seen in Sonic the Hedgehog 2 Chemical Plant Zone act 2.
samwise970
Posts: 24
Joined: Tue Oct 17, 2017 12:13 am

Re: Measuring lag, spare cycles in Mesen

Post by samwise970 »

Thank you guys for the awesome and helpful responses!

My first assumption was just that it's my crappy laptop, but I guess I was confused when I booted up SMB3, got 60 with no drops, and then booted my rom and got some drops.

When I read about the lag counter in mesen, I thought to test it by playing 1942, a crappy micronics game. No lag frames, but it's common knowledge that game skips frames.

I'll try the debugger, thanks sour! I have the same question as tokumaru regarding reassembly, and might try his way as well.
User avatar
tokumaru
Posts: 12427
Joined: Sat Feb 12, 2005 9:43 pm
Location: Rio de Janeiro - Brazil

Re: Measuring lag, spare cycles in Mesen

Post by tokumaru »

tepples wrote: Thu Mar 12, 2020 12:01 pmI don't seem to remember a lot of NES games that scrolled diagonally at 16 horizontal pixels and 16 vertical pixels per frame
I've coded at least 2 engines that did this on the NES using about 15% of the CPU time, I just never coded the rest of the game around them! :mrgreen:

You definitely don't need any sort of blast processing just to move objects fast and have the camera follow them. As for the rest of the logic, Sonic's physics are quite advanced, but most other objects are pretty dumb, just moving on the ground with no acceleration or not even colliding with the level map at all.

BTW, sorry for the off topic posts!
samwise970
Posts: 24
Joined: Tue Oct 17, 2017 12:13 am

Re: Measuring lag, spare cycles in Mesen

Post by samwise970 »

tokumaru wrote: Thu Mar 12, 2020 3:41 pmBTW, sorry for the off topic posts!
Why? I'm loving this conversation. I always fell for the idea that Sonic was a showcase of the Genesis's faster CPU, and that Super Mario World went in a different direction gameplay wise to compensate for slower clock speeds.
Sour
Posts: 890
Joined: Sun Feb 07, 2016 6:16 pm

Re: Measuring lag, spare cycles in Mesen

Post by Sour »

tokumaru wrote: Thu Mar 12, 2020 8:40 amDo you have to select the end of the game logic every time you reassemble your programs, due to the code moving around?
Yes - the tool just watches a specific address to see when the CPU reaches it. Reloading the ROM will also cause the tool to get turned back off, so you'll need to re-enable it after reassembling. If you're using ca65/asm6f and have label integration turned on, that should be pretty simple though (just put a label in your code at whatever point you want to track performance and navigate back to that label and turn it back on)

RE: frame rate dropping below 60fps in an emulator, an emulator's performance can vary wildly from one game to another, based on what the game does, and which mapper the game uses. e.g MMC5 games are a fair bit slower in Mesen compared to most other mappers. That said, though, getting below 60 fps in anything in FCEUX is fairly odd (although FCEUX does get fairly "slow" if you turn on the new PPU and set the audio quality to highest)
psycopathicteen
Posts: 3140
Joined: Wed May 19, 2010 6:12 pm

Re: Measuring lag, spare cycles in Mesen

Post by psycopathicteen »

samwise970 wrote: Thu Mar 12, 2020 6:22 pm
tokumaru wrote: Thu Mar 12, 2020 3:41 pmBTW, sorry for the off topic posts!
Why? I'm loving this conversation. I always fell for the idea that Sonic was a showcase of the Genesis's faster CPU, and that Super Mario World went in a different direction gameplay wise to compensate for slower clock speeds.
It's more like Nintendo didn't want to be sued for stealing Sega's gameplay idea.

Anyway, the speed difference between the SNES and Genesis has always been a bunch of overblown exaggerated bs. Game companies just hired a bunch of whiny bratty teenagers to program their games who thought they were being "cool" and "edgy" by deliberately giving Nintendo the crappy version of their games.
Last edited by psycopathicteen on Thu Mar 12, 2020 9:06 pm, edited 1 time in total.
samwise970
Posts: 24
Joined: Tue Oct 17, 2017 12:13 am

Re: Measuring lag, spare cycles in Mesen

Post by samwise970 »

Sour wrote: Thu Mar 12, 2020 6:36 pm RE: frame rate dropping below 60fps in an emulator, an emulator's performance can vary wildly from one game to another, based on what the game does, and which mapper the game uses. e.g MMC5 games are a fair bit slower in Mesen compared to most other mappers. That said, though, getting below 60 fps in anything in FCEUX is fairly odd (although FCEUX does get fairly "slow" if you turn on the new PPU and set the audio quality to highest)
It's a 2015 Lenovo with a 2Ghz CPU and 4 gigs of RAM running a clean install of windows 10.

So yeah it's a piece of crap but normally games run at 60 in FCEUX. My 'game' is simply UNROM and there's not much going on at the moment. Player and 6 NPCs 4 sprites each. My animations use lookups so not terribly efficient.

I'm gonna try out the debugger and see what's up.
User avatar
Controllerhead
Posts: 314
Joined: Tue Nov 13, 2018 4:58 am
Location: $4016
Contact:

Re: Measuring lag, spare cycles in Mesen

Post by Controllerhead »

samwise970 wrote: Wed Mar 11, 2020 7:23 pmIs there a better way to measure how many CPU cycles I have "left" between the end of my loop and NMI?...Is there a script anyone uses to determine how many cycles you have to work with?...just wondering if there's a rough outline of how to do this.
Hi! New dev here. I wrote an extra cycle counter:

Image

How does it work?

After game logic is done, i set extra0 and extra1 to 0, JMP to this Forever loop, and wait for NMI. Whilst waiting for NMI, i INCrement those two variables. extra0 increments 256 times until it overflows to 0, Z flag gets set, branch becomes equal, extra1 increments once, and the process repeats. When NMI hits, it interrupts the loop; that's how many extra cycles were in the previous frame. Rinse and repeat every frame.

So it says 0D C6, um, how many cycles is that?

Each extra1 increment takes 2056 cycles, and the leftover extra0 increments take 8 cycles each; extra1 = 0D = 13 decimal; extra0 = C6 = 198; so:
2056 * 13 = 26728
198 * 8 = 1584
So there were (approximately) 28312 extra cycles last frame; Neato!

An NTSC frame is 29780(ish) cycles, so the previous frame used (approximately) 1468 cycles.

I've been using it to measure the speed of different code options for an engine i'll probably never finish. Seems to work well.

Hope this helps!
Image
Post Reply