Emu in process as a learning project - timing help?

Emu in process as a learning project - timing help?
by relaxok on 2018-05-31 (#219254)

Hi all - yes, yet another beginner emu in progress.

I'm comparing my execution against FCEUX trace logs, so that I can be sure I don't have any bugs. I'm using the SMB1 NTSC rom. My problem is where the vblank flag changes (yes, this same old issue..)

I have all the cycle numbers, instruction numbers, registers, flags, and instruction opcode numbers matching the FCEUX trace logger output for the initial 6 instructions and the alternating LDA $2002/BPL $800A all the way up until a flag change happens.

I know vblank flag should be set at scanline 241 / dot 1. To me that first hits at total ppu dots in frame == 82181, and cpu tick 27394/instruction number 7828. I believe that one is skipped.

The next scanline 241/ dot 1 hits at the same ppu dots # in the frame, cpu tick 57174/instruction number 16337.

Therefore the trace log line of instruction 16339 is the first one where the A register changes to 90, e.g. the 0x80 flag is read in. That is my first log diff with FCEUX trace log.

In FCEUX's log, that doesn't happen until the line on cpu tick 59679 / instruction 17053 - so 714 instructions later.

I correctly have a total of 89342 dots per frame.

There's only a handful of instructions running up to that point and the cycle numbers/instruction numbers match, so there must be a bug somehow in the timing but I can't imagine what it would be given there's not much going on.

If anyone can check the math in their own project, I'd appreciate it - I have tried digging around other emulators to breakpoint where this would happen and look at the numbers, but I'm trying to stick with one I can compare trace logs with and I find FCEUX very hard to figure out the code for.

Thanks for your help..
-rel

Re: Emu in process as a learning project - timing help?
by Sour on 2018-06-01 (#219291)

relaxok wrote:

In FCEUX's log, that doesn't happen until the line on cpu tick 59679 / instruction 17053 - so 714 instructions later.

FCEUX is probably not the best emulator to be using to compare trace logs when it comes to the PPU's timing vs CPU. It's great for many things, but you shouldn't use it as your reference if you're trying to match the exact timings of the NES.

Mesen & Nintendulator both reach the instruction after the 2nd $2002 read loop ("8014 $A0 $FE LDY #$FE") at almost the same time (~57174 cpu cycles), which is essentially what you said you were expecting it to be. Bizhawk also has a trace logger (iirc) and should be essentially as accurate as those two, too.

Mesen's trace logger allows you to customize the trace log's output to be more or less whatever you need it to be, so that might help you if your trace log format is similar to FCEUX's, for example. This is a new feature that I just added, so you'll need to download this build if you want to try it out. If you're trying to debug your emulator, Mesen's debugging tools should be pretty useful in general, so you may want to take a look, if you have not yet. (Disclaimer: I'm Mesen's author, but I'm definitely not getting any money out of this :p)

Re: Emu in process as a learning project - timing help?
by relaxok on 2018-06-23 (#220142)

Sour wrote:

relaxok wrote:

In FCEUX's log, that doesn't happen until the line on cpu tick 59679 / instruction 17053 - so 714 instructions later.

FCEUX is probably not the best emulator to be using to compare trace logs when it comes to the PPU's timing vs CPU. It's great for many things, but you shouldn't use it as your reference if you're trying to match the exact timings of the NES.

Mesen & Nintendulator both reach the instruction after the 2nd $2002 read loop ("8014 $A0 $FE LDY #$FE") at almost the same time (~57174 cpu cycles), which is essentially what you said you were expecting it to be. Bizhawk also has a trace logger (iirc) and should be essentially as accurate as those two, too.

Mesen's trace logger allows you to customize the trace log's output to be more or less whatever you need it to be, so that might help you if your trace log format is similar to FCEUX's, for example. This is a new feature that I just added, so you'll need to download this build if you want to try it out. If you're trying to debug your emulator, Mesen's debugging tools should be pretty useful in general, so you may want to take a look, if you have not yet. (Disclaimer: I'm Mesen's author, but I'm definitely not getting any money out of this :p)

Sorry I disappeared for a bit - thanks a TON for this. I'm going to stop FCEUX for now and check out Mesen instead and report back!

Re: Emu in process as a learning project - timing help?
by relaxok on 2019-06-26 (#240148)

Sour wrote:

relaxok wrote:

In FCEUX's log, that doesn't happen until the line on cpu tick 59679 / instruction 17053 - so 714 instructions later.

FCEUX is probably not the best emulator to be using to compare trace logs when it comes to the PPU's timing vs CPU. It's great for many things, but you shouldn't use it as your reference if you're trying to match the exact timings of the NES.

Mesen & Nintendulator both reach the instruction after the 2nd $2002 read loop ("8014 $A0 $FE LDY #$FE") at almost the same time (~57174 cpu cycles), which is essentially what you said you were expecting it to be. Bizhawk also has a trace logger (iirc) and should be essentially as accurate as those two, too.

Mesen's trace logger allows you to customize the trace log's output to be more or less whatever you need it to be, so that might help you if your trace log format is similar to FCEUX's, for example. This is a new feature that I just added, so you'll need to download this build if you want to try it out. If you're trying to debug your emulator, Mesen's debugging tools should be pretty useful in general, so you may want to take a look, if you have not yet. (Disclaimer: I'm Mesen's author, but I'm definitely not getting any money out of this :p)

It took me a long time to get back to this, but I'm finally using Mesen and have the output all setup to compare to mine and am making good progress. I was surprised there was no instruction count in the logging format. What is the best way to communicate with you in a semi regular fashion? I went to see if you're on #nesdev irc but not sure if you are. The issues so far have to do with the ppu tick totals around the nmi.

I also think I have some logging bugs for you that I was going to report on the github.

Great job on Mesen though, from what I see so far.

Re: Emu in process as a learning project - timing help?
by Sour on 2019-06-26 (#240203)

relaxok wrote:

I was surprised there was no instruction count in the logging format

Technically, the line number in the trace log is the same as the instruction count (assuming you log from power on), so I haven't really ever had a reason to keep track of it (emulation-wise, it has no impact on anything)

I haven't used IRC in about 20 years, so you won't find me there. I hop onto the discord linked in this thread from time to time, though.

There isn't really anything special about NMIs - they take 7 CPU cycles (iirc), so 21 ppu cycles or so.

Feel free the report any of the bugs you find on github!