Performance Profiler - A first attempt

Page 8/8
1 | 2 | 3 | 4 | 5 | 6 | 7 |

By aoineko

Master (140)

aoineko's picture

06-02-2021, 20:49

@Grauw: I'm not sure to understand how set the section ID.

Quote:

The first 256 sections are instrumented with I/O port 2CH, read with “in” to start the section and write with “out” to end it. The section number is specified as the MSB of the 16-bit I/O address, a little known Z80 feature (see the Z80 manual). With out (n),a and in a,(n) the section number is specified in register A, with out (c),r and in r,(c) in register B

What I understand is that we have to put the ID in the register A, but I don't understand how the profiler can retrieve this value while A will be overwritten by the "in" instruction. Should we do it like this:

ld    a, #myID
in    a,(2Ch)
...
the code I want to measure
...
ld    a, #myID
out   (2Ch),a
Bengalack wrote:

1. VSCode with z80 extensions (syntax highlighting + clock cycle and byte count)

I've had to test VSCode for a long time but I'm struggling to get rid of Notepad++. ^^

@Bengalack What VSCode extension are you using? I found several z80 extension (event a MSX z80 one)

By aoineko

Master (140)

aoineko's picture

07-02-2021, 14:37

@Grauw I tried the script you pointed out to me, but I can't get any output at all. I saw that DamnedAngel also uses the above assembler code in its library for profiling, so I guess it's the right method. But when I load my program into OpenMSX (with 1 frame start/end and some sections start/end), nothing shows up when I try the profile or profile_osd commands. Note that I get no errors when I load the profile.tcl script (I tried both loading it manually with the source command and putting it in the share/scripts directory).

Am I missing something? Any ideas?

EDIT: I'm using OpenMSX 16.0

By salutte

Master (132)

salutte's picture

07-02-2021, 16:34

Guys, the advanced profiler I was working on is not abandoned, but progress is very slow. I am on 5 MSX projects, and the profiler is currently third on the priority list. It still has a large number of missing features to be really usable and it is extremely slow when profiling very complex games (e.g., Metal Gear). But progress is still there. Just recently I added limited support for SYM files.

By Grauw

Ascended (9763)

Grauw's picture

07-02-2021, 18:36

aoineko wrote:

What I understand is that we have to put the ID in the register A, but I don't understand how the profiler can retrieve this value while A will be overwritten by the "in" instruction.

The way you show it is correct, the emulator script simply gets a signal when the I/O occurs, and it just reads the contents of the A register from the CPU. There is no actual real I/O happening.

(Incidentally, I believe even on a real MSX this would be possible, since during in/out(A) the contents of the A register is placed on the high bits of the address bus.)

The example you gave is correct.

By aoineko

Master (140)

aoineko's picture

07-02-2021, 21:26

Thank you for the explanation.

Any idea why the version of your script you pointed don't show any thing in OpenMSX 16.0? (https://hg.sr.ht/~grauw/neonlib/browse/tools/profile.tcl?rev...)

By Grauw

Ascended (9763)

Grauw's picture

08-02-2021, 00:12

No, I don’t think openMSX 16 should have broken it, my latest version has no issues with it either.

Are you sure you are loading it correctly? What if you put a puts Hello at the end of the code, does it show in the console when you load the script with source? Similarly, you can debug if e.g. the watchpoints are triggered correctly by putting puts in the body of the debug set_watchpoint command callbacks…

By aoineko

Master (140)

aoineko's picture

08-02-2021, 11:49

The "hello" is well displayed when loading the script (anyway, the new commands of the profiler are displayed with the "help" command).

So, I guess the problem comes from the binary file of my program. Here is a snippet of the generated assembler code (my source is in C). Is it correct?

;D:\Dev\Private\MSX\proj\samples\s_sprite.c:297: PROFILE_SECTION_START(10, 0);
	ld a, #(10) 
	in a,(#0x2C) 
;D:\Dev\Private\MSX\proj\samples\s_sprite.c:298: WaitVBlank();
	call	_WaitVBlank
;D:\Dev\Private\MSX\proj\samples\s_sprite.c:299: PROFILE_SECTION_END(10, 0);
	ld a, #(10) 
	out (#0x2C), a 

By Grauw

Ascended (9763)

Grauw's picture

08-02-2021, 12:55

It looks alright, but I’m not too familiar with the SDCC(?) asm syntax. The easiest way to check is to add puts debugging logs in the debug set_watchpoint command callbacks, see if they get triggered properly.

By Bengalack

Champion (367)

Bengalack's picture

08-02-2021, 19:27

I mostly use the "profile::section_scope_bp", but I have used profile sections like that once. I got timings, but did never get a proper name in the overlay - but it didn't matter, the timings was there. Not sure if the instructions were correct though :-)

Inline C, I started with:

__asm 
    ld a, #254
    out ( #0x2c ), a
__endasm;

And after the block, inline C:

__asm 
    ld a, #254
    out ( #0x2d ), a
__endasm;
Page 8/8
1 | 2 | 3 | 4 | 5 | 6 | 7 |