Performance Profiler - A first attempt

By Sandy Brand

Expert (108)

Sandy Brand's picture

27-04-2015, 01:22

(Continued from receiving-debugdevice-stdout-or-stderr-messages-through-socket-connection)

Hello everyone,

I needed to get a better understanding of why the performance of my current project was not so good and came to the conclusion that I needed some tools to be able to profile the application while it is running in the openMSX emulator. As a result I wrote a fairly straightforward application using C# (UI) and some C++ (setting up socket connections and such) that can interface with openMSX and listen in on some special events that are generated through injection of special pieces of profiling code (for more information on how this is done I refer you to the documentation).

Although the resulting profiler is certainly not perfect, it suffices for my current needs and I can now spent my limited amount of time on other things again. This means I will probably not be able to support the further development of the tool, but I think it might still be very useful for other coders. This is why I want to make the tool available to all, also hoping that it may provide a first tentative step into writing a full-scale profiler for openMSX at some point in the future.

You can find the Windows binaries here, including some documentation and some examples on how to use/configure the profiler:

Google Drive: openMSX_Profiler_0.11.rar

Again, many thanks to all the people that helped with the TCL scripting side! I think it is fantastic that the MSX scene is still going strong, and it feels good to be actively contributing to it again after such a long time! :)

Login or register to post comments

By Manuel

Ascended (13469)

Manuel's picture

27-04-2015, 15:39

Great to read this Sandy! Congratulations Smile

By Grauw

Enlighted (6255)

Grauw's picture

27-04-2015, 16:27

Very interesting, the profiler.html document and examples in the archive elaborate on the methodology and are pretty extensive.

In my code I often enclose my procedures in PROC / ENDP markers (a Glass assembler feature), mostly for the purpose of introducing a local scope for labels, however I’m also thinking whether I could perhaps use this to aid with profiling.

p.s. Is the source code available somewhere? I don’t use Windows, and I spot a BSD license Wink.

By ARTRAG

Enlighted (5887)

ARTRAG's picture

29-04-2015, 22:00

Very interesting! going to test it very soon. Thanks for releasing, if you do not plan to maintain and extend the project, it could be a good thing to release the source as open

By Grauw

Enlighted (6255)

Grauw's picture

06-04-2017, 18:50

For measuring function performance in gunzip I made this profiler script: profile.tcl

It’s not a fully automated profiler, you have to manually set it up to profile a single function in a run, but it’s easy to set up/use, and produces useful output. It counts the time spent between two specific out instructions, and in the console you can issue a command to report the time spent. With it, I produced this data.

By sd_snatcher

Prophet (2577)

sd_snatcher's picture

06-04-2017, 03:41

Sorry, Graw, but I couldn't get how to use it.

1) I copied the profile.tcl to the openmsx/scripts folder
2) I included the OUT (2Ch),a before my function and the OUT (#2D) after it
3) When I run the profiler script without parameters in the console, it gives me a time and a counter. Every time I run the profiler script, the time and the counter increase. "Time" started with 0.09 and after many runs its already at 41.04.

How exactly am I supposed to interpret this?

By Grauw

Enlighted (6255)

Grauw's picture

06-04-2017, 18:39

It measures the total time spent (in seconds) between the block specified by the OUTs from the start of emulation, and how often it has encountered the block. Type the profile command to get the current results. If the ignored count goes up it means your code isn't fully enclosed.

Sounds like your function is looping. If you want an average, divide the total time by the count.

If you want to know the running time during a certain period, simply invoke profile twice and subtract the numbers.

If you want the numbers during a single frame, remember openMSX has commands to pause and run for one frame that you can use.

If you want a number of Z80 clock cycles, multiply time by 3579544.

By sd_snatcher

Prophet (2577)

sd_snatcher's picture

07-04-2017, 01:59

Thanks! I'll try again.

By santiontanon

Champion (391)

santiontanon's picture

11-04-2017, 05:23

I have been using a customized version of Grauw's script for profiling my code for a few months and it works very well! My edited version is here: https://dl.dropboxusercontent.com/u/3303662/profile.tcl

By Grauw

Enlighted (6255)

Grauw's picture

06-08-2017, 18:01

I updated my profiler script for openMSX: profile.tcl

New features:

  • Profile up to 257 sections at once
  • Frame synchronisation
  • OSD display

Note that the usage instructions changed a little.

My MSX profile