Profiling: Where did my milliseconds go?!

Hello

Following on this thread: https://forum.xojo.com/45636-add-on-appgamekit-game-engine
I really want to get this work. And I’m bothered by the poor performance of image loading.

So I made a testcase:

I made 297 images, generated by the game engine I’m using. I also made a Xojo project that does a few things. Just fire the Xojo project up, select the folder where the images are, and it will start loading the files and do some counting and FPS calculation.
Basicly, I set up a timer on 16ms, about 60FPS, and load a new image on every action of that timer.

When I load the images from my SSD, I get about 23,5 FPS
When I load the images from my RAMDisk, I get about 25.5 FPS

Ok, there could be an explanation for that: It’s not the file loading that is slow, it’s the parsing that is slow. Perfectly possible, right? And who even runs 25 images per second, right? That’s not bad.

This could be, but there are 2 main problems:

  1. The images are generated (so, written, not read, should be slower) at about 120 FPS by an interpreted language.
  2. If you enable profiling, you can see that the timer only takes 1.6 ms to do it’s work.

But, but, I only get 23.5 FPS, so my timer isn’t fired every 16ms, it’s fired every 42.5 ms. That is a huge difference. That means my timer is waiting over 40ms on every call, and the profiler doesn’t give me any clue.

Do you guys have any clue?
You can download the project and images here: Imageloader.zip
If you have some time, can you fire it up, enable profiling, and push the Quit button after a few seconds?

There must be a simple explanation, but I’m scratching my head.

Thanks a bunch!

Timers fire when they can, not exactly on the time you specify. Period is more of a “no more than this frequently” setting than it is a “fire exactly now”

I do understand that. But as you can see the profiler, there is no reason why they wouldn’t be able to. Or there is something else the profiler can’t catch?

Also, if it only takes 1,6 milliseconds to complete a task, how DO I force it to fire at least 60 times a second, if a timer is not the way to go?

I can’t do loops as that would clog up the GUI.

Loading this from disk and expecting fast performance is kind of nuts. Load them into memory, first, and then display.

Not only that but the profiler itself introduces delays… it should not be used to measure direct execution time, but rather relative time… not that method “A” takes 0.01 seconds and method “B” takes 0.10 but that “B” takes 10x longer than “A”

I’ve had apps that ran “fine”… then when I turned on the profiler, they were super slow.

The act of observing an event, changes the event being observed

That’s what I’m doing with my RAMDisk.
This is a test case. In a normal situation, the image is streamed.

I think he did so here:
“When I load the images from my SSD, I get about 23,5 FPS
When I load the images from my RAMDisk, I get about 25.5 FPS”

The better question is why he can get 120fps with the interpreted language, yet is struggling to get 30fps with his Xojo code.

I can up the performance by setting the interval of the timer to 1. Than I get a 60-70 FPS. But that is not feasable on Windows, minimum timer time is about 15ms.

[quote=370606:@LangueR]I think he did so here:
“When I load the images from my SSD, I get about 23,5 FPS
When I load the images from my RAMDisk, I get about 25.5 FPS”[/quote]

Indeed, this clearly shows read/write is not the performance crusher here. Also, the method takes 1.6 ms. So that’s not clogging up the code, it’s something else.

Have you looked at disabling background tasks and such pragmas?

I did also think of this. But the interpreted language is doing the same (and more, because writing) 4 times faster. On the same machine.

[quote=370606:@LangueR]I think he did so here:
“When I load the images from my SSD, I get about 23,5 FPS
When I load the images from my RAMDisk, I get about 25.5 FPS”[/quote]
No. NOT the same thing. Look, any time you use Picture.Open(folder item) you are loading from disk, converting to a picture.

I did a quick mod at https://www.dropbox.com/s/z6tjqfzyfn8xmw5/ImageLoaderBKS.xojo_binary_project?dl=0

I’m loading those images into an array in the Window Open Event and then iterate through the array when drawing to a canvas. My timer period is 10 and looks pretty smooth. I’m running on a Mac but I wouldn’t expect a lot of difference on Windows.

[quote=370614:@Bob Keeney]No. NOT the same thing. Look, any time you use Picture.Open(folder item) you are loading from disk, converting to a picture.

I did a quick mod at https://www.dropbox.com/s/z6tjqfzyfn8xmw5/ImageLoaderBKS.xojo_binary_project?dl=0

I’m loading those images into an array in the Window Open Event and then iterate through the array when drawing to a canvas. My timer period is 10 and looks pretty smooth. I’m running on a Mac but I wouldn’t expect a lot of difference on Windows.[/quote]

Thanks for you input Mr Keeney. But I am aware that preloading them in memory will be faster than doing it realtime.
But this is just a testcase with pregenerated images. In my realworld example, the images are streamed, so they can’t be preloaded, as they don’t exist yet.

¯\(?)/¯ You might be using the wrong tool then. If you are looking for Fast loading and displaying of images then you’ve already found the bottleneck. I don’t see any way around it native to Xojo. You might be able to find something the MBS plugins that does it but otherwise you’re outta luck.

Something is weird here - if I build a compiled app (with profiling off) and then run it in two versions of Xojo:

  • 30fps in Xojo 2014 R2.1
  • 16fps in Xojo 2017 R3

Testing under macOS 10.12.6

The point is, Xojo is fast. But something is holding it back, and I have no idea what.

[quote=370624:@Michael Diehr]Something is weird here - if I build a compiled app (with profiling off) and then run it in two versions of Xojo:

  • 30fps in Xojo 2014 R2.1
  • 16fps in Xojo 2017 R3

Testing under macOS 10.12.6[/quote]

That is pretty interesting information indeed. Big difference!

I made a few more changes:

  • using Canvas1.paint instead of Imagewell

  • Canvas1.UseFocusRing, EraseBackground, and Transparent to False (see <https://xojo.com/issue/26903> for the rationale)

  • update the labels only once per second

  • set the timer period to 1

  • Built compiled apps, no profiling

The results:

  • 38fps using 114% CPU (Xojo 2014R2.1)
  • 80fps using 80% CPU (Xojo 2017R3)

So clearly Xojo 2017 R3 is better (more efficient) but there is something going on throttling the frame rate at longer timer periods in Xojo 2017R3 that is worse when compared to 2014R2.1.

I have 60fps or even more with pure xojo code, using images, spritesheets, atlas, sound, twening, mouse and keyboard inputs using canvas or opengl (the problem is the old support of opengl) you can have these FPS loading all into RAM (as all game kit have it), see animator example here.